log_checkpoints, microseconds

Started by Peter Geogheganabout 12 years ago13 messagesbugs
Jump to latest

The following code appears within md.c:

if (seg != NULL &&
FileSync(seg->mdfd_vfd) >= 0)
{
/* Success; update statistics about sync timing */
INSTR_TIME_SET_CURRENT(sync_end);
sync_diff = sync_end;
INSTR_TIME_SUBTRACT(sync_diff, sync_start);
elapsed = INSTR_TIME_GET_MICROSEC(sync_diff);
if (elapsed > longest)
longest = elapsed;
total_elapsed += elapsed;
processed++;
if (log_checkpoints)
elog(DEBUG1, "checkpoint sync: number=%d file=%s time=%.3f msec",
processed,
FilePathName(seg->mdfd_vfd),
(double) elapsed / 1000);

break; /* out of retry loop */
}

Did the author of this code really intend that "elapsed" microseconds
be divided by 1000 like this?
--
Peter Geoghegan

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#2John R Pierce
pierce@hogranch.com
In reply to: Peter Geoghegan (#1)
Re: log_checkpoints, microseconds

On 4/9/2014 10:47 PM, Peter Geoghegan wrote:

if (log_checkpoints)
elog(DEBUG1, "checkpoint sync: number=%d file=%s time=%.3f msec",
processed,
FilePathName(seg->mdfd_vfd),
(double) elapsed / 1000);

break; /* out of retry loop */
}

Did the author of this code really intend that "elapsed" microseconds
be divided by 1000 like this?

thats just for the log, and you'll note it says "%.3f msec" in the entry.

--
john r pierce 37N 122W
somewhere on the middle of the left coast

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#3Bruce Momjian
bruce@momjian.us
In reply to: John R Pierce (#2)
Re: log_checkpoints, microseconds

On Thu, Apr 10, 2014 at 2:03 AM, John R Pierce <pierce@hogranch.com> wrote:

thats just for the log, and you'll note it says "%.3f msec" in the entry.

I think his point is that to go from microseconds to msec (which I
think should just be "ms" btw) you want to multiply by 1000 not
divide.

--
greg

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

In reply to: Bruce Momjian (#3)
Re: log_checkpoints, microseconds

On Thu, Apr 10, 2014 at 11:45 AM, Greg Stark <stark@mit.edu> wrote:

I think his point is that to go from microseconds to msec (which I
think should just be "ms" btw) you want to multiply by 1000 not
divide.

Right. Or just use the INSTR_TIME_GET_MILLISEC() macro to begin with,
and do neither.

--
Peter Geoghegan

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#5Tom Lane
tgl@sss.pgh.pa.us
In reply to: Peter Geoghegan (#4)
Re: log_checkpoints, microseconds

Peter Geoghegan <pg@heroku.com> writes:

On Thu, Apr 10, 2014 at 11:45 AM, Greg Stark <stark@mit.edu> wrote:

I think his point is that to go from microseconds to msec (which I
think should just be "ms" btw) you want to multiply by 1000 not
divide.

Right.

I think you're both wrong. 1000 usec = 1 msec, not the other way round.

Or just use the INSTR_TIME_GET_MILLISEC() macro to begin with,
and do neither.

The code appears to be trying to track stats at the microsecond
level. The printout is following a policy decision that we prefer
to report units of msec, but that does not mean that we shouldn't
keep microsecond precision internally.

In short, I see nothing that needs fixed here.

regards, tom lane

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

In reply to: Tom Lane (#5)
Re: log_checkpoints, microseconds

On Thu, Apr 10, 2014 at 12:20 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

I think you're both wrong. 1000 usec = 1 msec, not the other way round.

Yes, but why would you ever want to divide any number of microseconds
by 1000 like this, unless you were actually interested in nanoseconds?
The point is that we start out with microseconds "elapsed" here, not
milliseconds or seconds.

--
Peter Geoghegan

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#7Gavin Flower
GavinFlower@archidevsys.co.nz
In reply to: Peter Geoghegan (#6)
Re: log_checkpoints, microseconds

On 11/04/14 07:43, Peter Geoghegan wrote:

On Thu, Apr 10, 2014 at 12:20 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

I think you're both wrong. 1000 usec = 1 msec, not the other way round.

Yes, but why would you ever want to divide any number of microseconds
by 1000 like this, unless you were actually interested in nanoseconds?
The point is that we start out with microseconds "elapsed" here, not
milliseconds or seconds.

123456 microseconds = 123.456 milliseconds

So to get milliseconds you divide the number of microseconds by 1000.

Cheers,
Gavin

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#8Bruce Momjian
bruce@momjian.us
In reply to: Tom Lane (#5)
Re: log_checkpoints, microseconds

On Thu, Apr 10, 2014 at 3:20 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

I think you're both wrong. 1000 usec = 1 msec, not the other way round.

er, right, sorry.

--
greg

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#9Heikki Linnakangas
heikki.linnakangas@enterprisedb.com
In reply to: Peter Geoghegan (#6)
Re: log_checkpoints, microseconds

On 04/10/2014 10:43 PM, Peter Geoghegan wrote:

On Thu, Apr 10, 2014 at 12:20 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

I think you're both wrong. 1000 usec = 1 msec, not the other way round.

Yes, but why would you ever want to divide any number of microseconds
by 1000 like this, unless you were actually interested in nanoseconds?
The point is that we start out with microseconds "elapsed" here, not
milliseconds or seconds.

Take a break, then take another look.

The code first gets the number of microseconds elapsed. It wants to
print it out in milliseconds. The question is: "How many milliseconds is
X microseconds"? The answer is X / 1000.

For comparison, imagine that you know that 180 minutes has elapsed, and
you want to print that out in hours. To do that, you divide 180 by 60.

- Heikki

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

In reply to: Heikki Linnakangas (#9)
Re: log_checkpoints, microseconds

On Thu, Apr 10, 2014 at 1:00 PM, Heikki Linnakangas
<hlinnakangas@vmware.com> wrote:

Take a break, then take another look.

Ugh, I can't believe I made such an elementary error. Sorry for the noise.

--
Peter Geoghegan

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#11Gavin Flower
GavinFlower@archidevsys.co.nz
In reply to: Peter Geoghegan (#10)
Re: log_checkpoints, microseconds

On 11/04/14 08:03, Peter Geoghegan wrote:

On Thu, Apr 10, 2014 at 1:00 PM, Heikki Linnakangas
<hlinnakangas@vmware.com> wrote:

Take a break, then take another look.

Ugh, I can't believe I made such an elementary error. Sorry for the noise.

No worries!

To be Really Stupid requires Great Intelligence and a High Degree of
Creativity!

Cheers,
Gavin

(Who aspires to being merely Stupid.)

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#12Michael Paquier
michael@paquier.xyz
In reply to: Gavin Flower (#11)
Re: log_checkpoints, microseconds

On Fri, Apr 11, 2014 at 6:36 AM, Gavin Flower
<GavinFlower@archidevsys.co.nz> wrote:

On 11/04/14 08:03, Peter Geoghegan wrote:

On Thu, Apr 10, 2014 at 1:00 PM, Heikki Linnakangas
<hlinnakangas@vmware.com> wrote:

Take a break, then take another look.

Ugh, I can't believe I made such an elementary error. Sorry for the noise.

No worries!

To be Really Stupid requires Great Intelligence and a High Degree of
Creativity!

+1. Your quote?
-- 
Michael

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

#13Gavin Flower
GavinFlower@archidevsys.co.nz
In reply to: Michael Paquier (#12)
Re: log_checkpoints, microseconds

On 11/04/14 11:38, Michael Paquier wrote:

On Fri, Apr 11, 2014 at 6:36 AM, Gavin Flower
<GavinFlower@archidevsys.co.nz> wrote:

On 11/04/14 08:03, Peter Geoghegan wrote:

On Thu, Apr 10, 2014 at 1:00 PM, Heikki Linnakangas
<hlinnakangas@vmware.com> wrote:

Take a break, then take another look.

Ugh, I can't believe I made such an elementary error. Sorry for the noise.

No worries!

To be Really Stupid requires Great Intelligence and a High Degree of
Creativity!

+1. Your quote?

As far as I am aware, I made up the quote myself.

However, it would not surprise me to find someone else had said it years
before I was born!

Cheers,
Gavin

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs