On Thu, Sep 29, 2011 at 08:58:08AM +0100, Daniel P. Berrange wrote:
> 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.
Ah right, my bad, objection removed !
Worse is that I wrote that routine mostly, I will blame the old age :-)
It's virLogMessage() which (eventually) ends up writing to the log
outputs...
Daniel
--
Daniel Veillard | libxml Gnome XML XSLT toolkit http://xmlsoft.org/
daniel@xxxxxxxxxxxx | Rpmfind RPM search engine http://rpmfind.net/
http://veillard.com/ | virtualization library http://libvirt.org/
--
libvir-list mailing list
libvir-list@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/libvir-list