pajama

The partnum column in systables indicates the identification of the table inside a dbspace, when the value of partnum is zero, this means that it is a :

• fragmented table
• view
• synonym

You notice that long running sessions have large memory pools allocated (can be up to several gigabytes).

onstat -g ses

session                                      #RSAM    total      used       dynamic 
id       user     tty      pid      hostname threads  memory     memory     explain

<...>
229697969 user1 -        -1       192.168. 1        94208      87480      off 
229694677 user3 162      21785    host1    1        7140388864 946472     off 
229673199 user5 -        29050    host1    1        118784     92752      off 
229668414 user1 -        -1       192.168. 1        131072     107280     off 
229667792 user1 -        -1       192.168. 1        102400     69608      off 
229667782 user1 -        -1       192.168. 1        106496     85304      off 
229667776 user1 -        -1       192.168. 1        94208      87480      off 
229657782 user6 494      11416    host1    1        102400     71400      off 
229634560 user2   -        -1       192.168. 1        94208      67504      off 
229630635 user1 -        -1       192.168. 1        131072     107280     off 
229630075 user1 -        -1       192.168. 1        102400     69608      off 
229630064 user1 -        -1       192.168. 1        106496     85304      off 
229630055 user1 -        -1       192.168. 1        94208      87480      off 
229626281 user7 406      125      host1    1        139264     76040      off 
229623552 user5 -        25571    host1    1        471040     399904     off 
229617823 user8  -        6118     host1    1        798720     693920     off 
229612008 user4  -        -1       192.168. 1        90112      67472      off 
229611119 user4  -        -1       192.168. 1        90112      67472      off 
229605475 user9   951      7697     host1    1        348160     121784     off 
229588448 user10 1207     28006    host1    1        737280     521296     off 
229578372 user4  -        -1       192.168. 1        90112      67448      off 
229576124 informix -        29244    host1    2        131670016  129610816  off 
229565621 user1 -        -1       192.168. 1        131072     107280     off 
229565020 user1 -        -1       192.168. 1        102400     69608      off 
229565011 user1 -        -1       192.168. 1        106496     85664      off 
229565004 user1 -        -1       192.168. 1        94208      87480      off 
229546565 user2   -        -1       192.168. 1        94208      67504      off 
229531732 user2   -        -1       192.168. 1        98304      90568      off 
229531707 user2   -        -1       192.168. 1        94208      84976      off 
229519448 user3 154      19733    host1    1        753565696  30887704   off 
229512098 user3 133      16367    host1    1        851968     626672     off 
<...>

However, when you look at the session information, most of the allocated memory is shown as free.

onstat -g ses 229519448 

session           effective                            #RSAM    total      used       dynamic 
id       user     user      tty      pid      hostname threads  memory     memory     explain 
229519448 billproc -         154      19733    mobis    1        753565696  30887704   off 

Program :
-

tid      name     rstcb            flags    curstk   status
241358080 sqlexec  9a0ea1170        --BPR--  11263    ready-

Memory pools    count 3
name         class addr              totalsize  freesize   #allocfrag #freefrag 
229519448    V     80cb19040        753258496  722660672  604        31        
229519448*O  V     7e51bd040        12288      9000       1          3         
229519448_S  V     7eed67040        294912     8320       29         3         

But in time, the amount of allocated memory keeps growing which may result in additional segments allocated for the virtual portion of shared memory.

online.log

<...>
13:35:08  Maximum server connections 2943 
13:35:08  Checkpoint Statistics - Avg. Txn Block Time 0.004, # Txns blocked 63, Plog used 1561232, Llog used 180616

13:35:14  Requested shared memory segment size rounded from 409600KB to 425984KB
13:35:15  Dynamically allocated new virtual shared memory segment (size 425984KB)
13:35:15  Memory sizes:resident:27820032 KB, virtual:9899008 KB, no SHMTOTAL limit
13:35:15  Segment locked: addr=987000000, size=436207616
13:35:50  Requested shared memory segment size rounded from 409600KB to 425984KB
13:35:50  Dynamically allocated new virtual shared memory segment (size 425984KB)
13:35:50  Memory sizes:resident:27820032 KB, virtual:10324992 KB, no SHMTOTAL limit
13:35:50  Segment locked: addr=9a1000000, size=436207616
<...>

Having DONTDRAINPOOLS environment variable set on server's startup changes behavior of Informix memory manager to keep the memory in the local session and not release it back to the main memory pool until that session terminates and frees its pool.

Run 'onstat -g env' and see if the DONTDRAINPOOLS environment variable was set on startup:

Server start-up environment:

Variable Value [values-list]
DBDATE dmy4
DBDELIMITER |
DBMONEY .
DBPATH .
DBPRINT lp -s
DBTEMP /tmp
DONTDRAINPOOLS 1
IGNORE_UNDERFLOW 1
INFORMIXCONRETRY 1
INFORMIXCONTIME 10
INFORMIXDIR /informix/mobserver/inf11
<...>

Check messages in online.log file produced during server's startup if there is a message like "Server is disabling pools draining".

- You can run 'onmode -F' to free allocated memory.

- Unset DONTDRAINPOOLS environment variable and restart the Informix server.

When executing SQL like below:

Example:
unload to x.unl select tabname, "" from systables where tabname = "tab1" 

The output file contains:
tab1|\ |

It is expected behavior as NULL cannot be represented by "", because IBM Informix considers this an empty string internally.

Use one of the following workarounds to get || instead of |\ | :

1) SELECT NULL::CHAR FROM table


or

2) SELECT CAST(NULL AS CHAR) FROM table



This simply defines the data type of the result set to return to the client.

Example:

unload to tab1.unl select tabname,CAST(NULL AS CHAR) from systables where tabid = 99;

1 row(s) unloaded.

> !cat t1.unl
VERSION||

or

> unload to t1.unl select tabname,NULL::CHAR from systables where tabid = 99;

1 row(s) unloaded.

> !cat tab1.unl

You see messages in online.log. something similar to these:

04:15:08  sid 2011976 username sanjju@linux12 pid 2566 terminated.
04:15:08   killed(MCMD_KILL)

You will see such messages in online.log when someone kills session(s) either manually, or through some maintenance script, by running onmode -z.

Other scenarios where we can see these messages in online.log is when informix server kills sessions internally. Situations where server could be killing sessions internally are like, when the server is switching to a single user mode, or when it is shutting down.

Also, with newer version of Informix server (11.50.xC9, or 11.70.xC4 and higher versions) that supports Low Memory Management feature and has the feature enabled with a defined threshold, you can see sessions getting killed internally after the instance enters the defined threshold for low memory.

You can run 'onstat -g lmm' and review the output. This should list the sessions, if any were killed due to enabling of low memory management feature. For more information on this command, please check the link given in the "Related Information' section of this document.

Two new onstat commands introduced in 12.10.xC2 to view the dependencies between blocking and waiting threads. A running threads take ownership of various objects and resources; for example, buffers, locks, mutexes, decision support memory etc. Contention for these resources among hundreds or thousands of threads can result in chains of dependencies.

Now, you can use the 'onstat -g bth' command to display the dependencies between blocking and waiting threads. Next, use the 'onstat -g BTH' command to display session and stack information for the blocking threads.

Here is a scenario where these onstat commands can be helpful. It possible a thread that is blocked waiting to enter a critical section might own a row lock for which another thread is waiting. The second thread might be blocking a third thread that is waiting in the MGM query queue. Usually, the duration of such contention is short and user never notice any problem. However, if a thread is blocked long enough, you might need to identify the source of the contention. The 'onstat -g bth' command discovers the chains of dependency and displays blocker threads followed by waiting threads, in order.

The following is a sample output of the 'onstat -g bth' command where multiple threads are waiting on resources.

Highest level blocker(s)
 tid      name                 session
 48       sqlexec              26

Threads waiting on resources
 tid      name                 blocking resource              blocker
 49       sqlexec              MGM                            48
 13       readahead_0          Condition (ReadAhead)           -
 50       sqlexec              Lock (0x4411e578)              49
 51       sqlexec              Lock (0x4411e578)              49
 52       sqlexec              Lock (0x4411e578)              49
 53       sqlexec              Lock (0x4411e578)              49
 57       bf_priosweep()       Condition (bp_cond)             -
 58       scan_1.0             Condition (await_MC1)           -
 59       scan_1.0             Condition (await_MC1)           -

In the above example, four threads are waiting for a lock that is owned by thread 49. However, that's not the actual problem. The thread 49 is waiting for MGM resources that are owned by thread 48. So, originally problem started with the thread 48. Next, run the 'onstat -g BTH' command to see the session and stack information of thread 48. Following is the example for 'onstat -g BTH' output:

Stack for thread: 48 sqlexec
 base: 0x00000000461a3000
  len:   69632
   pc: 0x00000000017b32c3
  tos: 0x00000000461b2e30
state: ready
   vp: 1

0x00000000017b32c3 (oninit) yield_processor_svp
0x00000000017bca6c (oninit) mt_wait
0x00000000019d4e5c (oninit) net_buf_get
0x00000000019585bf (oninit) recvsocket
0x00000000019d1759 (oninit) tlRecv
0x00000000019ce62d (oninit) slSQIrecv
0x00000000019c43ed (oninit) pfRecv
0x00000000019b2580 (oninit) asfRecv
0x000000000193db2a (oninit) ASF_Call
0x0000000000c855dd (oninit) asf_recv
0x0000000000c8573c (oninit) _iread
0x0000000000c835cc (oninit) _igetint
0x0000000000c72a9e (oninit) sqmain
0x000000000194bb38 (oninit) listen_verify
0x000000000194ab8a (oninit) spawn_thread
0x0000000001817de3 (oninit) th_init_initgls
0x00000000017d3135 (oninit) startup



Highest level blocker(s)
 tid      name                 session
 48       sqlexec              26      

session          effective                  #RSAM    total   used   dynamic
id      user     user  tty   pid   hostname threads  memory  memory explain
26      informix -     45    31041 darwin   2        212992  186568 off

Program :
/usr/informix/bin/dbaccess

tid      name     rstcb            flags    curstk   status
48       sqlexec  448bc5e8         ---P---  4560     ready-
58       scan_1.0 448bb478         Y------  896      cond wait  await_MC1 -

Memory pools    count 2
name         class addr          totalsize  freesize   #allocfrag #freefrag
26           V     45fcc040      208896     25616      189        16        
26*O0        V     462ad040      4096       808        1          1        

name           free      used           name           free       used      
overhead       0         6576           mtmisc         0          72        
resident       0         72             scb            0          240      
opentable      0         7608           filetable      0          1376      
log            0         33072          temprec        0          17744    
blob           0         856            keys           0          176      
ralloc         0         55344          gentcb         0          2240      
ostcb          0         2992           sqscb          0          21280    
sql            0         11880          xchg_desc      0          1528      
xchg_port      0         1144           xchg_packet    0          440      
xchg_group     0         104            xchg_priv      0          336      
hashfiletab    0         1144           osenv          0          2520      
sqtcb          0         15872          fragman        0          1024      
shmblklist     0         416            sqlj           0          72        
rsam_seqscan   0         368            

sqscb info
scb              sqscb          optofc   pdqpriority optcompind  directives
4499c1c0         461c1028       0        100         2           1        

Sess       SQL          Current       Iso Lock       SQL  ISAM F.E.
Id         Stmt type    Database      Lvl Mode       ERR  ERR  Vers  Explain    
26         SELECT       stores        CR  Not Wait   0    0    9.24  Off        

Current statement name : unlcur

Current SQL statement (5) :
  select * from systables,syscolumns,sysfragments

Last parsed SQL statement :
  select * from systables,syscolumns,sysfragments

• Large buffers, which are used for large read and write I/O operations
• Sort-space pools
• Active thread-control blocks, stacks, and heaps
• User-session data
• Caches for SQL statements, data-dictionary information, and user-defined routines
• A global pool for network-interface message buffers and other information

During the Informix instance start you will see following types of error messages in the instance message log and the instance will not come online:

13:23:26  Assert Failed: No Exception Handler
13:23:26  IBM Informix Dynamic Server Version 11.70.FC7W2
13:23:26   Who: Thread(134, kaio, 0, 16)
  File: mtex.c Line: 490
13:23:26   Results: Exception Caught. Type: MT_EX_OS, Context: mem
13:23:26   Action: Please notify IBM Informix Technical Support.
13:23:26   See Also: /tmp/af.46e0eae, shmem.46e0eae.0

The af.<xxxxxx> file will contain an empty stack trace of the kaio thread; the si_signo value of 11 will indicate the SEGV signal received by the oninit process:

13:23:26  Stack for thread: 134 kaio

 base: 0x0000000146f02000
  len:   69632
   pc: 0x0000000101103350
  tos: 0x00000001019ff751
state: running
   vp: 22

 ucontext: 0x0000000101a00a20
  siginfo: 0x0000000101a00d00
           si_signo: 11  si_code: 1   si_errno: 0 si_pid: 0 si_uid: 0
           si_addr: 0x0000000001057d68 si_value: 0x0000000000000000  si_fd: 0

One of the possible causes of the problem is following Oracle Solaris defect:

15815250 : SUNBT7197575 AUTOMOUNTD FAILS TO MOUNT LDAP USERS HOME DIR on SOLARIS 10 BRANDED

Contact the Oracle Solaris support and ask them for following fix:

IDR-fix idr781.1 for Solaris 11.1.8.4

INTRODUCTION

This document describes a technique that can help you rebuild a table based on the data that might be still accessible. It uses the concept of the ROWIDs and the UNLOAD command.

Attention: This technique only saves rows that are still accessible. Damaged rows are lost.

Note: The technique will not work for fragmented tables, because they do not have rowids.

1. Use the UNLOAD command to extract the accessible rows from the table. This command will fail when the first corrupted row is encountered:

UNLOAD TO file1 SELECT rowid, * FROM table ;

file1  
File name where the data is going to the stored

table
Name of the source table

2. Open file1 and take note of the last ROWID that was unloaded successfully:

last_rowid = Last ROWID in file1

3. Add two units to the last_rowid. You will use this value in the next step:

next_rowid = last_rowid + 2

4. Run the UNLOAD command again, this time to retrieve the remaining rows of the table using the next_rowid as the filtering argument:

UNLOAD TO file2
SELECT rowid, * FROM table where rowid >= next_rowid

Note: If UNLOAD fails without producing any data, skip another rowid by increasing next_rowid. You might have to repeat steps 2, 3 and 4 many times depending on the quantity of corrupted rows. There are some scenarios where this technique can be very time-consuming.

5. After unloading all possible rows, repeat steps 1 and 2, this time without selecting the rowid in the column list of the SELECT statement.

UNLOAD TO file1 SELECT * FROM table ;
UNLOAD TO file2
SELECT * FROM table where rowid >= next_rowid

6. Recreate the table using the data that was just unloaded.

LOAD FROM file1 INSERT INTO table;
LOAD FROM file2 INSERT INTO table;

1. oncheck reported an error in the table customer. Run the first UNLOAD command until it fails.

UNLOAD TO file1 SELECT rowid, * FROM customer;

2. Suppose the last rowid found in the last record on file1 is decimal 1038:

last_rowid = 1038

3. Add two units to last_rowid :

next_rowid = (last_rowid + 2) = 1040

4. Using this calculation, restart the unload on rowid 1040:

UNLOAD TO file2
SELECT rowid, * FROM customer where rowid >= 1040;

5. Repeat this process until you scan the whole table. Assuming that the second UNLOAD command finished without errors, the next step is to run the same commands again without the rowid.

UNLOAD TO file1 SELECT * FROM customer;
UNLOAD TO file2
SELECT * FROM customer where rowid >=1040;

6. Recreate the table and load the data using file1 and file2 as input files:

LOAD from file1 insert into customer;
LOAD from file2 insert into customer;

Messages similar to the following will be displayed in the Message.log on Primary HDR server.

R: Needed to send a ping message but failed. 1
12:31:25 Logical Log 358 Complete, timestamp: 0x20c592c5.
12:31:27 DR: Needed to send a ping message but failed. 1
12:32:28 DR: Needed to send a ping message but failed. 1
12:33:11 Logical Log 359 Complete, timestamp: 0x20ca1170.
12:33:28 DR: Needed to send a ping message but failed. 1
12:33:59 DR: Needed to send a ping message but failed. 1
12:34:29 DR: Needed to send a ping message but failed. 1
12:35:06 Logi

This is strictly a new Warning message developed and released in IDS 11.70.xC7.

This message is displayed when the HDR buffer starts to backup and fill. This is usually evident of a very Busy system and no cause for alarm.

Monitor these Warnings. If the numeric value in the Warning message reaches a value of 3 or greater, possible Ping Time-out errors could start to occur.