Fix timestamp of sent message for write context in logical decoding

michaelpq · michaelpq · commit f7b0d0704923 · 2019-11-06T16:12:40.000+09:00
When sending data for logical decoding using the streaming replication protocol via a WAL sender, the timestamp of the sent write message is allocated at the beginning of the message when preparing for the write, and actually computed when the write message is ready to be sent. The timestamp was getting computed after sending the message. This impacts anything using logical decoding, causing for example logical replication to report mostly NULL for last_msg_send_time in pg_stat_subscription. This commit makes sure that the timestamp is computed before sending the message. This is wrong since 5a991ef, so backpatch down to 9.4. Author: Jeff Janes Discussion: https://postgr.es/m/CAMkU=1z=WMn8jt7iEdC5sYNaPgAgOASb_OW5JYv-vMdYaJSL-w@mail.gmail.com Backpatch-through: 9.4
diff --git a/src/backend/replication/walsender.c b/src/backend/replication/walsender.c
@@ -1157,9 +1157,6 @@ WalSndWriteData(LogicalDecodingContext *ctx, XLogRecPtr lsn, TransactionId xid,
 {
 	TimestampTz	now;
 
-	/* output previously gathered data in a CopyData packet */
-	pq_putmessage_noblock('d', ctx->out->data, ctx->out->len);
-
 	/*
 	 * Fill the send timestamp last, so that it is taken as late as possible.
 	 * This is somewhat ugly, but the protocol is set as it's already used for
@@ -1171,6 +1168,9 @@ WalSndWriteData(LogicalDecodingContext *ctx, XLogRecPtr lsn, TransactionId xid,
 	memcpy(&ctx->out->data[1 + sizeof(int64) + sizeof(int64)],
 		   tmpbuf.data, sizeof(int64));
 
+	/* output previously gathered data in a CopyData packet */
+	pq_putmessage_noblock('d', ctx->out->data, ctx->out->len);
+
 	CHECK_FOR_INTERRUPTS();
 
 	/* Try to flush pending output to the client */
