PostgreSQL Checkpoint Log Explained

checkpointlogpostgresqlwrite-ahead-logging

I know what PostgreSQL checkpoint is and when it is happening.

I need some additional information about the logs produced by the log_checkpoints = on parameter, so please explain some points of it to me:

2017-09-09 16:31:37 EEST [6428-6524] LOG: checkpoint complete: wrote 30057 buffers (22.9%); 0 transaction log file(s) added, 0 removed, 47 recycled; write=148.465 s, sync=34.339 s, total=182.814 s; sync files=159, longest=16.143 s, average=0.215 s

  1. I know that 22.9% of shared buffers are written (I have 1024 MB shared_buffers so that means 234 MB are written out).
  2. I know that 47 WAL files are recycled, i.e., they are not needed anymore for crash recovery, because the real data from them is already on disk.

Question A. But what about write=148.465 s and sync=34.339? What is the difference? What is write and why its time is far more than the fsync() operation?

Question B. What are sync files? Which files: WAL files? Why sync files are 159, but there are only 47 recycled files? What is the relation between these?

Thank you!

Best Answer

To your question A: "write" and "sync" mean exactly what they say; it's a sequence of buffered (as in filesystem I/O buffers) writes of dirty pages from the Postgres buffer pool, followed by fsync() (usually) to ensure that filesystem buffers are in fact written to disk. Writes are throttled and happen in the background, so they can take longer.

To your question B: sync files tells you how many OS files have been affected by the checkpoint. As each table and index is stored in its own file, the number gives you an idea of how many database objects have been affected by the checkpoint. WALs are synchronized when the WAL buffer is flushed, that is, way before the checkpoint; that's why it's called "write ahead".