On 7 Září 2011, 21:26, Martín Marqués wrote:
> I'm logging checkpoints to see how the background writter is working,
> and I bumped into log information that I don't fully understand:
>
> LOG: checkpoint complete: wrote 5015 buffers (15.1%); 0 transaction
> log file(s) added, 0 removed, 15 recycled; write=1004.333 s,
> sync=0.106 s, total=1004.571 s
>
> 5015 are the WAL buffers written to the transaction log, but what is the
> 15.1%?
That's the portion of shared buffers that was written. If 5015 is 15.1% of
shared buffers, I guess you have about 256MB shared buffers. Am I right?
> Also, what do the times at the end mean? Time to write the buffers to
> the transaction log, or to flush modificactions stored in the
> transaction logs to there final destination in the data base files?
No, this had nothing to do with transaction logs. Checkpoint means writing
dirty shared buffers to the data files. The numbers give you an idea how
long it took to write the data and sync them to the drive (to make sure
it's actually written to the device).
For example you know you had to write 5015 buffers (that's about 40MB),
and it took about 1000 seconds to write them - that means the average
write speed was about 40kB/s.
I guess this was a timed checkpoint - not sure what the actual timeout and
completion target was, but whenever a timeout expires a checkpoint is
issued (so that the recovery does not take too long). Timed checkpoints
generally are not very intrusive - if the timeout is 10 minutes and
completion target is 0.5, the checkpoint should finish in 5 minutes.
With forced checkpoint (e.g. when there are not enough checkpoint segments
or when you execute CHECKPOINT manually), the behaviour is much more
intrusive as the checkpoint needs to happen ASAP.
Tomas
