1
0
mirror of https://github.com/postgres/postgres.git synced 2025-06-29 10:41:53 +03:00

Fix and simplify some usages of TimestampDifference().

Introduce TimestampDifferenceMilliseconds() to simplify callers
that would rather have the difference in milliseconds, instead of
the select()-oriented seconds-and-microseconds format.  This gets
rid of at least one integer division per call, and it eliminates
some apparently-easy-to-mess-up arithmetic.

Two of these call sites were in fact wrong:

* pg_prewarm's autoprewarm_main() forgot to multiply the seconds
by 1000, thus ending up with a delay 1000X shorter than intended.
That doesn't quite make it a busy-wait, but close.

* postgres_fdw's pgfdw_get_cleanup_result() thought it needed to compute
microseconds not milliseconds, thus ending up with a delay 1000X longer
than intended.  Somebody along the way had noticed this problem but
misdiagnosed the cause, and imposed an ad-hoc 60-second limit rather
than fixing the units.  This was relatively harmless in context, because
we don't care that much about exactly how long this delay is; still,
it's wrong.

There are a few more callers of TimestampDifference() that don't
have a direct need for seconds-and-microseconds, but can't use
TimestampDifferenceMilliseconds() either because they do need
microsecond precision or because they might possibly deal with
intervals long enough to overflow 32-bit milliseconds.  It might be
worth inventing another API to improve that, but that seems outside
the scope of this patch; so those callers are untouched here.

Given the fact that we are fixing some bugs, and the likelihood
that future patches might want to back-patch code that uses this
new API, back-patch to all supported branches.

Alexey Kondratov and Tom Lane

Discussion: https://postgr.es/m/3b1c053a21c07c1ed5e00be3b2b855ef@postgrespro.ru
This commit is contained in:
Tom Lane
2020-11-10 22:51:19 -05:00
parent 19fd4f20b6
commit afce7908d7
7 changed files with 80 additions and 99 deletions

View File

@ -6074,8 +6074,7 @@ recoveryApplyDelay(XLogReaderState *record)
uint8 xact_info;
TimestampTz xtime;
TimestampTz delayUntil;
long secs;
int microsecs;
long msecs;
/* nothing to do if no delay configured */
if (recovery_min_apply_delay <= 0)
@ -6115,8 +6114,8 @@ recoveryApplyDelay(XLogReaderState *record)
* Exit without arming the latch if it's already past time to apply this
* record
*/
TimestampDifference(GetCurrentTimestamp(), delayUntil, &secs, &microsecs);
if (secs <= 0 && microsecs <= 0)
msecs = TimestampDifferenceMilliseconds(GetCurrentTimestamp(), delayUntil);
if (msecs <= 0)
return false;
while (true)
@ -6132,22 +6131,17 @@ recoveryApplyDelay(XLogReaderState *record)
/*
* Wait for difference between GetCurrentTimestamp() and delayUntil
*/
TimestampDifference(GetCurrentTimestamp(), delayUntil,
&secs, &microsecs);
msecs = TimestampDifferenceMilliseconds(GetCurrentTimestamp(),
delayUntil);
/*
* NB: We're ignoring waits below recovery_min_apply_delay's
* resolution.
*/
if (secs <= 0 && microsecs / 1000 <= 0)
if (msecs <= 0)
break;
elog(DEBUG2, "recovery apply delay %ld seconds, %d milliseconds",
secs, microsecs / 1000);
elog(DEBUG2, "recovery apply delay %ld milliseconds", msecs);
(void) WaitLatch(&XLogCtl->recoveryWakeupLatch,
WL_LATCH_SET | WL_TIMEOUT | WL_EXIT_ON_PM_DEATH,
secs * 1000L + microsecs / 1000,
msecs,
WAIT_EVENT_RECOVERY_APPLY_DELAY);
}
return true;
@ -8554,33 +8548,24 @@ LogCheckpointStart(int flags, bool restartpoint)
static void
LogCheckpointEnd(bool restartpoint)
{
long write_secs,
sync_secs,
total_secs,
longest_secs,
average_secs;
int write_usecs,
sync_usecs,
total_usecs,
longest_usecs,
average_usecs;
long write_msecs,
sync_msecs,
total_msecs,
longest_msecs,
average_msecs;
uint64 average_sync_time;
CheckpointStats.ckpt_end_t = GetCurrentTimestamp();
TimestampDifference(CheckpointStats.ckpt_write_t,
CheckpointStats.ckpt_sync_t,
&write_secs, &write_usecs);
write_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_write_t,
CheckpointStats.ckpt_sync_t);
TimestampDifference(CheckpointStats.ckpt_sync_t,
CheckpointStats.ckpt_sync_end_t,
&sync_secs, &sync_usecs);
sync_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_sync_t,
CheckpointStats.ckpt_sync_end_t);
/* Accumulate checkpoint timing summary data, in milliseconds. */
BgWriterStats.m_checkpoint_write_time +=
write_secs * 1000 + write_usecs / 1000;
BgWriterStats.m_checkpoint_sync_time +=
sync_secs * 1000 + sync_usecs / 1000;
BgWriterStats.m_checkpoint_write_time += write_msecs;
BgWriterStats.m_checkpoint_sync_time += sync_msecs;
/*
* All of the published timing statistics are accounted for. Only
@ -8589,25 +8574,20 @@ LogCheckpointEnd(bool restartpoint)
if (!log_checkpoints)
return;
TimestampDifference(CheckpointStats.ckpt_start_t,
CheckpointStats.ckpt_end_t,
&total_secs, &total_usecs);
total_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_start_t,
CheckpointStats.ckpt_end_t);
/*
* Timing values returned from CheckpointStats are in microseconds.
* Convert to the second plus microsecond form that TimestampDifference
* returns for homogeneous printing.
* Convert to milliseconds for consistent printing.
*/
longest_secs = (long) (CheckpointStats.ckpt_longest_sync / 1000000);
longest_usecs = CheckpointStats.ckpt_longest_sync -
(uint64) longest_secs * 1000000;
longest_msecs = (long) ((CheckpointStats.ckpt_longest_sync + 999) / 1000);
average_sync_time = 0;
if (CheckpointStats.ckpt_sync_rels > 0)
average_sync_time = CheckpointStats.ckpt_agg_sync_time /
CheckpointStats.ckpt_sync_rels;
average_secs = (long) (average_sync_time / 1000000);
average_usecs = average_sync_time - (uint64) average_secs * 1000000;
average_msecs = (long) ((average_sync_time + 999) / 1000);
elog(LOG, "%s complete: wrote %d buffers (%.1f%%); "
"%d WAL file(s) added, %d removed, %d recycled; "
@ -8620,12 +8600,12 @@ LogCheckpointEnd(bool restartpoint)
CheckpointStats.ckpt_segs_added,
CheckpointStats.ckpt_segs_removed,
CheckpointStats.ckpt_segs_recycled,
write_secs, write_usecs / 1000,
sync_secs, sync_usecs / 1000,
total_secs, total_usecs / 1000,
write_msecs / 1000, (int) (write_msecs % 1000),
sync_msecs / 1000, (int) (sync_msecs % 1000),
total_msecs / 1000, (int) (total_msecs % 1000),
CheckpointStats.ckpt_sync_rels,
longest_secs, longest_usecs / 1000,
average_secs, average_usecs / 1000,
longest_msecs / 1000, (int) (longest_msecs % 1000),
average_msecs / 1000, (int) (average_msecs % 1000),
(int) (PrevCheckPointDistance / 1024.0),
(int) (CheckPointDistanceEstimate / 1024.0));
}
@ -12219,13 +12199,10 @@ WaitForWALToBecomeAvailable(XLogRecPtr RecPtr, bool randAccess,
if (!TimestampDifferenceExceeds(last_fail_time, now,
wal_retrieve_retry_interval))
{
long secs,
wait_time;
int usecs;
long wait_time;
TimestampDifference(last_fail_time, now, &secs, &usecs);
wait_time = wal_retrieve_retry_interval -
(secs * 1000 + usecs / 1000);
TimestampDifferenceMilliseconds(last_fail_time, now);
(void) WaitLatch(&XLogCtl->recoveryWakeupLatch,
WL_LATCH_SET | WL_TIMEOUT |