Skip to content

Commit 210564a

Browse files
tglsfdctglsfdc
committed
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
1 parent f93f1a2 commit 210564a

File tree

6 files changed

+78
-92
lines changed

6 files changed

+78
-92
lines changed

‎contrib/postgres_fdw/connection.c

Lines changed: 2 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1153,20 +1153,15 @@ pgfdw_get_cleanup_result(PGconn *conn, TimestampTz endtime, PGresult **result)
11531153
{
11541154
int wc;
11551155
TimestampTz now = GetCurrentTimestamp();
1156-
long secs;
1157-
int microsecs;
11581156
long cur_timeout;
11591157

11601158
/* If timeout has expired, give up, else get sleep time. */
1161-
if (now >= endtime)
1159+
cur_timeout = TimestampDifferenceMilliseconds(now, endtime);
1160+
if (cur_timeout <= 0)
11621161
{
11631162
timed_out = true;
11641163
goto exit;
11651164
}
1166-
TimestampDifference(now, endtime, &secs, &microsecs);
1167-
1168-
/* To protect against clock skew, limit sleep to one minute. */
1169-
cur_timeout = Min(60000, secs * USECS_PER_SEC + microsecs);
11701165

11711166
/* Sleep until there's something to do */
11721167
wc = WaitLatchOrSocket(MyLatch,

‎src/backend/access/transam/xlog.c

Lines changed: 34 additions & 54 deletions
Original file line numberDiff line numberDiff line change
@@ -5765,8 +5765,7 @@ recoveryApplyDelay(XLogReaderState *record)
57655765
{
57665766
uint8 xact_info;
57675767
TimestampTz xtime;
5768-
long secs;
5769-
int microsecs;
5768+
long msecs;
57705769

57715770
/* nothing to do if no delay configured */
57725771
if (recovery_min_apply_delay <= 0)
@@ -5803,9 +5802,9 @@ recoveryApplyDelay(XLogReaderState *record)
58035802
* Exit without arming the latch if it's already past time to apply this
58045803
* record
58055804
*/
5806-
TimestampDifference(GetCurrentTimestamp(), recoveryDelayUntilTime,
5807-
&secs, &microsecs);
5808-
if (secs <= 0 && microsecs <= 0)
5805+
msecs = TimestampDifferenceMilliseconds(GetCurrentTimestamp(),
5806+
recoveryDelayUntilTime);
5807+
if (msecs <= 0)
58095808
return false;
58105809

58115810
while (true)
@@ -5822,19 +5821,17 @@ recoveryApplyDelay(XLogReaderState *record)
58225821
* Wait for difference between GetCurrentTimestamp() and
58235822
* recoveryDelayUntilTime
58245823
*/
5825-
TimestampDifference(GetCurrentTimestamp(), recoveryDelayUntilTime,
5826-
&secs, &microsecs);
5824+
msecs = TimestampDifferenceMilliseconds(GetCurrentTimestamp(),
5825+
recoveryDelayUntilTime);
58275826

5828-
/* NB: We're ignoring waits below min_apply_delay's resolution. */
5829-
if (secs <= 0 && microsecs / 1000 <= 0)
5827+
if (msecs <= 0)
58305828
break;
58315829

5832-
elog(DEBUG2, "recovery apply delay %ld seconds, %d milliseconds",
5833-
secs, microsecs / 1000);
5830+
elog(DEBUG2, "recovery apply delay %ld milliseconds", msecs);
58345831

5835-
WaitLatch(&XLogCtl->recoveryWakeupLatch,
5836-
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,
5837-
secs * 1000L + microsecs / 1000);
5832+
(void) WaitLatch(&XLogCtl->recoveryWakeupLatch,
5833+
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,
5834+
msecs);
58385835
}
58395836
return true;
58405837
}
@@ -8165,33 +8162,24 @@ LogCheckpointStart(int flags, bool restartpoint)
81658162
static void
81668163
LogCheckpointEnd(bool restartpoint)
81678164
{
8168-
long write_secs,
8169-
sync_secs,
8170-
total_secs,
8171-
longest_secs,
8172-
average_secs;
8173-
int write_usecs,
8174-
sync_usecs,
8175-
total_usecs,
8176-
longest_usecs,
8177-
average_usecs;
8165+
long write_msecs,
8166+
sync_msecs,
8167+
total_msecs,
8168+
longest_msecs,
8169+
average_msecs;
81788170
uint64 average_sync_time;
81798171

81808172
CheckpointStats.ckpt_end_t = GetCurrentTimestamp();
81818173

8182-
TimestampDifference(CheckpointStats.ckpt_write_t,
8183-
CheckpointStats.ckpt_sync_t,
8184-
&write_secs, &write_usecs);
8174+
write_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_write_t,
8175+
CheckpointStats.ckpt_sync_t);
81858176

8186-
TimestampDifference(CheckpointStats.ckpt_sync_t,
8187-
CheckpointStats.ckpt_sync_end_t,
8188-
&sync_secs, &sync_usecs);
8177+
sync_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_sync_t,
8178+
CheckpointStats.ckpt_sync_end_t);
81898179

81908180
/* Accumulate checkpoint timing summary data, in milliseconds. */
8191-
BgWriterStats.m_checkpoint_write_time +=
8192-
write_secs * 1000 + write_usecs / 1000;
8193-
BgWriterStats.m_checkpoint_sync_time +=
8194-
sync_secs * 1000 + sync_usecs / 1000;
8181+
BgWriterStats.m_checkpoint_write_time += write_msecs;
8182+
BgWriterStats.m_checkpoint_sync_time += sync_msecs;
81958183

81968184
/*
81978185
* All of the published timing statistics are accounted for. Only
@@ -8200,25 +8188,20 @@ LogCheckpointEnd(bool restartpoint)
82008188
if (!log_checkpoints)
82018189
return;
82028190

8203-
TimestampDifference(CheckpointStats.ckpt_start_t,
8204-
CheckpointStats.ckpt_end_t,
8205-
&total_secs, &total_usecs);
8191+
total_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_start_t,
8192+
CheckpointStats.ckpt_end_t);
82068193

82078194
/*
82088195
* Timing values returned from CheckpointStats are in microseconds.
8209-
* Convert to the second plus microsecond form that TimestampDifference
8210-
* returns for homogeneous printing.
8196+
* Convert to milliseconds for consistent printing.
82118197
*/
8212-
longest_secs = (long) (CheckpointStats.ckpt_longest_sync / 1000000);
8213-
longest_usecs = CheckpointStats.ckpt_longest_sync -
8214-
(uint64) longest_secs *1000000;
8198+
longest_msecs = (long) ((CheckpointStats.ckpt_longest_sync + 999) / 1000);
82158199

82168200
average_sync_time = 0;
82178201
if (CheckpointStats.ckpt_sync_rels > 0)
82188202
average_sync_time = CheckpointStats.ckpt_agg_sync_time /
82198203
CheckpointStats.ckpt_sync_rels;
8220-
average_secs = (long) (average_sync_time / 1000000);
8221-
average_usecs = average_sync_time - (uint64) average_secs *1000000;
8204+
average_msecs = (long) ((average_sync_time + 999) / 1000);
82228205

82238206
elog(LOG, "%s complete: wrote %d buffers (%.1f%%); "
82248207
"%d transaction log file(s) added, %d removed, %d recycled; "
@@ -8231,12 +8214,12 @@ LogCheckpointEnd(bool restartpoint)
82318214
CheckpointStats.ckpt_segs_added,
82328215
CheckpointStats.ckpt_segs_removed,
82338216
CheckpointStats.ckpt_segs_recycled,
8234-
write_secs, write_usecs / 1000,
8235-
sync_secs, sync_usecs / 1000,
8236-
total_secs, total_usecs / 1000,
8217+
write_msecs / 1000, (int) (write_msecs % 1000),
8218+
sync_msecs / 1000, (int) (sync_msecs % 1000),
8219+
total_msecs / 1000, (int) (total_msecs % 1000),
82378220
CheckpointStats.ckpt_sync_rels,
8238-
longest_secs, longest_usecs / 1000,
8239-
average_secs, average_usecs / 1000,
8221+
longest_msecs / 1000, (int) (longest_msecs % 1000),
8222+
average_msecs / 1000, (int) (average_msecs % 1000),
82408223
(int) (PrevCheckPointDistance / 1024.0),
82418224
(int) (CheckPointDistanceEstimate / 1024.0));
82428225
}
@@ -11619,13 +11602,10 @@ WaitForWALToBecomeAvailable(XLogRecPtr RecPtr, bool randAccess,
1161911602
if (!TimestampDifferenceExceeds(last_fail_time, now,
1162011603
wal_retrieve_retry_interval))
1162111604
{
11622-
long secs,
11623-
wait_time;
11624-
int usecs;
11605+
long wait_time;
1162511606

11626-
TimestampDifference(last_fail_time, now, &secs, &usecs);
1162711607
wait_time = wal_retrieve_retry_interval -
11628-
(secs * 1000 + usecs / 1000);
11608+
TimestampDifferenceMilliseconds(last_fail_time, now);
1162911609

1163011610
WaitLatch(&XLogCtl->recoveryWakeupLatch,
1163111611
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,

‎src/backend/replication/walreceiverfuncs.c

Lines changed: 4 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -325,10 +325,6 @@ GetReplicationApplyDelay(void)
325325

326326
XLogRecPtr receivePtr;
327327
XLogRecPtr replayPtr;
328-
329-
long secs;
330-
int usecs;
331-
332328
TimestampTz chunkReplayStartTime;
333329

334330
SpinLockAcquire(&walrcv->mutex);
@@ -345,11 +341,8 @@ GetReplicationApplyDelay(void)
345341
if (chunkReplayStartTime == 0)
346342
return -1;
347343

348-
TimestampDifference(chunkReplayStartTime,
349-
GetCurrentTimestamp(),
350-
&secs, &usecs);
351-
352-
return (((int) secs * 1000) + (usecs / 1000));
344+
return TimestampDifferenceMilliseconds(chunkReplayStartTime,
345+
GetCurrentTimestamp());
353346
}
354347

355348
/*
@@ -361,24 +354,14 @@ GetReplicationTransferLatency(void)
361354
{
362355
/* use volatile pointer to prevent code rearrangement */
363356
volatile WalRcvData *walrcv = WalRcv;
364-
365357
TimestampTz lastMsgSendTime;
366358
TimestampTz lastMsgReceiptTime;
367359

368-
long secs = 0;
369-
int usecs = 0;
370-
int ms;
371-
372360
SpinLockAcquire(&walrcv->mutex);
373361
lastMsgSendTime = walrcv->lastMsgSendTime;
374362
lastMsgReceiptTime = walrcv->lastMsgReceiptTime;
375363
SpinLockRelease(&walrcv->mutex);
376364

377-
TimestampDifference(lastMsgSendTime,
378-
lastMsgReceiptTime,
379-
&secs, &usecs);
380-
381-
ms = ((int) secs * 1000) + (usecs / 1000);
382-
383-
return ms;
365+
return TimestampDifferenceMilliseconds(lastMsgSendTime,
366+
lastMsgReceiptTime);
384367
}

‎src/backend/replication/walsender.c

Lines changed: 1 addition & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1781,8 +1781,6 @@ WalSndComputeSleeptime(TimestampTz now)
17811781
if (wal_sender_timeout > 0 && last_reply_timestamp > 0)
17821782
{
17831783
TimestampTz wakeup_time;
1784-
long sec_to_timeout;
1785-
int microsec_to_timeout;
17861784

17871785
/*
17881786
* At the latest stop sleeping once wal_sender_timeout has been
@@ -1801,11 +1799,7 @@ WalSndComputeSleeptime(TimestampTz now)
18011799
wal_sender_timeout / 2);
18021800

18031801
/* Compute relative time until wakeup. */
1804-
TimestampDifference(now, wakeup_time,
1805-
&sec_to_timeout, &microsec_to_timeout);
1806-
1807-
sleeptime = sec_to_timeout * 1000 +
1808-
microsec_to_timeout / 1000;
1802+
sleeptime = TimestampDifferenceMilliseconds(now, wakeup_time);
18091803
}
18101804

18111805
return sleeptime;

‎src/backend/utils/adt/timestamp.c

Lines changed: 35 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1671,12 +1671,14 @@ IntegerTimestampToTimestampTz(int64 timestamp)
16711671
* TimestampDifference -- convert the difference between two timestamps
16721672
* into integer seconds and microseconds
16731673
*
1674+
* This is typically used to calculate a wait timeout for select(2),
1675+
* which explains the otherwise-odd choice of output format.
1676+
*
16741677
* Both inputs must be ordinary finite timestamps (in current usage,
16751678
* they'll be results from GetCurrentTimestamp()).
16761679
*
1677-
* We expect start_time <= stop_time. If not, we return zeroes; for current
1678-
* callers there is no need to be tense about which way division rounds on
1679-
* negative inputs.
1680+
* We expect start_time <= stop_time. If not, we return zeros,
1681+
* since then we're already past the previously determined stop_time.
16801682
*/
16811683
void
16821684
TimestampDifference(TimestampTz start_time, TimestampTz stop_time,
@@ -1701,6 +1703,36 @@ TimestampDifference(TimestampTz start_time, TimestampTz stop_time,
17011703
}
17021704
}
17031705

1706+
/*
1707+
* TimestampDifferenceMilliseconds -- convert the difference between two
1708+
* timestamps into integer milliseconds
1709+
*
1710+
* This is typically used to calculate a wait timeout for WaitLatch()
1711+
* or a related function. The choice of "long" as the result type
1712+
* is to harmonize with that. It is caller's responsibility that the
1713+
* input timestamps not be so far apart as to risk overflow of "long"
1714+
* (which'd happen at about 25 days on machines with 32-bit "long").
1715+
*
1716+
* Both inputs must be ordinary finite timestamps (in current usage,
1717+
* they'll be results from GetCurrentTimestamp()).
1718+
*
1719+
* We expect start_time <= stop_time. If not, we return zero,
1720+
* since then we're already past the previously determined stop_time.
1721+
*
1722+
* Note we round up any fractional millisecond, since waiting for just
1723+
* less than the intended timeout is undesirable.
1724+
*/
1725+
long
1726+
TimestampDifferenceMilliseconds(TimestampTz start_time, TimestampTz stop_time)
1727+
{
1728+
TimestampTz diff = stop_time - start_time;
1729+
1730+
if (diff <= 0)
1731+
return 0;
1732+
else
1733+
return (long) ((diff + 999) / 1000);
1734+
}
1735+
17041736
/*
17051737
* TimestampDifferenceExceeds -- report whether the difference between two
17061738
* timestamps is >= a threshold (expressed in milliseconds)

‎src/include/utils/timestamp.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -216,6 +216,8 @@ extern Datum generate_series_timestamptz(PG_FUNCTION_ARGS);
216216
extern TimestampTz GetCurrentTimestamp(void);
217217
extern void TimestampDifference(TimestampTz start_time, TimestampTz stop_time,
218218
long *secs, int *microsecs);
219+
extern long TimestampDifferenceMilliseconds(TimestampTz start_time,
220+
TimestampTz stop_time);
219221
extern bool TimestampDifferenceExceeds(TimestampTz start_time,
220222
TimestampTz stop_time,
221223
int msec);

0 commit comments

Comments
 (0)