[libvirt] [PATCH] file: Log closing filedescriptors

--- src/util/virfile.c | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/src/util/virfile.c b/src/util/virfile.c index db3d737..bc7f2c9 100644 --- a/src/util/virfile.c +++ b/src/util/virfile.c @@ -35,6 +35,7 @@ #include "configmake.h" #include "memory.h" #include "virterror_internal.h" +#include "logging.h" #define VIR_FROM_THIS VIR_FROM_NONE #define virFileError(code, ...) \ @@ -51,6 +52,15 @@ int virFileClose(int *fdptr, bool preserve_errno) if (preserve_errno) saved_errno = errno; rc = close(*fdptr); + if (rc < 0) { + if (errno != EBADF) { + char ebuf[1024] ATTRIBUTE_UNUSED; + VIR_DEBUG("Failed to close fd %d: %d", + *fdptr, virStrerror(errno, ebuf, sizeof(ebuf))); + } + } else { + VIR_DEBUG("Closed fd %d", *fdptr); + } *fdptr = -1; if (preserve_errno) errno = saved_errno; -- 1.7.10.2

On 05/30/2012 08:34 AM, Jiri Denemark wrote:
--- src/util/virfile.c | 10 ++++++++++ 1 file changed, 10 insertions(+)
diff --git a/src/util/virfile.c b/src/util/virfile.c index db3d737..bc7f2c9 100644 --- a/src/util/virfile.c +++ b/src/util/virfile.c @@ -35,6 +35,7 @@ #include "configmake.h" #include "memory.h" #include "virterror_internal.h" +#include "logging.h"
#define VIR_FROM_THIS VIR_FROM_NONE #define virFileError(code, ...) \ @@ -51,6 +52,15 @@ int virFileClose(int *fdptr, bool preserve_errno) if (preserve_errno) saved_errno = errno; rc = close(*fdptr); + if (rc < 0) { + if (errno != EBADF) { + char ebuf[1024] ATTRIBUTE_UNUSED; + VIR_DEBUG("Failed to close fd %d: %d", + *fdptr, virStrerror(errno, ebuf, sizeof(ebuf)));
I think we _also_ need to log EBADF errors, those are usually the sign of developer bugs, as you are probably guilty of a double-close race. In fact, I think EBADF should be logged with higher severity than VIR_DEBUG, as we want to see that right away. -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

On Wed, May 30, 2012 at 08:48:22 -0600, Eric Blake wrote:
On 05/30/2012 08:34 AM, Jiri Denemark wrote:
--- src/util/virfile.c | 10 ++++++++++ 1 file changed, 10 insertions(+)
diff --git a/src/util/virfile.c b/src/util/virfile.c index db3d737..bc7f2c9 100644 --- a/src/util/virfile.c +++ b/src/util/virfile.c @@ -35,6 +35,7 @@ #include "configmake.h" #include "memory.h" #include "virterror_internal.h" +#include "logging.h"
#define VIR_FROM_THIS VIR_FROM_NONE #define virFileError(code, ...) \ @@ -51,6 +52,15 @@ int virFileClose(int *fdptr, bool preserve_errno) if (preserve_errno) saved_errno = errno; rc = close(*fdptr); + if (rc < 0) { + if (errno != EBADF) { + char ebuf[1024] ATTRIBUTE_UNUSED; + VIR_DEBUG("Failed to close fd %d: %d", + *fdptr, virStrerror(errno, ebuf, sizeof(ebuf)));
I think we _also_ need to log EBADF errors, those are usually the sign of developer bugs, as you are probably guilty of a double-close race. In fact, I think EBADF should be logged with higher severity than VIR_DEBUG, as we want to see that right away.
I explicitly didn't want to log them since you would see a lot of errors when after fork we are closing all available file descriptors except those we explicitly want to leave open... I'll add EBADF logging and handle those mass-closes separately. Jirka

On 05/30/2012 08:56 AM, Jiri Denemark wrote:
On Wed, May 30, 2012 at 08:48:22 -0600, Eric Blake wrote:
On 05/30/2012 08:34 AM, Jiri Denemark wrote:
--- src/util/virfile.c | 10 ++++++++++ 1 file changed, 10 insertions(+)
diff --git a/src/util/virfile.c b/src/util/virfile.c index db3d737..bc7f2c9 100644 --- a/src/util/virfile.c +++ b/src/util/virfile.c @@ -35,6 +35,7 @@ #include "configmake.h" #include "memory.h" #include "virterror_internal.h" +#include "logging.h"
#define VIR_FROM_THIS VIR_FROM_NONE #define virFileError(code, ...) \ @@ -51,6 +52,15 @@ int virFileClose(int *fdptr, bool preserve_errno) if (preserve_errno) saved_errno = errno; rc = close(*fdptr); + if (rc < 0) { + if (errno != EBADF) { + char ebuf[1024] ATTRIBUTE_UNUSED; + VIR_DEBUG("Failed to close fd %d: %d", + *fdptr, virStrerror(errno, ebuf, sizeof(ebuf)));
I think we _also_ need to log EBADF errors, those are usually the sign of developer bugs, as you are probably guilty of a double-close race. In fact, I think EBADF should be logged with higher severity than VIR_DEBUG, as we want to see that right away.
I explicitly didn't want to log them since you would see a lot of errors when after fork we are closing all available file descriptors except those we explicitly want to leave open... I'll add EBADF logging and handle those mass-closes separately.
Oh, good point. EBADF in the parent is almost always a bug (and if the race had gone the other way, you'd have a double-close). EBADF in the child is an annoyance - we know we are single-threaded and therefore there is no double-close race, and it is more efficient to try and waste a close() than it is to do an fcntl() filter to see if the fd is valid in order to decide whether to close. But that means that the _only_ place that should be ignoring EBADF on a mass-close is in the post-fork() closing of a child; so maybe the solution is: change the signature of virFileClose() to take an extra parameter to say whether to ignore EBADF, change VIR_FORCE_CLOSE to pass false to the new parameter, and change command.c's mass-close to use virFileClose() directly, with the parameter set to true -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
participants (2)
-
Eric Blake
-
Jiri Denemark