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

On Wed, 16 Jul 2025 at 21:30, Fujii Masao <masao.fujii@oss.nttdata.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