Re: bad logging around broken restore_command

On 2020/03/10 11:47, Kyotaro Horiguchi wrote:
> At Thu, 6 Feb 2020 23:23:42 +0900, Fujii Masao <masao(dot)fujii(at)oss(dot)nttdata(dot)com> wrote in
>> On 2020/02/06 1:10, Jeff Janes wrote:
>>> If the restore command claims to have succeeded, but fails to have created
>>> a file with the right name (due to typos or escaping or quoting issues, for
>>> example), no complaint is issued at the time, and it then fails later with
>>> a relatively uninformative error message like "could not locate required
>>> checkpoint record".
> ...
>>> I don't see why ENOENT is thought to deserve the silent treatment.  It
>>> seems weird that success gets logged ("restored log file \"%s\" from
>>> archive"), but one particular type of unexpected failure does not.
>>
>> Agreed.
>
> In the first place it is not perfectly silent and that problem cannot
> happen. In the ENOENT case, the function reports "could not restore
> file \"%s\" from archive: %s", but with DEBUG2 then returns false, and
> the callers treat the failure properly.

Yes.

>> I've attached a patch which emits a LOG message for ENOENT.
>>
>> Isn't it better to use "could not stat file" message even in ENOENT
>> case?
>> If yes, something like message that you used in the patch should be
>> logged as DETAIL or HINT message. So, what about the attached patch?
>
> If you want to see some log messages in the case, it is sufficient to
> raise the loglevel of the existing message from DEBUG2 to LOG.

Isn't it too noisy to log every time when we could not restore
the archived file? In archive recovery case, it's common to fail
to restore archive files and try to replay WAL files in pg_wal.

Regards,

--
Fujii Masao
NTT DATA CORPORATION
Advanced Platform Technology Group
Research and Development Headquarters