Logical replication wal sender timestamp bug

From: Jeff Janes <jeff(dot)janes(at)gmail(dot)com>
To: pgsql-hackers <pgsql-hackers(at)postgresql(dot)org>
Subject: Logical replication wal sender timestamp bug
Date: 2019-11-03 01:54:54
Message-ID: CAMkU=1z=WMn8jt7iEdC5sYNaPgAgOASb_OW5JYv-vMdYaJSL-w@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

While monitoring pg_stat_subscription, I noticed that last_msg_send_time
was usually NULL, which doesn't make sense. Why would we have a message,
but not know when it was sent?

Looking in src/backend/replication/walsender.c, there is this:

/* 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
* several releases by streaming physical replication.
*/
resetStringInfo(&tmpbuf);
now = GetCurrentTimestamp();
pq_sendint64(&tmpbuf, now);
memcpy(&ctx->out->data[1 + sizeof(int64) + sizeof(int64)],
tmpbuf.data, sizeof(int64));

Filling out the timestamp after the message has already been sent is taking
"as late as possible" a little too far. It results in every message having
a zero timestamp, other than keep-alives which go through a different path.

Re-ordering the code blocks as in the attached seems to fix it. But I have
to wonder, if this has been broken from the start and no one ever noticed,
is this even valuable information to relay in the first place? We could
just take the column out of the view, and not bother calling
GetCurrentTimestamp() for each message.

Cheers,

Jeff

Attachment Content-Type Size
walsender_timestamp_fix.patch application/octet-stream 1011 bytes

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Artur Zakirov 2019-11-03 03:50:45 Re: CREATE TEXT SEARCH DICTIONARY segfaulting on 9.6+
Previous Message Andres Freund 2019-11-03 00:00:17 Re: Remove configure --disable-float4-byval and --disable-float8-byval