Re: add recovery, backup, archive, streaming etc. activity messages to server logs along with ps display

On Thu, Nov 11, 2021 at 12:01 AM Bossart, Nathan <bossartn(at)amazon(dot)com> wrote:
>
> On 11/10/21, 9:43 AM, "Bharath Rupireddy" <bharath(dot)rupireddyforpostgres(at)gmail(dot)com> wrote:
> > As discussed in [1], isn't it a better idea to add some of activity
> > messages [2] such as recovery, archive, backup, streaming etc. to
> > server logs at LOG level? They are currently being set into ps display
> > which is good if the postgres is being run on a standalone box/VM
> > where users can see the ps display, but it doesn't help much in case
> > the postgres is being run on a cloud environment where users don't
> > have access to ps display output. Moreover, the ps display is
> > transient and will not help to analyze after an issue occurs.
> >
> > Having the above messages in the server logs will be useful to
> > understand how the system is/was doing/progressing with these
> > (sometimes time-intensive) operations.
>
> I think this would make the logs far too noisy for many servers. For
> archiving alone, this could cause tens of thousands more log messages
> per hour on a busy system. I think you can already see such
> information at a debug level, anyway.

You are right, having them at LOG level may blow up the log files and
disk storage, having them at DEBUG1 like other messages would at least
help than having them as activitymsg in ps display.

And not all of the activitymsgs are logged at DEBUGX level, at least I
don't see them(on a quick search).
snprintf(activitymsg, sizeof(activitymsg), "waiting for %s",
snprintf(activitymsg, sizeof(activitymsg), "recovering %s",
snprintf(activitymsg, sizeof(activitymsg), "performing %s%s%s",
snprintf(activitymsg, sizeof(activitymsg), "sending backup \"%s\"",
snprintf(activitymsg, sizeof(activitymsg), "restarting at %X/%X",
snprintf(activitymsg, sizeof(activitymsg), "streaming %X/%X",

But for the snprintf(activitymsg, sizeof(activitymsg), "archiving %s",
xlog); we have elog(DEBUG1, "archived write-ahead log file \"%s\"",
xlog); after the archiving command. It is also good to have a similar
debug message before archive command execution, we can get to know
whether archive command is executed or not, if yes how much time did
it take etc.?

I'm not sure whether it is okay to do the following, for every of the
activitymsg, before the command execution, we have an elog(DEBUG1
message and after the command execution another elog(DEBUG1 message.

Thoughts?

Regards,
Bharath Rupireddy.