[libvirt PATCH] util: Make virFileClose() quiet on success

Andrea Bolognani posted 1 patch 3 years, 5 months ago
Test syntax-check failed
Patches applied successfully (tree, apply log)
git fetch https://github.com/patchew-project/libvirt tags/patchew/20201112185137.559597-1-abologna@redhat.com
src/util/virfile.c | 2 --
1 file changed, 2 deletions(-)
[libvirt PATCH] util: Make virFileClose() quiet on success
Posted by Andrea Bolognani 3 years, 5 months ago
While it's certainly good to log events like "failed to close fd"
and "tried to close invalid fd", which are likely to be the
consequence of some bug in libvirt, logging a message every single
time a file descriptor is closed successfully is perhaps excessive
and can lead to useful information being missed among the noise.

Log filters don't help in this situation, because filtering out all
of util.file is too big a hammer and would cause important messages
to be left out as well.

To give an idea of just how much noise this single debug statement
can cause, here's a real life example from a quite large libvirtd
log I had to look at recently:

  $ grep virFile libvirt.log | wc -l
  1307
  $ grep virFile libvirt.log | grep -v 'Closed fd' | wc -l
  343

Signed-off-by: Andrea Bolognani <abologna@redhat.com>
---
 src/util/virfile.c | 2 --
 1 file changed, 2 deletions(-)

diff --git a/src/util/virfile.c b/src/util/virfile.c
index 9a7dcfc9a6..f57272ca2f 100644
--- a/src/util/virfile.c
+++ b/src/util/virfile.c
@@ -131,8 +131,6 @@ int virFileClose(int *fdptr, virFileCloseFlags flags)
                 VIR_DEBUG("Failed to close fd %d: %s",
                           *fdptr, g_strerror(errno));
             }
-        } else {
-            VIR_DEBUG("Closed fd %d", *fdptr);
         }
     }
     *fdptr = -1;
-- 
2.26.2

Re: [libvirt PATCH] util: Make virFileClose() quiet on success
Posted by Michal Privoznik 3 years, 5 months ago
On 11/12/20 7:51 PM, Andrea Bolognani wrote:
> While it's certainly good to log events like "failed to close fd"
> and "tried to close invalid fd", which are likely to be the
> consequence of some bug in libvirt, logging a message every single
> time a file descriptor is closed successfully is perhaps excessive
> and can lead to useful information being missed among the noise.
> 
> Log filters don't help in this situation, because filtering out all
> of util.file is too big a hammer and would cause important messages
> to be left out as well.
> 
> To give an idea of just how much noise this single debug statement
> can cause, here's a real life example from a quite large libvirtd
> log I had to look at recently:
> 
>    $ grep virFile libvirt.log | wc -l
>    1307
>    $ grep virFile libvirt.log | grep -v 'Closed fd' | wc -l
>    343
> 
> Signed-off-by: Andrea Bolognani <abologna@redhat.com>
> ---
>   src/util/virfile.c | 2 --
>   1 file changed, 2 deletions(-)
> 
> diff --git a/src/util/virfile.c b/src/util/virfile.c
> index 9a7dcfc9a6..f57272ca2f 100644
> --- a/src/util/virfile.c
> +++ b/src/util/virfile.c
> @@ -131,8 +131,6 @@ int virFileClose(int *fdptr, virFileCloseFlags flags)
>                   VIR_DEBUG("Failed to close fd %d: %s",
>                             *fdptr, g_strerror(errno));
>               }
> -        } else {
> -            VIR_DEBUG("Closed fd %d", *fdptr);
>           }
>       }
>       *fdptr = -1;
> 

Right, this was needed in the old times when we had some FD leak bugs 
(shush, /dev/mapper/control leak is an exception!), but with more 
adoption of VIR_AUTOCLOSE I don't think we can have many FD leaks.

Reviewed-by: Michal Privoznik <mprivozn@redhat.com>

Michal