Checkpoint logging, revised patch

From: Heikki Linnakangas <heikki(at)enterprisedb(dot)com>
To: Patches <pgsql-patches(at)postgresql(dot)org>
Subject: Checkpoint logging, revised patch
Date: 2007-06-29 20:31:29
Message-ID: 46856C21.5060401@enterprisedb.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-patches

Here's a reworked version Greg Smith's patch for logging checkpoints. It
adds a GUC variable, log_checkpoints, along the lines of log_connections
and log_autovacuum. Enabling it causes two lines to be printed to the
system log per checkpoint, like this:

LOG: checkpoint starting
LOG: checkpoint complete; buffers written=5869 (35.8%); write=2.081 s,
sync=4.851 s, total=7.066 s

The purpose of the first message is that by inspecting the logs, you can
easily see when a checkpoint is/was active. And if you experience
mysterious slowdowns etc., you can see if they coincide with a
checkpoint if you have log_min_duration enabled. The completion message
prints stats conveniently in a single line so it can be easily grepped
and parsed from the logs.

The implementation uses a global CheckpointStats-struct where data is
collected during the checkpoint. At the end, it's spit out to the log as
a nicely formatted message. I refactored PreallocXlogFiles and
RemoveXlogFiles to use that struct as well for reporting the # of WAL
segments removed, added and recycled. Global variables are generally not
considered good style, but IMHO in this case it's the cleanest approach.
Another options would be to pass down a reference to the struct to all
functions involved in checkpointing, or return individual numbers from
all functions and collect them together in CreateCheckPoint. Both
alternatives would complicate the function signatures significantly.
There's precedent for this approach in BgWriterStats and the buffer
usage counters (BufferHitCount et al).

One thing that's missing, that I originally hoped to achieve with this,
is logging the cause of a checkpoint. Doing that would have required
either sprinkling elogs to all callers of RequestCheckpoint, or adding a
"reason" parameter to it and decoding that to a log message inside
RequestCheckpoint, which seems a bit ugly just for logging purposes.
Also, that would have meant printing one more log message per
checkpoint, making it more chatty than I'd like it to be. Instead, I'm
just printing a different log message for immediate checkpoint requests.
Differentiating between immediate checkpoints triggered by a command
like CHECKPOINT or CREATE DATABASE and normal checkpoints should be
enough in practice.

I'm done with this.

--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com

Attachment Content-Type Size
log_checkpoints-1.patch text/x-diff 14.8 KB

Responses

Browse pgsql-patches by date

  From Date Subject
Next Message Tom Lane 2007-06-29 20:37:29 Re: SPI-header-files safe for C++-compiler
Previous Message Neil Conway 2007-06-29 19:43:00 Re: SPI-header-files safe for C++-compiler