Re: [PATCH 059/104] virtiofsd: Add ID to the log with FUSE_LOG_DEBUG level

[Daniel P . Berrangé]

On Thu, Dec 12, 2019 at 04:38:19PM +0000, Dr. David Alan Gilbert (git) wrote:
> From: Masayoshi Mizuma <address@hidden>
> 
> virtiofsd has some threads, so we see a lot of logs with debug option.
> It would be useful for debugging if we can identify the specific thread
> from the log.
> 
> Add ID, which is got by gettid(), to the log with FUSE_LOG_DEBUG level
> so that we can grep the specific thread.
> 
> The log is like as:
> 
>   ]# ./virtiofsd -d -o vhost_user_socket=/tmp/vhostqemu0 -o 
> source=/tmp/share0 -o cache=auto
>   ...
>   [ID: 00000097]    unique: 12696, success, outsize: 120
>   [ID: 00000097] virtio_send_msg: elem 18: with 2 in desc of length 120
>   [ID: 00000003] fv_queue_thread: Got queue event on Queue 1
>   [ID: 00000003] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 65552 
> out: 80
>   [ID: 00000003] fv_queue_thread: Waiting for Queue 1 event
>   [ID: 00000071] fv_queue_worker: elem 33: with 2 out desc of length 80 
> bad_in_num=0 bad_out_num=0
>   [ID: 00000071] unique: 12694, opcode: READ (15), nodeid: 2, insize: 80, 
> pid: 2014
>   [ID: 00000071] lo_read(ino=2, size=65536, off=131072)
> 
> Signed-off-by: Masayoshi Mizuma <address@hidden>
> ---
>  tools/virtiofsd/passthrough_ll.c | 13 ++++++++++++-
>  1 file changed, 12 insertions(+), 1 deletion(-)

> 
> diff --git a/tools/virtiofsd/passthrough_ll.c 
> b/tools/virtiofsd/passthrough_ll.c
> index 6f398a7ff2..8e00a90e6f 100644
> --- a/tools/virtiofsd/passthrough_ll.c
> +++ b/tools/virtiofsd/passthrough_ll.c
> @@ -42,6 +42,7 @@
>  #include <cap-ng.h>
>  #include <dirent.h>
>  #include <errno.h>
> +#include <glib.h>
>  #include <inttypes.h>
>  #include <limits.h>
>  #include <pthread.h>
> @@ -2248,12 +2249,18 @@ static void setup_nofile_rlimit(void)
>      }
>  }
>  
> -static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
> +static void log_func(enum fuse_log_level level, const char *_fmt, va_list ap)
>  {
> +    char *fmt = (char *)_fmt;

Reusing a variable for data that may be const from stack or
non-const from heap is really gross & asking for trouble.

If instead it does:

    g_autofree *localfmt = NULL;

> +
>      if (current_log_level < level) {
>          return;
>      }
>  
> +    if (current_log_level == FUSE_LOG_DEBUG) {
> +        fmt = g_strdup_printf("[ID: %08ld] %s", syscall(__NR_gettid), _fmt);

Then:

           localfmt = g_strdup_printf(....)
           fmt = localfmt;

> +    }
> +
>      if (use_syslog) {
>          int priority = LOG_ERR;
>          switch (level) {
> @@ -2286,6 +2293,10 @@ static void log_func(enum fuse_log_level level, const 
> char *fmt, va_list ap)
>      } else {
>          vfprintf(stderr, fmt, ap);
>      }
> +
> +    if (current_log_level == FUSE_LOG_DEBUG) {
> +        g_free(fmt);
> +    }

This can then be deleted.

>  }

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|