Re: Log prefix missing for subscriber log messages received from publisher

On 2025/07/16 19:45, vignesh C wrote:
> If we don't trim the trailing newline, an extra blank line will appear
> after the message is printed, like this:
> 2025-07-16 12:44:20.076 IST [534376] LOG: logical replication table
> synchronization worker for subscription "sub1", table "t2" has started
> 2025-07-16 12:44:20.294 IST [534374] LOG: received message via
> replication: WARNING: could not remove directory
> "pg_replslot/pg_16396_sync_16384_7527574647116269356.tmp"
>
> 2025-07-16 12:44:20.294 IST [534374] LOG: logical replication table
> synchronization worker for subscription "sub1", table "t1" has
> finished
>
> This occurs because a newline is appended to the message in
> pqBuildErrorMessage3, which is called when the message is received in
> pqGetErrorNotice3:
> ...
> }
> appendPQExpBufferChar(msg, '\n');
> if (verbosity != PQERRORS_TERSE)
> ...

You're right, the message text passed to the notice processor includes
a trailing newline. I confirmed this is documented in the PQsetNoticeProcessor
docs [1], so I agree it's reasonable to trim the newline for cleaner log output.

Regarding the current implementation:
+ /* Trim trailing newline for cleaner logs */
+ size_t len = strlen(message);
+
+ if (len > 0 && message[len - 1] == '\n')
+ ereport(LOG,
+ errmsg("received message via replication: %.*s",
+ (int) (len - 1), message));
+ else
+ ereport(LOG,
+ errmsg("received message via replication: %s", message));

To avoid repeating ereport(), how about refactoring it like this?
I think it's simpler and easier to read:

---------------------------------------
/*
* Custom notice processor for replication connection.
*/
static void
notice_processor(void *arg, const char *message)
{
int len;

/*
* Trim the trailing newline from the message text passed to the notice
* processor, as it always includes one, to produce cleaner log output.
*/
len = strlen(message);
if (len > 0 && message[len - 1] == '\n')
len--;

ereport(LOG,
errmsg("received message via replication: %.*s",
len, message));
}
---------------------------------------

Also, I suggest adding the prototype for notice_processor() in libpqwalreceiver.c:

---------------------------------------
/* Prototypes for private functions */
static void notice_processor(void *arg, const char *message);
static char *stringlist_to_identifierstr(PGconn *conn, List *strings);
---------------------------------------

Currently, notice_processor() is placed just before libpqrcv_connect(),
but I think it would be better to move it before stringlist_to_identifierstr(),
since the libpqwalreceiver.c seems to follow a structure where private
functions come after the libpqrcv_* functions.

+ PQsetNoticeProcessor(conn->streamConn, notice_processor, NULL);

It might be helpful to add a comment explaining the purpose, such as:

Set a custom notice processor so that notice, warning, and similar messages
received via the replication connection are logged in our preferred style,
instead of just being printed to stderr.

Thought?

>> The phrase "from publisher" could be misleading, since the sender might be
>> a primary in physical replication, not necessarily a logical publisher.
>> Maybe something like "received message via replication" would be clearer?
>> I'd like to hear others' thoughts on a better wording.
>
> Modified the message to "received message via replication." Will
> update it further if we get any better wording.

+1

Regards,

[1] https://www.postgresql.org/docs/devel/libpq-notice-processing.html

--
Fujii Masao
NTT DATA Japan Corporation