Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly
Appearance settings

Commit cd39c23

Browse filesBrowse 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 efc3069 commit cd39c23
Copy full SHA for cd39c23

File tree

Expand file treeCollapse file tree

6 files changed

+78
-92
lines changed
Filter options
Expand file treeCollapse file tree

6 files changed

+78
-92
lines changed

‎contrib/postgres_fdw/connection.c

Copy file name to clipboardExpand all lines: contrib/postgres_fdw/connection.c
+2-7Lines changed: 2 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1148,20 +1148,15 @@ pgfdw_get_cleanup_result(PGconn *conn, TimestampTz endtime, PGresult **result)
11481148
{
11491149
int wc;
11501150
TimestampTz now = GetCurrentTimestamp();
1151-
long secs;
1152-
int microsecs;
11531151
long cur_timeout;
11541152

11551153
/* If timeout has expired, give up, else get sleep time. */
1156-
if (now >= endtime)
1154+
cur_timeout = TimestampDifferenceMilliseconds(now, endtime);
1155+
if (cur_timeout <= 0)
11571156
{
11581157
timed_out = true;
11591158
goto exit;
11601159
}
1161-
TimestampDifference(now, endtime, &secs, &microsecs);
1162-
1163-
/* To protect against clock skew, limit sleep to one minute. */
1164-
cur_timeout = Min(60000, secs * USECS_PER_SEC + microsecs);
11651160

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

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

Copy file name to clipboardExpand all lines: src/backend/access/transam/xlog.c
+34-54Lines changed: 34 additions & 54 deletions
Original file line numberDiff line numberDiff line change
@@ -5813,8 +5813,7 @@ recoveryApplyDelay(XLogReaderState *record)
58135813
{
58145814
uint8 xact_info;
58155815
TimestampTz xtime;
5816-
long secs;
5817-
int microsecs;
5816+
long msecs;
58185817

58195818
/* nothing to do if no delay configured */
58205819
if (recovery_min_apply_delay <= 0)
@@ -5851,9 +5850,9 @@ recoveryApplyDelay(XLogReaderState *record)
58515850
* Exit without arming the latch if it's already past time to apply this
58525851
* record
58535852
*/
5854-
TimestampDifference(GetCurrentTimestamp(), recoveryDelayUntilTime,
5855-
&secs, &microsecs);
5856-
if (secs <= 0 && microsecs <= 0)
5853+
msecs = TimestampDifferenceMilliseconds(GetCurrentTimestamp(),
5854+
recoveryDelayUntilTime);
5855+
if (msecs <= 0)
58575856
return false;
58585857

58595858
while (true)
@@ -5870,19 +5869,17 @@ recoveryApplyDelay(XLogReaderState *record)
58705869
* Wait for difference between GetCurrentTimestamp() and
58715870
* recoveryDelayUntilTime
58725871
*/
5873-
TimestampDifference(GetCurrentTimestamp(), recoveryDelayUntilTime,
5874-
&secs, &microsecs);
5872+
msecs = TimestampDifferenceMilliseconds(GetCurrentTimestamp(),
5873+
recoveryDelayUntilTime);
58755874

5876-
/* NB: We're ignoring waits below min_apply_delay's resolution. */
5877-
if (secs <= 0 && microsecs / 1000 <= 0)
5875+
if (msecs <= 0)
58785876
break;
58795877

5880-
elog(DEBUG2, "recovery apply delay %ld seconds, %d milliseconds",
5881-
secs, microsecs / 1000);
5878+
elog(DEBUG2, "recovery apply delay %ld milliseconds", msecs);
58825879

5883-
WaitLatch(&XLogCtl->recoveryWakeupLatch,
5884-
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,
5885-
secs * 1000L + microsecs / 1000);
5880+
(void) WaitLatch(&XLogCtl->recoveryWakeupLatch,
5881+
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,
5882+
msecs);
58865883
}
58875884
return true;
58885885
}
@@ -8218,33 +8215,24 @@ LogCheckpointStart(int flags, bool restartpoint)
82188215
static void
82198216
LogCheckpointEnd(bool restartpoint)
82208217
{
8221-
long write_secs,
8222-
sync_secs,
8223-
total_secs,
8224-
longest_secs,
8225-
average_secs;
8226-
int write_usecs,
8227-
sync_usecs,
8228-
total_usecs,
8229-
longest_usecs,
8230-
average_usecs;
8218+
long write_msecs,
8219+
sync_msecs,
8220+
total_msecs,
8221+
longest_msecs,
8222+
average_msecs;
82318223
uint64 average_sync_time;
82328224

82338225
CheckpointStats.ckpt_end_t = GetCurrentTimestamp();
82348226

8235-
TimestampDifference(CheckpointStats.ckpt_write_t,
8236-
CheckpointStats.ckpt_sync_t,
8237-
&write_secs, &write_usecs);
8227+
write_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_write_t,
8228+
CheckpointStats.ckpt_sync_t);
82388229

8239-
TimestampDifference(CheckpointStats.ckpt_sync_t,
8240-
CheckpointStats.ckpt_sync_end_t,
8241-
&sync_secs, &sync_usecs);
8230+
sync_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_sync_t,
8231+
CheckpointStats.ckpt_sync_end_t);
82428232

82438233
/* Accumulate checkpoint timing summary data, in milliseconds. */
8244-
BgWriterStats.m_checkpoint_write_time +=
8245-
write_secs * 1000 + write_usecs / 1000;
8246-
BgWriterStats.m_checkpoint_sync_time +=
8247-
sync_secs * 1000 + sync_usecs / 1000;
8234+
BgWriterStats.m_checkpoint_write_time += write_msecs;
8235+
BgWriterStats.m_checkpoint_sync_time += sync_msecs;
82488236

82498237
/*
82508238
* All of the published timing statistics are accounted for. Only
@@ -8253,25 +8241,20 @@ LogCheckpointEnd(bool restartpoint)
82538241
if (!log_checkpoints)
82548242
return;
82558243

8256-
TimestampDifference(CheckpointStats.ckpt_start_t,
8257-
CheckpointStats.ckpt_end_t,
8258-
&total_secs, &total_usecs);
8244+
total_msecs = TimestampDifferenceMilliseconds(CheckpointStats.ckpt_start_t,
8245+
CheckpointStats.ckpt_end_t);
82598246

82608247
/*
82618248
* Timing values returned from CheckpointStats are in microseconds.
8262-
* Convert to the second plus microsecond form that TimestampDifference
8263-
* returns for homogeneous printing.
8249+
* Convert to milliseconds for consistent printing.
82648250
*/
8265-
longest_secs = (long) (CheckpointStats.ckpt_longest_sync / 1000000);
8266-
longest_usecs = CheckpointStats.ckpt_longest_sync -
8267-
(uint64) longest_secs *1000000;
8251+
longest_msecs = (long) ((CheckpointStats.ckpt_longest_sync + 999) / 1000);
82688252

82698253
average_sync_time = 0;
82708254
if (CheckpointStats.ckpt_sync_rels > 0)
82718255
average_sync_time = CheckpointStats.ckpt_agg_sync_time /
82728256
CheckpointStats.ckpt_sync_rels;
8273-
average_secs = (long) (average_sync_time / 1000000);
8274-
average_usecs = average_sync_time - (uint64) average_secs *1000000;
8257+
average_msecs = (long) ((average_sync_time + 999) / 1000);
82758258

82768259
elog(LOG, "%s complete: wrote %d buffers (%.1f%%); "
82778260
"%d transaction log file(s) added, %d removed, %d recycled; "
@@ -8284,12 +8267,12 @@ LogCheckpointEnd(bool restartpoint)
82848267
CheckpointStats.ckpt_segs_added,
82858268
CheckpointStats.ckpt_segs_removed,
82868269
CheckpointStats.ckpt_segs_recycled,
8287-
write_secs, write_usecs / 1000,
8288-
sync_secs, sync_usecs / 1000,
8289-
total_secs, total_usecs / 1000,
8270+
write_msecs / 1000, (int) (write_msecs % 1000),
8271+
sync_msecs / 1000, (int) (sync_msecs % 1000),
8272+
total_msecs / 1000, (int) (total_msecs % 1000),
82908273
CheckpointStats.ckpt_sync_rels,
8291-
longest_secs, longest_usecs / 1000,
8292-
average_secs, average_usecs / 1000,
8274+
longest_msecs / 1000, (int) (longest_msecs % 1000),
8275+
average_msecs / 1000, (int) (average_msecs % 1000),
82938276
(int) (PrevCheckPointDistance / 1024.0),
82948277
(int) (CheckPointDistanceEstimate / 1024.0));
82958278
}
@@ -11715,13 +11698,10 @@ WaitForWALToBecomeAvailable(XLogRecPtr RecPtr, bool randAccess,
1171511698
if (!TimestampDifferenceExceeds(last_fail_time, now,
1171611699
wal_retrieve_retry_interval))
1171711700
{
11718-
long secs,
11719-
wait_time;
11720-
int usecs;
11701+
long wait_time;
1172111702

11722-
TimestampDifference(last_fail_time, now, &secs, &usecs);
1172311703
wait_time = wal_retrieve_retry_interval -
11724-
(secs * 1000 + usecs / 1000);
11704+
TimestampDifferenceMilliseconds(last_fail_time, now);
1172511705

1172611706
WaitLatch(&XLogCtl->recoveryWakeupLatch,
1172711707
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,

‎src/backend/replication/walreceiverfuncs.c

Copy file name to clipboardExpand all lines: src/backend/replication/walreceiverfuncs.c
+4-21Lines changed: 4 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -318,10 +318,6 @@ GetReplicationApplyDelay(void)
318318
WalRcvData *walrcv = WalRcv;
319319
XLogRecPtr receivePtr;
320320
XLogRecPtr replayPtr;
321-
322-
long secs;
323-
int usecs;
324-
325321
TimestampTz chunkReplayStartTime;
326322

327323
SpinLockAcquire(&walrcv->mutex);
@@ -338,11 +334,8 @@ GetReplicationApplyDelay(void)
338334
if (chunkReplayStartTime == 0)
339335
return -1;
340336

341-
TimestampDifference(chunkReplayStartTime,
342-
GetCurrentTimestamp(),
343-
&secs, &usecs);
344-
345-
return (((int) secs * 1000) + (usecs / 1000));
337+
return TimestampDifferenceMilliseconds(chunkReplayStartTime,
338+
GetCurrentTimestamp());
346339
}
347340

348341
/*
@@ -353,24 +346,14 @@ int
353346
GetReplicationTransferLatency(void)
354347
{
355348
WalRcvData *walrcv = WalRcv;
356-
357349
TimestampTz lastMsgSendTime;
358350
TimestampTz lastMsgReceiptTime;
359351

360-
long secs = 0;
361-
int usecs = 0;
362-
int ms;
363-
364352
SpinLockAcquire(&walrcv->mutex);
365353
lastMsgSendTime = walrcv->lastMsgSendTime;
366354
lastMsgReceiptTime = walrcv->lastMsgReceiptTime;
367355
SpinLockRelease(&walrcv->mutex);
368356

369-
TimestampDifference(lastMsgSendTime,
370-
lastMsgReceiptTime,
371-
&secs, &usecs);
372-
373-
ms = ((int) secs * 1000) + (usecs / 1000);
374-
375-
return ms;
357+
return TimestampDifferenceMilliseconds(lastMsgSendTime,
358+
lastMsgReceiptTime);
376359
}

‎src/backend/replication/walsender.c

Copy file name to clipboardExpand all lines: src/backend/replication/walsender.c
+1-7Lines changed: 1 addition & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1784,8 +1784,6 @@ WalSndComputeSleeptime(TimestampTz now)
17841784
if (wal_sender_timeout > 0 && last_reply_timestamp > 0)
17851785
{
17861786
TimestampTz wakeup_time;
1787-
long sec_to_timeout;
1788-
int microsec_to_timeout;
17891787

17901788
/*
17911789
* At the latest stop sleeping once wal_sender_timeout has been
@@ -1804,11 +1802,7 @@ WalSndComputeSleeptime(TimestampTz now)
18041802
wal_sender_timeout / 2);
18051803

18061804
/* Compute relative time until wakeup. */
1807-
TimestampDifference(now, wakeup_time,
1808-
&sec_to_timeout, &microsec_to_timeout);
1809-
1810-
sleeptime = sec_to_timeout * 1000 +
1811-
microsec_to_timeout / 1000;
1805+
sleeptime = TimestampDifferenceMilliseconds(now, wakeup_time);
18121806
}
18131807

18141808
return sleeptime;

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

Copy file name to clipboardExpand all lines: src/backend/utils/adt/timestamp.c
+35-3Lines changed: 35 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1744,12 +1744,14 @@ IntegerTimestampToTimestampTz(int64 timestamp)
17441744
* TimestampDifference -- convert the difference between two timestamps
17451745
* into integer seconds and microseconds
17461746
*
1747+
* This is typically used to calculate a wait timeout for select(2),
1748+
* which explains the otherwise-odd choice of output format.
1749+
*
17471750
* Both inputs must be ordinary finite timestamps (in current usage,
17481751
* they'll be results from GetCurrentTimestamp()).
17491752
*
1750-
* We expect start_time <= stop_time. If not, we return zeros; for current
1751-
* callers there is no need to be tense about which way division rounds on
1752-
* negative inputs.
1753+
* We expect start_time <= stop_time. If not, we return zeros,
1754+
* since then we're already past the previously determined stop_time.
17531755
*/
17541756
void
17551757
TimestampDifference(TimestampTz start_time, TimestampTz stop_time,
@@ -1774,6 +1776,36 @@ TimestampDifference(TimestampTz start_time, TimestampTz stop_time,
17741776
}
17751777
}
17761778

1779+
/*
1780+
* TimestampDifferenceMilliseconds -- convert the difference between two
1781+
* timestamps into integer milliseconds
1782+
*
1783+
* This is typically used to calculate a wait timeout for WaitLatch()
1784+
* or a related function. The choice of "long" as the result type
1785+
* is to harmonize with that. It is caller's responsibility that the
1786+
* input timestamps not be so far apart as to risk overflow of "long"
1787+
* (which'd happen at about 25 days on machines with 32-bit "long").
1788+
*
1789+
* Both inputs must be ordinary finite timestamps (in current usage,
1790+
* they'll be results from GetCurrentTimestamp()).
1791+
*
1792+
* We expect start_time <= stop_time. If not, we return zero,
1793+
* since then we're already past the previously determined stop_time.
1794+
*
1795+
* Note we round up any fractional millisecond, since waiting for just
1796+
* less than the intended timeout is undesirable.
1797+
*/
1798+
long
1799+
TimestampDifferenceMilliseconds(TimestampTz start_time, TimestampTz stop_time)
1800+
{
1801+
TimestampTz diff = stop_time - start_time;
1802+
1803+
if (diff <= 0)
1804+
return 0;
1805+
else
1806+
return (long) ((diff + 999) / 1000);
1807+
}
1808+
17771809
/*
17781810
* TimestampDifferenceExceeds -- report whether the difference between two
17791811
* timestamps is >= a threshold (expressed in milliseconds)

‎src/include/utils/timestamp.h

Copy file name to clipboardExpand all lines: src/include/utils/timestamp.h
+2Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -218,6 +218,8 @@ extern Datum generate_series_timestamptz(PG_FUNCTION_ARGS);
218218
extern TimestampTz GetCurrentTimestamp(void);
219219
extern void TimestampDifference(TimestampTz start_time, TimestampTz stop_time,
220220
long *secs, int *microsecs);
221+
extern long TimestampDifferenceMilliseconds(TimestampTz start_time,
222+
TimestampTz stop_time);
221223
extern bool TimestampDifferenceExceeds(TimestampTz start_time,
222224
TimestampTz stop_time,
223225
int msec);

0 commit comments

Comments
0 (0)
Morty Proxy This is a proxified and sanitized view of the page, visit original site.