IT29960: INDEX BUILD CAN HAVE BUFFERS X LOCKED FOR A LONG TIME, INCREASING FLUSH DURATION OF NON-BLOCKING INTERVAL CHECKPOINTS

APAR status

• Closed as program error.

Error description

• When building an index, the code currently looks to see if there
  is a pending checkpoint, and if so, it exits critical section
  and releases the buffers it holds to allow the checkpoint to
  continue.  However, as soon as the it can, it re-enters it's
  critical section and then grabs all it's buffers again with X
  locks.  If it's able to get it's buffers back before the
  checkpoint process was able to flush them, it can then hold the
  buffers for a long time causing the checkpoint to not be able to
  finish flushing the required buffers to close out the
  checkpoint.  This shows up as long duration checkpoints where
  all the time is in the flush portion of the checkpoint, and then
  would artificially decrease the disk flushes per second in the
  onstat -g ckp output (which might cause people to think there
  was some IO issue).
  
  You would likely see the following if encountering the problem.
  
  First, the main_loop thread will be running very frequently, but
  if you can get a stack trace from it when it is yielding, it
  would look like this:
  
  yield_processor
  ckpt_dskflush
  checkpoint
  main_loop
  th_init_initgls
  startup
  
  Also, you would see some amount of buffers in onstat -b output
  that had there xflags set to "80" (to be xlocked) and if you
  were to trace the owner of those buffers, they would track back
  to xchg threads of part of an index build.
  
  onstat -b output:
  
  IBM Informix Dynamic Server Version 12.10.FC12 -- On-Line (CKPT
  INP) -- Up 7 days 23:13:04 -- 251036672 Kbytes
  
  Buffers
  address           userthread        flgs pagenum
  memaddr           nslots pgflgs xflgs owner             waitlist
  
  Buffer pool page size: 2048
  6b19fe858        0                10807 23:1596663
  cb17be000        14     10     80    240147388        0
  6b1a08ad8        0                10807 23:1607198
  cb1840000        12     10     80    16e73c638        0
  6b1c65cb8        0                10807 23:1645611
  cb3681800        11     10     80    126ec8518        0
  6b1fa5b58        0                10807 23:1601752
  cb601a000        14     10     80    254441718        0
  ...
  
  Now we look up owner value in onstat -g ath output:
  
  grep 240147388 onstat.g.ath*
   3319075  2304ff2b0        240147388        1    cond wait
  sortproc:0  17cpu         xchg_2.1
  
  Can also look for that owner value in onstat -g ses 0 output,
  and we have the following:
  
  session
  #RSAM    total      used       dynamic
  id       user     tty      pid      hostname
  threads  memory     memory     explain
  64299    informix -        6008     host1
  23       4788224    2794520    off
  
  tid      name     rstcb            flags    curstk   status
  ...
  3319075  xchg_2.1 240147388        Y-B-X--  6815     cond wait
  sortproc:0-
  ...
  sqscb info
  scb              sqscb            optofc   pdqpriority
  optcompind  directives
  15e798230        231cd3028        0        10          2
  1
  
  Sess       SQL            Current            Iso Lock       SQL
  ISAM F.E.
  Id         Stmt type      Database           Lvl Mode       ERR
  ERR  Vers  Explain
  64299      CREATE INDEX   db1                CR  Not Wait   0
  0    9.24  Off
  
  Current SQL statement (13) :
    create index "informix".t1_idx1 on "informix".t1 (c1,
       c2, c3) using btree  in s07 online
  

Local fix

Problem summary

• ****************************************************************
  * USERS AFFECTED:                                              *
  * Users of Informix Server prior to 12.10.xC14 and 14.10.xC4.  *
  ****************************************************************
  * PROBLEM DESCRIPTION:                                         *
  * See Error Description                                        *
  ****************************************************************
  * RECOMMENDATION:                                              *
  * Update to Informix Server 12.10.xC14 or 14.10.xC4 (when      *
  * available).                                                  *
  ****************************************************************
  

Problem conclusion

• Fixed in Informix Server 12.10.xC14 and 14.10.xC4.
  

Temporary fix

Comments

APAR Information

• APAR is sysrouted FROM one or more of the following:

• APAR is sysrouted TO one or more of the following:

Fix information

• Fixed component name

  INFORMIX SERVER

• Fixed component ID

  5725A3900

Applicable component levels