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 :|
--
libvir-list mailing list
libvir-list@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/libvir-list