IDS Forum

Re: Non-Blocking Checkpoints Appear to be Blocking

Posted By: JACQUES RENAUT
Date: Wednesday, 3 February 2010, at 1:24 p.m.

In Response To: Non-Blocking Checkpoints Appear to be Blocking (Plugge, Joe R.)

Sorry to top post but I still haven't found a good way to post to the forum from work.

From the onstat -g ckp output, all the RTO checkpoints are flagged as interval flushing (nonblocking for the flush) due to the lack of the "*". There are several blocking checkpoints, the "User" and "Backup" ones.

The checkpoint statistics itself does show 13 txns did have to block but the avg block time was 0.001. Since the checkpoint duration itself was 32 seconds, if it was really blocking during the buffer pool flush I would expect that your stored procedures (at least 1 or some of them) would have come closer to matching the entire checkpoint duration, not just a fairly small portion of it (6.9 seconds out of 32). Could there be some other contention that would hold up the procedure from completing? Like a lock or maybe even IO? To really say for sure that it's the checkpoint blocking modifications, I'd really like to see onstat -u output showing users waiting on the checkpoint flag. I'd maybe start to collect onstat -u and onstat -g ath output that you can look at that would also coincide with the long stored procedure runnings to try and identify for sure what is holding the procedure up as the onstat -g ckp output you have doesn't indicate any transactions/users that were held up for nearly that long at all. I think the longest wait for that checkpoint was 0.4 seconds. So while it is certainly possible that checkpoint statistics could be incorrect, I would think it's also possible that it was something else that caused the stored procedures to run much longer then expected.

Jacques Renaut
IBM Informix Advanced Support
APD team

You wrote--------------------------------------------------------
IDS 11.50.FC4X1 Running on AIX 5300-10. Physical Log size: 2GB

Why would 11.50 touted non-blocking checkpoints be blocking on RTO checkpoint?

I have stored procedures that normally run in 0.0580 seconds and logs show that during this checkpoint they lengthened out to max of 6.915 seconds. This time frame from our logs coincides exactly with the checkpoint listed below:

11:41:55 Checkpoint Completed: duration was 32 seconds.
11:41:55 Checkpoint Statistics - Avg. Txn Block Time 0.001, # Txns blocked 13, Plog used 107308, Llog used 193875

<stuff deleted>

AUTO_CKPTS=On RTO_SERVER_RESTART=60 seconds Estimated recovery time 21 seconds

Critical Sections Physical Log Logical Log

Clock Total Flush Block # Ckpt Wait Long # Dirty Dskflu Total Avg Total Avg
Interval Time Trigger LSN Time Time Time Waits Time Time Time Buffers /Sec Pages /Sec Pages /Sec
100595 22:48:16 RTO 5257:0xf587018 12.6 12.5 0.0 5 0.0 0.1 0.1 59380 4749 58660 26 219019 99
100596 23:22:05 RTO 5260:0x116bc018 13.8 13.8 0.0 2 0.0 0.1 0.1 57247 4162 56585 27 223985 110
100597 23:58:52 RTO 5264:0x937018 16.7 16.6 0.0 2 0.0 0.0 0.1 63266 3806 62737 28 218204 99
100598 03:10:35 RTO 5266:0xfb82018 45.5 45.4 0.0 0 0.0 0.0 0.0 92849 2046 92353 8 205129 17
100599 04:55:19 *User 5268:0x9fed2ac 0.1 0.1 0.0 1 0.0 0.1 0.1 213 213 51468 8 119537 18
100600 04:55:29 *User 5268:0xa0d8018 0.1 0.0 0.0 1 0.0 0.1 0.1 226 226 556 55 235 23
100601 05:00:12 *User 5268:0xa34c428 0.1 0.0 0.0 1 0.0 0.1 0.1 182 182 683 2 628 2
100602 05:01:05 *Backup 5268:0xa3ad88c 0.1 0.1 0.0 0 0.0 0.0 0.0 356 356 193 3 97 1
100603 11:41:55 RTO 5271:0xc0aa018 32.2 31.7 0.0 13 0.0 0.2 0.4 94655 2982 107308 4 193875 8
100604 14:44:01 RTO 5274:0xb2d3018 33.7 33.6 0.0 2 0.0 0.0 0.0 86938 2588 81431 7 211561 19
100605 17:36:06 RTO 5277:0xa4f2018 32.3 32.3 0.0 4 0.0 0.0 0.0 85584 2653 79542 7 211501 20
<stuff deleted>

Anybody have any tips on this?

Messages In This Thread

• Non-Blocking Checkpoints Appear to be Blocking
  Plugge, Joe R. -- Wednesday, 3 February 2010, at 12:12 p.m.
  • Re: Non-Blocking Checkpoints Appear to be Blocking
    JACQUES RENAUT -- Wednesday, 3 February 2010, at 1:24 p.m.

IDS Forum is maintained by Administrator with WebBBS 5.12.