pajama

If a log file is archived and contains no open transactions, the DB2 database manager does not delete the file but renames it as the next log file when such a file is needed. This process improves performance because creating a new log file instead of renaming the file would require all pages to be written out to guarantee that the necessary disk space or other storage space is available.

The database manager retains up to 8 extra log files in the active log path for renaming purposes.

Aim is that there is existing log file can be used to rename when high workload comes:
(1) at that point the log consumption will become very quickly.
(2) creating new log file is a high cost operation since DB2 need to write to log file in advance, otherwise, the disk space may not be actually allocated to DB2.

You can collect "db2pd -db <database> -dpsdbcb" data.

Please provide the output file of db2pd command to IBM DB2 Service to check rename array for confirmation.

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

When the history information is not available for a backup image, the db2ckbkp utility can be used to identity if the backup was taken online or offline, and which logs are needed to rollforward the database.

You can use the db2ckbkp utility with the -h option and look for the "Backup Mode" parameter in the media header information. If the "Backup Mode" parameter is set to "0", the backup was taken offline; if it is set to "1", the backup was taken online. Furthermore, in case of an online backup, you can see if the logs are included by looking at the "Includes Logs" parameter.

=====================
MEDIA HEADER REACHED:
=====================
Server Database Name           -- SAMPLE
Server Database Alias          -- SAMPLE
Client Database Alias          -- SAMPLE
Timestamp                      -- 20100730130237
Database Partition Number      -- 0
Instance                       -- db2inst1
Sequence Number                -- 1
Release ID                     -- D00
Database Seed                  -- A05E5954
DB Comment's Codepage (Volume) -- 0
DB Comment (Volume)            --                               
DB Comment's Codepage (System) -- 0
DB Comment (System)            --                               
Authentication Value           -- -1
 Backup Mode                    -- 1
 Includes Logs                  -- 1
Compression                    -- 1
Backup Type                    -- 0
Backup Gran.                   -- 0
Status Flags                   -- 20
System Cats inc                -- 1
Catalog Partition Number       -- 0
DB Codeset                     -- UTF-8
DB Territory                   -- 
LogID                          -- 1279748926
LogPath                        -- /home/db2inst1/db2inst1/NODE0000/SQL00001/SQLOGDIR/
Backup Buffer Size             -- 524288
Number of Sessions             -- 1
Platform                       -- 12


If the backup was taken online, you can use the db2ckbkp utility with the -l and -o options to identify which logs are required to rollforward the database. Under the LOG.FILE.HEADER section, the "Head Extent ID" line will give you the first log the first log required, and the second number on the "Backup End Marker" will give you the last log required.

BufAddr  PoolID Token Type     Offset   FileSize ObjectSize   OrigSize Object Name
-------- ------ ----- ---- ---------- ---------- ---------- ---------- -----------
00000000:     0     0    8          0      12288      12288          0 "LOG.FILE.HEADER"

          Consistency Counter one = 2245
               Log Format Version = 10
                  Database Log ID = 1279748926
      Number of Primary Log Files = 10
    Number of Secondary Log Files = 2
                    Log File Size = 32
           Transaction Table Size = 128
                          baseLso = 43857761
                       lowtranlsn = 0000000002A431DC
                       minbufflsn = 0000000002A18528
                          headlsn = 0000000002A18528
              hdrSNextExtToRename = 0
                   Head Extent ID = 55
            Last Commit Timestamp = 0  1970-01-01-00.00.00 GMT
                   Last Extent ID = 1280505751
                         Base TID = 00000000038B
                    Database seed = 2690537812
         Log Chain Wrap Indicator = 0
                    rawLogDevSize = 0
                 rawLogHeadExtNum = 0
               Past Log File Size = 32, starting from extent 0
               Past Log File Size = 0, starting from extent 0
               Past Log File Size = 0, starting from extent 0
                    Log File Path = Default
                   Dual Log Flags = 00000000
             Mirror Log File Path = 
                         Last CId = 1280505739
          Soft checkpoint maximum = 131072
                   Log File Flag1 = 00004020
                   Log File Flag2 = 00000000
                   Log File Flag3 = 00000000
                      lfhLogAtBkp = (0, 0, 0)
                     FirstArchNum = 56
                    FirstArchNum2 = SQLPG_EXTNUM_UNDEFINE
                    RenameArchNum = 50
     On-line Backup End Timestamp = 1280505777
           Recoverable Start Time = 1280503612
   Rollforward stoptime in effect = 0
             Backup End Timestamp = 0
                Backup End Marker = 1280505777, 78, 0000000002D0324C


Please refer to the db2ckbkp Information Center link in the 'Related URL' section below to obtain further details on how to use this utility.

Note from DB CFG that STMM is disabled:

$ db2 get db cfg |grep -i self_tuning_mem
Self tuning memory                    (SELF_TUNING_MEM) = OFF

From stmm.log file we can see events like the following still being dumped:

2013-05-24-09.34.38.373583-180 I195993E593         LEVEL: Event
PID     : 2961                 TID  : 139972652820224PROC : db2sysc 0
INSTANCE: db2inst2             NODE : 000          DB   : INTERSEC
APPHDL  : 0-8                  APPID: *LOCAL.DB2.130524032237
AUTHID  : DB2INST2
EDUID   : 25                   EDUNAME: db2stmm (INTERSEC) 0
FUNCTION: DB2 UDB, Self tuning memory manager, stmmMemoryTunerMain, probe:0
MESSAGE : ZRC=0x0000067F=1663
DATA #1 : String, 115 bytes
Going to sleep for 180000 milliseconds.
Interval = 185, State = 1, intervalsBeforeStateChange = 10, lost4KPages = 0

2013-05-24-09.37.38.365898-180 I196587E454         LEVEL: Event
PID     : 2961                 TID  : 139972652820224PROC : db2sysc 0
INSTANCE: db2inst2             NODE : 000          DB   : INTERSEC
APPHDL  : 0-8                  APPID: *LOCAL.DB2.130524032237
AUTHID  : DB2INST2
EDUID   : 25                   EDUNAME: db2stmm (INTERSEC) 0
FUNCTION: DB2 UDB, Self tuning memory manager, stmmMemoryTunerMain, probe:1528
MESSAGE : Starting New Interval

Turning OFF STMM via DB CFG parameter disables STMM feature, however it does not disable STMM logging.

Check whether SELF_TUNING_MEM parameter is disabled or not into DB CFG configuration.

db2 get db cfg |grep -i self_tuning_mem

SELF_TUNING_MEM parameter must be set to OFF like below:

Self tuning memory                    (SELF_TUNING_MEM) = OFF

Check the last events from stmm.log file in order to confirm that it is still being updated.

In order to completely disable STMM set the following DB2 registry variable as follows:

db2set DB2STMM=OFF

Run db2stop / db2start 

The stmm.log file will not have further updates with new messages.

In certain cases the Optimizer will choose to do a full index scan and join it with the table scan, because there may be 'EMPTY' pages in the table. Performing an index scan can help avoid these empty pages, as opposed to a full table scan.

To calculate the number of empty pages in a table, query the FPAGES and NPAGES columns in the SYSCAT.TABLES view and then subtract the NPAGES value (the number of pages that contain rows) from the FPAGES value (the total number of pages in use). Empty pages can occur when entire ranges of rows are deleted.

As the number of empty pages increases, so does the need for table reorganization. Reorganizing a table reclaims empty pages and reduces the amount of space that a table uses. In addition, because empty pages are read into the buffer pool during a table scan, reclaiming unused pages can improve scan performance. The quickest solution is to REORG the table to remove the empty pages.

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

Slow transaction commit times may sometimes be caused because of a slowdown when writing to the History File.

If the database History File size has grown to a large size (symptoms may start appearing at 10MB and up), then it might start hampering the commit performance by a few seconds.

In general, the mechanism of commit is as follows:
1) Thread doing Commit puts in the request to write the log record and waits
2) if MINCOMMIT=1 the db2loggw thread takes the record and writes the record to disk
3) if it is the end of log file, it requests a new log file to be set up and db2loggr fulfills the request
4) db2loggr has to write into the history file that the log file has been cut
5) Also, writes the same info in the backup file as well.
6) Sends a request to db2logmgr to archive the log file
7) db2loggw resumes writing

If by any chance the history file has become large enough that it cannot be held into memory any longer, it has to write to disk to update it. And since it has to do it serially, it has to read all the records in a serial fashion and append to the history file, this can cause a slowdown.

1) Prune the History File as much as possible using the PRUNE HISTORY command and see if the performance becomes consistent.

2) Consider lowering the value of REC_HIS_RETENTN

http://www-01.ibm.com/support/docview.wss?uid=swg21646712&myns=swgimgmt&mynp=OCSSEPGG&mync=E