| Message ID | 20191212163904.159893-60-dgilbert@redhat.com |
|---|---|
| State | New |
| Headers | show |
| Series | virtiofs daemon [all] | expand |
On Thu, Dec 12, 2019 at 04:38:19PM +0000, Dr. David Alan Gilbert (git) wrote: > From: Masayoshi Mizuma <m.mizuma@jp.fujitsu.com> > > 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 <m.mizuma@jp.fujitsu.com> > --- > 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
* Daniel P. Berrangé (berrange@redhat.com) wrote: > On Thu, Dec 12, 2019 at 04:38:19PM +0000, Dr. David Alan Gilbert (git) wrote: > > From: Masayoshi Mizuma <m.mizuma@jp.fujitsu.com> > > > > 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 <m.mizuma@jp.fujitsu.com> > > --- > > 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. Yeh, that is a bit of a hack. > If instead it does: > > g_autofree *localfmt = NULL; ^ char > > + > > 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. Yes, that works nicely. Dave > > } > > 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 :| -- Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK
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; + if (current_log_level < level) { return; } + if (current_log_level == FUSE_LOG_DEBUG) { + fmt = g_strdup_printf("[ID: %08ld] %s", syscall(__NR_gettid), _fmt); + } + 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); + } } int main(int argc, char *argv[])