[libvirt] [PATCH 1/2] logging: Do not log timestamp through syslog

Daniel P. Berrange berrange at redhat.com
Thu Sep 29 07:58:08 UTC 2011


On Thu, Sep 29, 2011 at 09:05:59AM +0800, Daniel Veillard wrote:
> On Wed, Sep 28, 2011 at 04:46:11PM +0200, Jiri Denemark wrote:
> > Syslog puts the timestamp to every message anyway so this removes
> > redundant data.
> > ---
> >  src/util/logging.c |  121 +++++++++++++++++++++++++++++++--------------------
> >  src/util/logging.h |    9 ++--
> >  2 files changed, 78 insertions(+), 52 deletions(-)
> > 
> > diff --git a/src/util/logging.c b/src/util/logging.c
> > index a638510..4ffaf75 100644
> > --- a/src/util/logging.c
> > +++ b/src/util/logging.c
> > @@ -98,7 +98,8 @@ static int virLogResetFilters(void);
> >  static int virLogResetOutputs(void);
> >  static int virLogOutputToFd(const char *category, int priority,
> >                              const char *funcname, long long linenr,
> > -                            const char *str, int len, void *data);
> > +                            const char *timestamp, const char *str,
> > +                            void *data);
> >  
> >  /*
> >   * Logs accesses must be serialized though a mutex
> > @@ -282,16 +283,16 @@ void virLogShutdown(void) {
> >  /*
> >   * Store a string in the ring buffer
> >   */
> > -static void virLogStr(const char *str, int len) {
> > +static void virLogStr(const char *str)
> > +{
> >      int tmp;
> > +    int len;
> >  
> >      if ((str == NULL) || (virLogBuffer == NULL) || (virLogSize <= 0))
> >          return;
> > -    if (len <= 0)
> > -        len = strlen(str);
> > +    len = strlen(str);
> >      if (len >= virLogSize)
> >          return;
> > -    virLogLock();
> >  
> >      /*
> >       * copy the data and reset the end, we cycle over the end of the buffer
> > @@ -317,7 +318,6 @@ static void virLogStr(const char *str, int len) {
> >          if (virLogStart >= virLogSize)
> >              virLogStart -= virLogSize;
> >      }
> > -    virLogUnlock();
> >  }
> >  
> >  static void virLogDumpAllFD(const char *msg, int len) {
> > @@ -618,12 +618,28 @@ cleanup:
> >      return ret;
> >  }
> >  
> > +static char *
> > +virLogFormatTimestamp(void)
> > +{
> > +    struct timeval cur_time;
> > +    struct tm time_info;
> > +    char *str = NULL;
> > +
> > +    gettimeofday(&cur_time, NULL);
> > +    localtime_r(&cur_time.tv_sec, &time_info);
> > +
> > +    if (virAsprintf(&str, "%02d:%02d:%02d.%03d",
> > +                    time_info.tm_hour, time_info.tm_min, time_info.tm_sec,
> > +                    (int) (cur_time.tv_usec / 1000)) < 0)
> > +        return NULL;
> > +
> > +    return str;
> > +}
> > +
> >  static int
> >  virLogFormatString(char **msg,
> >                     const char *funcname,
> >                     long long linenr,
> > -                   struct tm *time_info,
> > -                   struct timeval *cur_time,
> >                     int priority,
> >                     const char *str)
> >  {
> > @@ -637,25 +653,19 @@ virLogFormatString(char **msg,
> >       * to just grep for it to find the right place.
> >       */
> >      if ((funcname != NULL)) {
> > -        ret = virAsprintf(msg, "%02d:%02d:%02d.%03d: %d: %s : %s:%lld : %s\n",
> > -                          time_info->tm_hour, time_info->tm_min,
> > -                          time_info->tm_sec, (int) cur_time->tv_usec / 1000,
> > -                          virThreadSelfID(),
> > -                          virLogPriorityString(priority), funcname, linenr, str);
> > +        ret = virAsprintf(msg, "%d: %s : %s:%lld : %s\n",
> > +                          virThreadSelfID(), virLogPriorityString(priority),
> > +                          funcname, linenr, str);
> >      } else {
> > -        ret = virAsprintf(msg, "%02d:%02d:%02d.%03d: %d: %s : %s\n",
> > -                          time_info->tm_hour, time_info->tm_min,
> > -                          time_info->tm_sec, (int) cur_time->tv_usec / 1000,
> > -                          virThreadSelfID(),
> > -                          virLogPriorityString(priority), str);
> > +        ret = virAsprintf(msg, "%d: %s : %s\n",
> > +                          virThreadSelfID(), virLogPriorityString(priority),
> > +                          str);
> >      }
> >      return ret;
> >  }
> >  
> >  static int
> > -virLogVersionString(char **msg,
> > -                    struct tm *time_info,
> > -                    struct timeval *cur_time)
> > +virLogVersionString(char **msg)
> >  {
> >  #ifdef PACKAGER_VERSION
> >  # ifdef PACKAGER
> > @@ -670,9 +680,7 @@ virLogVersionString(char **msg,
> >      "libvirt version: " VERSION
> >  #endif
> >  
> > -    return virLogFormatString(msg, NULL, 0,
> > -                              time_info, cur_time,
> > -                              VIR_LOG_INFO, LOG_VERSION_STRING);
> > +    return virLogFormatString(msg, NULL, 0, VIR_LOG_INFO, LOG_VERSION_STRING);
> >  }
> >  
> >  /**
> > @@ -694,9 +702,8 @@ void virLogMessage(const char *category, int priority, const char *funcname,
> >      static bool logVersionStderr = true;
> >      char *str = NULL;
> >      char *msg = NULL;
> > -    struct timeval cur_time;
> > -    struct tm time_info;
> > -    int len, fprio, i, ret;
> > +    char *timestamp = NULL;
> > +    int fprio, i, ret;
> >      int saved_errno = errno;
> >      int emit = 1;
> >      va_list ap;
> > @@ -730,16 +737,15 @@ void virLogMessage(const char *category, int priority, const char *funcname,
> >          goto cleanup;
> >      }
> >      va_end(ap);
> > -    gettimeofday(&cur_time, NULL);
> > -    localtime_r(&cur_time.tv_sec, &time_info);
> >  
> > -    ret = virLogFormatString(&msg, funcname, linenr,
> > -                             &time_info, &cur_time,
> > -                             priority, str);
> > +    ret = virLogFormatString(&msg, funcname, linenr, priority, str);
> >      VIR_FREE(str);
> >      if (ret < 0)
> >          goto cleanup;
> >  
> > +    if (!(timestamp = virLogFormatTimestamp()))
> > +        goto cleanup;
> > +
> >      /*
> >       * Log based on defaults, first store in the history buffer,
> >       * then if emit push the message on the outputs defined, if none
> > @@ -748,42 +754,49 @@ void virLogMessage(const char *category, int priority, const char *funcname,
> >       *       threads, but avoid intermixing. Maybe set up locks per output
> >       *       to improve paralellism.
> >       */
> > -    len = strlen(msg);
> > -    virLogStr(msg, len);
> > +    virLogLock();
> > +    virLogStr(timestamp);
> > +    virLogStr(msg);
> > +    virLogUnlock();
> 
>   Hum, I'm not sure I like that, I think virLogStr ends up doing a
> synchronous write, and if that's the case we are doing 2 costly
> operations instead of one. I really prefer we merge the strings in
> memory before calling virLogStr()

I think you might be mixing up virLogStr() with a different method.
virLogStr() merely memcpy()'s the data into the ring buffer.

Regards,
Daniel
-- 
|: http://berrange.com      -o-    http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org              -o-             http://virt-manager.org :|
|: http://autobuild.org       -o-         http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org       -o-       http://live.gnome.org/gtk-vnc :|




More information about the libvir-list mailing list