Print logical WAL message content
Hi,
Right now pg_waldump just prints whether the message is transactional
or not and its size. That doesn't help much to understand the message
itself. If it prints the contents of a logical WAL message, it helps
debugging logical replication related problems. Prefix is a
null-terminated ASCII string, so no problem printing that. Even the
contents can be printed as a series of hex bytes. Here's a patch to do
that.
I tested this manually as below
postgres=# select pg_logical_emit_message(false, 'some_prefix', 'some
message'::text);
pg_logical_emit_message
-------------------------
0/1570658
(1 row)
$> pg_waldump --start 0/1570600 -p data/
first record is after 0/1570600, at 0/1570608, skipping over 8 bytes
rmgr: LogicalMessage len (rec/tot): 74/ 74, tx: 0,
lsn: 0/01570608, prev 0/015705D0, desc: MESSAGE nontransactional
message size 12 bytes, prefix some_prefix; mesage: 73 6F 6D 65 20 6D
65 73 73 61 67 65
rmgr: Standby len (rec/tot): 50/ 50, tx: 0, lsn:
0/01570658, prev 0/01570608, desc: RUNNING_XACTS nextXid 504
latestCompletedXid 503 oldestRunningXid 504
pg_waldump: fatal: error in WAL record at 0/1570658: invalid record
length at 0/1570690: wanted 24, got 0
I didn't find any tests for pg_waldump to test its output, so haven't
added one in the patch.
--
Best Wishes,
Ashutosh Bapat
Attachments:
0001-Print-prefix-and-logical-WAL-message-content-in-pg_w.patchtext/x-patch; charset=US-ASCII; name=0001-Print-prefix-and-logical-WAL-message-content-in-pg_w.patchDownload
From 1547277944f7aceb1d5b0a3ae46ec2acf02f3b06 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@2ndquadrant.com>
Date: Tue, 18 Aug 2020 11:05:29 +0530
Subject: [PATCH] Print prefix and logical WAL message content in pg_waldump
Print logical WAL message prefix which is a null terminated ASCII
string. Print the actual message as a space separated hex byte string
since it may contain binary data. This is useful for debugging purposes.
Ashutosh Bapat
---
src/backend/access/rmgrdesc/logicalmsgdesc.c | 18 ++++++++++++++++--
1 file changed, 16 insertions(+), 2 deletions(-)
diff --git a/src/backend/access/rmgrdesc/logicalmsgdesc.c b/src/backend/access/rmgrdesc/logicalmsgdesc.c
index bff298c928..fdd03362e7 100644
--- a/src/backend/access/rmgrdesc/logicalmsgdesc.c
+++ b/src/backend/access/rmgrdesc/logicalmsgdesc.c
@@ -24,10 +24,24 @@ logicalmsg_desc(StringInfo buf, XLogReaderState *record)
if (info == XLOG_LOGICAL_MESSAGE)
{
xl_logical_message *xlrec = (xl_logical_message *) rec;
+ /*
+ * Per LogLogicalMessage() actual logical message follows a null-terminated prefix of length
+ * prefix_size.
+ */
+ char *prefix = xlrec->message;
+ char *message = xlrec->message + xlrec->prefix_size;
+ int cnt;
+ char *sep = "";
- appendStringInfo(buf, "%s message size %zu bytes",
+ appendStringInfo(buf, "%s message size %zu bytes, prefix %s; mesage: ",
xlrec->transactional ? "transactional" : "nontransactional",
- xlrec->message_size);
+ xlrec->message_size, prefix);
+ /* Write actual message as a series of hex bytes. */
+ for (cnt = 0; cnt < xlrec->message_size; cnt++)
+ {
+ appendStringInfo(buf, "%s%02X", sep, (unsigned char)message[cnt]);
+ sep = " ";
+ }
}
}
--
2.17.1
On 2020-Aug-18, Ashutosh Bapat wrote:
Right now pg_waldump just prints whether the message is transactional
or not and its size. That doesn't help much to understand the message
itself. If it prints the contents of a logical WAL message, it helps
debugging logical replication related problems. Prefix is a
null-terminated ASCII string, so no problem printing that. Even the
contents can be printed as a series of hex bytes. Here's a patch to do
that.
Looks like a good idea.
I didn't like that you're documenting the message format in the new
function:
xl_logical_message *xlrec = (xl_logical_message *) rec; + /* + * Per LogLogicalMessage() actual logical message follows a null-terminated prefix of length + * prefix_size.
I would prefer to remove this comment, and instead add a comment atop
xl_logical_message's struct definition in message.h to say that the
message has a valid C-string as prefix, whose length is prefix_size, and
please see logicalmesg_desc() if you change this.
This way, you don't need to blame LogLogicalMessage for this
restriction, but it's actually part of the definition of the WAL
message.
+ /* + * Per LogLogicalMessage() actual logical message follows a null-terminated prefix of length + * prefix_size. + */ + char *prefix = xlrec->message; + char *message = xlrec->message + xlrec->prefix_size; + int cnt; + char *sep = "";
This would cause a crash if the message actually fails to follow the
rule. Let's test that prefix[xlrec->prefix_size] is a trailing zero,
and if not, avoid printing it. Although, just Assert()'ing that it's a
trailing zero would seem to suffice.
+ appendStringInfo(buf, "%s message size %zu bytes, prefix %s; mesage: ", xlrec->transactional ? "transactional" : "nontransactional", - xlrec->message_size); + xlrec->message_size, prefix);
Misspelled "message", but also the line looks a bit repetitive -- the
word "message" would appear three times:
lsn: 0/01570608, prev 0/015705D0, desc: MESSAGE nontransactional message size 12 bytes, prefix some_prefix; mesage: 73 6F 6D 65 20 6D 65 73 73 61 67 65
I would reduce it to
lsn: 0/01570608, prev 0/015705D0, desc: MESSAGE nontransactional, prefix "some_prefix"; payload (12 bytes): 73 6F 6D 65 20 6D 65 73 73 61 67 65
--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Thanks Alvaro for review.
On Wed, Aug 19, 2020 at 3:21 AM Alvaro Herrera <alvherre@2ndquadrant.com> wrote:
I didn't like that you're documenting the message format in the new
function:xl_logical_message *xlrec = (xl_logical_message *) rec; + /* + * Per LogLogicalMessage() actual logical message follows a null-terminated prefix of length + * prefix_size.I would prefer to remove this comment, and instead add a comment atop
xl_logical_message's struct definition in message.h to say that the
message has a valid C-string as prefix, whose length is prefix_size, and
please see logicalmesg_desc() if you change this.
It's documented in the struct definition. Added a note about logicalmesg_desc().
This way, you don't need to blame LogLogicalMessage for this
restriction, but it's actually part of the definition of the WAL
message.+ /* + * Per LogLogicalMessage() actual logical message follows a null-terminated prefix of length + * prefix_size. + */ + char *prefix = xlrec->message; + char *message = xlrec->message + xlrec->prefix_size; + int cnt; + char *sep = "";This would cause a crash if the message actually fails to follow the
rule. Let's test that prefix[xlrec->prefix_size] is a trailing zero,
and if not, avoid printing it. Although, just Assert()'ing that it's a
trailing zero would seem to suffice.
Added an Assert.
+ appendStringInfo(buf, "%s message size %zu bytes, prefix %s; mesage: ", xlrec->transactional ? "transactional" : "nontransactional", - xlrec->message_size); + xlrec->message_size, prefix);Misspelled "message", but also the line looks a bit repetitive -- the
word "message" would appear three times:lsn: 0/01570608, prev 0/015705D0, desc: MESSAGE nontransactional message size 12 bytes, prefix some_prefix; mesage: 73 6F 6D 65 20 6D 65 73 73 61 67 65
I would reduce it to
lsn: 0/01570608, prev 0/015705D0, desc: MESSAGE nontransactional, prefix "some_prefix"; payload (12 bytes): 73 6F 6D 65 20 6D 65 73 73 61 67 65
I like this format as well. Done.
PFA the patch attached with your comments addressed.
Thanks for your review.
--
Best Wishes,
Ashutosh Bapat
Attachments:
0001-Print-prefix-and-logical-WAL-message-content-in-pg_w.v2.patchtext/x-patch; charset=US-ASCII; name=0001-Print-prefix-and-logical-WAL-message-content-in-pg_w.v2.patchDownload
From d32859c8368ac25366b156c3247a5b77d9b72ce8 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@2ndquadrant.com>
Date: Tue, 18 Aug 2020 11:05:29 +0530
Subject: [PATCH] Print prefix and logical WAL message content in pg_waldump
Print logical WAL message prefix which is a null terminated ASCII
string. Print the actual message as a space separated hex byte string
since it may contain binary data. This is useful for debugging purposes.
Ashutosh Bapat, reviewed by Alvaro Herrera
---
src/backend/access/rmgrdesc/logicalmsgdesc.c | 16 ++++++++++++++--
src/include/replication/message.h | 4 +++-
2 files changed, 17 insertions(+), 3 deletions(-)
diff --git a/src/backend/access/rmgrdesc/logicalmsgdesc.c b/src/backend/access/rmgrdesc/logicalmsgdesc.c
index bff298c928..5da2625a0b 100644
--- a/src/backend/access/rmgrdesc/logicalmsgdesc.c
+++ b/src/backend/access/rmgrdesc/logicalmsgdesc.c
@@ -24,10 +24,22 @@ logicalmsg_desc(StringInfo buf, XLogReaderState *record)
if (info == XLOG_LOGICAL_MESSAGE)
{
xl_logical_message *xlrec = (xl_logical_message *) rec;
+ char *prefix = xlrec->message;
+ char *message = xlrec->message + xlrec->prefix_size;
+ int cnt;
+ char *sep = "";
- appendStringInfo(buf, "%s message size %zu bytes",
+ Assert(prefix[xlrec->prefix_size] != '\0');
+
+ appendStringInfo(buf, "%s, prefix \"%s\"; payload (%zu bytes): ",
xlrec->transactional ? "transactional" : "nontransactional",
- xlrec->message_size);
+ prefix, xlrec->message_size);
+ /* Write actual message as a series of hex bytes. */
+ for (cnt = 0; cnt < xlrec->message_size; cnt++)
+ {
+ appendStringInfo(buf, "%s%02X", sep, (unsigned char)message[cnt]);
+ sep = " ";
+ }
}
}
diff --git a/src/include/replication/message.h b/src/include/replication/message.h
index 937addde48..7b882296ec 100644
--- a/src/include/replication/message.h
+++ b/src/include/replication/message.h
@@ -25,7 +25,9 @@ typedef struct xl_logical_message
Size message_size; /* size of the message */
char message[FLEXIBLE_ARRAY_MEMBER]; /* message including the null
* terminated prefix of length
- * prefix_size */
+ * prefix_size. Please see
+ * logicalmsg_desc(), if you
+ * change this. */
} xl_logical_message;
#define SizeOfLogicalMessage (offsetof(xl_logical_message, message))
--
2.17.1
On 2020-Aug-19, Ashutosh Bapat wrote:
I like this format as well. Done.
PFA the patch attached with your comments addressed.
Pushed, thanks!
--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services