BUG #9849: walreceiver's DEBUG message reports wrong timestamp

Started by TAKATSUKA Harukaabout 12 years ago2 messagesbugs
Jump to latest
#1TAKATSUKA Haruka
harukat@sraoss.co.jp

The following bug has been logged on the website:

Bug reference: 9849
Logged by: TAKATSUKA Haruka
Email address: harukat@sraoss.co.jp
PostgreSQL version: 9.3.4
Operating system: CentOS 6.2 (64bit / gcc 4.4.7)
Description:

We get the folloging message at the standby server.

DEBUG: sendtime 2014-04-04 11:26:02.425368+09 receipttime 2014-04-04
11:26:02.425368+09 replication apply delay 0 ms transfer latency 224043 ms

Though sendtime equals receipttime, transfer latency is large.
This receipttime may be wrong.

When I change the code as the following for as a trial,
messages that have same sendtime and receipttime are gone.

diff --git a/src/backend/replication/walreceiver.c
b/src/backend/replication/wal
index 43db108..af21b5d 100644
--- a/src/backend/replication/walreceiver.c
+++ b/src/backend/replication/walreceiver.c
@@ -1198,10 +1198,13 @@ ProcessWalSndrMessage(XLogRecPtr walEnd, TimestampTz
sen
        walrcv->lastMsgReceiptTime = lastMsgReceiptTime;
        SpinLockRelease(&walrcv->mutex);
-       if (log_min_messages <= DEBUG2)
+       if (log_min_messages <= DEBUG2) {
+               char* strSendTime = strdupa(timestamptz_to_str(sendTime));
+               char* strReceiptTime =
strdupa(timestamptz_to_str(lastMsgReceipt
+               int applyDelay = GetReplicationApplyDelay();
+               int transferLatency = GetReplicationTransferLatency();
+
                elog(DEBUG2, "sendtime %s receipttime %s replication apply
delay
-                        timestamptz_to_str(sendTime),
-                        timestamptz_to_str(lastMsgReceiptTime),
-                        GetReplicationApplyDelay(),
-                        GetReplicationTransferLatency());
+                        strSendTime, strReceiptTime, applyDelay,
transferLatenc
+       }
 }

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

#2Tom Lane
tgl@sss.pgh.pa.us
In reply to: TAKATSUKA Haruka (#1)
Re: BUG #9849: walreceiver's DEBUG message reports wrong timestamp

harukat@sraoss.co.jp writes:

We get the folloging message at the standby server.

DEBUG: sendtime 2014-04-04 11:26:02.425368+09 receipttime 2014-04-04
11:26:02.425368+09 replication apply delay 0 ms transfer latency 224043 ms

Though sendtime equals receipttime, transfer latency is large.
This receipttime may be wrong.

Yeah, somebody forgot that timestamptz_to_str returns a static buffer.

strdupa is not a portable solution though.

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