Re: Instrument checkpoint sync calls

Robert Haas wrote:
> I took a look at this and it looks generally good, but I'm wondering
> why md.c is converting the results from an exact value to a floating
> point, only to have xlog.c turn around and convert back to an integer.
> I think it could just return milliseconds directly, or if you're
> worried about a checkpoint that takes more than 24 days to complete,
> seconds and microseconds.

Attached patch now does something like this, except without the
roll-over concern. INSTR_TIME_GET_MICROSEC returns a uint64 value. I
just made that the storage format for all these values until they're
converted for display. Test output:

LOG: checkpoint starting: xlog
DEBUG: checkpoint sync: number=1 file=base/16385/16480 time=10422.859 msec
DEBUG: checkpoint sync: number=2 file=base/16385/16475_vm time=2896.614
msec
DEBUG: checkpoint sync: number=3 file=base/16385/16475.1 time=57.836 msec
DEBUG: checkpoint sync: number=4 file=base/16385/16466 time=20.080 msec
DEBUG: checkpoint sync: number=5 file=base/16385/16463 time=74.926 msec
DEBUG: checkpoint sync: number=6 file=base/16385/16482 time=74.263 msec
DEBUG: checkpoint sync: number=7 file=base/16385/16475_fsm time=7.062 msec
DEBUG: checkpoint sync: number=8 file=base/16385/16475 time=35.164 msec
LOG: checkpoint complete: wrote 2143 buffers (52.3%); 0 transaction log
file(s) added, 0 removed, 3 recycled; write=1.213 s, sync=13.589 s,
total=24.744 s; sync files=8, longest=10.422 s, average=1.698 s

This shows the hard truncation used, so 10422.859 msec becomes 10.422
s. I don't think allowing up to 0.999ms of error there is a problem
given the expected scale. But since none of the precision is lost until
the end, that could be changed with only touching the final display
formatting conversion of the value. Following your general idea
further, why throw away any resolution inside of md.c; let xlog.c decide
how to show it.

Note that I also fixed the DEBUG level lines to only show their actual
precision. Before that was printing 6 digits to the right of the
decimal point each time, the last three of which were always 0.

--
Greg Smith 2ndQuadrant US greg(at)2ndQuadrant(dot)com Baltimore, MD
PostgreSQL Training, Services and Support www.2ndQuadrant.us
"PostgreSQL 9.0 High Performance": http://www.2ndQuadrant.com/books