Informix nonblocking checkpoints slow
Posted in 2012
A user on Informix 11 saw system slowdowns and timeouts during checkpoints despite non-blocking checkpoints, with checkpoint times of 60-300 seconds. Advisers asked for 'onstat -g ckp' output; it showed almost all checkpoint time spent in flushing, with few/short checkpoint waits and 10,000-50,000 dirty pages flushed per checkpoint. Conclusion: the problem is I/O load from flushing, not checkpoint blocking. Suggested remedies were more buffers (his pool was only 80000 2K buffers), tuning the checkpoint interval, and lowering LRU_MIN_DIRTY/LRU_MAX_DIRTY, with deeper OS/storage analysis if needed. No confirmed fix is reported in the thread.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Topics: Logging & Checkpoints
Hi, Ive got informix 11 running, its supposed to have non blocking checkpoints right? However during checkpoint times, my system still behaves really slow. Normal checkpoint times are 60 seconds above during peak period. I. Even getting checkpoint times 300 seconds above and quite frequently during checkpoints. My question is, is it still good for us to tune the checkpoint duration? M pretty sure that slowness is related to checkpoints since everytime it would slowdown, i would be getting timeouts from my system. Transactions are not blocked however system behaves poorly. Thanks Horacio
What does the onstat -g ckp report show?
Art
Art S. Kagel
Advanced DataTools (www.advancedatatools.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 my employer, Advanced DataTools, 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 Wed, Jan 11, 2012 at 10:48 AM, NATYURAL HORACIO <
horacio.natyural@gmail.com> wrote:
> Hi,
>
> Ive got informix 11 running, its supposed to have non blocking checkpoints
> right?
> However during checkpoint times, my system still behaves really slow.
> Normal
> checkpoint times are 60 seconds above during peak period. I. Even getting
> checkpoint times 300 seconds above and quite frequently during checkpoints.
>
> My question is, is it still good for us to tune the checkpoint duration? M
> pretty sure that slowness is related to checkpoints since everytime it
> would
> slowdown, i would be getting timeouts from my system. Transactions are not
> blocked however system behaves poorly.
>
> Thanks
> Horacio
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--e89a8f3bb08d0bea4504b6431898
Do you use HDR?
In general I think customers should still tune the checkpoints. Not saying
this is your case, but if you let your system get to the checkpoint
ocurrence with 2GB of data to write, yes, you can expect performance
degradation.
You should check the output from "onstat -g ckp" as Art already wrote to
see the flush time, the number of dirty buffers etc.
Also things like the checkpoint interval, auto_ckp configuration, RTO etc
are useful.
Regards.
On Wed, Jan 11, 2012 at 3:48 PM, NATYURAL HORACIO <
horacio.natyural@gmail.com> wrote:
> Hi,
>
> Ive got informix 11 running, its supposed to have non blocking checkpoints
> right?
> However during checkpoint times, my system still behaves really slow.
> Normal
> checkpoint times are 60 seconds above during peak period. I. Even getting
> checkpoint times 300 seconds above and quite frequently during checkpoints.
>
> My question is, is it still good for us to tune the checkpoint duration? M
> pretty sure that slowness is related to checkpoints since everytime it
> would
> slowdown, i would be getting timeouts from my system. Transactions are not
> blocked however system behaves poorly.
>
> Thanks
> Horacio
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--
Fernando Nunes
Portugal
http://informix-technology.blogspot.com
My email works... but I don't check it frequently...
--00248c6a6a42b2715904b644d626
On 11 Jan 2012, at 15:48, NATYURAL HORACIO wrote:
> Hi,
>
> Ive got informix 11 running, its supposed to have non blocking checkpoints
> right?
> However during checkpoint times, my system still behaves really slow. Normal
> checkpoint times are 60 seconds above during peak period. I. Even getting
> checkpoint times 300 seconds above and quite frequently during checkpoints.
>
> My question is, is it still good for us to tune the checkpoint duration? M
> pretty sure that slowness is related to checkpoints since everytime it would
> slowdown, i would be getting timeouts from my system. Transactions are not
> blocked however system behaves poorly.
Post the output from onstat -ckp
here it is, oddly the dskflu/sec are really low. checkpoints are long when the dsk flu/seconds are high. 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 387978 14:20:17 CKPTINTVL 1153313:0x4a0a0bc 125.3 125.0 0.0 10 0.1 0.1 0.2 13323 106 7149 23 19240 63 387979 14:26:24 CKPTINTVL 1153313:0x9e9c2a0 187.2 180.1 0.0 123 7.0 3.3 7.1 16321 90 10757 34 26726 85 387980 14:30:04 CKPTINTVL 1153313:0xe380018 100.0 99.9 0.0 2 0.0 0.1 0.1 15631 156 8314 27 25301 84 387981 14:37:34 CKPTINTVL 1153314:0x68073b8 240.8 239.6 0.0 13 0.3 0.8 1.2 16993 70 11837 38 47907 154 387982 14:42:17 CKPTINTVL 1153314:0xc91b750 193.0 190.4 0.0 97 2.4 1.4 2.6 16987 89 9631 29 28383 85 387983 14:45:09 CKPTINTVL 1153315:0x58d2a4 52.3 52.0 0.0 21 0.1 0.1 0.4 10312 198 5349 17 14800 47 387984 14:52:17 CKPTINTVL 1153315:0x687e654 158.8 156.2 0.0 17 0.3 1.5 2.6 18160 116 12074 37 35648 110 387985 14:57:37 CKPTINTVL 1153315:0xbe970b4 170.5 170.3 0.0 4 0.0 0.2 0.2 17055 100 9795 32 35193 115 387986 15:03:47 CKPTINTVL 1153316:0x3851180 220.4 189.3 0.0 372 30.9 12.3 30.8 16335 86 10037 28 28886 82 387987 15:07:09 CKPTINTVL 1153316:0x755a0bc 83.0 82.6 0.0 7 0.0 0.3 0.3 16281 197 8188 26 20897 67 387988 15:13:49 CKPTINTVL 1153316:0xdbf63b0 158.2 157.9 0.0 13 0.1 0.2 0.3 16160 102 11392 35 33779 104 387989 15:18:48 CKPTINTVL 1153317:0x3c2442c 149.4 147.8 0.0 28 0.5 1.0 1.6 15788 106 9297 30 23258 75 387990 15:22:05 CKPTINTVL 1153317:0x86d4048 17.2 17.1 0.0 5 0.0 0.1 0.1 16925 987 9848 30 20380 62 387991 15:27:18 CKPTINTVL 1153318:0x5ae11d0 14.0 13.7 0.0 6 0.0 0.2 0.2 16785 1222 19510 61 50050 157 387992 15:32:30 CKPTINTVL 1153318:0xe194068 12.8 12.7 0.0 7 0.0 0.1 0.1 16478 1299 14081 44 35540 113 387993 15:37:42 CKPTINTVL 1153319:0x79530bc 12.6 12.2 0.0 12 0.1 0.2 0.3 16599 1356 12728 40 34188 109 387994 15:43:00 CKPTINTVL 1153319:0xd15713c 18.2 17.7 0.0 18 0.2 0.3 0.4 16624 936 8120 26 22847 73 387995 15:48:12 CKPTINTVL 1153320:0x1cc11b0 12.8 12.4 0.0 11 0.2 0.3 0.4 16736 1344 6786 21 14690 46 387996 15:53:25 CKPTINTVL 1153320:0x91eb3e8 14.0 13.7 0.0 13 0.0 0.2 0.3 16543 1208 14065 45 30922 99 387997 15:58:39 CKPTINTVL 1153320:0xe9ec5cc 14.7 14.4 0.0 8 0.0 0.2 0.2 16837 1165 10719 34 23309 74
Horatio: OK, so, I reformatted some of the output below so I can read it better. It looks like over 95% of the checkpoint time is being spend on disk flushing. Note that always the number of checkpoint waits is usually zero and not greater than 23 and that the average block time is less then 1/10 of a second. I believe that the performance problems you are seeing are a side effect of the high IO during the checkpoints when, typically, between 10,000 and 50,000 dirty pages have to be flushed to disk. It is the IO activity due to these flushes that is slowing down read activity required to service your other active sessions during the checkpoint, not the checkpoint itself. There are several possible causes and several possible ways to ameliorate the problem and to ultimately resolve it. If you do not have the technical System Administration and Storage Administration staff available to help you do that I suggest that you get outside help. I can offer the services of Advanced DataTools Corp. if you want to contact me or our offices directly. Beyond that I would suggest that you get help. There may be OS problems, storage array problems, server tuning problems, IO channel problems, network problems any and all of which may be causing this. Here are some general suggestions: - More buffers will reduce the load on the IO subsystems during checkpoints be making more data available in memory. - Reducing the checkpoint interval may reduce the amount of IO at each checkpoint but that may just exacerbate the IO problems if this is actually related to slow write IO. - You can try decreasing the lru_min_dirty and lru_max_dirty values for your buffer caches which will reduce the amount of dirty pages that need to be flushed out at checkpoint time. If these suggestions do not help, then more extensive analysis of the problem is required to determine the root cause and to find solutions. Art Art S. Kagel Advanced DataTools (www.advancedatatools.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 my employer, Advanced DataTools, 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 Thu, Jan 12, 2012 at 8:43 AM, NATYURAL HORACIO < horacio.natyural@gmail.com> wrote: > here it is, oddly the dskflu/sec are really low. checkpoints are long when > the > dsk flu/seconds are high. > > 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 > 387978 14:20:17 CKPTINTVL 1153313:0x4a0a0bc 125.3 125.0 0.0 10 0.1 0.1 > 0.2 13323 106 7149 23 19240 63 > 387979 14:26:24 CKPTINTVL 1153313:0x9e9c2a0 187.2 180.1 0.0 123 7.0 3.3 > 7.1 16321 90 10757 34 26726 85 > 387980 14:30:04 CKPTINTVL 1153313:0xe380018 100.0 99.9 0.0 2 0.0 0.1 > 0.1 15631 156 8314 27 25301 84 > 387981 14:37:34 CKPTINTVL 1153314:0x68073b8 240.8 239.6 0.0 13 0.3 0.8 > 1.2 16993 70 11837 38 47907 154 > 387982 14:42:17 CKPTINTVL 1153314:0xc91b750 193.0 190.4 0.0 97 2.4 1.4 2.6 > 16987 89 9631 29 28383 85 > 387983 14:45:09 CKPTINTVL 1153315:0x58d2a4 52.3 52.0 0.0 21 0.1 0.1 0.4 > 10312 > 198 5349 17 14800 47 > 387984 14:52:17 CKPTINTVL 1153315:0x687e654 158.8 156.2 0.0 17 0.3 1.5 2.6 > 18160 116 12074 37 35648 110 > 387985 14:57:37 CKPTINTVL 1153315:0xbe970b4 170.5 170.3 0.0 4 0.0 0.2 0.2 > 17055 100 9795 32 35193 115 > 387986 15:03:47 CKPTINTVL 1153316:0x3851180 220.4 189.3 0.0 372 30.9 12.3 > 30.8 > 16335 86 10037 28 28886 82 > 387987 15:07:09 CKPTINTVL 1153316:0x755a0bc 83.0 82.6 0.0 7 0.0 0.3 0.3 > 16281 > 197 8188 26 20897 67 > 387988 15:13:49 CKPTINTVL 1153316:0xdbf63b0 158.2 157.9 0.0 13 0.1 0.2 0.3 > 16160 102 11392 35 33779 104 > 387989 15:18:48 CKPTINTVL 1153317:0x3c2442c 149.4 147.8 0.0 28 0.5 1.0 1.6 > 15788 106 9297 30 23258 75 > 387990 15:22:05 CKPTINTVL 1153317:0x86d4048 17.2 17.1 0.0 5 0.0 0.1 0.1 > 16925 > 987 9848 30 20380 62 > 387991 15:27:18 CKPTINTVL 1153318:0x5ae11d0 14.0 13.7 0.0 6 0.0 0.2 0.2 > 16785 > 1222 19510 61 50050 157 > 387992 15:32:30 CKPTINTVL 1153318:0xe194068 12.8 12.7 0.0 7 0.0 0.1 0.1 > 16478 > 1299 14081 44 35540 113 > 387993 15:37:42 CKPTINTVL 1153319:0x79530bc 12.6 12.2 0.0 12 0.1 0.2 0.3 > 16599 > 1356 12728 40 34188 109 > 387994 15:43:00 CKPTINTVL 1153319:0xd15713c 18.2 17.7 0.0 18 0.2 0.3 0.4 > 16624 > 936 8120 26 22847 73 > 387995 15:48:12 CKPTINTVL 1153320:0x1cc11b0 12.8 12.4 0.0 11 0.2 0.3 0.4 > 16736 > 1344 6786 21 14690 46 > 387996 15:53:25 CKPTINTVL 1153320:0x91eb3e8 14.0 13.7 0.0 13 0.0 0.2 0.3 > 16543 > 1208 14065 45 30922 99 > 387997 15:58:39 CKPTINTVL 1153320:0xe9ec5cc 14.7 14.4 0.0 8 0.0 0.2 0.2 > 16837 > 1165 10719 34 23309 74 > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --e89a8f3bb03931add404b657ac00
i was suspecting that it was indeed I/O. having read this, I have a further question, I have seen my active sessions during the said period and most of them were trying to insert into a particular table. what i've noticed was inserts and updates to large tables are taking longer times. however, during non peak periods, they behave very well. I don't think index is the problem. now, during normal times, this particular table's write speed is very fast. almost of all of our statements write into this particular table. it's a table that has millions of rows around 15, has a large number of columns and has lots of indexes. would the insert be slower during peak periods? are inserts particularly slower as the number of records grows? should purging this table help in our I/O problem? I have also seen issues with regards to possibly buffers. Our buffer pool is only 80000 and size is 2kb which is really quite small. This is a really big system. You available in other countries? I can give your contact and your site.
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