We're still learning to tune PostgreSQL for our production setup, and over
the weekend we saw a huge spike in INSERT/UPDATE completion time for a
short period which turned out to correlate to an oversized checkpoint. I've
included the preceding and following checkpoints for reference points, as
they're typical of the usual checkpoints we see:
Jun 16 06:01:19 sql-2 postgres[19015]: [10706-1] 2014-06-16 06:01:19
UTC LOG: checkpoint starting: time
Jun 16 06:04:40 sql-2 postgres[19015]: [10707-1] 2014-06-16 06:04:40
UTC LOG: checkpoint complete: wrote 1962 buffers (0.7%); 0 transaction log
file(s) added, 0 removed, 1 recycled; write=197.906 s, sync=2.411 s,
total=200.697 s; sync files=42, longest=1.110 s, average=0.057 s
Jun 16 06:06:19 sql-2 postgres[19015]: [10708-1] 2014-06-16 06:06:19
UTC LOG: checkpoint starting: time
Jun 16 06:12:03 sql-2 postgres[19015]: [10709-1] 2014-06-16 06:12:03
UTC LOG: checkpoint complete: wrote 25958 buffers (9.9%); 0 transaction
log file(s) added, 0 removed, 12 recycled; write=269.832 s, sync=74.105 s,
total=344.294 s; sync files=49, longest=64.421 s, average=1.512 s
Jun 16 06:12:03 sql-2 postgres[19015]: [10710-1] 2014-06-16 06:12:03
UTC LOG: checkpoint starting: time
Jun 16 06:16:35 sql-2 postgres[19015]: [10711-1] 2014-06-16 06:16:35
UTC LOG: checkpoint complete: wrote 2900 buffers (1.1%); 0 transaction log
file(s) added, 0 removed, 1 recycled; write=269.369 s, sync=2.357 s,
total=271.820 s; sync files=47, longest=0.694 s, average=0.050 s
What I don't understand and am hoping you can help me with is why a
checkpoint would balloon like the 06:06:19 one did. While we were
experiencing higher load on our systems at this time, the elevated load
lasted for almost an hour at a constant clip, and only this one checkpoint
ballooned. As far as I can tell there wasn't anything unique or abnormal
about the queries being run during this particular checkpoint.
Somewhat unique aspects to our PostgreSQL usage:
- we only INSERT/UPDATE, never DELETE
- we use pk+hstore tables exclusively
- we write more than we read
What can trigger this kind of out of character checkpoint? What should I be
looking at to understand this?
Thanks!
--
Nathaniel
