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

On Wed, 16 Jul 2025 at 21:30, Fujii Masao <masao(dot)fujii(at)oss(dot)nttdata(dot)com> wrote:
>
>
>
> 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));
> }
> ---------------------------------------

Looks good, modified

> 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.

Modified

>
> + 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.

Modified

The attached v4 version patch has the changes for the same.

Regards,
Vignesh