Monday, March 25

Measuring PostgreSQL Checkpoint Statistics

Checkpoints can be a major drag on write-heavy PostgreSQL installations. The first step toward identifying issues in this area is to monitor how often they happen, which just got an easier to use interface added to the database recently.


Checkpoints are periodic maintenance operations the database performs to make sure that everything it’s been caching in memory has been synchronized with the disk. The idea is that once you’ve finished one, you can eliminate needing to worry about older entries placed into the write-ahead log of the database. That means less time to recover after a crash.
The problem with checkpoints is that they can be very intensive, because to complete one requires writing every single bit of changed data in the database’s buffer cache out to disk. There were a number of features added to PostgreSQL 8.3 that allow you to better monitor the checkpoint overhead, and to lower it by spreading the activity over a longer period of time. I wrote a long article about those changes called Checkpoints and the Background Writer that goes over what changed, but it’s pretty dry reading.
What you probably want to know is how to monitor checkpoints on your production system, and how to tell if they’re happening too often. Even though things have improved, “checkpoint spikes” where disk I/O becomes really heavy are still possible even in current PostgreSQL versions. And it doesn’t help that the default configuration is tuned for very low disk space and fast crash recovery rather than performance. The checkpoint_segments parameter that’s one input on how often a checkpoint happens defaults to 3, which forces a checkpoint after only 48MB of writes.
You can find out checkpoint frequency two ways. You can turn on log_checkpoints and watch what happens in the logs. You can also use the pg_stat_bgwriter view, which gives a count of each of the two sources for checkpoints (time passing and writes occurring) as well as statistics about how much work they did.
The main problem with making that easier to do is that until recently, it’s been impossible to reset the counters inside of pg_stat_bgwriter. That means you have to take a snapshot with a timestamp on it, wait a while, take another snapshot, then subtract all the values to derive any useful statistics from the data. That’s a pain.
Enough of a pain that I wrote a patch to make it easier. With the current development version of the database, you can now call pg_stat_reset_shared(‘bgwriter’) and pop all these values back to 0 again. This allows following a practice that used to be common on PostgreSQL. Before 8.3, there was a parameter named stats_reset_on_server_start you could turn on. That reset all of the server’s internal statistics each time you started it. That meant that you could call the handy pg_postmaster_start_time() function, compare with the current time, and always have an accurate count in terms of operations/second of any statistic available on the system.
It’s still not automatic, but now that resetting these shared pieces is possible you can do it yourself. The first key is to integrate statistics clearing into your server startup sequence. A script like this will work:


pg_ctl start -l $PGLOG -w
psql -c "select pg_stat_reset();"
psql -c "select pg_stat_reset_shared('bgwriter');"

Note the “-w” on the start command there–that will make pg_ctl wait until the server is finished starting before it returns, which is vital if you want to immediately execute a statement against it.
If you’ve done that, and your server start time is essentially the same as when the background writer stats started collection, you can now use this fun query:


SELECT
total_checkpoints,
seconds_since_start / total_checkpoints / 60 AS minutes_between_checkpoints
FROM
(SELECT
EXTRACT(EPOCH FROM (now() - pg_postmaster_start_time())) AS seconds_since_start
(checkpoints_timed+checkpoints_req) AS total_checkpoints
FROM pg_stat_bgwriter
) AS sub;

And get a simple report of exactly how often checkpoints are happening on your system. The output looks like this:


total_checkpoints           | 9
minutes_between_checkpoints | 3.82999310740741

What you do with this information is stare at the average time interval and see if it seems too fast. Normally, you’d want a checkpoint to happen no more than every five minutes, and on a busy system you might need to push it to ten minutes or more to have a hope of keeping up. With this example, every 3.8 minutes is probably too fast–this is a system that needs checkpoint_segments to be higher.
Using this technique to measure the checkpoint interval lets you know if you need to increase the checkpoint_segments and checkpoint_timeout parameters in order to achieve that goal. You can compute the numbers manually right now, and once 9.0 ships it’s something you can consider making completely automatic–so long as you don’t mind your stats going away each time the server restarts.
There are some other interesting ways to analyze the data the background writer provides for you in pg_stat_bgwriter, but I’m not going to give away all of my tricks today.

One Comment

  • springrider

    the last sql missed a comma, “AS seconds_since_start (checkpoints_timed+checkpoints_req) AS total_checkpoints”

    should be:

    “AS seconds_since_start, (checkpoints_timed+checkpoints_req)”.

    nice tip, thanks!

Leave a Reply

Your email address will not be published. Required fields are marked *