Re: Logging checkpoints and other slowdown causes

On Fri, 11 May 2007, Heikki Linnakangas wrote:

> Printing the messages at LOG-level would bring the code in line with the
> documentation, but I don't think we want to fill the log with checkpoint
> chatter unless the DBA explicitly asks for that.  How about INFO?

In putting that together, I pushed everything toward the lowest DEBUG
level that it was possible for it to run at without the messages I wanted
to see being completely lost.  I didn't want this to get rejected just on
the basis of being too chatty for regular users.  Putting a single line in
for each checkpoint at INFO, with all the individual progress points being
at DEBUG1 or 2, would be close to optimal as far as I'm concerned.  More
on this below.

> Or we could add a GUC variable similar to log_connections or log_statement to
> control if the messages are printed or not, and use LOG.

If the levels for the individual messages are adjusted usefully the
ability to control whether they show up or not falls out of the existing
log level adjustments; I haven't ever felt a strong need for GUC when
using this code.  If, as you say, there's already a move in this
direction, then fine--another GUC would be better.

> We don't need to print the times elapsed in each phase on a separate
> line, that's just derived information from the other lines, unless we
> use different log-levels for detail lines

Let me turn this around for a second and ask you this:  what do you think
people are going to do with this information?  I can tell you what I do.
I parse the logs and look for that single line with the summary
information.  I then take the three pieces of information it provides (MB
written, time to write, time to fsync) and save them into a table.  From
there I generate stats, scatter plots, all sorts of useful stuff.

If you know when the checkpoint ended, and you know how long each of the
pieces took, you can reconstruct the other times easily.  The way you
describe this it is true--that the summary is redundant given the
detail--but if you put yourself in the shoes of a log file parser the
other way around is easier to work with.  Piecing together log entries is
a pain, splitting them is easy.

If I had to only keep one line out of this, it would be the one with the
summary.  It would be nice to have it logged at INFO.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD