pajama

PROBLEM

There is an undocumented limitation in IBM® Informix Server™ that sets the maximum number of transactions opened at checkpoint time. If this limit is exceeded, the instance will stop

If the number of open transactions open at checkpoint time exceeds certain number (This number is dependant of the Logical Log Buffer Size), the instance will stop. You can check that the Assert Failure File will show this message:

14:51:48  log_put( OLDRSAM:66, 35052): log record too long
logrec
Bc87a2044: 000088ec 00000042 00000010 00000000 .......B ........
Bc87a2054: 00000001 01c72018 09bae247 00000000 ...... . ...G....

15:24:55  Checkpoint log record may not fit into the logical log buffer.
Recommended minimum value for LOGBUFF is 36.

36 + 24xN bytes

• TAPEBLK is set too low in the onCONFIG to take full advantage of the device's I/O throughput potential.
• The actual I/O speed is lower than the expected I/O speed of the devices used.
  
• Not enough resources available on computer like CPU, memory, and so on. The system might be busy.

• Run a timed test to determine approximate speed of I/O from a chunk to the backup device . Run the dd command with a block size (bs) equal to the block size value for TAPEBLK in the onCONFIG. Try to use a chunk that is at least 2 GB.
  
  Note: This test might not work on a running instance because of an OS lock on the chunk that will not allow the dd command to run. If you cannot run the dd command on an actual chunk then you must use or create a file which resides in the same location as the chunks ( the same directory, same disk, same NFS mount, same SAN, and so on ). This is critical for this test to yield accurate timings.
  
  Here is the command:
  
  timex dd if=/full/path/to/informix/chunk of=/full/path/to/backup_directory/timetest.out bs=128k
  
  
  Here is an actual example:
  
  timex dd if=/informix/chunks/rootdbs of=/informix/backups/timetest.out bs=256k
  586+1 records in
  586+1 records out
  
  real 7.76
  user 0.00
  sys 0.48
  
  This dd test shows the speed for this backup would be about 18.9 MB/second or 66.4 GB/hour. This would be the approximate speed of ontape I/O with some consideration for ontape overhead.

• Capture and review the ontape function stacks to find out exactly what ontape is doing. Soon after you start the ontape backup you should see these 3 threads listed in the onstat -g ath output:
  
  ontape
  arcbackup1
  arcbackup2
  
  The output will be similar to this:
  
  ...
  213  41dac918  40347be0  1   cond wait  netnorm  1cpu   ontape
  214  41980a28  40348c50  1   IO Wait             1cpu   arcbackup1
  215  41980c88  40344a90  2   sleeping secs: 1    1cpu   arcbackup2 
  
  To get the stack trace from each thread you will need to 3 separate commands. The first column of the onstat -g ath output is the thread id. Using the example output from above you would run these commands to continuously capture stack information for each of the 3 threads every 5 seconds:
  
  onstat -g stk 213 -r > ontape.out
  onstat -g stk 214 -r > arcbackup1.out
  onstat -g stk 215 -r > arcbackup2.out
  
  You can run these in the background or in 3 separate windows. Stop them when the backup is complete.

• Increase the value of the onCONFIG configuration parameter TAPEBLK. If using a tape device, then use the device's suggested maximum block size. If writing the backup to disk, then continue increasing TAPEBLK on subsequent backups until you reach the point where increasing TAPEBLK does not decrease time to complete the backup ( you could start at 128 then go to 256, 512, 1024, and so on ).

• Use faster backup device or find ways to increase I/O of that device. Some examples:
  
  • use a faster tape drive or a tape that can handle higher I/O speeds
  • backup to local disk then ftp the backup to a SAN

• Collect ontape thread stack traces and analyze or send to technical support for analysis.

The database server is blocked with a checkpoint request that never finishes. User sessions are only able to perform read operations and any update, delete or insert operations will hang. 

When you run the onstat - command, the output shows that the database server is Online, but blocked on a checkpoint request:  

• There is a message in the online.log file that says:

• The output of the onstat -d command shows one or more dbspaces marked as down (indicated by a D in the flags column). Any dbspace marked as down will have all its chunks marked as down as well.

When one or more dbspaces become unavailable and the configuration parameter ONDBSPACEDOWNis set to 2, the database server will prevent any further updates to the database and waits for intervention from the database administrator.

There are two reasons why the database server will mark a dbspace as down:

1. The database server has been unable to access the primary chunk of a dbspace and its mirror chunk either does not exist or is not accessible.

2. The database server has detected corruption within the chunk. The database server will mark the chunk as down to help preserve the integrity of the database.

There are two possible solutions available. 

• Run onmode -O (Override)

The database server will issue a checkpoint and will then be available for use. The down dbspaces will continue to be disabled and will only become available if they are restored from archive. 

Important: This action can not be reversed as information about down dbspaces is written to the reserved pages of the database server. 

1. There will be a message on the screen after issuing the onmode -O command:



2. Press the keys y+Enter to confirm or press the keys n+Enter to cancel.

• Run onmode -ky (Shutdown)

The database server will stop without issuing a checkpoint and information about down dbspaces will not be written to the reserved pages of the database server.

• There will be a message on the screen after issuing the onmode -ky command (except for versions 9.21x and 7.30x):



• There will be also a message in the online.log (except for versions 9.21x and 7.30x):

If you seem to have sluggish performance during peak I/O usage times or see a message in the online.log that says:

KAIO out of OS resources errno = 11

or

*** _aiowrite() returning EAGAIN ***

To lower the number of concurrent KAIO requests to 512 from the default of 1024 : 

$  export IFMX_AIXKAIO_NUM_REQ=512

Query response time becomes longer and longer for all queries.

Overuse of PDQ feature.

Find there are many sessions were accumulated in PDQ queue.

onstat -g mgm

IBM Informix Dynamic Server Version 11.50.FC4 -- on-Line -- Up 18:04:23 -- 16821136 Kbytes

Memory Grant Manager (MGM)
--------------------------

MAX_PDQPRIORITY: 50
DS_MAX_QUERIES: 32000
DS_MAX_SCANS: 1048576
DS_NONPDQ_QUERY_MEM: 1024 KB
DS_TOTAL_MEMORY: 4096000 KB

Queries: Active Ready Maximum
205 42 32000

Memory: Total Free Quantum
(KB) 4096000 0 128

Scans: Total Free Quantum
1048576 1048374 1

Load Control: (Memory) (Scans) (Priority) (Max Queries) (Reinit)
Gate 1 Gate 2 Gate 3 Gate 4 Gate 5
(Queue Length) 1 0 41 0 0

Active Queries:
---------------
Session Query Priority Thread Memory Scans Gate
22 700000228709438 25 700000227c24028 0/0 1/1 -
42 70000022804fbf8 25 700000227ff5970 0/0 1/1 -
43 700000228a9fbf8 25 7000002280a7a30 0/0 1/1 -
44 700000228b53bf8 25 700000228b09028 0/0 1/1 -
45 700000228c08bf8 25 700000228bbd028 0/0 1/1 -
46 700000228cbcbf8 25 700000228c60310 0/0 1/1 -
47 700000228d70bf8 25 700000228d145b0 0/0 1/1 -
48 700000228e24bf8 25 700000228dc8850 0/0 1/1 -
49 700000228ed8bf8 25 700000228e7cb38 0/0 1/1 -
50 700000228f8cbf8 25 700000228eebd70 0/0 1/1 -
51 700000229041bf8 25 700000228ff6028 0/0 1/1 -
52 7000002290f5bf8 25 700000229099280 0/0 1/1 -
53 7000002291a9bf8 25 700000229151610 0/0 1/1 -
54 700000229205bf8 25 7000002291bb028 0/0 1/1 -
55 70000022930dbf8 25 70000022926f028 0/0 1/1 -
57 700000229422bf8 25 7000002293c6280 0/0 1/1 -
58 7000002294d6bf8 25 70000022947a460 0/0 1/1 -
59 70000022958abf8 25 70000022952e658 0/0 1/1 -
60 70000022963ebf8 25 7000002295e2850 0/0 1/1 -
......

1. Set PDQPRIORITY lower in application, especially in OLTP environment.

2. If no time to change the application, we can turn off the PDQ feature by setting MAX_PDQPRIORITY to 0 in onconfig or execute onmode -D 0 without need to restart the server.

These are the common causes, there could be others:

• Slow I/O ( Informix or disk )
• Too many indexes
• Indexes need to be reorganized
  

1. Find free space in the table for the row.
2. Insert row into table.
3. Read through index keys to find the slot for the new index key.
4. Insert new key into index. This leads to index page splits which 
   

• indexes grow larger
• index has many extents
• duplicate values exist in the index

Slow I/O 

Slow I/O can typically be seen by examining onstat -g ioq output or by using the dd command on UNIX/Linux.

onstat -g ioq:

Look at the maxlen column of onstat -g ioq. Generically speaking, if you use aio and you see maxlen at 25 or greater that indicates you need more aio vps.
dd ( UNIX/Linux ):


Determine the potential speed of the disk. Copy a file that is at least 1 GB in size to the disk using dd. If the dd copy is significantly slower than what is expected from the disk specifications then that could easily cause inserts ( and any other operations ) to run slowly. Run man dd for the syntax. Here is an example:

dd if=/path/to/1GB/file.test of=/path/to/slow/disk/file.test


Too many indexes

Are all the indexes used? 
Could indexes be consolidated and queries rewritten in a way to use 1 index instead of 3?


Indexes need to be reorganized

If the index has many extents which are physically sitting all over on a disk there will be more time associated with I/O as the disk controller moves all over the disk. Use this query to return the number of extents a specific named index has:

SELECT a.dbsname,a.tabname,count(*) num_of_extents,sum(b.pe_size)
total_size 
FROM systabnames a,sysptnext b 
WHERE a.partnum = b.pe_partnum 
AND a.tabname[1,3]!='sys' 
AND a.tabname!='TBLSpace' 
AND a.dbsname[1,3]!='sys' 

and a.tabname ="index_name" 

GROUP BY 1, 2 
ORDER BY 3 desc,4 desc

Slow I/O

Add more aio vps ( see onmode -p, VPCLASS, NUMAIOVPS, AUTO_AIOVPS ) or troubleshoot slow disk I/O problems with the help of your system administrator.


Too many indexes

Drop and consolidate as many indexes as possible. Make sure you rewrite queries to take advantage of the new indexes. Here is an example:

Some of these indexes should be consolidated to reduce the number of indexes. Look at these 4 indexes on table slowio:

create index index1 on slowio (col4) using btree;
create index index2 on slowio (col1,col2,col4) using btree;
create index index3 on slowio (col1,col4) using btree;
create index index4 on slowio (col4,col2,col3) using btree;

create index consolidate_idx on slowio (col4, col1, col2, col3) using btree;

select ... where col4 ...;
select ... where col4 ... and/or col1 ...;
select ... where col4 ... and/or col1 ... and/or col2 ...;
select ... where col4 ... and/or col1 ... and/or col2 ... and/or col3 ...;

select ... where col1 ...;
select ... where col3 ...;
select ... where col4 ... and/or col2 ...;
select ... where col4 ... and/or col3 ... and/or col2 ... and/or col1 ...;