Incorrect errno used with %m for backend code

Started by Michael Paquieralmost 8 years ago11 messageshackers
Jump to latest
#1Michael Paquier
michael@paquier.xyz

Hi all,

I have been reviewing the use of errno in the backend code when %m is
used in the logs, and found more places than when I looked at improving
the error messages for read() calls which bloat the errno value because
of intermediate system calls. As the problem is separate and should be
back-patched, I have preferred beginning a new thread.

A couple of places use CloseTransientFile without bothering much that
this can overwrite errno. I was tempted in keeping errno saved and kept
if set to a non-zero value, but refrained from doing so as some callers
may rely on the existing behavior, and the attached shows better the
intention.

Attached is a patch with everything I have spotted. Any opinions or
thoughts in getting this back-patched?

Thanks,
--
Michael

Attachments:

errno-m-logs-v1.patchtext/x-diff; charset=us-asciiDownload+63-2
#2Ashutosh Sharma
ashu.coek88@gmail.com
In reply to: Michael Paquier (#1)
Re: Incorrect errno used with %m for backend code

Hi,

It seems like in case of few system calls for e.g. write system call,
errno is not set even if the number of bytes written is smaller than
the bytes requested and for such cases we explicitly set an errno to
ENOSPC. Something like this,

/*
* if write didn't set errno, assume problem is no disk space
*/
errno = save_errno ? save_errno : ENOSPC;

Shouldn't we do similar handling in your patch as well or please let
me know if i am missing something here.

Show quoted text

On Fri, Jun 22, 2018 at 11:45 AM, Michael Paquier <michael@paquier.xyz> wrote:

Hi all,

I have been reviewing the use of errno in the backend code when %m is
used in the logs, and found more places than when I looked at improving
the error messages for read() calls which bloat the errno value because
of intermediate system calls. As the problem is separate and should be
back-patched, I have preferred beginning a new thread.

A couple of places use CloseTransientFile without bothering much that
this can overwrite errno. I was tempted in keeping errno saved and kept
if set to a non-zero value, but refrained from doing so as some callers
may rely on the existing behavior, and the attached shows better the
intention.

Attached is a patch with everything I have spotted. Any opinions or
thoughts in getting this back-patched?

Thanks,
--
Michael

#3Michael Paquier
michael@paquier.xyz
In reply to: Ashutosh Sharma (#2)
Re: Incorrect errno used with %m for backend code

On Fri, Jun 22, 2018 at 01:00:45PM +0530, Ashutosh Sharma wrote:

It seems like in case of few system calls for e.g. write system call,
errno is not set even if the number of bytes written is smaller than
the bytes requested and for such cases we explicitly set an errno to
ENOSPC. Something like this,

/*
* if write didn't set errno, assume problem is no disk space
*/
errno = save_errno ? save_errno : ENOSPC;

Shouldn't we do similar handling in your patch as well or please let
me know if i am missing something here.

Yeah, I can see at least three of them in twophase.c. Let's fix those
as well at the same time.
--
Michael

#4Ashutosh Sharma
ashu.coek88@gmail.com
In reply to: Michael Paquier (#3)
Re: Incorrect errno used with %m for backend code

On Fri, Jun 22, 2018 at 2:44 PM, Michael Paquier <michael@paquier.xyz> wrote:

On Fri, Jun 22, 2018 at 01:00:45PM +0530, Ashutosh Sharma wrote:

It seems like in case of few system calls for e.g. write system call,
errno is not set even if the number of bytes written is smaller than
the bytes requested and for such cases we explicitly set an errno to
ENOSPC. Something like this,

/*
* if write didn't set errno, assume problem is no disk space
*/
errno = save_errno ? save_errno : ENOSPC;

Shouldn't we do similar handling in your patch as well or please let
me know if i am missing something here.

Yeah, I can see at least three of them in twophase.c. Let's fix those
as well at the same time.

Okay, thanks for the confirmation. Few of them are also there in
origin.c and snapbuild.c files.

--
With Regards,
Ashutosh Sharma
EnterpriseDB:http://www.enterprisedb.com

#5Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Michael Paquier (#1)
Re: Incorrect errno used with %m for backend code

On 2018-Jun-22, Michael Paquier wrote:

A couple of places use CloseTransientFile without bothering much that
this can overwrite errno. I was tempted in keeping errno saved and kept
if set to a non-zero value, but refrained from doing so as some callers
may rely on the existing behavior, and the attached shows better the
intention.

I wondered for a bit if it would be a better idea to have
CloseTransientFile restore the existing errno if there is any and close
works fine -- when I noticed that that function itself says that caller
should check errno for close() errors. Most callers seem to do it
correctly, but a few fail to check the return value.

Quite some places open files O_RDONLY, so lack of error checking after
closing seems ok. (Unless there's some funny interaction with the fsync
fiasco, of course.)

A bunch of other places use CloseTransientFile while closing shop after
some other syscall failure, which is what your patch fixes. I didn't
review those; checking for close failure seems pointless.

In some cases, we fsync the file and check that return value, then close
the file and do *not* check CloseTransientFile's return value --
examples are CheckPointLogicalRewriteHeap, heap_xlog_logical_rewrite,
SnapBuildSerialize, SaveSlotToPath, durable_rename. I don't know if
it's reasonable for close() to fail after successfully fsyncing a file;
maybe this is not a problem. I would patch those nonetheless.

be_lo_export() is certainly missing a check: it writes and closes,
without intervening fsync.

I don't understand the logic in RestoreSlotFromDisk that fsync the file
prior to reading it. What are we protecting against?

Anyway, while I think it would be nice to have CloseTransientFile
restore the original errno if there was one and close goes well, it
probably unduly complicates its API contract.

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

#6Andres Freund
andres@anarazel.de
In reply to: Alvaro Herrera (#5)
Re: Incorrect errno used with %m for backend code

Hi,

On 2018-06-22 11:15:53 -0400, Alvaro Herrera wrote:

I don't understand the logic in RestoreSlotFromDisk that fsync the file
prior to reading it. What are we protecting against?

we could previously have crashed before fsyncing. But we can only rely
on slot contents being durable if we fsync them. Therefore we fsync
before reading, after a crash.

Anyway, while I think it would be nice to have CloseTransientFile
restore the original errno if there was one and close goes well, it
probably unduly complicates its API contract.

Yea, agreed.

Greetings,

Andres Freund

#7Michael Paquier
michael@paquier.xyz
In reply to: Ashutosh Sharma (#4)
Re: Incorrect errno used with %m for backend code

On Fri, Jun 22, 2018 at 03:45:33PM +0530, Ashutosh Sharma wrote:

Okay, thanks for the confirmation. Few of them are also there in
origin.c and snapbuild.c files.

Thanks Ashutosh. I have been reviewing the whole tree and I found more
places where this is missing, like rewriteheap.c, reorderbuffer.c or
pg_basebackup, which gives the attached.
--
Michael

Attachments:

errno-m-logs-v2.patchtext/x-diff; charset=us-asciiDownload+120-6
#8Michael Paquier
michael@paquier.xyz
In reply to: Alvaro Herrera (#5)
Re: Incorrect errno used with %m for backend code

On Fri, Jun 22, 2018 at 11:15:53AM -0400, Alvaro Herrera wrote:

I wondered for a bit if it would be a better idea to have
CloseTransientFile restore the existing errno if there is any and close
works fine -- when I noticed that that function itself says that caller
should check errno for close() errors. Most callers seem to do it
correctly, but a few fail to check the return value.

Yeah, the API in its current shape is simpler to understand. Once you
get used to the errno stanza of course...

A bunch of other places use CloseTransientFile while closing shop after
some other syscall failure, which is what your patch fixes. I didn't
review those; checking for close failure seems pointless.

Agreed.

In some cases, we fsync the file and check that return value, then close
the file and do *not* check CloseTransientFile's return value --
examples are CheckPointLogicalRewriteHeap, heap_xlog_logical_rewrite,
SnapBuildSerialize, SaveSlotToPath, durable_rename. I don't know if
it's reasonable for close() to fail after successfully fsyncing a file;
maybe this is not a problem. I would patch those nonetheless.

And writeTimeLineHistory.

be_lo_export() is certainly missing a check: it writes and closes,
without intervening fsync.

One problem at the same time if possible :) I think that those
adjustments should be a separate patch.
--
Michael

#9Ashutosh Sharma
ashu.coek88@gmail.com
In reply to: Michael Paquier (#7)
Re: Incorrect errno used with %m for backend code

On Sat, Jun 23, 2018 at 6:43 PM, Michael Paquier <michael@paquier.xyz> wrote:

On Fri, Jun 22, 2018 at 03:45:33PM +0530, Ashutosh Sharma wrote:

Okay, thanks for the confirmation. Few of them are also there in
origin.c and snapbuild.c files.

Thanks Ashutosh. I have been reviewing the whole tree and I found more
places where this is missing, like rewriteheap.c, reorderbuffer.c or
pg_basebackup, which gives the attached.
--

Okay, I too had a quick look into the source code to see if there are
still some places where we could have missed to set an errno to ENOSPC
in case of write system call failure but, couldn't find any such place
in the code. The v2 version of patch looks good to me.

So, to conclude, now, v2 patch fixes two things - 1) It makes ereport
to print a correct error number (the error number that matches with
the error message), 2) It sets the errno to ENOSPC (assuming that the
problem is no disk space) if write system call fails to set an errno.

--
With Regards,
Ashutosh Sharma
EnterpriseDB:http://www.enterprisedb.com

#10Michael Paquier
michael@paquier.xyz
In reply to: Ashutosh Sharma (#9)
Re: Incorrect errno used with %m for backend code

On Sun, Jun 24, 2018 at 09:22:01AM +0530, Ashutosh Sharma wrote:

Okay, I too had a quick look into the source code to see if there are
still some places where we could have missed to set an errno to ENOSPC
in case of write system call failure but, couldn't find any such place
in the code. The v2 version of patch looks good to me.

Thanks for the review. I'll try to wrap that tomorrow with proper
patches for back-branches as things diverge a bit here and there.

So, to conclude, now, v2 patch fixes two things - 1) It makes ereport
to print a correct error number (the error number that matches with
the error message), 2) It sets the errno to ENOSPC (assuming that the
problem is no disk space) if write system call fails to set an errno.

Yes, 1) and 2) and not completely exclusive either, there are some code
paths where both problems happen, like RecreateTwoPhaseFile.
--
Michael

#11Michael Paquier
michael@paquier.xyz
In reply to: Michael Paquier (#10)
Re: Incorrect errno used with %m for backend code

On Sun, Jun 24, 2018 at 09:23:50PM +0900, Michael Paquier wrote:

On Sun, Jun 24, 2018 at 09:22:01AM +0530, Ashutosh Sharma wrote:

Okay, I too had a quick look into the source code to see if there are
still some places where we could have missed to set an errno to ENOSPC
in case of write system call failure but, couldn't find any such place
in the code. The v2 version of patch looks good to me.

Thanks for the review. I'll try to wrap that tomorrow with proper
patches for back-branches as things diverge a bit here and there.

Pushed down to 9.3. All branches conflicted, and particularly in
pg_basebackup some write() calls have been moved around.
--
Michael