I/O writes

Hi, Below are the stats gathered from an IDS instance (restarted around 2 hours ago). We see that checkpoints are taking too much time sometimes. Problems looks in I/O. How can we improve "LRU writes" and reduce "Chunk writes" as I read that "LRU writes" are better. Also how to keep max length (onstat -g ioq) shorter. OS: SunOS 5.10 sun4v sparc regards, Kamran -------------------------------------------------------------- $ onstat -F IBM Informix Dynamic Server Version 11.50.FC3W1 -- On-Line (Prim) -- Up 01:09:50 -- 921600 Kbytes Fg Writes LRU Writes Chunk Writes 0 0 622567 address flusher state data # LRU Chunk Wakeups Idle Tim 119c6d870 0 I 0 0 32 4202 4172.668 119c6e0b8 1 I 0 0 36 4190 4154.733 119c6e900 2 I 0 0 28 4197 4173.793 119c6f148 3 I 0 0 30 4196 4166.957 119c6f990 4 I 0 0 30 4194 4163.863 119c701d8 5 I 0 0 34 4179 4145.377 119c70a20 6 I 0 0 36 4181 4145.399 119c71268 7 I 0 0 29 4197 4167.696 119c71ab0 8 I 0 0 28 4197 4169.929 119c722f8 9 I 0 0 24 4199 4176.918 119c72b40 10 I 0 0 24 4196 4172.204 119c73388 11 I 0 0 23 4192 4171.186 119c73bd0 12 I 0 0 22 4192 4171.252 119c74418 13 I 0 0 20 4196 4176.573 119c74c60 14 I 0 0 20 4193 4175.085 119c754a8 15 I 0 0 20 4192 4174.220 119c75cf0 16 I 0 0 20 4188 4170.391 119c76538 17 I 0 0 20 4193 4173.006 119c76d80 18 I 0 0 19 4188 4170.294 119c775c8 19 I 0 0 18 4185 4166.483 119c77e10 20 I 0 0 17 4175 4157.900 119c78658 21 I 0 0 17 4153 4135.801 119c78ea0 22 I 0 0 16 4147 4130.073 119c796e8 23 I 0 0 16 4148 4131.168 states: Exit Idle Chunk Lru $ onstat -g ioq IBM Informix Dynamic Server Version 11.50.FC3W1 -- On-Line (Prim) -- Up 01:10:04 -- 921600 Kbytes AIO I/O queues:q name/id len maxlen totalops dskread dskwrite dskcopy drda_dbg 0 0 0 0 0 0 0 sqli_dbg 0 0 0 0 0 0 0 adt 0 0 0 0 0 0 0 msc 0 0 2 10356 0 0 0 aio 0 0 34 4957068 26 4954270 0 pio 0 0 1 4208 0 4208 0 lio 0 0 1 934928 0 934928 0 gfd 3 0 3 44271 44168 103 0 gfd 4 0 5 183 52 131 0 gfd 5 0 31 164375 163919 456 0 gfd 6 0 16 5707 1454 4253 0 gfd 7 0 2 25179 25179 0 0 gfd 8 0 31 657803 657480 323 0 gfd 9 0 14 3977 3879 98 0 gfd 10 0 31 581371 577245 4126 0 gfd 11 0 30 46808 46730 78 0 gfd 12 0 11 3140 3076 64 0 gfd 13 0 1 1153 1153 0 0 gfd 14 0 45 245420 244784 636 0 gfd 15 0 29 15783 15335 448 0 gfd 16 0 1 17 17 0 0 gfd 17 0 1 20 20 0 0 gfd 18 0 30 224616 224114 502 0 gfd 19 0 2 3273 3266 7 0 gfd 20 0 30 62404 61709 695 0 gfd 21 0 30 170825 169045 1780 0 gfd 22 0 30 11490 11065 425 0 gfd 23 0 31 232938 231740 1198 0 gfd 24 0 30 68956 65598 3358 0 gfd 25 0 31 175224 174670 554 0 gfd 26 0 31 253559 251803 1756 0 gfd 27 0 30 201740 199354 2386 0 gfd 28 0 43 717590 707646 9944 0 gfd 29 0 31 790372 774676 15696 0 gfd 30 0 1 1 1 0 0 gfd 31 0 46 719426 679486 39940 0 gfd 32 0 32 853121 759948 93173 0 gfd 33 0 48 1158744 1006962 151782 0 gfd 34 0 1 83 83 0 0 gfd 35 0 41 728786 654252 74534 0 gfd 36 0 32 692805 615643 77162 0 gfd 37 0 31 1075115 934510 140605 0 gfd 38 0 1 1 1 0 0 gfd 39 0 0 0 0 0 0 gfd 40 0 0 0 0 0 0 gfd 41 0 0 0 0 0 0 gfd 42 0 0 0 0 0 0 gfd 43 0 0 0 0 0 0 gfd 44 0 0 0 0 0 0 gfd 45 0 0 0 0 0 0 gfd 46 0 0 0 0 0 0 gfd 47 0 0 0 0 0 0 gfd 48 0 0 0 0 0 0 gfd 49 0 0 0 0 0 0 gfd 50 0 0 0 0 0 0 gfd 51 0 0 0 0 0 0 gfd 52 0 0 0 0 0 0 gfd 53 0 0 0 0 0 0 gfd 54 0 0 0 0 0 0 gfd 55 0 0 0 0 0 0 gfd 56 0 0 0 0 0 0 gfd 57 0 0 0 0 0 0 gfd 58 0 0 0 0 0 0 gfd 59 0 0 0 0 0 0 gfd 60 0 0 0 0 0 0 gfd 61 0 0 0 0 0 0 gfd 62 0 0 0 0 0 0 gfd 63 0 0 0 0 0 0 gfd 64 0 0 0 0 0 0 gfd 65 0 0 0 0 0 0 gfd 66 0 0 0 0 0 0 gfd 67 0 0 0 0 0 0 gfd 68 0 0 0 0 0 0 gfd 69 0 0 0 0 0 0 gfd 70 0 0 0 0 0 0 gfd 71 0 0 0 0 0 0 gfd 72 0 0 0 0 0 0 gfd 73 0 0 0 0 0 0 gfd 74 0 0 0 0 0 0 $ onstat -p IBM Informix Dynamic Server Version 11.50.FC3W1 -- On-Line (Prim) -- Up 01:10:19 -- 921600 Kbytes Profile dskreads pagreads bufreads %cached dskwrits pagwrits bufwrits %cached 9355610 16947434 166184193 94.37 1568001 2150214 6486797 75.88 isamtot open start read write rewrite delete commit rollbk 173486072 3649325 17192634 82339872 730432 30257 463299 941887 35 gp_read gp_write gp_rewrt gp_del gp_alloc gp_free gp_curs 0 0 0 0 0 0 0 ovlock ovuserthread ovbuff usercpu syscpu numckpts flushes 0 0 0 12088.14 2358.88 27 30 bufwaits lokwaits lockreqs deadlks dltouts ckpwaits compress seqscans 550159 79 123453819 0 0 67 150460 120453 ixda-RA idx-RA da-RA RA-pgsused lchwaits 2025249 1361 1499088 3519878 468120

Kamran, You are running IDS 11.50 which implements non-blocking checkpoints. In this and all following releases CHUNK writes are actually preferred. Since your checkpoints are non-blocking except for a very brief setup phase, you should not need to worry about long checkpoints any longer. Indeed, you are more concerned with the blocking time displayed at the end of the checkpoint trace in the message log. If you are not sure how to read that, then post some message log output that shows the specific checkpoints that are giving yoiu concern. In general, and this was always true, CHUNK writes are more efficient for the OS and IO subsytems and even for the Informix engine itself than LRU writes. The reason that a balance of about 60-70% LRU writes to 30-40% CHUNK writes was recommended in earlier releases for OLTP systems was that extensive chunk writes can result in longer checkpoints and prior to IDS v11 checkpoints blocked transactions and user sessions in critical code sections could delay the start of a checkpoint which would increase the blockout time for other sessions. With non-blocking checkpoints, this is no longer a problem so IBM and the user community have reverted back to recommending configuring higher LRU_MIN_DIRTY & LRU_MAX_DIRTY levels to shift the balance to mostly CHUNK writes or even 100% CHUNK writes. Art Art S. Kagel Oninit (www.oninit.com) IIUG Board of Directors (art@iiug.org) Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on my employer, Oninit, the IIUG, nor any other organization with which I am associated either explicitly or implicitly. 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 Fri, Jul 17, 2009 at 9:33 AM, KAMRAN HAQ <khaq@i2cinc.com> wrote: > Hi, > Below are the stats gathered from an IDS instance (restarted around 2 hours > ago). We see that checkpoints are taking too much time sometimes. Problems > looks in I/O. How can we improve "LRU writes" and reduce "Chunk writes" as > I > read that "LRU writes" are better. Also how to keep max length (onstat -g > ioq) > shorter. > OS: SunOS 5.10 sun4v sparc > regards, > Kamran > -------------------------------------------------------------- > > $ onstat -F> > IBM Informix Dynamic Server Version 11.50.FC3W1 -- On-Line (Prim) -- Up > 01:09:50 -- 921600 Kbytes> > Fg Writes LRU Writes Chunk Writes > 0 0 622567 > > address flusher state data # LRU Chunk Wakeups Idle Tim > 119c6d870 0 I 0 0 32 4202 4172.668 > 119c6e0b8 1 I 0 0 36 4190 4154.733 > 119c6e900 2 I 0 0 28 4197 4173.793 > 119c6f148 3 I 0 0 30 4196 4166.957 > 119c6f990 4 I 0 0 30 4194 4163.863 > 119c701d8 5 I 0 0 34 4179 4145.377 > 119c70a20 6 I 0 0 36 4181 4145.399 > 119c71268 7 I 0 0 29 4197 4167.696 > 119c71ab0 8 I 0 0 28 4197 4169.929 > 119c722f8 9 I 0 0 24 4199 4176.918 > 119c72b40 10 I 0 0 24 4196 4172.204 > 119c73388 11 I 0 0 23 4192 4171.186 > 119c73bd0 12 I 0 0 22 4192 4171.252 > 119c74418 13 I 0 0 20 4196 4176.573 > 119c74c60 14 I 0 0 20 4193 4175.085 > 119c754a8 15 I 0 0 20 4192 4174.220 > 119c75cf0 16 I 0 0 20 4188 4170.391 > 119c76538 17 I 0 0 20 4193 4173.006 > 119c76d80 18 I 0 0 19 4188 4170.294 > 119c775c8 19 I 0 0 18 4185 4166.483 > 119c77e10 20 I 0 0 17 4175 4157.900 > 119c78658 21 I 0 0 17 4153 4135.801 > 119c78ea0 22 I 0 0 16 4147 4130.073 > 119c796e8 23 I 0 0 16 4148 4131.168 > > states: Exit Idle Chunk Lru > > $ onstat -g ioq> > IBM Informix Dynamic Server Version 11.50.FC3W1 -- On-Line (Prim) -- Up > 01:10:04 -- 921600 Kbytes > > AIO I/O queues:> q name/id len maxlen totalops dskread dskwrite dskcopy > drda_dbg 0 0 0 0 0 0 0 > sqli_dbg 0 0 0 0 0 0 0 > adt 0 0 0 0 0 0 0 > msc 0 0 2 10356 0 0 0 > aio 0 0 34 4957068 26 4954270 0 > pio 0 0 1 4208 0 4208 0 > lio 0 0 1 934928 0 934928 0 > gfd 3 0 3 44271 44168 103 0 > gfd 4 0 5 183 52 131 0 > gfd 5 0 31 164375 163919 456 0 > gfd 6 0 16 5707 1454 4253 0 > gfd 7 0 2 25179 25179 0 0 > gfd 8 0 31 657803 657480 323 0 > gfd 9 0 14 3977 3879 98 0 > gfd 10 0 31 581371 577245 4126 0 > gfd 11 0 30 46808 46730 78 0 > gfd 12 0 11 3140 3076 64 0 > gfd 13 0 1 1153 1153 0 0 > gfd 14 0 45 245420 244784 636 0 > gfd 15 0 29 15783 15335 448 0 > gfd 16 0 1 17 17 0 0 > gfd 17 0 1 20 20 0 0 > gfd 18 0 30 224616 224114 502 0 > gfd 19 0 2 3273 3266 7 0 > gfd 20 0 30 62404 61709 695 0 > gfd 21 0 30 170825 169045 1780 0 > gfd 22 0 30 11490 11065 425 0 > gfd 23 0 31 232938 231740 1198 0 > gfd 24 0 30 68956 65598 3358 0 > gfd 25 0 31 175224 174670 554 0 > gfd 26 0 31 253559 251803 1756 0 > gfd 27 0 30 201740 199354 2386 0 > gfd 28 0 43 717590 707646 9944 0 > gfd 29 0 31 790372 774676 15696 0 > gfd 30 0 1 1 1 0 0 > gfd 31 0 46 719426 679486 39940 0 > gfd 32 0 32 853121 759948 93173 0 > gfd 33 0 48 1158744 1006962 151782 0 > gfd 34 0 1 83 83 0 0 > gfd 35 0 41 728786 654252 74534 0 > gfd 36 0 32 692805 615643 77162 0 > gfd 37 0 31 1075115 934510 140605 0 > gfd 38 0 1 1 1 0 0 > gfd 39 0 0 0 0 0 0 > gfd 40 0 0 0 0 0 0 > gfd 41 0 0 0 0 0 0 > gfd 42 0 0 0 0 0 0 > gfd 43 0 0 0 0 0 0 > gfd 44 0 0 0 0 0 0 > gfd 45 0 0 0 0 0 0 > gfd 46 0 0 0 0 0 0 > gfd 47 0 0 0 0 0 0 > gfd 48 0 0 0 0 0 0 > gfd 49 0 0 0 0 0 0 > gfd 50 0 0 0 0 0 0 > gfd 51 0 0 0 0 0 0 > gfd 52 0 0 0 0 0 0 > gfd 53 0 0 0 0 0 0 > gfd 54 0 0 0 0 0 0 > gfd 55 0 0 0 0 0 0 > gfd 56 0 0 0 0 0 0 > gfd 57 0 0 0 0 0 0 > gfd 58 0 0 0 0 0 0 > gfd 59 0 0 0 0 0 0 > gfd 60 0 0 0 0 0 0 > gfd 61 0 0 0 0 0 0 > gfd 62 0 0 0 0 0 0 > gfd 63 0 0 0 0 0 0 > gfd 64 0 0 0 0 0 0 > gfd 65 0 0 0 0 0 0 > gfd 66 0 0 0 0 0 0 > gfd 67 0 0 0 0 0 0 > gfd 68 0 0 0 0 0 0 > gfd 69 0 0 0 0 0 0 > gfd 70 0 0 0 0 0 0 > gfd 71 0 0 0 0 0 0 > gfd 72 0 0 0 0 0 0 > gfd 73 0 0 0 0 0 0 > gfd 74 0 0 0 0 0 0 > > $ onstat -p> > IBM Informix Dynamic Server Version 11.50.FC3W1 -- On-Line (Prim) -- Up > 01:10:19 -- 921600 Kbytes> > Profile > dskreads pagreads bufreads %cached dskwrits pagwrits bufwrits %cached > 9355610 16947434 166184193 94.37 1568001 2150214 6486797 75.88 > > isamtot open start read write rewrite delete commit rollbk > 173486072 3649325 17192634 82339872 730432 30257 463299 941887 35 > > gp_read gp_write gp_rewrt gp_del gp_alloc gp_free gp_curs > 0 0 0 0 0 0 0 > > ovlock ovuserthread ovbuff usercpu syscpu numckpts flushes > 0 0 0 12088.14 2358.88 27 30 > > bufwaits lokwaits lockreqs deadlks dltouts ckpwaits compress seqscans > 550159 79 123453819 0 0 67 150460 120453 > > ixda-RA idx-RA da-RA RA-pgsused lchwaits > 2025249 1361 1499088 3519878 468120 > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001636c5a9bf9d7014046ee7c1d3

Thanks a lot. It got me out of confusion. And do you hinkthat I/O queue length are not bad? Here are recent messages found in online.log ------------------------------------------------------------------ 07:35:02 Logical Log 27846 Complete, timestamp: 0x5a4d390a. 07:35:02 Process exited with return code 1: /bin/sh /bin/sh -c /u/informix11.5-3/etc/alarmprogram.sh 2 23 "" "Logical Log 27846 Complete, tim estamp: 0x5a4d390a." "" 07:37:15 Checkpoint Completed: duration was 4 seconds. 07:37:15 Maximum server connections 130 07:37:15 Checkpoint Statistics - Avg. Txn Block Time 0.020, # Txns blocked 8, Plog used 15193, Llog used 43011 07:42:19 Checkpoint Completed: duration was 3 seconds. 07:42:19 Maximum server connections 133 07:42:19 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 5, Plog used 19672, Llog used 58077 07:44:09 Dynamically allocated new virtual shared memory segment (size 131072KB) 07:44:09 Memory sizes:resident:253952 KB, virtual:929792 KB, SHMTOTAL:4096000 KB 07:47:25 Checkpoint Completed: duration was 7 seconds. 07:47:25 Maximum server connections 133 07:47:25 Checkpoint Statistics - Avg. Txn Block Time 0.003, # Txns blocked 5, Plog used 22393, Llog used 70361 07:48:34 Checkpoint Completed: duration was 2 seconds. 07:48:34 Maximum server connections 133 07:48:34 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 1, Plog used 5302, Llog used 15777 07:48:34 Checkpoint Completed: duration was 0 seconds. 07:48:34 Maximum server connections 133 07:48:34 Checkpoint Statistics - Avg. Txn Block Time 0.003, # Txns blocked 1, Plog used 137, Llog used 262 07:48:35 Checkpoint Completed: duration was 0 seconds. 07:48:35 Maximum server connections 133 07:48:35 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 1, Plog used 191, Llog used 163 07:48:35 Checkpoint Completed: duration was 0 seconds. 07:48:35 Maximum server connections 133 07:48:35 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 1, Plog used 103, Llog used 142 07:48:36 Checkpoint Completed: duration was 0 seconds. 07:48:36 Maximum server connections 133 07:48:36 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 2, Plog used 73, Llog used 133

Hi Art, Conitued to previous email, there are strange checkpoint triggers against "onstst -g ckp" ------------------------------------------------------- $ onstat -g ckp IBM Informix Dynamic Server Version 11.50.FC3W1 -- On-Line (Prim) (CKPT INP) -- Up 02:48:27 -- 1183744 Kbytes AUTO_CKPTS=On RTO_SERVER_RESTART=Off 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 47878 07:48:34 HA 27847:0x27950018 0.1 0.0 0.0 7 0.0 0.1 0.2 147 147 137 137 262 262 47879 07:48:34 HA 27847:0x279dc19c 0.1 0.1 0.0 1 0.0 0.0 0.0 196 196 191 191 163 163 47880 07:48:35 HA 27847:0x27a63018 0.1 0.0 0.0 1 0.0 0.0 0.0 92 92 103 103 142 142 47881 07:48:35 HA 27847:0x27ae3018 0.1 0.0 0.0 2 0.0 0.0 0.0 78 78 73 73 133 133 47882 07:48:36 HA 27847:0x27b89018 0.1 0.1 0.0 2 0.0 0.0 0.0 188 188 169 169 184 184 47883 07:48:37 HA 27847:0x27c6f018 0.2 0.1 0.0 3 0.0 0.1 0.1 248 248 198 198 271 271 47884 07:48:37 HA 27847:0x27d05148 0.1 0.1 0.0 1 0.0 0.0 0.0 128 128 131 131 163 163 47885 07:48:38 HA 27847:0x27de3148 0.1 0.1 0.0 1 0.0 0.0 0.0 188 188 172 172 232 232 47886 07:48:39 HA 27847:0x27e85018 0.1 0.1 0.0 2 0.0 0.0 0.0 155 155 152 152 171 171 47887 07:48:40 HA 27847:0x27f4c21c 0.1 0.1 0.0 2 0.0 0.0 0.0 152 152 146 146 220 220 47888 07:53:50 CKPTINTVL 27847:0x3bbcf148 4.9 4.9 0.0 3 0.0 0.0 0.0 32071 6545 24851 81 81973 267 47889 07:58:35 HA 27848:0xdfac018 4.5 4.5 0.0 5 0.0 0.0 0.0 26676 5961 21268 74 69274 243 47890 07:58:36 HA 27848:0xe2ba018 0.2 0.2 0.0 1 0.0 0.0 0.0 462 462 491 98 808 161 47891 07:58:42 HA 27848:0xe7ce018 0.3 0.3 0.0 3 0.0 0.0 0.0 770 770 675 112 1364 227 47892 07:58:42 HA 27848:0xe87321c 0.1 0.1 0.0 2 0.0 0.0 0.0 184 184 156 156 182 182 47893 07:58:44 HA 27848:0xe9b4018 0.2 0.1 0.0 4 0.0 0.0 0.0 258 258 235 117 351 175 47894 07:58:45 HA 27848:0xea6e018 0.2 0.1 0.0 3 0.0 0.0 0.0 173 173 166 166 204 204 47895 07:58:45 HA 27848:0xeafb018 0.1 0.1 0.0 2 0.0 0.0 0.0 150 150 150 150 152 152 47896 07:58:46 HA 27848:0xeb93018 0.1 0.0 0.0 2 0.0 0.0 0.0 97 97 92 92 157 157 47897 07:58:46 HA 27848:0xec24148 0.1 0.1 0.0 3 0.0 0.0 0.0 142 142 131 131 162 162 Max Plog Max Llog Max Dskflush Avg Dskflush Avg Dirty Blocked pages/sec pages/sec Time pages/sec pages/sec Time 351 560 9 3245 163 0

Right, so the worst of it was a 4 second checkpoint during which 8 user sessions were blocked for an average of 0.02 seconds and a 7 second checkpoint during which 5 user sessions were blocked for an average of 0.003 seconds. That's a HUGE improvement over earlier releases where those sessions would have been blocked for an average of 2 full seconds and 3.5 seconds respectively! Your queue lengths are only high in a couple of chunks and only in the 30's and 40's, not awful. More important is what are the service times for those devices? You'll have to get that information out of the OS, your VM management SW, or the SAN's. Typically you want low double digits, say below 30ms. If they are higher you should rebalance your storage, move or fragment your tables to other dbspaces or reconfigure your arrays to get more throughput. Art Art S. Kagel Oninit (www.oninit.com) IIUG Board of Directors (art@iiug.org) Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on my employer, Oninit, the IIUG, nor any other organization with which I am associated either explicitly or implicitly. 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 Fri, Jul 17, 2009 at 11:00 AM, KAMRAN HAQ <khaq@i2cinc.com> wrote: > Thanks a lot. It got me out of confusion. And do you hinkthat I/O queue > length > are not bad? > Here are recent messages found in online.log > ------------------------------------------------------------------ > 07:35:02 Logical Log 27846 Complete, timestamp: 0x5a4d390a. > 07:35:02 Process exited with return code 1: /bin/sh /bin/sh -c > /u/informix11.5-3/etc/alarmprogram.sh 2 23 "" "Logical Log 27846 Complete, > tim > estamp: 0x5a4d390a." "" > 07:37:15 Checkpoint Completed: duration was 4 seconds. > > 07:37:15 Maximum server connections 130 > 07:37:15 Checkpoint Statistics - Avg. Txn Block Time 0.020, # Txns blocked > 8, > Plog used 15193, Llog used 43011 > > 07:42:19 Checkpoint Completed: duration was 3 seconds. > > 07:42:19 Maximum server connections 133 > 07:42:19 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked > 5, > Plog used 19672, Llog used 58077 > > 07:44:09 Dynamically allocated new virtual shared memory segment (size > 131072KB) > 07:44:09 Memory sizes:resident:253952 KB, virtual:929792 KB, > SHMTOTAL:4096000 > KB > 07:47:25 Checkpoint Completed: duration was 7 seconds. > > 07:47:25 Maximum server connections 133 > 07:47:25 Checkpoint Statistics - Avg. Txn Block Time 0.003, # Txns blocked > 5, > Plog used 22393, Llog used 70361 > > 07:48:34 Checkpoint Completed: duration was 2 seconds. > > 07:48:34 Maximum server connections 133 > 07:48:34 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked > 1, > Plog used 5302, Llog used 15777 > > 07:48:34 Checkpoint Completed: duration was 0 seconds. > > 07:48:34 Maximum server connections 133 > 07:48:34 Checkpoint Statistics - Avg. Txn Block Time 0.003, # Txns blocked > 1, > Plog used 137, Llog used 262 > > 07:48:35 Checkpoint Completed: duration was 0 seconds. > > 07:48:35 Maximum server connections 133 > 07:48:35 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked > 1, > Plog used 191, Llog used 163 > > 07:48:35 Checkpoint Completed: duration was 0 seconds. > > 07:48:35 Maximum server connections 133 > 07:48:35 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked > 1, > Plog used 103, Llog used 142 > > 07:48:36 Checkpoint Completed: duration was 0 seconds. > > 07:48:36 Maximum server connections 133 > 07:48:36 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked > 2, > Plog used 73, Llog used 133 > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001636c5b154cc0e2f046ee8342d

Strange how? The CKPTINTVL checkpoints were triggered by CKPTINTVL expiring, the HA checkpoints were triggered by AUTO_CKPTS to maintain required recovery time. They are triggered to make certain that there isn't too much data to roll forward during recovery after a crash. The engine has to roll forward from the last completed checkpoint, so if you have that feature turned on, the engine will insert more frequent checkpoints occassionally during periods of high update load to minimize recovery time. Art Art S. Kagel Oninit (www.oninit.com) IIUG Board of Directors (art@iiug.org) Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on my employer, Oninit, the IIUG, nor any other organization with which I am associated either explicitly or implicitly. 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 Fri, Jul 17, 2009 at 11:06 AM, KAMRAN HAQ <khaq@i2cinc.com> wrote: > Hi Art, > Conitued to previous email, there are strange checkpoint triggers against > "onstst -g ckp" > > ------------------------------------------------------- > $ onstat -g ckp> > IBM Informix Dynamic Server Version 11.50.FC3W1 -- On-Line (Prim) (CKPT > INP) > -- Up 02:48:27 -- 1183744 Kbytes > > AUTO_CKPTS=On RTO_SERVER_RESTART=Off> > 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 > 47878 07:48:34 HA 27847:0x27950018 0.1 0.0 0.0 7 0.0 0.1 0.2 147 147 137 > 137 > 262 262 > 47879 07:48:34 HA 27847:0x279dc19c 0.1 0.1 0.0 1 0.0 0.0 0.0 196 196 191 > 191 > 163 163 > 47880 07:48:35 HA 27847:0x27a63018 0.1 0.0 0.0 1 0.0 0.0 0.0 92 92 103 103 > 142 > 142 > 47881 07:48:35 HA 27847:0x27ae3018 0.1 0.0 0.0 2 0.0 0.0 0.0 78 78 73 73 > 133 > 133 > 47882 07:48:36 HA 27847:0x27b89018 0.1 0.1 0.0 2 0.0 0.0 0.0 188 188 169 > 169 > 184 184 > 47883 07:48:37 HA 27847:0x27c6f018 0.2 0.1 0.0 3 0.0 0.1 0.1 248 248 198 > 198 > 271 271 > 47884 07:48:37 HA 27847:0x27d05148 0.1 0.1 0.0 1 0.0 0.0 0.0 128 128 131 > 131 > 163 163 > 47885 07:48:38 HA 27847:0x27de3148 0.1 0.1 0.0 1 0.0 0.0 0.0 188 188 172 > 172 > 232 232 > 47886 07:48:39 HA 27847:0x27e85018 0.1 0.1 0.0 2 0.0 0.0 0.0 155 155 152 > 152 > 171 171 > 47887 07:48:40 HA 27847:0x27f4c21c 0.1 0.1 0.0 2 0.0 0.0 0.0 152 152 146 > 146 > 220 220 > 47888 07:53:50 CKPTINTVL 27847:0x3bbcf148 4.9 4.9 0.0 3 0.0 0.0 0.0 32071 > 6545 > 24851 81 81973 267 > 47889 07:58:35 HA 27848:0xdfac018 4.5 4.5 0.0 5 0.0 0.0 0.0 26676 5961 > 21268 > 74 69274 243 > 47890 07:58:36 HA 27848:0xe2ba018 0.2 0.2 0.0 1 0.0 0.0 0.0 462 462 491 98 > 808 > 161 > 47891 07:58:42 HA 27848:0xe7ce018 0.3 0.3 0.0 3 0.0 0.0 0.0 770 770 675 112 > 1364 227 > 47892 07:58:42 HA 27848:0xe87321c 0.1 0.1 0.0 2 0.0 0.0 0.0 184 184 156 156 > 182 182 > 47893 07:58:44 HA 27848:0xe9b4018 0.2 0.1 0.0 4 0.0 0.0 0.0 258 258 235 117 > 351 175 > 47894 07:58:45 HA 27848:0xea6e018 0.2 0.1 0.0 3 0.0 0.0 0.0 173 173 166 166 > 204 204 > 47895 07:58:45 HA 27848:0xeafb018 0.1 0.1 0.0 2 0.0 0.0 0.0 150 150 150 150 > 152 152 > 47896 07:58:46 HA 27848:0xeb93018 0.1 0.0 0.0 2 0.0 0.0 0.0 97 97 92 92 157 > 157 > 47897 07:58:46 HA 27848:0xec24148 0.1 0.1 0.0 3 0.0 0.0 0.0 142 142 131 131 > 162 162 > > Max Plog Max Llog Max Dskflush Avg Dskflush Avg Dirty Blocked > pages/sec pages/sec Time pages/sec pages/sec Time > 351 560 9 3245 163 0 > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001636c5b8efbfe483046ee8427f

Hi Art, These stats are of a primary node in HDR cluster with 1 secondary and 2 RSS nodes. Does HDR also has non-blocking checkpoints?

If your secondaries are read-only then the checkpoints there are irrelevant because there are no local transactions to block. If the secondaries are writeable, then it is really only the checkpoints on the primary that we are concerned about anyway because when you write to a session on a secondary server the write request is forwarded to the primary which makes the update there and notifies the secondary that it can safely change it's own cached copy of the page. So, either way, only the checkpoints on the primary really block anything even for the brief time that the blocks exist. Beyond that, SDS secondaries don't ever write to the disk at all except for their locally defined temp dbspaces and HDR secondaries don't perform buffer flushes and normal checkpoints either, they are just applying the logical log records that the primary is sending over, so a checkpoint is just a note in the local copy of the logical log. There are never any dirty buffers that will be flushed on secondaries unless the primary crashes and the secondary has to become a primary or stand-alone server. Art Art S. Kagel Oninit (www.oninit.com) IIUG Board of Directors (art@iiug.org) Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on my employer, Oninit, the IIUG, nor any other organization with which I am associated either explicitly or implicitly. 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 Fri, Jul 17, 2009 at 11:25 AM, KAMRAN HAQ <khaq@i2cinc.com> wrote: > Hi Art, > These stats are of a primary node in HDR cluster with 1 secondary and 2 RSS > nodes. Does HDR also has non-blocking checkpoints? > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001636c5bb71eacb8f046ee88da4