Обсуждение: Emit "checkpoint skipped because system is idle" message at LOG level if log_checkpoints is set

Hi,

Postgres server emits a message at DEBUG1 level when it skips a
checkpoint. At times, developers might be surprised after figuring out
from server logs that there were no checkpoints happening at all
during a certain period of time when DEBUG1 messages aren't captured.
How about emitting the message at LOG level if log_checkpoints is set?
Patch attached.

Thoughts?

Regards,
Bharath Rupireddy.

On Wed, Jan 5, 2022 at 10:24 AM Bharath Rupireddy
<bharath.rupireddyforpostgres@gmail.com> wrote:
>
> Hi,
>
> Postgres server emits a message at DEBUG1 level when it skips a
> checkpoint. At times, developers might be surprised after figuring out
> from server logs that there were no checkpoints happening at all
> during a certain period of time when DEBUG1 messages aren't captured.
> How about emitting the message at LOG level if log_checkpoints is set?
> Patch attached.
>
> Thoughts?

+1 to convert to LOG when log_checkpoints is set.

-- 
Regards,
Dilip Kumar
EnterpriseDB: http://www.enterprisedb.com

At Wed, 5 Jan 2022 17:18:06 -0600, Justin Pryzby <pryzby@telsasoft.com> wrote in 
> On Wed, Jan 05, 2022 at 10:45:06AM +0530, Dilip Kumar wrote:
> > On Wed, Jan 5, 2022 at 10:24 AM Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com> wrote:
> > >
> > > Postgres server emits a message at DEBUG1 level when it skips a
> > > checkpoint. At times, developers might be surprised after figuring out
> > > from server logs that there were no checkpoints happening at all
> > > during a certain period of time when DEBUG1 messages aren't captured.
> > > How about emitting the message at LOG level if log_checkpoints is set?
> > > Patch attached.
> > 
> > +1 to convert to LOG when log_checkpoints is set.
> 
> I think it would be odd to write logs of increased severity, for the case where
> we did not do anything.  I think it really is a debug log.
> 
> I don't think the log level should be changed to avoid "developer" confusion,
> as you said (I'm not sure if you mean a postgres developer or an application
> developer, though).
> 
> Is there any evidence that this has caused user confusion in the last 4 years ?
> 
> |commit 6ef2eba3f57f17960b7cd4958e18aa79e357de2f
> |Author: Andres Freund <andres@anarazel.de>
> |Date:   Thu Dec 22 11:31:50 2016 -0800
> |
> |    Skip checkpoints, archiving on idle systems.
> 
> Note that logging a message may not be benign ; I think it could cause the
> disks to spin up, that would othewise have been in power saving mode,
> especially if you log to syslog, which can issue fsync.  Also, part of the
> argument for enabling log_checkpoint by default was that a small, quiescent
> instance would not write logs every 5 minutes.

Agreed. -1 to just raising elevel of the message.

If someone keen to show some debug messages, it is viable for
arbitrary messages by lowering log_min_messages then inserting a
custom filter to emit_log_hook.  It invites some overhead on
irrelevant processes, but that overhead would be avoidable with a
*bit* dirty hack in the filter,

We might want to discuss more convenient or cleaner way to get the
same result.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center