Physical Log size
Posted in 2019
Topics: Logging & Checkpoints
IDS 12.10.FC9W1
AIX 7
I am trying to calculate if our Physical Log size is big enough.
My reason:
Checkpoint Completed: duration was 171 seconds.
Sometimes we get hit by large checkpoints.
From the manual:
----------------
To ensure that you have an abundance of space, set the size of the physical
log to at least 110 percent of the size of all buffer pools.
From my server:
---------------
BUFFERPOOL
size=4K,buffers=21750000,lrus=256,lru_min_dirty=0.00,lru_max_dirty=0.50
BUFFERPOOL
size=8K,buffers=2625000,lrus=128,lru_min_dirty=0.00,lru_max_dirty=0.50
BUFFERPOOL default,buffers=1000,lrus=22,lru_min_dirty=50.00,lru_max_dirty=60.00
Here I am stuck. Do I look at Total Bufferpool (4k + 8k) ? Or do I dig deeper,
and if so, how ?
Another question, on this one -
PHYSDBS physdbs # Location (dbspace) of physical log
PHYSFILE 54000000 # Physical log file size (Kbytes)
PHYSBUFF 4096 # Physical log buffer size (Kbytes)
If I increase this, can I decrease it again ?
Hi Dirk,
I don't know your system but unless you have a specific reason to suspect the
physical log size, I don't think it is a likely cause, especially as it is
quite large already. I would start by looking at what is happening during your
slow checkpoints.
Do you have output from 'onstat -g ckp' or sysadmin:mon_checkpoint, assuming
you have the mon_checkpoint scheduler job running? It would be interesting to
see the slow checkpoint alongside a "good" checkpoint or two.
During a long checkpoint roughly how much time does the server spend in states
'CKPT REQ' and 'CKPT INP' (check with 'onstat -')? When it's in 'CKPT INP'
have you captured data from 'onstat -F' showing which flushers are active and
which chunks they are working on?
Ben.
Thank you for your response. I will have to RTFM regarding this. A bit over my
head right now.
I will share the onstat -g ckp so long:
(at the bottom it says, physical log might be too small)
onstat -g ckp
IBM Informix Dynamic Server Version 12.10.FC9W1 -- On-Line -- Up 13 days
08:48:59 -- 227111520 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
790824 11:29:09 CKPTINTVL 13144:0xb237f8c 4.5 4.1 0.0 50 0.0 0.2 0.3 55070
13344 367615 1127 91 0
790825 11:34:19 CKPTINTVL 13144:0xb25273c 5.2 4.8 0.0 48 0.0 0.3 0.3 45834
9606 231831 750 27 0
790826 11:39:27 CKPTINTVL 13144:0xb264424 2.8 2.5 0.0 37 0.0 0.1 0.2 80756
31708 142367 457 18 0
790827 11:44:41 CKPTINTVL 13144:0xb2ba4bc 7.6 7.2 0.0 43 0.0 0.2 0.2 84469
11689 127533 412 86 0
790828 11:49:44 CKPTINTVL 13144:0xb2cc2ac 2.3 2.0 0.0 43 0.0 0.2 0.2 75226
37138 157719 512 18 0
790829 11:54:50 CKPTINTVL 13144:0xb2f13b4 4.3 4.0 0.0 49 0.0 0.2 0.2 74725
18888 349106 1148 37 0
790830 11:59:56 CKPTINTVL 13144:0xb30f13c 3.4 3.1 0.0 48 0.0 0.2 0.2 37980
12436 534563 1741 30 0
790831 12:05:11 CKPTINTVL 13144:0xb323c58 6.2 4.8 0.0 92 0.0 0.9 1.1 53189
11091 818213 2614 20 0
790832 12:10:22 CKPTINTVL 13144:0xb3348b0 5.7 5.1 0.0 60 0.0 0.2 0.3 44907
8763 498561 1603 17 0
790833 12:15:29 CKPTINTVL 13144:0xb371084 4.6 4.2 0.0 44 0.0 0.2 0.3 70508
16985 564826 1833 61 0
790834 12:20:37 CKPTINTVL 13144:0xb392e74 4.9 4.6 0.0 40 0.0 0.2 0.2 42949
9320 595028 1931 33 0
790835 12:25:51 CKPTINTVL 13144:0xb3f0b0c 8.6 8.2 0.0 31 0.0 0.2 0.3 50988
6205 493491 1591 95 0
790836 12:31:05 CKPTINTVL 13144:0xb406230 4.3 4.0 0.0 25 0.0 0.1 0.2 55619
13844 365788 1150 22 0
790837 12:36:10 CKPTINTVL 13144:0xb41beb4 3.4 3.1 0.0 21 0.0 0.2 0.3 44075
14363 216661 708 21 0
790838 12:41:17 CKPTINTVL 13144:0xb483018 6.4 6.0 0.0 24 0.0 0.1 0.2 61208
10166 105972 348 104 0
790839 12:46:29 CKPTINTVL 13144:0xb49b0e8 8.3 8.0 0.0 22 0.0 0.2 0.2 52890
6589 135857 438 24 0
790840 12:51:36 CKPTINTVL 13144:0xb86e2bc 6.9 6.6 0.0 18 0.0 0.1 0.2 58071
8861 101357 328 979 3
790841 12:56:45 CKPTINTVL 13144:0xb8828fc 5.9 5.5 0.0 24 0.0 0.1 0.2 54951
10042 180011 580 20 0
790842 13:02:10 CKPTINTVL 13144:0xb899710 24.2 23.8 0.0 39 0.0 0.2 0.3 62783
2638 294797 963 23 0
790843 13:06:50 CKPTINTVL 13144:0xb8b1e54 4.7 4.2 0.0 24 0.0 0.2 0.3 55090
13048 617363 2057 24 0
Max Plog Max Llog Max Dskflush Avg Dskflush Avg Dirty Blocked
pages/sec pages/sec Time pages/sec pages/sec Time
29703 1534 1985 9331 33 0
Based on the current workload, the physical log might be too small
to accommodate the time it takes to flush the buffer pool during
checkpoint processing. The server might block transactions during checkpoints.
If the server blocks transactions, increase the physical log size to
at least 240000240 KB.
Looking at your 'onstat -g ckp' output, most of the time is spent flushing
data to disk which means your server should be in state 'CKPT INP' for most of
the checkpoint.
The next step is to collect data from 'onstat -F' during a long checkpoint,
say every second. You would be looking for particular chunks that take a long
time to flush. The next step would be to understand what is in those chunks
(oncheck -pe) and why there are a lot of changes to flush. Possibly you could
move things around to balance the load across more chunks, reducing the flush
time. Depending on how much effort this is, you might want to consider whether
the long checkpoints are actually a problem or not, since they should be
non-blocking. It's also worth checking disk I/O rates.
The message is basically saying that for a non-blocking checkpoint to work the
physical log needs to be large enough to hold changes that occur while the
checkpoint is occurring. Theoretically the system could need to flush every
buffer pool page. If the physical log is too small the system will block until
the checkpoint finishes. I can't see that this is happening on your system
from the data supplied and the 1.1x the total bufferpools suggestion is a
worst case scenario.
Ben.
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