Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

Started by bt23nguyentover 2 years ago22 messageshackers
Jump to latest
#1bt23nguyent
bt23nguyent@oss.nttdata.com

Hi,

When archive_library is set to 'basic_archive' but
basic_archive.archive_directory is not set, WAL archiving doesn't work
and only the following warning message is logged.

$ emacs $PGDATA/postgresql.conf
archive_mode = on
archive_library = 'basic_archive'

$ bin/pg_ctl -D $PGDATA restart
....
WARNING: archive_mode enabled, yet archiving is not configured

The issue here is that this warning message doesn't suggest any hint
regarding the cause of WAL archiving failure. In other words, I think
that the log message in this case should report that WAL archiving
failed because basic_archive.archive_directory is not set. Thus, I think
it's worth implementing new patch that improves that warning message,
and here is the patch for that.

Best regards,
Tung Nguyen

Attachments:

v1-0001-Improve-log-message-output-of-basic-archive.patchtext/x-diff; name=v1-0001-Improve-log-message-output-of-basic-archive.patchDownload+14-6
#2Daniel Gustafsson
daniel@yesql.se
In reply to: bt23nguyent (#1)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 15 Sep 2023, at 11:38, bt23nguyent <bt23nguyent@oss.nttdata.com> wrote:

Hi,

When archive_library is set to 'basic_archive' but basic_archive.archive_directory is not set, WAL archiving doesn't work and only the following warning message is logged.

$ emacs $PGDATA/postgresql.conf
archive_mode = on
archive_library = 'basic_archive'

$ bin/pg_ctl -D $PGDATA restart
....
WARNING: archive_mode enabled, yet archiving is not configured

The issue here is that this warning message doesn't suggest any hint regarding the cause of WAL archiving failure. In other words, I think that the log message in this case should report that WAL archiving failed because basic_archive.archive_directory is not set.

That doesn't seem unreasonable, and I can imagine other callbacks having the
need to give errhints as well to assist the user.

Thus, I think it's worth implementing new patch that improves that warning message, and here is the patch for that.

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, const char **errmsg)

The variable name errmsg implies that it will contain the errmsg() data when it
in fact is used for errhint() data, so it should be named accordingly.

It's probably better to define the interface as ArchiveCheckConfiguredCB
functions returning an allocated string in the passed pointer which the caller
is responsible for freeing.

--
Daniel Gustafsson

#3Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Daniel Gustafsson (#2)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 2023-Sep-15, Daniel Gustafsson wrote:

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, const char **errmsg)

The variable name errmsg implies that it will contain the errmsg() data when it
in fact is used for errhint() data, so it should be named accordingly.

It's probably better to define the interface as ArchiveCheckConfiguredCB
functions returning an allocated string in the passed pointer which the caller
is responsible for freeing.

Also note that this callback is documented in archive-modules.sgml, so
that needs to be updated as well. This also means you can't backpatch
this change, or you risk breaking external software that implements this
interface.

I suggest that 'msg' shouldn't be a global variable. There's no need
for that AFAICS; but if there is, this is a terrible name for it.

--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/

#4Daniel Gustafsson
daniel@yesql.se
In reply to: Alvaro Herrera (#3)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 15 Sep 2023, at 12:49, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

On 2023-Sep-15, Daniel Gustafsson wrote:

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, const char **errmsg)

The variable name errmsg implies that it will contain the errmsg() data when it
in fact is used for errhint() data, so it should be named accordingly.

It's probably better to define the interface as ArchiveCheckConfiguredCB
functions returning an allocated string in the passed pointer which the caller
is responsible for freeing.

Also note that this callback is documented in archive-modules.sgml, so
that needs to be updated as well. This also means you can't backpatch
this change, or you risk breaking external software that implements this
interface.

Absolutely, this is master only for v17.

I suggest that 'msg' shouldn't be a global variable. There's no need
for that AFAICS; but if there is, this is a terrible name for it.

Agreed.

--
Daniel Gustafsson

#5Nathan Bossart
nathandbossart@gmail.com
In reply to: Daniel Gustafsson (#4)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On Fri, Sep 15, 2023 at 02:48:55PM +0200, Daniel Gustafsson wrote:

On 15 Sep 2023, at 12:49, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

On 2023-Sep-15, Daniel Gustafsson wrote:

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, const char **errmsg)

The variable name errmsg implies that it will contain the errmsg() data when it
in fact is used for errhint() data, so it should be named accordingly.

I have no objection to allowing this callback to provide additional
information, but IMHO this should use errdetail() instead of errhint(). In
the provided patch, the new message explains how the module is not
configured. It doesn't hint at how to fix it (although presumably one
could figure that out pretty easily).

It's probably better to define the interface as ArchiveCheckConfiguredCB
functions returning an allocated string in the passed pointer which the caller
is responsible for freeing.

That does seem more flexible.

Also note that this callback is documented in archive-modules.sgml, so
that needs to be updated as well. This also means you can't backpatch
this change, or you risk breaking external software that implements this
interface.

Absolutely, this is master only for v17.

+1

--
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

#6Daniel Gustafsson
daniel@yesql.se
In reply to: Nathan Bossart (#5)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 15 Sep 2023, at 16:38, Nathan Bossart <nathandbossart@gmail.com> wrote:

this should use errdetail() instead of errhint(). In
the provided patch, the new message explains how the module is not
configured. It doesn't hint at how to fix it (although presumably one
could figure that out pretty easily).

Fair point, I agree with your reasoning that errdetail seems more appropriate.

--
Daniel Gustafsson

#7bt23nguyent
bt23nguyent@oss.nttdata.com
In reply to: Nathan Bossart (#5)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 2023-09-15 23:38, Nathan Bossart wrote:

On Fri, Sep 15, 2023 at 02:48:55PM +0200, Daniel Gustafsson wrote:

On 15 Sep 2023, at 12:49, Alvaro Herrera <alvherre@alvh.no-ip.org>
wrote:

On 2023-Sep-15, Daniel Gustafsson wrote:

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, const char 
**errmsg)

The variable name errmsg implies that it will contain the errmsg()
data when it
in fact is used for errhint() data, so it should be named
accordingly.

I have no objection to allowing this callback to provide additional
information, but IMHO this should use errdetail() instead of errhint().
In
the provided patch, the new message explains how the module is not
configured. It doesn't hint at how to fix it (although presumably one
could figure that out pretty easily).

It's probably better to define the interface as
ArchiveCheckConfiguredCB
functions returning an allocated string in the passed pointer which
the caller
is responsible for freeing.

That does seem more flexible.

Also note that this callback is documented in archive-modules.sgml,
so
that needs to be updated as well. This also means you can't
backpatch
this change, or you risk breaking external software that implements
this
interface.

Absolutely, this is master only for v17.

+1

Thank you for all of your comments!

They are all really constructive and I totally agree with the points you
brought up.
I have updated the patch accordingly.

Please let me know if you have any further suggestions that I can
improve more.

Best regards,
Tung Nguyen

Attachments:

v2-0001-Improve-log-message-output-of-basic-archive.patchtext/x-diff; name=v2-0001-Improve-log-message-output-of-basic-archive.patchDownload+23-11
#8Daniel Gustafsson
daniel@yesql.se
In reply to: bt23nguyent (#7)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 19 Sep 2023, at 11:21, bt23nguyent <bt23nguyent@oss.nttdata.com> wrote:

Please let me know if you have any further suggestions that I can improve more.

+ *logdetail = pstrdup("WAL archiving failed because basic_archive.archive_directory is not set");

Nitpick: detail messages should end with a period per the error message style
guide [0]https://www.postgresql.org/docs/devel/error-style-guide.html.

-    archiving will proceed only when it returns <literal>true</literal>.
+    archiving will proceed only when it returns <literal>true</literal>. The
+    archiver may also emit the detail explaining how the module is not configured
+    to the sever log if the archive module has any. 

I think this paragraph needs to be updated to include how the returned
logdetail is emitted, since it currently shows the WARNING without mentioning
the added detail in case returned. It would also be good to mention that it
should be an allocated string which the caller can free.

--
Daniel Gustafsson

[0]: https://www.postgresql.org/docs/devel/error-style-guide.html

#9bt23nguyent
bt23nguyent@oss.nttdata.com
In reply to: Daniel Gustafsson (#8)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 2023-09-20 21:14, Daniel Gustafsson wrote:

On 19 Sep 2023, at 11:21, bt23nguyent <bt23nguyent@oss.nttdata.com>
wrote:

Please let me know if you have any further suggestions that I can
improve more.

+ *logdetail = pstrdup("WAL archiving failed because
basic_archive.archive_directory is not set");

Nitpick: detail messages should end with a period per the error message
style
guide [0].

Yes! I totally missed this detail.

-    archiving will proceed only when it returns 
<literal>true</literal>.
+    archiving will proceed only when it returns 
<literal>true</literal>. The
+    archiver may also emit the detail explaining how the module is
not configured
+    to the sever log if the archive module has any.

I think this paragraph needs to be updated to include how the returned
logdetail is emitted, since it currently shows the WARNING without
mentioning
the added detail in case returned. It would also be good to mention
that it
should be an allocated string which the caller can free.

--
Daniel Gustafsson

[0] https://www.postgresql.org/docs/devel/error-style-guide.html

Thank you for your kind review comment!

I agree with you that this document update is not explanatory enough.
So here is an updated patch.

If there is any further suggestion, please let me know.

Best regards,
Tung Nguyen

Attachments:

v3-0001-Improve-log-message-output-of-basic-archive.patchtext/x-diff; name=v3-0001-Improve-log-message-output-of-basic-archive.patchDownload+24-11
#10Nathan Bossart
nathandbossart@gmail.com
In reply to: bt23nguyent (#9)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On Thu, Sep 21, 2023 at 11:18:00AM +0900, bt23nguyent wrote:

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, char **logdetail)

Could we do something more like GUC_check_errdetail() instead to maintain
backward compatibility with v16?

--
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

#11Daniel Gustafsson
daniel@yesql.se
In reply to: Nathan Bossart (#10)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 26 Sep 2023, at 00:20, Nathan Bossart <nathandbossart@gmail.com> wrote:

On Thu, Sep 21, 2023 at 11:18:00AM +0900, bt23nguyent wrote:

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, char **logdetail)

Could we do something more like GUC_check_errdetail() instead to maintain
backward compatibility with v16?

We'd still need something exported to call into which isn't in 16, so it
wouldn't be more than optically backwards compatible since a module written for
17 won't compile for 16, or am I missing something?

--
Daniel Gustafsson

#12Nathan Bossart
nathandbossart@gmail.com
In reply to: Daniel Gustafsson (#11)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On Tue, Sep 26, 2023 at 08:13:45AM +0200, Daniel Gustafsson wrote:

On 26 Sep 2023, at 00:20, Nathan Bossart <nathandbossart@gmail.com> wrote:

On Thu, Sep 21, 2023 at 11:18:00AM +0900, bt23nguyent wrote:

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, char **logdetail)

Could we do something more like GUC_check_errdetail() instead to maintain
backward compatibility with v16?

We'd still need something exported to call into which isn't in 16, so it
wouldn't be more than optically backwards compatible since a module written for
17 won't compile for 16, or am I missing something?

I only mean that a module written for v16 could continue to be used in v17
without any changes. You are right that a module that uses this new
functionality wouldn't compile for v16. But IMHO the interface is nicer,
too, since module authors wouldn't need to worry about allocating the space
for the string or formatting the message.

--
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

#13Daniel Gustafsson
daniel@yesql.se
In reply to: Nathan Bossart (#12)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 13 Oct 2023, at 04:25, Nathan Bossart <nathandbossart@gmail.com> wrote:

On Tue, Sep 26, 2023 at 08:13:45AM +0200, Daniel Gustafsson wrote:

On 26 Sep 2023, at 00:20, Nathan Bossart <nathandbossart@gmail.com> wrote:

On Thu, Sep 21, 2023 at 11:18:00AM +0900, bt23nguyent wrote:

-basic_archive_configured(ArchiveModuleState *state)
+basic_archive_configured(ArchiveModuleState *state, char **logdetail)

Could we do something more like GUC_check_errdetail() instead to maintain
backward compatibility with v16?

We'd still need something exported to call into which isn't in 16, so it
wouldn't be more than optically backwards compatible since a module written for
17 won't compile for 16, or am I missing something?

I only mean that a module written for v16 could continue to be used in v17
without any changes. You are right that a module that uses this new
functionality wouldn't compile for v16.

Sure, but that also means that few if any existing modules will be updated to
provide this =).

But IMHO the interface is nicer,

That's a more compelling reason IMO. I'm not sure if I prefer the
GUC_check_errdetail-like approach better, I would for sure not be opposed to
reviewing a version of the patch doing it that way.

Tung Nguyen: are you interested in updating the patch along these lines
suggested by Nathan?

since module authors wouldn't need to worry about allocating the space
for the string or formatting the message.

Well, they still need to format it; and calling <new_api>_errdetail(msg),
pstrdup(msg) or psprintf(msg) isn't a world of difference.

--
Daniel Gustafsson

#14Nathan Bossart
nathandbossart@gmail.com
In reply to: Daniel Gustafsson (#13)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On Fri, Oct 13, 2023 at 11:02:39AM +0200, Daniel Gustafsson wrote:

That's a more compelling reason IMO. I'm not sure if I prefer the
GUC_check_errdetail-like approach better, I would for sure not be opposed to
reviewing a version of the patch doing it that way.

Tung Nguyen: are you interested in updating the patch along these lines
suggested by Nathan?

I gave it a try.

--
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

Attachments:

v4-0001-add-support-for-emitting-errdetail-from-archive-m.patchtext/x-diff; charset=us-asciiDownload+22-3
#15Nathan Bossart
nathandbossart@gmail.com
In reply to: Nathan Bossart (#14)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On Fri, Jan 05, 2024 at 05:03:57PM -0600, Nathan Bossart wrote:

I gave it a try.

Is there any interest in this? If not, I'll withdraw the commitfest entry.

--
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

#16Daniel Gustafsson
daniel@yesql.se
In reply to: Nathan Bossart (#15)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 28 Feb 2024, at 19:51, Nathan Bossart <nathandbossart@gmail.com> wrote:

On Fri, Jan 05, 2024 at 05:03:57PM -0600, Nathan Bossart wrote:

I gave it a try.

Is there any interest in this? If not, I'll withdraw the commitfest entry.

I'm still interested, please leave it in and I'll circle around to it.

--
Daniel Gustafsson

#17Nathan Bossart
nathandbossart@gmail.com
In reply to: Daniel Gustafsson (#16)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On Wed, Feb 28, 2024 at 10:05:26PM +0100, Daniel Gustafsson wrote:

On 28 Feb 2024, at 19:51, Nathan Bossart <nathandbossart@gmail.com> wrote:
Is there any interest in this? If not, I'll withdraw the commitfest entry.

I'm still interested, please leave it in and I'll circle around to it.

Thanks, Daniel.

--
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

#18Daniel Gustafsson
daniel@yesql.se
In reply to: Nathan Bossart (#14)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 6 Jan 2024, at 00:03, Nathan Bossart <nathandbossart@gmail.com> wrote:

I gave it a try.

Looking at this again I think this is about ready to go in. My only comment is
that doc/src/sgml/archive-modules.sgml probably should be updated to refer to
setting the errdetail, especially since we document the errormessage there.

--
Daniel Gustafsson

#19Nathan Bossart
nathandbossart@gmail.com
In reply to: Daniel Gustafsson (#18)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On Mon, Mar 04, 2024 at 03:21:59PM +0100, Daniel Gustafsson wrote:

Looking at this again I think this is about ready to go in. My only comment is
that doc/src/sgml/archive-modules.sgml probably should be updated to refer to
setting the errdetail, especially since we document the errormessage there.

Thanks for reviewing. How does this look?

--
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

Attachments:

v5-0001-Add-macro-for-customizing-an-archive-module-WARNI.patchtext/x-diff; charset=iso-8859-1Download+39-4
#20Daniel Gustafsson
daniel@yesql.se
In reply to: Nathan Bossart (#19)
Re: Improve the log message output of basic_archive when basic_archive.archive_directory parameter is not set

On 4 Mar 2024, at 18:22, Nathan Bossart <nathandbossart@gmail.com> wrote:

On Mon, Mar 04, 2024 at 03:21:59PM +0100, Daniel Gustafsson wrote:

Looking at this again I think this is about ready to go in. My only comment is
that doc/src/sgml/archive-modules.sgml probably should be updated to refer to
setting the errdetail, especially since we document the errormessage there.

Thanks for reviewing. How does this look?

Looks good from a read-through, I like it. A few comments on the commit
message only:

actionable details about the source of the miconfiguration. This
s/miconfiguration/misconfiguration/

Reviewed-by: Daniel Gustafsson, ¡lvaro Herrera
Alvaro's name seems wrong.

--
Daniel Gustafsson

#21Nathan Bossart
nathandbossart@gmail.com
In reply to: Daniel Gustafsson (#20)
#22Tom Lane
tgl@sss.pgh.pa.us
In reply to: Nathan Bossart (#21)