diff mbox series

[7/7] virtiofsd: use GDateTime for formatting timestamp for debug messages

Message ID 20210505103702.521457-8-berrange@redhat.com
State New
Headers show
Series replace all use of strftime() with g_date_time_format() | expand

Commit Message

Daniel P. Berrangé May 5, 2021, 10:37 a.m. UTC 
The GDateTime APIs provided by GLib avoid portability pitfalls, such
as some platforms where 'struct timeval.tv_sec' field is still 'long'
instead of 'time_t'. When combined with automatic cleanup, GDateTime
often results in simpler code too.

Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
---
 tools/virtiofsd/passthrough_ll.c | 25 ++++---------------------
 1 file changed, 4 insertions(+), 21 deletions(-)

Comments

Dr. David Alan Gilbert May 5, 2021, 2:51 p.m. UTC | #1 
* Daniel P. Berrangé (berrange@redhat.com) wrote:
> The GDateTime APIs provided by GLib avoid portability pitfalls, such
> as some platforms where 'struct timeval.tv_sec' field is still 'long'
> instead of 'time_t'. When combined with automatic cleanup, GDateTime
> often results in simpler code too.
> 
> Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>

Reviewed-by: Dr. David Alan Gilbert <dgilbert@redhat.com>

> ---
>  tools/virtiofsd/passthrough_ll.c | 25 ++++---------------------
>  1 file changed, 4 insertions(+), 21 deletions(-)
> 
> diff --git a/tools/virtiofsd/passthrough_ll.c b/tools/virtiofsd/passthrough_ll.c
> index 1553d2ef45..cdd224918c 100644
> --- a/tools/virtiofsd/passthrough_ll.c
> +++ b/tools/virtiofsd/passthrough_ll.c
> @@ -3558,10 +3558,6 @@ static void setup_nofile_rlimit(unsigned long rlimit_nofile)
>  static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
>  {
>      g_autofree char *localfmt = NULL;
> -    struct timespec ts;
> -    struct tm tm;
> -    char sec_fmt[sizeof "2020-12-07 18:17:54"];
> -    char zone_fmt[sizeof "+0100"];
>  
>      if (current_log_level < level) {
>          return;
> @@ -3573,23 +3569,10 @@ static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
>              localfmt = g_strdup_printf("[ID: %08ld] %s", syscall(__NR_gettid),
>                                         fmt);
>          } else {
> -            /* try formatting a broken-down timestamp */
> -            if (clock_gettime(CLOCK_REALTIME, &ts) != -1 &&
> -                localtime_r(&ts.tv_sec, &tm) != NULL &&
> -                strftime(sec_fmt, sizeof sec_fmt, "%Y-%m-%d %H:%M:%S",
> -                         &tm) != 0 &&
> -                strftime(zone_fmt, sizeof zone_fmt, "%z", &tm) != 0) {
> -                localfmt = g_strdup_printf("[%s.%02ld%s] [ID: %08ld] %s",
> -                                           sec_fmt,
> -                                           ts.tv_nsec / (10L * 1000 * 1000),
> -                                           zone_fmt, syscall(__NR_gettid),
> -                                           fmt);
> -            } else {
> -                /* fall back to a flat timestamp */
> -                localfmt = g_strdup_printf("[%" PRId64 "] [ID: %08ld] %s",
> -                                           get_clock(), syscall(__NR_gettid),
> -                                           fmt);
> -            }
> +            g_autoptr(GDateTime) now = g_date_time_new_now_local();
> +            g_autofree char *nowstr = g_date_time_format(now, "%Y-%m-%d %H:%M:%S.%f%z");
> +            localfmt = g_strdup_printf("[%s] [ID: %08ld] %s",
> +                                       nowstr, syscall(__NR_gettid), fmt);
>          }
>          fmt = localfmt;
>      }
> -- 
> 2.31.1
>
Dr. David Alan Gilbert May 6, 2021, 4 p.m. UTC | #2 
* Dr. David Alan Gilbert (dgilbert@redhat.com) wrote:
> * Daniel P. Berrangé (berrange@redhat.com) wrote:
> > The GDateTime APIs provided by GLib avoid portability pitfalls, such
> > as some platforms where 'struct timeval.tv_sec' field is still 'long'
> > instead of 'time_t'. When combined with automatic cleanup, GDateTime
> > often results in simpler code too.
> > 
> > Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
> 
> Reviewed-by: Dr. David Alan Gilbert <dgilbert@redhat.com>

Queued this 7/7 via virtiofsd

> > ---
> >  tools/virtiofsd/passthrough_ll.c | 25 ++++---------------------
> >  1 file changed, 4 insertions(+), 21 deletions(-)
> > 
> > diff --git a/tools/virtiofsd/passthrough_ll.c b/tools/virtiofsd/passthrough_ll.c
> > index 1553d2ef45..cdd224918c 100644
> > --- a/tools/virtiofsd/passthrough_ll.c
> > +++ b/tools/virtiofsd/passthrough_ll.c
> > @@ -3558,10 +3558,6 @@ static void setup_nofile_rlimit(unsigned long rlimit_nofile)
> >  static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
> >  {
> >      g_autofree char *localfmt = NULL;
> > -    struct timespec ts;
> > -    struct tm tm;
> > -    char sec_fmt[sizeof "2020-12-07 18:17:54"];
> > -    char zone_fmt[sizeof "+0100"];
> >  
> >      if (current_log_level < level) {
> >          return;
> > @@ -3573,23 +3569,10 @@ static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
> >              localfmt = g_strdup_printf("[ID: %08ld] %s", syscall(__NR_gettid),
> >                                         fmt);
> >          } else {
> > -            /* try formatting a broken-down timestamp */
> > -            if (clock_gettime(CLOCK_REALTIME, &ts) != -1 &&
> > -                localtime_r(&ts.tv_sec, &tm) != NULL &&
> > -                strftime(sec_fmt, sizeof sec_fmt, "%Y-%m-%d %H:%M:%S",
> > -                         &tm) != 0 &&
> > -                strftime(zone_fmt, sizeof zone_fmt, "%z", &tm) != 0) {
> > -                localfmt = g_strdup_printf("[%s.%02ld%s] [ID: %08ld] %s",
> > -                                           sec_fmt,
> > -                                           ts.tv_nsec / (10L * 1000 * 1000),
> > -                                           zone_fmt, syscall(__NR_gettid),
> > -                                           fmt);
> > -            } else {
> > -                /* fall back to a flat timestamp */
> > -                localfmt = g_strdup_printf("[%" PRId64 "] [ID: %08ld] %s",
> > -                                           get_clock(), syscall(__NR_gettid),
> > -                                           fmt);
> > -            }
> > +            g_autoptr(GDateTime) now = g_date_time_new_now_local();
> > +            g_autofree char *nowstr = g_date_time_format(now, "%Y-%m-%d %H:%M:%S.%f%z");
> > +            localfmt = g_strdup_printf("[%s] [ID: %08ld] %s",
> > +                                       nowstr, syscall(__NR_gettid), fmt);
> >          }
> >          fmt = localfmt;
> >      }
> > -- 
> > 2.31.1
> > 
> -- 
> Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK
> 
>
Dr. David Alan Gilbert May 6, 2021, 5:45 p.m. UTC | #3 
* Dr. David Alan Gilbert (dgilbert@redhat.com) wrote:
> * Dr. David Alan Gilbert (dgilbert@redhat.com) wrote:
> > * Daniel P. Berrangé (berrange@redhat.com) wrote:
> > > The GDateTime APIs provided by GLib avoid portability pitfalls, such
> > > as some platforms where 'struct timeval.tv_sec' field is still 'long'
> > > instead of 'time_t'. When combined with automatic cleanup, GDateTime
> > > often results in simpler code too.
> > > 
> > > Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
> > 
> > Reviewed-by: Dr. David Alan Gilbert <dgilbert@redhat.com>
> 
> Queued this 7/7 via virtiofsd

Hi Dan,
  I've had to drop this because it triggers seccomp:

#0  0x00007f0afec4d21b in readlink () from /lib64/libc.so.6
#1  0x00007f0afeecff24 in g_file_read_link () from /lib64/libglib-2.0.so.0
#2  0x00007f0afef16390 in g_time_zone_new_identifier () from /lib64/libglib-2.0.so.0
#3  0x00007f0afef16fe8 in g_time_zone_new_local () from /lib64/libglib-2.0.so.0
#4  0x00007f0afeec9520 in g_date_time_new_now_local () from /lib64/libglib-2.0.so.0
#5  0x000055a6bd6bc27a in log_func (level=FUSE_LOG_INFO, fmt=0x55a6bd6e3cda "%s: Entry\n", ap=0x7ffece4b2f50) at ../tools/virtiofsd/passthrough_ll.c:3578
#6  0x000055a6bd6b3dd5 in fuse_log (level=level@entry=FUSE_LOG_INFO, fmt=fmt@entry=0x55a6bd6e3cda "%s: Entry\n") at ../tools/virtiofsd/fuse_log.c:37
#7  0x000055a6bd6ba9fd in virtio_loop (se=se@entry=0x55a6bee29a30) at ../tools/virtiofsd/fuse_virtio.c:878
#8  0x000055a6bd6b2017 in main (argc=<optimized out>, argv=<optimized out>) at ../tools/virtiofsd/passthrough_ll.c:3868


so you either need to add seccomp rules and/or persuade it not to moan;
maybe dropping down to UTC would work.

Dave

> > > ---
> > >  tools/virtiofsd/passthrough_ll.c | 25 ++++---------------------
> > >  1 file changed, 4 insertions(+), 21 deletions(-)
> > > 
> > > diff --git a/tools/virtiofsd/passthrough_ll.c b/tools/virtiofsd/passthrough_ll.c
> > > index 1553d2ef45..cdd224918c 100644
> > > --- a/tools/virtiofsd/passthrough_ll.c
> > > +++ b/tools/virtiofsd/passthrough_ll.c
> > > @@ -3558,10 +3558,6 @@ static void setup_nofile_rlimit(unsigned long rlimit_nofile)
> > >  static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
> > >  {
> > >      g_autofree char *localfmt = NULL;
> > > -    struct timespec ts;
> > > -    struct tm tm;
> > > -    char sec_fmt[sizeof "2020-12-07 18:17:54"];
> > > -    char zone_fmt[sizeof "+0100"];
> > >  
> > >      if (current_log_level < level) {
> > >          return;
> > > @@ -3573,23 +3569,10 @@ static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
> > >              localfmt = g_strdup_printf("[ID: %08ld] %s", syscall(__NR_gettid),
> > >                                         fmt);
> > >          } else {
> > > -            /* try formatting a broken-down timestamp */
> > > -            if (clock_gettime(CLOCK_REALTIME, &ts) != -1 &&
> > > -                localtime_r(&ts.tv_sec, &tm) != NULL &&
> > > -                strftime(sec_fmt, sizeof sec_fmt, "%Y-%m-%d %H:%M:%S",
> > > -                         &tm) != 0 &&
> > > -                strftime(zone_fmt, sizeof zone_fmt, "%z", &tm) != 0) {
> > > -                localfmt = g_strdup_printf("[%s.%02ld%s] [ID: %08ld] %s",
> > > -                                           sec_fmt,
> > > -                                           ts.tv_nsec / (10L * 1000 * 1000),
> > > -                                           zone_fmt, syscall(__NR_gettid),
> > > -                                           fmt);
> > > -            } else {
> > > -                /* fall back to a flat timestamp */
> > > -                localfmt = g_strdup_printf("[%" PRId64 "] [ID: %08ld] %s",
> > > -                                           get_clock(), syscall(__NR_gettid),
> > > -                                           fmt);
> > > -            }
> > > +            g_autoptr(GDateTime) now = g_date_time_new_now_local();
> > > +            g_autofree char *nowstr = g_date_time_format(now, "%Y-%m-%d %H:%M:%S.%f%z");
> > > +            localfmt = g_strdup_printf("[%s] [ID: %08ld] %s",
> > > +                                       nowstr, syscall(__NR_gettid), fmt);
> > >          }
> > >          fmt = localfmt;
> > >      }
> > > -- 
> > > 2.31.1
> > > 
> > -- 
> > Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK
> > 
> > 
> -- 
> Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK
diff mbox series

Patch

diff --git a/tools/virtiofsd/passthrough_ll.c b/tools/virtiofsd/passthrough_ll.c
index 1553d2ef45..cdd224918c 100644
--- a/tools/virtiofsd/passthrough_ll.c
+++ b/tools/virtiofsd/passthrough_ll.c
@@ -3558,10 +3558,6 @@  static void setup_nofile_rlimit(unsigned long rlimit_nofile)
 static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
 {
     g_autofree char *localfmt = NULL;
-    struct timespec ts;
-    struct tm tm;
-    char sec_fmt[sizeof "2020-12-07 18:17:54"];
-    char zone_fmt[sizeof "+0100"];
 
     if (current_log_level < level) {
         return;
@@ -3573,23 +3569,10 @@  static void log_func(enum fuse_log_level level, const char *fmt, va_list ap)
             localfmt = g_strdup_printf("[ID: %08ld] %s", syscall(__NR_gettid),
                                        fmt);
         } else {
-            /* try formatting a broken-down timestamp */
-            if (clock_gettime(CLOCK_REALTIME, &ts) != -1 &&
-                localtime_r(&ts.tv_sec, &tm) != NULL &&
-                strftime(sec_fmt, sizeof sec_fmt, "%Y-%m-%d %H:%M:%S",
-                         &tm) != 0 &&
-                strftime(zone_fmt, sizeof zone_fmt, "%z", &tm) != 0) {
-                localfmt = g_strdup_printf("[%s.%02ld%s] [ID: %08ld] %s",
-                                           sec_fmt,
-                                           ts.tv_nsec / (10L * 1000 * 1000),
-                                           zone_fmt, syscall(__NR_gettid),
-                                           fmt);
-            } else {
-                /* fall back to a flat timestamp */
-                localfmt = g_strdup_printf("[%" PRId64 "] [ID: %08ld] %s",
-                                           get_clock(), syscall(__NR_gettid),
-                                           fmt);
-            }
+            g_autoptr(GDateTime) now = g_date_time_new_now_local();
+            g_autofree char *nowstr = g_date_time_format(now, "%Y-%m-%d %H:%M:%S.%f%z");
+            localfmt = g_strdup_printf("[%s] [ID: %08ld] %s",
+                                       nowstr, syscall(__NR_gettid), fmt);
         }
         fmt = localfmt;
     }