Long Blocking Checkpoint Duration And IDS 12.1 Msg
Posted in 2014
A user on IDS 12.1 reported sudden very long blocking checkpoints (300+ seconds, ~700 transactions blocked, avg block time ~292s) and asked whether a new online.log message, "Physical Logging during partition extend: Number of bit map pages to be logged in critical section...", was the cause. Art Kagel listed general checkpoint-tuning advice (lower lru_min/max_dirty, avoid AUTO_CKPTS/RTO_SERVER_RESTART, unbuffered logging, separate spindles for logical/physical logs and data, enough cleaners, no RAID5, no VMs) and said partition extends normally shouldn't greatly affect checkpoint time. The poster had already tuned LRUs, cleaners and buffer pool. Mike Walker suggested running onstat -g ckp after a long checkpoint to see where the time goes. No resolution is recorded in the thread.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Topics: Logging & Checkpoints
Hi, We are suddenly getting very long checkpoint durations. I would like to ask if any of you have encountered this error message ? We are already using the latest build of informix 12.1 Thank you. 15:32:31 Physical Logging during partition extend: Number of bit map pages to be logged in critcal section: 62 Remaining Phyical Log: 370473 15:34:34 Checkpoint Completed: duration was 302 seconds. 15:34:34 Tue Nov 25 - loguniq 1312102, logpos 0xa73e018, timestamp: 0x60494ffc Interval: 689688 15:34:34 Maximum server connections 1663 15:34:34 Checkpoint Statistics - Avg. Txn Block Time 291.913, # Txns blocked 721, Plog used 9528, Llog used 37075 Please take note that the average transaction blocktime is very high 291 seconds and the checkpoint duration was very high as well. I just would like to know if the messages are related to each other. The physical logging during partition extend. I tried searching the net and the forums but no explanation yet. Please help as we are experiencing issues when the long checkpoints happen. Also, what parameter can be tuned for the long checkpoint we have or are the two messages related ? Thank you.
Is the previous message just an informational message or could the checkpoint have been long and blocking due to the Partition Extend. Do partition extends affect checkpoint duration ? Thanks A Lot!
Tuning checkpoint duration and block time: 1. Reduce IO at checkpoint time by decreasing lru_min_dirty and lru_max_dirty settings in your BUFFERPOOL parameters to flush more aggressively between checkpoints. 2. Avoid AUTO_CKPTS and RTO_SERVER_RESTART. 3. Make all databases UNBUFFERED logging or use a small logical log buffer if using BUFFERED logging. 4. Make sure that logical log, physical log, and data chunks are all on separate sets of spindles from each other. 5. Make sure that there are as many CLEANERS configured as the larger of actively updated #chunks and #lru queues (up to the max of 128). 6. NO RAID5!!!!!!!!!!! 7. No VMs running servers with high data volume requirements. Art Art S. Kagel, President and Principal Consultant ASK Database Management www.askdbmgt.com Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Mon, Dec 1, 2014 at 7:29 AM, NATYURAL HORACIO <horacio.natyural@gmail.com > wrote: > Hi, > > We are suddenly getting very long checkpoint durations. > > I would like to ask if any of you have encountered this error message ? > > We are already using the latest build of informix 12.1 > > Thank you. > > 15:32:31 Physical Logging during partition extend: Number of bit map pages > to > be logged in critcal section: 62 Remaining Phyical Log: 370473 > 15:34:34 Checkpoint Completed: duration was 302 seconds. > 15:34:34 Tue Nov 25 - loguniq 1312102, logpos 0xa73e018, timestamp: > 0x60494ffc > Interval: 689688 > > 15:34:34 Maximum server connections 1663 > 15:34:34 Checkpoint Statistics - Avg. Txn Block Time 291.913, # Txns > blocked > 721, Plog used 9528, Llog used 37075 > > Please take note that the average transaction blocktime is very high 291 > seconds and the checkpoint duration was very high as well. > > I just would like to know if the messages are related to each other. The > physical logging during partition extend. > > I tried searching the net and the forums but no explanation yet. > > Please help as we are experiencing issues when the long checkpoints happen. > Also, what parameter can be tuned for the long checkpoint we have or are > the > two messages related ? > > Thank you. > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --089e0158b6b83080c305092786b5
Typically a partition extend should not have a major impact on checkpoint times, no. Art Art S. Kagel, President and Principal Consultant ASK Database Management www.askdbmgt.com Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Mon, Dec 1, 2014 at 7:34 AM, NATYURAL HORACIO <horacio.natyural@gmail.com > wrote: > Is the previous message just an informational message or could the > checkpoint > have been long and blocking due to the > > Partition Extend. > > Do partition extends affect checkpoint duration ? > > Thanks A Lot! > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --089e01419d865c78430509278c63
Thanks Art,
Just to give you a background.
We already have set the LRU's to 128, the CLEANERS to 110,
The buffer pool at:
BUFFERPOOL
size=2K,buffers=2000000,lrus=128,lru_min_dirty=1.000000,lru_max_dirty=2.000000
This was already set 3 years ago.
It is only very recently when we upgraded to Informix 12.1 that we experienced
this long checkpoints again...
I was just wondering if the message was related.
The incident occurred again the second time around. I am asking for the
online.logs and would check if the same message appeared.
Interestlingly, the message only appeared when we applied the latest patch..
15:32:31 Physical Logging during partition extend: Number of bit map pages to
be logged in critcal section: 62 Remaining Phyical Log: 370473
15:34:34 Checkpoint Completed: duration was 302 seconds.
15:34:34 Tue Nov 25 - loguniq 1312102, logpos 0xa73e018, timestamp: 0x60494ffc
Interval: 689688
Have you ever encountered seen this mesage before ?
Can you run "onstat -g ckp" after one of these long checkpoints and see
where the time is being spent?
-----Original Message-----
From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] On Behalf Of
NATYURAL HORACIO
Sent: Monday, December 01, 2014 6:40 AM
To: ids@iiug.org
Subject: Re: Long Blocking Checkpoint Duration And IDS 12.1 [34237]
Thanks Art,
Just to give you a background.
We already have set the LRU's to 128, the CLEANERS to 110,
The buffer pool at:
BUFFERPOOL
size=2K,buffers=2000000,lrus=128,lru_min_dirty=1.000000,lru_max_dirty=2.000000
This was already set 3 years ago.
It is only very recently when we upgraded to Informix 12.1 that we
experienced this long checkpoints again...
I was just wondering if the message was related.
The incident occurred again the second time around. I am asking for the
online.logs and would check if the same message appeared.
Interestlingly, the message only appeared when we applied the latest patch..
15:32:31 Physical Logging during partition extend: Number of bit map pages
to be logged in critcal section: 62 Remaining Phyical Log: 370473
15:34:34 Checkpoint Completed: duration was 302 seconds.
15:34:34 Tue Nov 25 - loguniq 1312102, logpos 0xa73e018, timestamp:
0x60494ffc
Interval: 689688
Have you ever encountered seen this mesage before ?
****************************************************************************
***
Forum Note: Use "Reply" to post a response in the discussion forum.
Hi art Thanks So in short the messages are not related ? As of the moment I don't really know what caused the checkpoint to last for 5 minutes. During other times the checkpoint was just normal. We had another incident in which the checkpoint lasted 10 minutes. I am still waiting for the online.log to check for any messages that the engine is throwing. Thank you
Related threads
- Posting from the Informix-list
- Migrating from IDS 9.40.UC6 to 11.50.UC3
- Ip for a network session
- questions onstat -g