22

Here's part of my checkpoint log:

2014-03-26 11:51:29.341 CDT,,,18682,,532854fc.48fa,4985,,2014-03-18 09:15:24 CDT,,0,LOG,00000,"checkpoint complete: wrote 15047 buffers (1.4%); 0 transaction log file(s) added, 0 removed, 30 recycled; write=68.980 s, sync=1.542 s, total=70.548 s; sync files=925, longest=0.216 s, average=0.001 s",,,,,,,,,""
2014-03-26 11:56:05.430 CDT,,,18682,,532854fc.48fa,4987,,2014-03-18 09:15:24 CDT,,0,LOG,00000,"checkpoint complete: wrote 16774 buffers (1.6%); 0 transaction log file(s) added, 0 removed, 31 recycled; write=72.542 s, sync=17.164 s, total=89.733 s; sync files=885, longest=3.812 s, average=0.019 s",,,,,,,,,""
2014-03-26 12:01:21.650 CDT,,,18682,,532854fc.48fa,4989,,2014-03-18 09:15:24 CDT,,0,LOG,00000,"checkpoint complete: wrote 14436 buffers (1.4%); 0 transaction log file(s) added, 0 removed, 33 recycled; write=122.350 s, sync=5.212 s, total=127.676 s; sync files=924, longest=3.740 s, average=0.005 s",,,,,,,,,""
2014-03-26 12:06:25.028 CDT,,,18682,,532854fc.48fa,4991,,2014-03-18 09:15:24 CDT,,0,LOG,00000,"checkpoint complete: wrote 13277 buffers (1.3%); 0 transaction log file(s) added, 0 removed, 29 recycled; write=126.217 s, sync=5.733 s, total=131.991 s; sync files=894, longest=1.859 s, average=0.006 s",,,,,,,,,""
2014-03-26 12:10:41.958 CDT,,,18682,,532854fc.48fa,4993,,2014-03-18 09:15:24 CDT,,0,LOG,00000,"checkpoint complete: wrote 20765 buffers (2.0%); 0 transaction log file(s) added, 0 removed, 28 recycled; write=88.015 s, sync=10.818 s, total=98.872 s; sync files=881, longest=2.690 s, average=0.012 s",,,,,,,,,""

I noticed that sometimes our database is very slow - you can see a very large number of normally short queries stuck for much longer than now. It happens regularly without a clear culprit.

Question: Could checkpoint cause this? What happens in the "sync" phase of checkpoint?

32

During its operation, PostgreSQL records changes to transaction log files, but it doesn't immediately flush them to the actual database tables. It usually just keeps the changes in memory, and returns them from memory when they are requested, unless RAM starts getting full and it has to write them out.

This means that if it crashes, the on disk tables won't be up to date. It has to replay the transaction logs, applying the changes to the on-disk tables, before it can start back up. That can take a while for a big, busy database.

For that reason, and so that the transaction logs do not keep growing forever, PostgreSQL periodically does a checkpoint where it makes sure the DB is in a clean state. It flushes all pending changes to disk and recycles the transaction logs that were being used to keep a crash recovery record of the changes.

This flush happens in two phases:

  • Buffered write()s of dirty shared_buffers to the tables; and
  • fsync() of affected files to make sure the changes really hit disk

Both of those can increase disk I/O load. Contention caused by these writes can slow down reads, and can also slow down flushing of WAL segments that's required in order to commit transactions.

It's been a longstanding challenge, but it's getting worse as we see systems with more and more RAM so they can buffer more data and take longer to write it out. There's discussion between the Linux and PostgreSQL communities on how to deal with this at the moment, as discussed in this LWN.net article. (LWN.net won't be able to keep writing this sort of great work if people don't subscribe. I'm a subscriber and sharing this link because it's useful and informative. Please consider subscribing if you want to see more of this sort of thing.)

The main thing you can do to reduce the impact of checkpoints at the moment is to spread checkpoint activity out by increasing checkpoint_completion_target so that more of the data has been written out by the time the final checkpoint arrives. This has a cost, though - if you update a page (say) ten times, it might be written to disk multiple times before the checkpoint with a high completion target, even though it only strictly had to be written out once for crash safety. A higher completion target makes for smoother I/O patterns but more overall I/O overhead.

The other thing you can do to help is tell your operating system to immediately start writing data when it gets buffered writes. This is like the kernel side of setting checkpoint_completion_target and has a similar trade-off. See the linux vm documentation, in particular dirty_background_bytes, dirty_background_ratio, dirty_expire_centisecs.

  • The write is spread out over a long time and I don't think it's causing issues. What about the sync, is it by any chance a stop-the-world kind of operation? – Konrad Garus Mar 27 '14 at 16:20
  • @KonradGarus The sync shouldn't be a stop-the-world kind of operation, but it often is anyway. Read the article I linked to above, it's a very timely and useful summary of the issues, albeit from a fairly technical point of view. The short version is "fsync() on Linux tends to completely trash performance of any I/O concurrent with the fsync()". You can mitigate that with the tuning options listed above, to reduce the amount that must be flushed out by an fsync. – Craig Ringer Mar 28 '14 at 0:01
1

Flushing the dirty OS file system buffers caused by exceeding dirty_bytes or dirty_ratio is a foreground blocking operation!

The kernel tunables dirty_bytes, dirty_background_bytes, dirty_ratio, dirty_background_ratio and dirty_centisecs control flushing of dirty OS file system buffers to disk. dirty_bytes is the threshold in bytes, dirty_ratio is the threshold as a ratio of total memory. dirty_background_bytes and dirty_background_ratio are similar thresholds, but flushing happens in the background and does not block other read/write operations until it completes. dirty_centisecs is how many centiseconds can pass before a flush is initiated.

Recently the defaults for these tunables was lowered in Linux, as memory size for modern machines has increased dramatically. Even ratios of 5 and 10% for dirty_background_ratio and dirty_ratio on a 256GB machine can flood an I/O system.

Tuning dirty_background_bytes or dirty_background_ratio to start flushing dirty buffers in the background is tricky. Fortunately you can tune these settings without having to stop either PostgreSQL or the host by echoing new values to the appropriate files:

$ sudo echo [int value of bytes] > /proc/sys/vm/dirty_background_bytes

for example to set the number of dirtied bytes to trigger a background flush. If you are using a battery-backed, capacitor-backed, or flash memory RAID card (you do want to keep your data in case of a crash, don't you?) start by tuning dirty_background_bytes to 1/2 the write cache buffer size and dirty_bytes to 3/4 that size. Monitor your I/O profile with iostats and if you are still seeing latency issues that means your database write load is still overwhelming the file buffer cache flushes. Turn the values down until latency improves or consider upgrading your I/O subsystem. FusionIO cards and SSDs are two possibilities for extreme I/O throughput.

Good luck!

  • Your comment on "dirty" data is a relevant point for the slowness. Essentially: the larger the dirty ratio, the more buffer is allocated for dirty data before flushing kicks in. Thus, minimizing flushing delays means increasing the dirty buffer, or increasing the time the dirty data can remain in memory. – Peter Teoh Aug 30 '16 at 15:59

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.