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

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

> 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
workand 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
otherwords, I think that the log message in this case should report that WAL archiving failed because
basic_archive.archive_directoryis 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

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/

> 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

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

> 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

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

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

-    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

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

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

> 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

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

> 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

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

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

> 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

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

> 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

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

> 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

On Mon, Mar 04, 2024 at 09:27:23PM +0100, Daniel Gustafsson wrote:
> 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/

I reworded the commit message a bit to avoid the word "misconfiguration,"
as it felt a bit misleading to me.  In any case, this was fixed, albeit
indirectly.

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

Hm.  It looks alright to me.  I copied the name from his e-mail signature,
which has an accent over the first 'A'.  I assume that's why it's not
showing up correctly in some places.

Anyway, I've committed this now.  Thanks for taking a look!

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

Nathan Bossart <nathandbossart@gmail.com> writes:
> On Mon, Mar 04, 2024 at 09:27:23PM +0100, Daniel Gustafsson wrote:
>> Reviewed-by: Daniel Gustafsson, ¡lvaro Herrera
>> Alvaro's name seems wrong.

> Hm.  It looks alright to me.  I copied the name from his e-mail signature,
> which has an accent over the first 'A'.  I assume that's why it's not
> showing up correctly in some places.

I think that git has an expectation of commit log entries being in
UTF8.  The committed message looks okay from my end, but maybe some
encoding mangling happened to the version Daniel was looking at?

            regards, tom lane