[libvirt] [PATCH 0/9] Use the systemd journal for logging
The systemd journal provides a highly efficient way for apps to generate structured log messages. Since systemd will be used by default on future Fedora/RHEL distros (and likely many others), we should take advantage of the journal out of the box for improved logging capabilities. Amongst other things, this allows very easy browsing of the libvirt logs after the fact, filtering on filename / line number / function name and more. This is a big benefit to debugging, compared to current case where we need to decide the filters when starting libvirtd. For example it becomes possible to configure libvirt to include all QEMU logging, and then later ask the journal for only messages related to the QEMU json monitor.
From: "Daniel P. Berrange" <berrange@redhat.com> The log priority levels are an enum, but most of the code was just using a plain 'int' for function params / variables. Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 34 +++++++++++++++++----------------- src/util/logging.h | 14 +++++++------- 2 files changed, 24 insertions(+), 24 deletions(-) diff --git a/src/util/logging.c b/src/util/logging.c index ae11267..4222b92 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -63,7 +63,7 @@ static int virLogEnd = 0; */ struct _virLogFilter { const char *match; - int priority; + virLogPriority priority; unsigned int flags; }; typedef struct _virLogFilter virLogFilter; @@ -81,7 +81,7 @@ struct _virLogOutput { void *data; virLogOutputFunc f; virLogCloseFunc c; - int priority; + virLogPriority priority; virLogDestination dest; const char *name; }; @@ -98,7 +98,7 @@ static virLogPriority virLogDefaultPriority = VIR_LOG_DEFAULT; static int virLogResetFilters(void); static int virLogResetOutputs(void); -static void virLogOutputToFd(const char *category, int priority, +static void virLogOutputToFd(const char *category, virLogPriority priority, const char *funcname, long long linenr, const char *timestamp, unsigned int flags, @@ -418,7 +418,7 @@ virLogEmergencyDumpAll(int signum) { * * Returns 0 if successful, -1 in case of error. */ -int virLogSetDefaultPriority(int priority) { +int virLogSetDefaultPriority(virLogPriority priority) { if ((priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) { VIR_WARN("Ignoring invalid log level setting."); return -1; @@ -460,7 +460,7 @@ static int virLogResetFilters(void) { * * Returns -1 in case of failure or the filter number if successful */ -int virLogDefineFilter(const char *match, int priority, +int virLogDefineFilter(const char *match, virLogPriority priority, unsigned int flags) { int i; @@ -564,7 +564,7 @@ static int virLogResetOutputs(void) { * Returns -1 in case of failure or the output number if successful */ int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, - int priority, int dest, const char *name, + virLogPriority priority, int dest, const char *name, unsigned int flags) { int ret = -1; @@ -606,7 +606,7 @@ static int virLogFormatString(char **msg, const char *funcname, long long linenr, - int priority, + virLogPriority priority, const char *str) { int ret; @@ -663,7 +663,7 @@ virLogVersionString(const char **rawmsg, char **msg) * Call the libvirt logger with some information. Based on the configuration * the message may be stored, sent to output or just discarded */ -void virLogMessage(const char *category, int priority, const char *funcname, +void virLogMessage(const char *category, virLogPriority priority, const char *funcname, long long linenr, unsigned int flags, const char *fmt, ...) { va_list ap; @@ -685,7 +685,7 @@ void virLogMessage(const char *category, int priority, const char *funcname, * Call the libvirt logger with some information. Based on the configuration * the message may be stored, sent to output or just discarded */ -void virLogVMessage(const char *category, int priority, const char *funcname, +void virLogVMessage(const char *category, virLogPriority priority, const char *funcname, long long linenr, unsigned int flags, const char *fmt, va_list vargs) { @@ -811,7 +811,7 @@ static void virLogStackTraceToFd(int fd) } static void virLogOutputToFd(const char *category ATTRIBUTE_UNUSED, - int priority ATTRIBUTE_UNUSED, + virLogPriority priority ATTRIBUTE_UNUSED, const char *funcname ATTRIBUTE_UNUSED, long long linenr ATTRIBUTE_UNUSED, const char *timestamp, @@ -843,14 +843,14 @@ static void virLogCloseFd(void *data) VIR_LOG_CLOSE(fd); } -static int virLogAddOutputToStderr(int priority) { +static int virLogAddOutputToStderr(virLogPriority priority) { if (virLogDefineOutput(virLogOutputToFd, NULL, (void *)2L, priority, VIR_LOG_TO_STDERR, NULL, 0) < 0) return -1; return 0; } -static int virLogAddOutputToFile(int priority, const char *file) { +static int virLogAddOutputToFile(virLogPriority priority, const char *file) { int fd; fd = open(file, O_CREAT | O_APPEND | O_WRONLY, S_IRUSR | S_IWUSR); @@ -883,7 +883,7 @@ static int virLogPrioritySyslog(virLogPriority priority) } static void virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED, - int priority, + virLogPriority priority, const char *funcname ATTRIBUTE_UNUSED, long long linenr ATTRIBUTE_UNUSED, const char *timestamp ATTRIBUTE_UNUSED, @@ -904,7 +904,7 @@ static void virLogCloseSyslog(void *data ATTRIBUTE_UNUSED) { VIR_FREE(current_ident); } -static int virLogAddOutputToSyslog(int priority, const char *ident) { +static int virLogAddOutputToSyslog(virLogPriority priority, const char *ident) { /* * ident needs to be kept around on Solaris */ @@ -955,7 +955,7 @@ int virLogParseOutputs(const char *outputs) { const char *cur = outputs, *str; char *name; char *abspath; - int prio; + virLogPriority prio; int ret = -1; int count = 0; @@ -1046,7 +1046,7 @@ cleanup: int virLogParseFilters(const char *filters) { const char *cur = filters, *str; char *name; - int prio; + virLogPriority prio; int ret = -1; int count = 0; @@ -1091,7 +1091,7 @@ cleanup: * * Returns the current logging priority level. */ -int virLogGetDefaultPriority(void) { +virLogPriority virLogGetDefaultPriority(void) { return virLogDefaultPriority; } diff --git a/src/util/logging.h b/src/util/logging.h index 584e2b4..88fb785 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -96,7 +96,7 @@ typedef enum { * * Callback function used to output messages */ -typedef void (*virLogOutputFunc) (const char *category, int priority, +typedef void (*virLogOutputFunc) (const char *category, virLogPriority priority, const char *funcname, long long linenr, const char *timestamp, unsigned int flags, @@ -119,13 +119,13 @@ extern int virLogGetNbFilters(void); extern int virLogGetNbOutputs(void); extern char *virLogGetFilters(void); extern char *virLogGetOutputs(void); -extern int virLogGetDefaultPriority(void); -extern int virLogSetDefaultPriority(int priority); +extern virLogPriority virLogGetDefaultPriority(void); +extern int virLogSetDefaultPriority(virLogPriority priority); extern void virLogSetFromEnv(void); -extern int virLogDefineFilter(const char *match, int priority, +extern int virLogDefineFilter(const char *match, virLogPriority priority, unsigned int flags); extern int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, - int priority, int dest, const char *name, + virLogPriority priority, int dest, const char *name, unsigned int flags); /* @@ -138,11 +138,11 @@ extern int virLogReset(void); extern int virLogParseDefaultPriority(const char *priority); extern int virLogParseFilters(const char *filters); extern int virLogParseOutputs(const char *output); -extern void virLogMessage(const char *category, int priority, +extern void virLogMessage(const char *category, virLogPriority priority, const char *funcname, long long linenr, unsigned int flags, const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(6, 7); -extern void virLogVMessage(const char *category, int priority, +extern void virLogVMessage(const char *category, virLogPriority priority, const char *funcname, long long linenr, unsigned int flags, const char *fmt, -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
The log priority levels are an enum, but most of the code was just using a plain 'int' for function params / variables.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 34 +++++++++++++++++----------------- src/util/logging.h | 14 +++++++------- 2 files changed, 24 insertions(+), 24 deletions(-)
ACK. Fairly straight-forward. -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On 09/27/2012 12:18 PM, Eric Blake wrote:
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
The log priority levels are an enum, but most of the code was just using a plain 'int' for function params / variables.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 34 +++++++++++++++++----------------- src/util/logging.h | 14 +++++++------- 2 files changed, 24 insertions(+), 24 deletions(-)
ACK. Fairly straight-forward.
Spoke too soon; I got a test failure: testutils.c: In function 'virtTestMain': testutils.c:613:32: error: passing argument 1 of 'virLogDefineOutput' from incompatible pointer type [-Werror] In file included from testutils.c:47:0: ../src/util/logging.h:127:12: note: expected 'virLogOutputFunc' but argument is of type 'void (*)(const char *, int, const char *, long long int, const char *, unsigned int, const char *, const char *, void *)' Squash this in: diff --git i/tests/testutils.c w/tests/testutils.c index a33b10d..86be3f5 100644 --- i/tests/testutils.c +++ w/tests/testutils.c @@ -481,7 +481,7 @@ static struct virtTestLogData testLog = { VIR_BUFFER_INITIALIZER }; static void virtTestLogOutput(const char *category ATTRIBUTE_UNUSED, - int priority ATTRIBUTE_UNUSED, + virLogPriority priority ATTRIBUTE_UNUSED, const char *funcname ATTRIBUTE_UNUSED, long long lineno ATTRIBUTE_UNUSED, const char *timestamp, @@ -610,7 +610,7 @@ int virtTestMain(int argc, virLogSetFromEnv(); if (!getenv("LIBVIRT_DEBUG") && !virLogGetNbOutputs()) { if (virLogDefineOutput(virtTestLogOutput, virtTestLogClose, &testLog, - 0, 0, NULL, 0) < 0) + VIR_LOG_DEBUG, 0, NULL, 0) < 0) return 1; } -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
From: "Daniel P. Berrange" <berrange@redhat.com> The __LINE__ macro value is specified to fit in the size_t type, so use that instead of 'long long' in the logging code Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 14 +++++++------- src/util/logging.h | 6 +++--- 2 files changed, 10 insertions(+), 10 deletions(-) diff --git a/src/util/logging.c b/src/util/logging.c index 4222b92..f47b98f 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -99,7 +99,7 @@ static virLogPriority virLogDefaultPriority = VIR_LOG_DEFAULT; static int virLogResetFilters(void); static int virLogResetOutputs(void); static void virLogOutputToFd(const char *category, virLogPriority priority, - const char *funcname, long long linenr, + const char *funcname, size_t linenr, const char *timestamp, unsigned int flags, const char *rawstr, const char *str, @@ -605,7 +605,7 @@ cleanup: static int virLogFormatString(char **msg, const char *funcname, - long long linenr, + size_t linenr, virLogPriority priority, const char *str) { @@ -619,7 +619,7 @@ virLogFormatString(char **msg, * to just grep for it to find the right place. */ if ((funcname != NULL)) { - ret = virAsprintf(msg, "%d: %s : %s:%lld : %s\n", + ret = virAsprintf(msg, "%d: %s : %s:%zu : %s\n", virThreadSelfID(), virLogPriorityString(priority), funcname, linenr, str); } else { @@ -664,7 +664,7 @@ virLogVersionString(const char **rawmsg, char **msg) * the message may be stored, sent to output or just discarded */ void virLogMessage(const char *category, virLogPriority priority, const char *funcname, - long long linenr, unsigned int flags, const char *fmt, ...) + size_t linenr, unsigned int flags, const char *fmt, ...) { va_list ap; va_start(ap, fmt); @@ -686,7 +686,7 @@ void virLogMessage(const char *category, virLogPriority priority, const char *fu * the message may be stored, sent to output or just discarded */ void virLogVMessage(const char *category, virLogPriority priority, const char *funcname, - long long linenr, unsigned int flags, const char *fmt, + size_t linenr, unsigned int flags, const char *fmt, va_list vargs) { static bool logVersionStderr = true; @@ -813,7 +813,7 @@ static void virLogStackTraceToFd(int fd) static void virLogOutputToFd(const char *category ATTRIBUTE_UNUSED, virLogPriority priority ATTRIBUTE_UNUSED, const char *funcname ATTRIBUTE_UNUSED, - long long linenr ATTRIBUTE_UNUSED, + size_t linenr ATTRIBUTE_UNUSED, const char *timestamp, unsigned int flags, const char *rawstr ATTRIBUTE_UNUSED, @@ -885,7 +885,7 @@ static int virLogPrioritySyslog(virLogPriority priority) static void virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED, virLogPriority priority, const char *funcname ATTRIBUTE_UNUSED, - long long linenr ATTRIBUTE_UNUSED, + size_t linenr ATTRIBUTE_UNUSED, const char *timestamp ATTRIBUTE_UNUSED, unsigned int flags, const char *rawstr ATTRIBUTE_UNUSED, diff --git a/src/util/logging.h b/src/util/logging.h index 88fb785..32d14a8 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -97,7 +97,7 @@ typedef enum { * Callback function used to output messages */ typedef void (*virLogOutputFunc) (const char *category, virLogPriority priority, - const char *funcname, long long linenr, + const char *funcname, size_t linenr, const char *timestamp, unsigned int flags, const char *rawstr, const char *str, @@ -139,11 +139,11 @@ extern int virLogParseDefaultPriority(const char *priority); extern int virLogParseFilters(const char *filters); extern int virLogParseOutputs(const char *output); extern void virLogMessage(const char *category, virLogPriority priority, - const char *funcname, long long linenr, + const char *funcname, size_t linenr, unsigned int flags, const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(6, 7); extern void virLogVMessage(const char *category, virLogPriority priority, - const char *funcname, long long linenr, + const char *funcname, size_t linenr, unsigned int flags, const char *fmt, va_list vargs) ATTRIBUTE_FMT_PRINTF(6, 0); -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
The __LINE__ macro value is specified to fit in the size_t
Not quite accurate. C99 merely says: 6.10.4 p3: ... a line number as specified by the digit sequence (interpreted as a decimal integer). The digit sequence shall not specify zero, nor a number greater than 2147483647. 6.10.8 p1: _ _LINE_ _ The presumed line number (within the current source file) of the current source line (an integer constant). So in fact, __LINE__ is guaranteed to fit within a 32-bit signed integer, and you could s/size_t/int/ with no loss in functionality since we don't port to 16-bit 'int' platforms. That said, I'm not too fussed with things; size_t is definitely better than 'long long', so I'm okay even if you don't further relax to 'int'.
type, so use that instead of 'long long' in the logging code
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 14 +++++++------- src/util/logging.h | 6 +++--- 2 files changed, 10 insertions(+), 10 deletions(-)
Again, testing failed: testutils.c: In function 'virtTestMain': testutils.c:613:32: error: passing argument 1 of 'virLogDefineOutput' from incompatible pointer type [-Werror] In file included from testutils.c:47:0: ../src/util/logging.h:127:12: note: expected 'virLogOutputFunc' but argument is of type 'void (*)(const char *, enum virLogPriority, const char *, long long int, const char *, unsigned int, const char *, const char *, void *)' cc1: all warnings being treated as errors ACK with this squashed in (or the obvious change if you go all the way to int): diff --git i/tests/testutils.c w/tests/testutils.c index 86be3f5..a85f560 100644 --- i/tests/testutils.c +++ w/tests/testutils.c @@ -483,7 +483,7 @@ static void virtTestLogOutput(const char *category ATTRIBUTE_UNUSED, virLogPriority priority ATTRIBUTE_UNUSED, const char *funcname ATTRIBUTE_UNUSED, - long long lineno ATTRIBUTE_UNUSED, + size_t lineno ATTRIBUTE_UNUSED, const char *timestamp, unsigned int flags, const char *rawstr ATTRIBUTE_UNUSED, -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On Thu, Sep 27, 2012 at 01:05:55PM -0600, Eric Blake wrote:
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
The __LINE__ macro value is specified to fit in the size_t
Not quite accurate. C99 merely says:
6.10.4 p3: ... a line number as specified by the digit sequence (interpreted as a decimal integer). The digit sequence shall not specify zero, nor a number greater than 2147483647.
6.10.8 p1: _ _LINE_ _ The presumed line number (within the current source file) of the current source line (an integer constant).
So in fact, __LINE__ is guaranteed to fit within a 32-bit signed integer, and you could s/size_t/int/ with no loss in functionality since we don't port to 16-bit 'int' platforms. That said, I'm not too fussed with things; size_t is definitely better than 'long long', so I'm okay even if you don't further relax to 'int'.
Based on discussion in the later patches, I'm happy to change this to just 'int'. Still surprised it wasn't actually size_t in the standard, but oh well. 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 :|
From: "Daniel P. Berrange" <berrange@redhat.com> The log destinations are an enum, but most of the code was just using a plain 'int' for function params / variables. Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 4 ++-- src/util/logging.h | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/src/util/logging.c b/src/util/logging.c index f47b98f..d8c9b75 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -564,7 +564,7 @@ static int virLogResetOutputs(void) { * Returns -1 in case of failure or the output number if successful */ int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, - virLogPriority priority, int dest, const char *name, + virLogPriority priority, virLogDestination dest, const char *name, unsigned int flags) { int ret = -1; @@ -1139,7 +1139,7 @@ char *virLogGetOutputs(void) { virLogLock(); for (i = 0; i < virLogNbOutputs; i++) { - int dest = virLogOutputs[i].dest; + virLogDestination dest = virLogOutputs[i].dest; if (i) virBufferAsprintf(&outputbuf, " "); switch (dest) { diff --git a/src/util/logging.h b/src/util/logging.h index 32d14a8..2d500a4 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -125,7 +125,7 @@ extern void virLogSetFromEnv(void); extern int virLogDefineFilter(const char *match, virLogPriority priority, unsigned int flags); extern int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, - virLogPriority priority, int dest, const char *name, + virLogPriority priority, virLogDestination dest, const char *name, unsigned int flags); /* -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
The log destinations are an enum, but most of the code was just using a plain 'int' for function params / variables.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 4 ++-- src/util/logging.h | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-)
ACK. This time, no testsuite failure, but I'd still suggest squashing this in before pushing, since '0' is not a valid virLogDestination: diff --git i/tests/testutils.c w/tests/testutils.c index a85f560..e144d33 100644 --- i/tests/testutils.c +++ w/tests/testutils.c @@ -610,7 +610,7 @@ int virtTestMain(int argc, virLogSetFromEnv(); if (!getenv("LIBVIRT_DEBUG") && !virLogGetNbOutputs()) { if (virLogDefineOutput(virtTestLogOutput, virtTestLogClose, &testLog, - VIR_LOG_DEBUG, 0, NULL, 0) < 0) + VIR_LOG_DEBUG, VIR_LOG_TO_STDERR, NULL, 0) < 0) return 1; } -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
From: "Daniel P. Berrange" <berrange@redhat.com> General whitespace cleanup in the logging files - Move '{' to a new line after funtion declaration - Put each parameter on a new line to avoid long lines - Put return type on new line - Leave 2 blank lines between functions Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 239 +++++++++++++++++++++++++++++++++++++++-------------- src/util/logging.h | 32 ++++--- 2 files changed, 197 insertions(+), 74 deletions(-) diff --git a/src/util/logging.c b/src/util/logging.c index d8c9b75..5b29646 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -98,11 +98,14 @@ static virLogPriority virLogDefaultPriority = VIR_LOG_DEFAULT; static int virLogResetFilters(void); static int virLogResetOutputs(void); -static void virLogOutputToFd(const char *category, virLogPriority priority, - const char *funcname, size_t linenr, +static void virLogOutputToFd(const char *category, + virLogPriority priority, + const char *funcname, + size_t linenr, const char *timestamp, unsigned int flags, - const char *rawstr, const char *str, + const char *rawstr, + const char *str, void *data); /* @@ -110,16 +113,23 @@ static void virLogOutputToFd(const char *category, virLogPriority priority, */ virMutex virLogMutex; -void virLogLock(void) +void +virLogLock(void) { virMutexLock(&virLogMutex); } -void virLogUnlock(void) + + +void +virLogUnlock(void) { virMutexUnlock(&virLogMutex); } -static const char *virLogOutputString(virLogDestination ldest) { + +static const char * +virLogOutputString(virLogDestination ldest) +{ switch (ldest) { case VIR_LOG_TO_STDERR: return "stderr"; @@ -131,7 +141,10 @@ static const char *virLogOutputString(virLogDestination ldest) { return "unknown"; } -static const char *virLogPriorityString(virLogPriority lvl) { + +static const char * +virLogPriorityString(virLogPriority lvl) +{ switch (lvl) { case VIR_LOG_DEBUG: return "debug"; @@ -146,7 +159,8 @@ static const char *virLogPriorityString(virLogPriority lvl) { } -static int virLogOnceInit(void) +static int +virLogOnceInit(void) { const char *pbm = NULL; @@ -180,6 +194,7 @@ static int virLogOnceInit(void) VIR_ONCE_GLOBAL_INIT(virLog) + /** * virLogSetBufferSize: * @size: size of the buffer in kilobytes or <= 0 to deactivate @@ -190,8 +205,9 @@ VIR_ONCE_GLOBAL_INIT(virLog) * * Return -1 in case of failure or 0 in case of success */ -extern int -virLogSetBufferSize(int size) { +int +virLogSetBufferSize(int size) +{ int ret = 0; int oldsize; char *oldLogBuffer; @@ -237,6 +253,7 @@ error: return ret; } + /** * virLogReset: * @@ -244,7 +261,9 @@ error: * * Returns 0 if successful, and -1 in case or error */ -int virLogReset(void) { +int +virLogReset(void) +{ if (virLogInitialize() < 0) return -1; @@ -259,10 +278,12 @@ int virLogReset(void) { return 0; } + /* * Store a string in the ring buffer */ -static void virLogStr(const char *str) +static void +virLogStr(const char *str) { int tmp; int len; @@ -299,7 +320,10 @@ static void virLogStr(const char *str) } } -static void virLogDumpAllFD(const char *msg, int len) { + +static void +virLogDumpAllFD(const char *msg, int len) +{ int i, found = 0; if (len <= 0) @@ -319,6 +343,7 @@ static void virLogDumpAllFD(const char *msg, int len) { ignore_value (safewrite(STDERR_FILENO, msg, len)); } + /** * virLogEmergencyDumpAll: * @signum: the signal number @@ -329,7 +354,8 @@ static void virLogDumpAllFD(const char *msg, int len) { * In case none is found it is emitted to standard error. */ void -virLogEmergencyDumpAll(int signum) { +virLogEmergencyDumpAll(int signum) +{ int len; int oldLogStart, oldLogLen; @@ -408,6 +434,7 @@ virLogEmergencyDumpAll(int signum) { virLogDumpAllFD("\n\n ====== end of log =====\n\n", -1); } + /** * virLogSetDefaultPriority: * @priority: the default priority level @@ -418,7 +445,9 @@ virLogEmergencyDumpAll(int signum) { * * Returns 0 if successful, -1 in case of error. */ -int virLogSetDefaultPriority(virLogPriority priority) { +int +virLogSetDefaultPriority(virLogPriority priority) +{ if ((priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) { VIR_WARN("Ignoring invalid log level setting."); return -1; @@ -430,6 +459,7 @@ int virLogSetDefaultPriority(virLogPriority priority) { return 0; } + /** * virLogResetFilters: * @@ -437,7 +467,9 @@ int virLogSetDefaultPriority(virLogPriority priority) { * * Returns the number of filters removed */ -static int virLogResetFilters(void) { +static int +virLogResetFilters(void) +{ int i; for (i = 0; i < virLogNbFilters;i++) @@ -447,6 +479,7 @@ static int virLogResetFilters(void) { return i; } + /** * virLogDefineFilter: * @match: the pattern to match @@ -460,8 +493,10 @@ static int virLogResetFilters(void) { * * Returns -1 in case of failure or the filter number if successful */ -int virLogDefineFilter(const char *match, virLogPriority priority, - unsigned int flags) +int +virLogDefineFilter(const char *match, + virLogPriority priority, + unsigned int flags) { int i; char *mdup = NULL; @@ -500,6 +535,7 @@ cleanup: return i; } + /** * virLogFiltersCheck: * @input: the input string @@ -510,8 +546,10 @@ cleanup: * * Returns 0 if not matched or the new priority if found. */ -static int virLogFiltersCheck(const char *input, - unsigned int *flags) { +static int +virLogFiltersCheck(const char *input, + unsigned int *flags) +{ int ret = 0; int i; @@ -527,6 +565,7 @@ static int virLogFiltersCheck(const char *input, return ret; } + /** * virLogResetOutputs: * @@ -534,7 +573,9 @@ static int virLogFiltersCheck(const char *input, * * Returns the number of output removed */ -static int virLogResetOutputs(void) { +static int +virLogResetOutputs(void) +{ int i; for (i = 0;i < virLogNbOutputs;i++) { @@ -548,6 +589,7 @@ static int virLogResetOutputs(void) { return i; } + /** * virLogDefineOutput: * @f: the function to call to output a message @@ -563,9 +605,14 @@ static int virLogResetOutputs(void) { * * Returns -1 in case of failure or the output number if successful */ -int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, - virLogPriority priority, virLogDestination dest, const char *name, - unsigned int flags) +int +virLogDefineOutput(virLogOutputFunc f, + virLogCloseFunc c, + void *data, + virLogPriority priority, + virLogDestination dest, + const char *name, + unsigned int flags) { int ret = -1; char *ndup = NULL; @@ -630,8 +677,10 @@ virLogFormatString(char **msg, return ret; } + static int -virLogVersionString(const char **rawmsg, char **msg) +virLogVersionString(const char **rawmsg, + char **msg) { #ifdef PACKAGER_VERSION # ifdef PACKAGER @@ -650,6 +699,7 @@ virLogVersionString(const char **rawmsg, char **msg) return virLogFormatString(msg, NULL, 0, VIR_LOG_INFO, LOG_VERSION_STRING); } + /** * virLogMessage: * @category: where is that message coming from @@ -663,8 +713,13 @@ virLogVersionString(const char **rawmsg, char **msg) * Call the libvirt logger with some information. Based on the configuration * the message may be stored, sent to output or just discarded */ -void virLogMessage(const char *category, virLogPriority priority, const char *funcname, - size_t linenr, unsigned int flags, const char *fmt, ...) +void +virLogMessage(const char *category, + virLogPriority priority, + const char *funcname, + size_t linenr, + unsigned int flags, + const char *fmt, ...) { va_list ap; va_start(ap, fmt); @@ -672,6 +727,7 @@ void virLogMessage(const char *category, virLogPriority priority, const char *fu va_end(ap); } + /** * virLogVMessage: * @category: where is that message coming from @@ -685,9 +741,14 @@ void virLogMessage(const char *category, virLogPriority priority, const char *fu * Call the libvirt logger with some information. Based on the configuration * the message may be stored, sent to output or just discarded */ -void virLogVMessage(const char *category, virLogPriority priority, const char *funcname, - size_t linenr, unsigned int flags, const char *fmt, - va_list vargs) +void +virLogVMessage(const char *category, + virLogPriority priority, + const char *funcname, + size_t linenr, + unsigned int flags, + const char *fmt, + va_list vargs) { static bool logVersionStderr = true; char *str = NULL; @@ -791,7 +852,8 @@ cleanup: } -static void virLogStackTraceToFd(int fd) +static void +virLogStackTraceToFd(int fd) { void *array[100]; int size; @@ -810,15 +872,17 @@ static void virLogStackTraceToFd(int fd) #undef STRIP_DEPTH } -static void virLogOutputToFd(const char *category ATTRIBUTE_UNUSED, - virLogPriority priority ATTRIBUTE_UNUSED, - const char *funcname ATTRIBUTE_UNUSED, - size_t linenr ATTRIBUTE_UNUSED, - const char *timestamp, - unsigned int flags, - const char *rawstr ATTRIBUTE_UNUSED, - const char *str, - void *data) + +static void +virLogOutputToFd(const char *category ATTRIBUTE_UNUSED, + virLogPriority priority ATTRIBUTE_UNUSED, + const char *funcname ATTRIBUTE_UNUSED, + size_t linenr ATTRIBUTE_UNUSED, + const char *timestamp, + unsigned int flags, + const char *rawstr ATTRIBUTE_UNUSED, + const char *str, + void *data) { int fd = (intptr_t) data; char *msg; @@ -836,21 +900,30 @@ static void virLogOutputToFd(const char *category ATTRIBUTE_UNUSED, virLogStackTraceToFd(fd); } -static void virLogCloseFd(void *data) + +static void +virLogCloseFd(void *data) { int fd = (intptr_t) data; VIR_LOG_CLOSE(fd); } -static int virLogAddOutputToStderr(virLogPriority priority) { + +static int +virLogAddOutputToStderr(virLogPriority priority) +{ if (virLogDefineOutput(virLogOutputToFd, NULL, (void *)2L, priority, VIR_LOG_TO_STDERR, NULL, 0) < 0) return -1; return 0; } -static int virLogAddOutputToFile(virLogPriority priority, const char *file) { + +static int +virLogAddOutputToFile(virLogPriority priority, + const char *file) +{ int fd; fd = open(file, O_CREAT | O_APPEND | O_WRONLY, S_IRUSR | S_IWUSR); @@ -865,8 +938,10 @@ static int virLogAddOutputToFile(virLogPriority priority, const char *file) { return 0; } + #if HAVE_SYSLOG_H -static int virLogPrioritySyslog(virLogPriority priority) +static int +virLogPrioritySyslog(virLogPriority priority) { switch (priority) { case VIR_LOG_DEBUG: @@ -882,15 +957,17 @@ static int virLogPrioritySyslog(virLogPriority priority) } } -static void virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED, - virLogPriority priority, - const char *funcname ATTRIBUTE_UNUSED, - size_t linenr ATTRIBUTE_UNUSED, - const char *timestamp ATTRIBUTE_UNUSED, - unsigned int flags, - const char *rawstr ATTRIBUTE_UNUSED, - const char *str, - void *data ATTRIBUTE_UNUSED) + +static void +virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED, + virLogPriority priority, + const char *funcname ATTRIBUTE_UNUSED, + size_t linenr ATTRIBUTE_UNUSED, + const char *timestamp ATTRIBUTE_UNUSED, + unsigned int flags, + const char *rawstr ATTRIBUTE_UNUSED, + const char *str, + void *data ATTRIBUTE_UNUSED) { virCheckFlags(VIR_LOG_STACK_TRACE,); @@ -899,12 +976,19 @@ static void virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED, static char *current_ident = NULL; -static void virLogCloseSyslog(void *data ATTRIBUTE_UNUSED) { + +static void +virLogCloseSyslog(void *data ATTRIBUTE_UNUSED) +{ closelog(); VIR_FREE(current_ident); } -static int virLogAddOutputToSyslog(virLogPriority priority, const char *ident) { + +static int +virLogAddOutputToSyslog(virLogPriority priority, + const char *ident) +{ /* * ident needs to be kept around on Solaris */ @@ -928,6 +1012,7 @@ static int virLogAddOutputToSyslog(virLogPriority priority, const char *ident) { ((*cur == ' ') || (*cur == '\t') || (*cur == '\n') || \ (*cur == '\r') || (*cur == '\\')) + /** * virLogParseOutputs: * @outputs: string defining a (set of) output(s) @@ -951,7 +1036,9 @@ static int virLogAddOutputToSyslog(virLogPriority priority, const char *ident) { * * Returns the number of output parsed and installed or -1 in case of error */ -int virLogParseOutputs(const char *outputs) { +int +virLogParseOutputs(const char *outputs) +{ const char *cur = outputs, *str; char *name; char *abspath; @@ -1025,6 +1112,7 @@ cleanup: return ret; } + /** * virLogParseFilters: * @filters: string defining a (set of) filter(s) @@ -1043,7 +1131,9 @@ cleanup: * * Returns the number of filter parsed and installed or -1 in case of error */ -int virLogParseFilters(const char *filters) { +int +virLogParseFilters(const char *filters) +{ const char *cur = filters, *str; char *name; virLogPriority prio; @@ -1086,15 +1176,19 @@ cleanup: return ret; } + /** * virLogGetDefaultPriority: * * Returns the current logging priority level. */ -virLogPriority virLogGetDefaultPriority(void) { +virLogPriority +virLogGetDefaultPriority(void) +{ return virLogDefaultPriority; } + /** * virLogGetFilters: * @@ -1102,7 +1196,9 @@ virLogPriority virLogGetDefaultPriority(void) { * specified in the config file or environment. Caller must free the * result. */ -char *virLogGetFilters(void) { +char * +virLogGetFilters(void) +{ int i; virBuffer filterbuf = VIR_BUFFER_INITIALIZER; @@ -1126,6 +1222,7 @@ char *virLogGetFilters(void) { return virBufferContentAndReset(&filterbuf); } + /** * virLogGetOutputs: * @@ -1133,7 +1230,9 @@ char *virLogGetFilters(void) { * specified in the config file or environment. Caller must free the * result. */ -char *virLogGetOutputs(void) { +char * +virLogGetOutputs(void) +{ int i; virBuffer outputbuf = VIR_BUFFER_INITIALIZER; @@ -1166,24 +1265,31 @@ char *virLogGetOutputs(void) { return virBufferContentAndReset(&outputbuf); } + /** * virLogGetNbFilters: * * Returns the current number of defined log filters. */ -int virLogGetNbFilters(void) { +int +virLogGetNbFilters(void) +{ return virLogNbFilters; } + /** * virLogGetNbOutputs: * * Returns the current number of defined log outputs. */ -int virLogGetNbOutputs(void) { +int +virLogGetNbOutputs(void) +{ return virLogNbOutputs; } + /** * virLogParseDefaultPriority: * @priority: string defining the desired logging level @@ -1197,7 +1303,9 @@ int virLogGetNbOutputs(void) { * * Returns the parsed log level or -1 on error. */ -int virLogParseDefaultPriority(const char *priority) { +int +virLogParseDefaultPriority(const char *priority) +{ int ret = -1; if (STREQ(priority, "1") || STREQ(priority, "debug")) @@ -1214,13 +1322,16 @@ int virLogParseDefaultPriority(const char *priority) { return ret; } + /** * virLogSetFromEnv: * * Sets virLogDefaultPriority, virLogFilters and virLogOutputs based on * environment variables. */ -void virLogSetFromEnv(void) { +void +virLogSetFromEnv(void) +{ char *debugEnv; debugEnv = getenv("LIBVIRT_DEBUG"); diff --git a/src/util/logging.h b/src/util/logging.h index 2d500a4..6e1de5d 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -96,11 +96,14 @@ typedef enum { * * Callback function used to output messages */ -typedef void (*virLogOutputFunc) (const char *category, virLogPriority priority, - const char *funcname, size_t linenr, +typedef void (*virLogOutputFunc) (const char *category, + virLogPriority priority, + const char *funcname, + size_t linenr, const char *timestamp, unsigned int flags, - const char *rawstr, const char *str, + const char *rawstr, + const char *str, void *data); /** @@ -122,10 +125,15 @@ extern char *virLogGetOutputs(void); extern virLogPriority virLogGetDefaultPriority(void); extern int virLogSetDefaultPriority(virLogPriority priority); extern void virLogSetFromEnv(void); -extern int virLogDefineFilter(const char *match, virLogPriority priority, +extern int virLogDefineFilter(const char *match, + virLogPriority priority, unsigned int flags); -extern int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, - virLogPriority priority, virLogDestination dest, const char *name, +extern int virLogDefineOutput(virLogOutputFunc f, + virLogCloseFunc c, + void *data, + virLogPriority priority, + virLogDestination dest, + const char *name, unsigned int flags); /* @@ -138,12 +146,16 @@ extern int virLogReset(void); extern int virLogParseDefaultPriority(const char *priority); extern int virLogParseFilters(const char *filters); extern int virLogParseOutputs(const char *output); -extern void virLogMessage(const char *category, virLogPriority priority, - const char *funcname, size_t linenr, +extern void virLogMessage(const char *category, + virLogPriority priority, + const char *funcname, + size_t linenr, unsigned int flags, const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(6, 7); -extern void virLogVMessage(const char *category, virLogPriority priority, - const char *funcname, size_t linenr, +extern void virLogVMessage(const char *category, + virLogPriority priority, + const char *funcname, + size_t linenr, unsigned int flags, const char *fmt, va_list vargs) ATTRIBUTE_FMT_PRINTF(6, 0); -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
General whitespace cleanup in the logging files
- Move '{' to a new line after funtion declaration - Put each parameter on a new line to avoid long lines - Put return type on new line - Leave 2 blank lines between functions
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/logging.c | 239 +++++++++++++++++++++++++++++++++++++++-------------- src/util/logging.h | 32 ++++--- 2 files changed, 197 insertions(+), 74 deletions(-)
No semantic change. ACK. -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
From: "Daniel P. Berrange" <berrange@redhat.com> Currently the logging APIs have a 'const char *category' parameter which indicates where the log message comes from. This is typically a combination of the __FILE__ string and other prefix. Split the __FILE__ off into a dedicated parameter so it can passed to the log outputs Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/internal.h | 8 ++++---- src/node_device/node_device_udev.c | 2 +- src/util/logging.c | 35 ++++++++++++++++++++------------ src/util/logging.h | 41 ++++++++++++++++++++------------------ src/util/viraudit.c | 4 ++-- src/util/virterror.c | 4 ++-- tests/testutils.c | 5 +++-- 7 files changed, 56 insertions(+), 43 deletions(-) diff --git a/src/internal.h b/src/internal.h index 8037a4a..a1d46b9 100644 --- a/src/internal.h +++ b/src/internal.h @@ -349,15 +349,15 @@ # define PROBE_EXPAND(NAME, ARGS) NAME(ARGS) # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace." __FILE__ , __func__, __LINE__, \ + VIR_DEBUG_INT("trace", __FILE__ , __LINE__, __func__, \ #NAME ": " FMT, __VA_ARGS__); \ - if (LIBVIRT_ ## NAME ## _ENABLED()) { \ - PROBE_EXPAND(LIBVIRT_ ## NAME, \ + if (LIBVIRT_ ## NAME ## _ENABLED()) { \ + PROBE_EXPAND(LIBVIRT_ ## NAME, \ VIR_ADD_CASTS(__VA_ARGS__)); \ } # else # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace." __FILE__, __func__, __LINE__, \ + VIR_DEBUG_INT("trace", __FILE__, __LINE__, __func__, \ #NAME ": " FMT, __VA_ARGS__); # endif diff --git a/src/node_device/node_device_udev.c b/src/node_device/node_device_udev.c index ba17010..2104bd3 100644 --- a/src/node_device/node_device_udev.c +++ b/src/node_device/node_device_udev.c @@ -358,7 +358,7 @@ static void udevLogFunction(struct udev *udev ATTRIBUTE_UNUSED, const char *fmt, va_list args) { - VIR_ERROR_INT(file, fn, line, fmt, args); + VIR_ERROR_INT("library", file, line, fn, fmt, args); } diff --git a/src/util/logging.c b/src/util/logging.c index 5b29646..ceab64d 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -100,8 +100,9 @@ static int virLogResetFilters(void); static int virLogResetOutputs(void); static void virLogOutputToFd(const char *category, virLogPriority priority, - const char *funcname, + const char *filename, size_t linenr, + const char *funcname, const char *timestamp, unsigned int flags, const char *rawstr, @@ -651,8 +652,8 @@ cleanup: static int virLogFormatString(char **msg, - const char *funcname, size_t linenr, + const char *funcname, virLogPriority priority, const char *str) { @@ -696,7 +697,7 @@ virLogVersionString(const char **rawmsg, #endif *rawmsg = LOG_VERSION_STRING; - return virLogFormatString(msg, NULL, 0, VIR_LOG_INFO, LOG_VERSION_STRING); + return virLogFormatString(msg, 0, NULL, VIR_LOG_INFO, LOG_VERSION_STRING); } @@ -716,14 +717,17 @@ virLogVersionString(const char **rawmsg, void virLogMessage(const char *category, virLogPriority priority, - const char *funcname, + const char *filename, size_t linenr, + const char *funcname, unsigned int flags, const char *fmt, ...) { va_list ap; va_start(ap, fmt); - virLogVMessage(category, priority, funcname, linenr, flags, fmt, ap); + virLogVMessage(category, priority, + filename, linenr, funcname, + flags, fmt, ap); va_end(ap); } @@ -744,8 +748,9 @@ virLogMessage(const char *category, void virLogVMessage(const char *category, virLogPriority priority, - const char *funcname, + const char *filename, size_t linenr, + const char *funcname, unsigned int flags, const char *fmt, va_list vargs) @@ -786,7 +791,7 @@ virLogVMessage(const char *category, goto cleanup; } - ret = virLogFormatString(&msg, funcname, linenr, priority, str); + ret = virLogFormatString(&msg, linenr, funcname, priority, str); if (ret < 0) goto cleanup; @@ -816,13 +821,14 @@ virLogVMessage(const char *category, char *ver = NULL; if (virLogVersionString(&rawver, &ver) >= 0) virLogOutputs[i].f(category, VIR_LOG_INFO, - __func__, __LINE__, + __FILE__, __LINE__, __func__, timestamp, 0, rawver, ver, virLogOutputs[i].data); VIR_FREE(ver); virLogOutputs[i].logVersion = false; } - virLogOutputs[i].f(category, priority, funcname, linenr, + virLogOutputs[i].f(category, priority, + filename, linenr, funcname, timestamp, filterflags, str, msg, virLogOutputs[i].data); } @@ -833,13 +839,14 @@ virLogVMessage(const char *category, char *ver = NULL; if (virLogVersionString(&rawver, &ver) >= 0) virLogOutputToFd(category, VIR_LOG_INFO, - __func__, __LINE__, + __FILE__, __LINE__, __func__, timestamp, 0, rawver, ver, (void *) STDERR_FILENO); VIR_FREE(ver); logVersionStderr = false; } - virLogOutputToFd(category, priority, funcname, linenr, + virLogOutputToFd(category, priority, + filename, linenr, funcname, timestamp, filterflags, str, msg, (void *) STDERR_FILENO); } @@ -876,8 +883,9 @@ virLogStackTraceToFd(int fd) static void virLogOutputToFd(const char *category ATTRIBUTE_UNUSED, virLogPriority priority ATTRIBUTE_UNUSED, - const char *funcname ATTRIBUTE_UNUSED, + const char *filename ATTRIBUTE_UNUSED, size_t linenr ATTRIBUTE_UNUSED, + const char *funcname ATTRIBUTE_UNUSED, const char *timestamp, unsigned int flags, const char *rawstr ATTRIBUTE_UNUSED, @@ -961,8 +969,9 @@ virLogPrioritySyslog(virLogPriority priority) static void virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED, virLogPriority priority, - const char *funcname ATTRIBUTE_UNUSED, + const char *filename ATTRIBUTE_UNUSED, size_t linenr ATTRIBUTE_UNUSED, + const char *funcname ATTRIBUTE_UNUSED, const char *timestamp ATTRIBUTE_UNUSED, unsigned int flags, const char *rawstr ATTRIBUTE_UNUSED, diff --git a/src/util/logging.h b/src/util/logging.h index 6e1de5d..25e6a1c 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -31,8 +31,8 @@ * defined at runtime from the libvirt daemon configuration file */ # ifdef ENABLE_DEBUG -# define VIR_DEBUG_INT(category, f, l, ...) \ - virLogMessage(category, VIR_LOG_DEBUG, f, l, 0, __VA_ARGS__) +# define VIR_DEBUG_INT(category, filename, linenr, funcname, ...) \ + virLogMessage(category, VIR_LOG_DEBUG, filename, linenr, funcname, 0, __VA_ARGS__) # else /** * virLogEatParams: @@ -44,25 +44,25 @@ static inline void virLogEatParams(const char *unused, ...) /* Silence gcc */ unused = unused; } -# define VIR_DEBUG_INT(category, f, l, ...) \ - virLogEatParams(category, f, l, __VA_ARGS__) +# define VIR_DEBUG_INT(category, filename, linenr, funcname, ...) \ + virLogEatParams(category, filename, linenr, funcname, __VA_ARGS__) # endif /* !ENABLE_DEBUG */ -# define VIR_INFO_INT(category, f, l, ...) \ - virLogMessage(category, VIR_LOG_INFO, f, l, 0, __VA_ARGS__) -# define VIR_WARN_INT(category, f, l, ...) \ - virLogMessage(category, VIR_LOG_WARN, f, l, 0, __VA_ARGS__) -# define VIR_ERROR_INT(category, f, l, ...) \ - virLogMessage(category, VIR_LOG_ERROR, f, l, 0, __VA_ARGS__) +# define VIR_INFO_INT(category, filename, linenr, funcname, ...) \ + virLogMessage(category, VIR_LOG_INFO, filename, linenr, funcname, 0, __VA_ARGS__) +# define VIR_WARN_INT(category, filename, linenr, funcname, ...) \ + virLogMessage(category, VIR_LOG_WARN, filename, linenr, funcname, 0, __VA_ARGS__) +# define VIR_ERROR_INT(category, filename, linenr, funcname, ...) \ + virLogMessage(category, VIR_LOG_ERROR, filename, linenr, funcname, 0, __VA_ARGS__) # define VIR_DEBUG(...) \ - VIR_DEBUG_INT("file." __FILE__, __func__, __LINE__, __VA_ARGS__) + VIR_DEBUG_INT("file", __FILE__, __LINE__, __func__, __VA_ARGS__) # define VIR_INFO(...) \ - VIR_INFO_INT("file." __FILE__, __func__, __LINE__, __VA_ARGS__) + VIR_INFO_INT("file", __FILE__, __LINE__, __func__, __VA_ARGS__) # define VIR_WARN(...) \ - VIR_WARN_INT("file." __FILE__, __func__, __LINE__, __VA_ARGS__) + VIR_WARN_INT("file", __FILE__, __LINE__, __func__, __VA_ARGS__) # define VIR_ERROR(...) \ - VIR_ERROR_INT("file." __FILE__, __func__, __LINE__, __VA_ARGS__) + VIR_ERROR_INT("file", __FILE__, __LINE__, __func__, __VA_ARGS__) /* * To be made public @@ -98,8 +98,9 @@ typedef enum { */ typedef void (*virLogOutputFunc) (const char *category, virLogPriority priority, - const char *funcname, + const char *filename, size_t linenr, + const char *funcname, const char *timestamp, unsigned int flags, const char *rawstr, @@ -148,17 +149,19 @@ extern int virLogParseFilters(const char *filters); extern int virLogParseOutputs(const char *output); extern void virLogMessage(const char *category, virLogPriority priority, - const char *funcname, + const char *filename, size_t linenr, + const char *funcname, unsigned int flags, - const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(6, 7); + const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(7, 8); extern void virLogVMessage(const char *category, virLogPriority priority, - const char *funcname, + const char *filename, size_t linenr, + const char *funcname, unsigned int flags, const char *fmt, - va_list vargs) ATTRIBUTE_FMT_PRINTF(6, 0); + va_list vargs) ATTRIBUTE_FMT_PRINTF(7, 0); extern int virLogSetBufferSize(int size); extern void virLogEmergencyDumpAll(int signum); #endif diff --git a/src/util/viraudit.c b/src/util/viraudit.c index 5941714..ea1a79b 100644 --- a/src/util/viraudit.c +++ b/src/util/viraudit.c @@ -103,10 +103,10 @@ void virAuditSend(const char *file ATTRIBUTE_UNUSED, const char *func, if (auditlog && str) { if (success) - virLogMessage("audit", VIR_LOG_INFO, func, linenr, 0, + virLogMessage("audit", VIR_LOG_INFO, file, linenr, func, 0, "success=yes %s", str); else - virLogMessage("audit", VIR_LOG_WARN, func, linenr, 0, + virLogMessage("audit", VIR_LOG_WARN, file, linenr, func, 0, "success=no %s", str); } diff --git a/src/util/virterror.c b/src/util/virterror.c index b257e25..53f80af 100644 --- a/src/util/virterror.c +++ b/src/util/virterror.c @@ -676,8 +676,8 @@ virRaiseErrorFull(const char *filename ATTRIBUTE_UNUSED, priority = virErrorLevelPriority(level); if (virErrorLogPriorityFilter) priority = virErrorLogPriorityFilter(to, priority); - virLogMessage(filename, priority, - funcname, linenr, + virLogMessage("error", priority, + filename, linenr, funcname, virErrorLogPriorityFilter ? 0 : 1, "%s", str); diff --git a/tests/testutils.c b/tests/testutils.c index a33b10d..244db43 100644 --- a/tests/testutils.c +++ b/tests/testutils.c @@ -481,9 +481,10 @@ static struct virtTestLogData testLog = { VIR_BUFFER_INITIALIZER }; static void virtTestLogOutput(const char *category ATTRIBUTE_UNUSED, - int priority ATTRIBUTE_UNUSED, + virLogPriority priority ATTRIBUTE_UNUSED, + const char *filename ATTRIBUTE_UNUSED, + size_t lineno ATTRIBUTE_UNUSED, const char *funcname ATTRIBUTE_UNUSED, - long long lineno ATTRIBUTE_UNUSED, const char *timestamp, unsigned int flags, const char *rawstr ATTRIBUTE_UNUSED, -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
Currently the logging APIs have a 'const char *category' parameter which indicates where the log message comes from. This is typically a combination of the __FILE__ string and other prefix. Split the __FILE__ off into a dedicated parameter so it can passed to the log outputs
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/internal.h | 8 ++++---- src/node_device/node_device_udev.c | 2 +- src/util/logging.c | 35 ++++++++++++++++++++------------ src/util/logging.h | 41 ++++++++++++++++++++------------------ src/util/viraudit.c | 4 ++-- src/util/virterror.c | 4 ++-- tests/testutils.c | 5 +++-- 7 files changed, 56 insertions(+), 43 deletions(-)
diff --git a/src/internal.h b/src/internal.h index 8037a4a..a1d46b9 100644 --- a/src/internal.h +++ b/src/internal.h @@ -349,15 +349,15 @@
# define PROBE_EXPAND(NAME, ARGS) NAME(ARGS) # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace." __FILE__ , __func__, __LINE__, \ + VIR_DEBUG_INT("trace", __FILE__ , __LINE__, __func__, \
While you are touching this line, get rid of the space before comma.
+++ b/tests/testutils.c @@ -481,9 +481,10 @@ static struct virtTestLogData testLog = { VIR_BUFFER_INITIALIZER };
static void virtTestLogOutput(const char *category ATTRIBUTE_UNUSED, - int priority ATTRIBUTE_UNUSED, + virLogPriority priority ATTRIBUTE_UNUSED, + const char *filename ATTRIBUTE_UNUSED, + size_t lineno ATTRIBUTE_UNUSED, const char *funcname ATTRIBUTE_UNUSED, - long long lineno ATTRIBUTE_UNUSED, const char *timestamp,
I see you already covered the test failures I reported in 1/9 and 2/9. ACK with this squashed in: diff --git i/src/internal.h w/src/internal.h index 8037a4a..f8d9044 100644 --- i/src/internal.h +++ w/src/internal.h @@ -349,10 +349,10 @@ # define PROBE_EXPAND(NAME, ARGS) NAME(ARGS) # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace." __FILE__ , __func__, __LINE__, \ + VIR_DEBUG_INT("trace." __FILE__, __func__, __LINE__, \ #NAME ": " FMT, __VA_ARGS__); \ - if (LIBVIRT_ ## NAME ## _ENABLED()) { \ - PROBE_EXPAND(LIBVIRT_ ## NAME, \ + if (LIBVIRT_ ## NAME ## _ENABLED()) { \ + PROBE_EXPAND(LIBVIRT_ ## NAME, \ VIR_ADD_CASTS(__VA_ARGS__)); \ } # else -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On 09/27/2012 01:39 PM, Eric Blake wrote:
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
Currently the logging APIs have a 'const char *category' parameter which indicates where the log message comes from. This is typically a combination of the __FILE__ string and other prefix. Split the __FILE__ off into a dedicated parameter so it can passed to the log outputs
+ VIR_DEBUG_INT("trace", __FILE__ , __LINE__, __func__, \
While you are touching this line, get rid of the space before comma.
ACK with this squashed in:
diff --git i/src/internal.h w/src/internal.h index 8037a4a..f8d9044 100644 --- i/src/internal.h +++ w/src/internal.h @@ -349,10 +349,10 @@
# define PROBE_EXPAND(NAME, ARGS) NAME(ARGS) # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace." __FILE__ , __func__, __LINE__, \ + VIR_DEBUG_INT("trace." __FILE__, __func__, __LINE__, \ #NAME ": " FMT, __VA_ARGS__); \ - if (LIBVIRT_ ## NAME ## _ENABLED()) { \
Phooey - I diffed against the wrong patch. The intent was to fix just the space before comma, or even to squash that fix into 4/9 (along with the other whitespace fixes). -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
From: "Daniel P. Berrange" <berrange@redhat.com> The 'const char *category' parameter only has a few possible values now that the filename has been separated. Turn this parameter into an enum instead. Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/internal.h | 6 +++-- src/node_device/node_device_udev.c | 2 +- src/uml/uml_conf.c | 3 --- src/util/logging.c | 49 ++++++++++++++++++--------------- src/util/logging.h | 55 ++++++++++++++++++++++---------------- src/util/viraudit.c | 9 ++++--- src/util/viraudit.h | 6 ++--- src/util/virterror.c | 5 ++-- tests/testutils.c | 2 +- 9 files changed, 76 insertions(+), 61 deletions(-) diff --git a/src/internal.h b/src/internal.h index a1d46b9..2d378fd 100644 --- a/src/internal.h +++ b/src/internal.h @@ -349,7 +349,8 @@ # define PROBE_EXPAND(NAME, ARGS) NAME(ARGS) # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace", __FILE__ , __LINE__, __func__, \ + VIR_DEBUG_INT(VIR_LOG_FROM_TRACE, \ + __FILE__ , __LINE__, __func__, \ #NAME ": " FMT, __VA_ARGS__); \ if (LIBVIRT_ ## NAME ## _ENABLED()) { \ PROBE_EXPAND(LIBVIRT_ ## NAME, \ @@ -357,7 +358,8 @@ } # else # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace", __FILE__, __LINE__, __func__, \ + VIR_DEBUG_INT(VIR_LOG_FROM_TRACE, \ + __FILE__ , __LINE__, __func__, \ #NAME ": " FMT, __VA_ARGS__); # endif diff --git a/src/node_device/node_device_udev.c b/src/node_device/node_device_udev.c index 2104bd3..943e020 100644 --- a/src/node_device/node_device_udev.c +++ b/src/node_device/node_device_udev.c @@ -358,7 +358,7 @@ static void udevLogFunction(struct udev *udev ATTRIBUTE_UNUSED, const char *fmt, va_list args) { - VIR_ERROR_INT("library", file, line, fn, fmt, args); + VIR_ERROR_INT(VIR_LOG_FROM_LIBRARY, file, line, fn, fmt, args); } diff --git a/src/uml/uml_conf.c b/src/uml/uml_conf.c index a317bcc..d0a2d97 100644 --- a/src/uml/uml_conf.c +++ b/src/uml/uml_conf.c @@ -52,9 +52,6 @@ #define VIR_FROM_THIS VIR_FROM_UML -#define umlLog(level, msg, ...) \ - virLogMessage(__FILE__, level, 0, msg, __VA_ARGS__) - static int umlDefaultConsoleType(const char *ostype ATTRIBUTE_UNUSED) { diff --git a/src/util/logging.c b/src/util/logging.c index ceab64d..fef4577 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -47,6 +47,14 @@ #define VIR_FROM_THIS VIR_FROM_NONE +VIR_ENUM_DECL(virLogSource) +VIR_ENUM_IMPL(virLogSource, VIR_LOG_FROM_LAST, + "file", + "error", + "audit", + "trace", + "library"); + /* * A logging buffer to keep some history over logs */ @@ -98,7 +106,7 @@ static virLogPriority virLogDefaultPriority = VIR_LOG_DEFAULT; static int virLogResetFilters(void); static int virLogResetOutputs(void); -static void virLogOutputToFd(const char *category, +static void virLogOutputToFd(virLogSource src, virLogPriority priority, const char *filename, size_t linenr, @@ -703,11 +711,11 @@ virLogVersionString(const char **rawmsg, /** * virLogMessage: - * @category: where is that message coming from + * @source: where is that message coming from * @priority: the priority level - * @funcname: the function emitting the (debug) message + * @filename: file where the message was emitted * @linenr: line where the message was emitted - * @flags: extra flags, 1 if coming from the error handler + * @funcname: the function emitting the (debug) message * @fmt: the string format * @...: the arguments * @@ -715,30 +723,29 @@ virLogVersionString(const char **rawmsg, * the message may be stored, sent to output or just discarded */ void -virLogMessage(const char *category, +virLogMessage(virLogSource source, virLogPriority priority, const char *filename, size_t linenr, const char *funcname, - unsigned int flags, const char *fmt, ...) { va_list ap; va_start(ap, fmt); - virLogVMessage(category, priority, + virLogVMessage(source, priority, filename, linenr, funcname, - flags, fmt, ap); + fmt, ap); va_end(ap); } /** * virLogVMessage: - * @category: where is that message coming from + * @source: where is that message coming from * @priority: the priority level - * @funcname: the function emitting the (debug) message + * @filename: file where the message was emitted * @linenr: line where the message was emitted - * @flags: extra flags, 1 if coming from the error handler + * @funcname: the function emitting the (debug) message * @fmt: the string format * @vargs: format args * @@ -746,12 +753,11 @@ virLogMessage(const char *category, * the message may be stored, sent to output or just discarded */ void -virLogVMessage(const char *category, +virLogVMessage(virLogSource source, virLogPriority priority, const char *filename, size_t linenr, const char *funcname, - unsigned int flags, const char *fmt, va_list vargs) { @@ -773,7 +779,7 @@ virLogVMessage(const char *category, /* * check against list of specific logging patterns */ - fprio = virLogFiltersCheck(category, &filterflags); + fprio = virLogFiltersCheck(filename, &filterflags); if (fprio == 0) { if (priority < virLogDefaultPriority) emit = 0; @@ -820,32 +826,32 @@ virLogVMessage(const char *category, const char *rawver; char *ver = NULL; if (virLogVersionString(&rawver, &ver) >= 0) - virLogOutputs[i].f(category, VIR_LOG_INFO, + virLogOutputs[i].f(VIR_LOG_FROM_FILE, VIR_LOG_INFO, __FILE__, __LINE__, __func__, timestamp, 0, rawver, ver, virLogOutputs[i].data); VIR_FREE(ver); virLogOutputs[i].logVersion = false; } - virLogOutputs[i].f(category, priority, + virLogOutputs[i].f(source, priority, filename, linenr, funcname, timestamp, filterflags, str, msg, virLogOutputs[i].data); } } - if ((virLogNbOutputs == 0) && (flags != 1)) { + if ((virLogNbOutputs == 0) && (source != VIR_LOG_FROM_ERROR)) { if (logVersionStderr) { const char *rawver; char *ver = NULL; if (virLogVersionString(&rawver, &ver) >= 0) - virLogOutputToFd(category, VIR_LOG_INFO, + virLogOutputToFd(VIR_LOG_FROM_FILE, VIR_LOG_INFO, __FILE__, __LINE__, __func__, timestamp, 0, rawver, ver, (void *) STDERR_FILENO); VIR_FREE(ver); logVersionStderr = false; } - virLogOutputToFd(category, priority, + virLogOutputToFd(source, priority, filename, linenr, funcname, timestamp, filterflags, str, msg, (void *) STDERR_FILENO); @@ -879,9 +885,8 @@ virLogStackTraceToFd(int fd) #undef STRIP_DEPTH } - static void -virLogOutputToFd(const char *category ATTRIBUTE_UNUSED, +virLogOutputToFd(virLogSource source ATTRIBUTE_UNUSED, virLogPriority priority ATTRIBUTE_UNUSED, const char *filename ATTRIBUTE_UNUSED, size_t linenr ATTRIBUTE_UNUSED, @@ -967,7 +972,7 @@ virLogPrioritySyslog(virLogPriority priority) static void -virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED, +virLogOutputToSyslog(virLogSource source ATTRIBUTE_UNUSED, virLogPriority priority, const char *filename ATTRIBUTE_UNUSED, size_t linenr ATTRIBUTE_UNUSED, diff --git a/src/util/logging.h b/src/util/logging.h index 25e6a1c..e5918db 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -31,8 +31,8 @@ * defined at runtime from the libvirt daemon configuration file */ # ifdef ENABLE_DEBUG -# define VIR_DEBUG_INT(category, filename, linenr, funcname, ...) \ - virLogMessage(category, VIR_LOG_DEBUG, filename, linenr, funcname, 0, __VA_ARGS__) +# define VIR_DEBUG_INT(src, filename, linenr, funcname, ...) \ + virLogMessage(src, VIR_LOG_DEBUG, filename, linenr, funcname, __VA_ARGS__) # else /** * virLogEatParams: @@ -44,25 +44,25 @@ static inline void virLogEatParams(const char *unused, ...) /* Silence gcc */ unused = unused; } -# define VIR_DEBUG_INT(category, filename, linenr, funcname, ...) \ - virLogEatParams(category, filename, linenr, funcname, __VA_ARGS__) +# define VIR_DEBUG_INT(src, filename, linenr, funcname, ...) \ + virLogEatParams(src, filename, linenr, funcname, __VA_ARGS__) # endif /* !ENABLE_DEBUG */ -# define VIR_INFO_INT(category, filename, linenr, funcname, ...) \ - virLogMessage(category, VIR_LOG_INFO, filename, linenr, funcname, 0, __VA_ARGS__) -# define VIR_WARN_INT(category, filename, linenr, funcname, ...) \ - virLogMessage(category, VIR_LOG_WARN, filename, linenr, funcname, 0, __VA_ARGS__) -# define VIR_ERROR_INT(category, filename, linenr, funcname, ...) \ - virLogMessage(category, VIR_LOG_ERROR, filename, linenr, funcname, 0, __VA_ARGS__) +# define VIR_INFO_INT(src, filename, linenr, funcname, ...) \ + virLogMessage(src, VIR_LOG_INFO, filename, linenr, funcname, __VA_ARGS__) +# define VIR_WARN_INT(src, filename, linenr, funcname, ...) \ + virLogMessage(src, VIR_LOG_WARN, filename, linenr, funcname, __VA_ARGS__) +# define VIR_ERROR_INT(src, filename, linenr, funcname, ...) \ + virLogMessage(src, VIR_LOG_ERROR, filename, linenr, funcname, __VA_ARGS__) # define VIR_DEBUG(...) \ - VIR_DEBUG_INT("file", __FILE__, __LINE__, __func__, __VA_ARGS__) + VIR_DEBUG_INT(VIR_LOG_FROM_FILE, __FILE__, __LINE__, __func__, __VA_ARGS__) # define VIR_INFO(...) \ - VIR_INFO_INT("file", __FILE__, __LINE__, __func__, __VA_ARGS__) + VIR_INFO_INT(VIR_LOG_FROM_FILE, __FILE__, __LINE__, __func__, __VA_ARGS__) # define VIR_WARN(...) \ - VIR_WARN_INT("file", __FILE__, __LINE__, __func__, __VA_ARGS__) + VIR_WARN_INT(VIR_LOG_FROM_FILE, __FILE__, __LINE__, __func__, __VA_ARGS__) # define VIR_ERROR(...) \ - VIR_ERROR_INT("file", __FILE__, __LINE__, __func__, __VA_ARGS__) + VIR_ERROR_INT(VIR_LOG_FROM_FILE, __FILE__, __LINE__, __func__, __VA_ARGS__) /* * To be made public @@ -82,12 +82,23 @@ typedef enum { VIR_LOG_TO_FILE, } virLogDestination; +typedef enum { + VIR_LOG_FROM_FILE, + VIR_LOG_FROM_ERROR, + VIR_LOG_FROM_AUDIT, + VIR_LOG_FROM_TRACE, + VIR_LOG_FROM_LIBRARY, + + VIR_LOG_FROM_LAST, +} virLogSource; + /** * virLogOutputFunc: - * @category: the category for the message + * @src: the src for the message * @priority: the priority for the message - * @funcname: the function emitting the message + * @filename: file where the message was emitted * @linenr: line where the message was emitted + * @funcname: the function emitting the message * @timestamp: zero terminated string with timestamp of the message * @flags: flags associated with the message * @rawstr: the unformatted message to log, zero terminated @@ -96,7 +107,7 @@ typedef enum { * * Callback function used to output messages */ -typedef void (*virLogOutputFunc) (const char *category, +typedef void (*virLogOutputFunc) (virLogSource src, virLogPriority priority, const char *filename, size_t linenr, @@ -147,21 +158,19 @@ extern int virLogReset(void); extern int virLogParseDefaultPriority(const char *priority); extern int virLogParseFilters(const char *filters); extern int virLogParseOutputs(const char *output); -extern void virLogMessage(const char *category, +extern void virLogMessage(virLogSource src, virLogPriority priority, const char *filename, size_t linenr, const char *funcname, - unsigned int flags, - const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(7, 8); -extern void virLogVMessage(const char *category, + const char *fmt, ...) ATTRIBUTE_FMT_PRINTF(6, 7); +extern void virLogVMessage(virLogSource src, virLogPriority priority, const char *filename, size_t linenr, const char *funcname, - unsigned int flags, const char *fmt, - va_list vargs) ATTRIBUTE_FMT_PRINTF(7, 0); + va_list vargs) ATTRIBUTE_FMT_PRINTF(6, 0); extern int virLogSetBufferSize(int size); extern void virLogEmergencyDumpAll(int signum); #endif diff --git a/src/util/viraudit.c b/src/util/viraudit.c index ea1a79b..61f09eb 100644 --- a/src/util/viraudit.c +++ b/src/util/viraudit.c @@ -74,8 +74,9 @@ void virAuditLog(int logging) } -void virAuditSend(const char *file ATTRIBUTE_UNUSED, const char *func, +void virAuditSend(const char *filename, size_t linenr, + const char *funcname, const char *clienttty ATTRIBUTE_UNUSED, const char *clientaddr ATTRIBUTE_UNUSED, enum virAuditRecordType type ATTRIBUTE_UNUSED, bool success, @@ -103,10 +104,12 @@ void virAuditSend(const char *file ATTRIBUTE_UNUSED, const char *func, if (auditlog && str) { if (success) - virLogMessage("audit", VIR_LOG_INFO, file, linenr, func, 0, + virLogMessage(VIR_LOG_FROM_AUDIT, VIR_LOG_INFO, + filename, linenr, funcname, "success=yes %s", str); else - virLogMessage("audit", VIR_LOG_WARN, file, linenr, func, 0, + virLogMessage(VIR_LOG_FROM_AUDIT, VIR_LOG_WARN, + filename, linenr, funcname, "success=no %s", str); } diff --git a/src/util/viraudit.h b/src/util/viraudit.h index 36fdd7f..b0356da 100644 --- a/src/util/viraudit.h +++ b/src/util/viraudit.h @@ -35,7 +35,7 @@ int virAuditOpen(void); void virAuditLog(int enabled); -void virAuditSend(const char *file, const char *func, size_t linenr, +void virAuditSend(const char *filename, size_t linenr, const char *funcname, const char *clienttty, const char *clientaddr, enum virAuditRecordType type, bool success, const char *fmt, ...) @@ -46,11 +46,11 @@ char *virAuditEncode(const char *key, const char *value); void virAuditClose(void); # define VIR_AUDIT(type, success, ...) \ - virAuditSend(__FILE__, __func__, __LINE__, \ + virAuditSend(__FILE__, __LINE__, __func__, \ NULL, NULL, type, success, __VA_ARGS__); # define VIR_AUDIT_USER(type, success, clienttty, clientaddr, ...) \ - virAuditSend(__FILE__, __func__, __LINE__, \ + virAuditSend(__FILE__, __LINE__, __func__, \ clienttty, clientaddr, type, success, __VA_ARGS__); # define VIR_AUDIT_STR(str) \ diff --git a/src/util/virterror.c b/src/util/virterror.c index 53f80af..ed1ff87 100644 --- a/src/util/virterror.c +++ b/src/util/virterror.c @@ -671,14 +671,13 @@ virRaiseErrorFull(const char *filename ATTRIBUTE_UNUSED, /* * Hook up the error or warning to the logging facility - * XXXX should we include filename as 'category' instead of domain name ? */ priority = virErrorLevelPriority(level); if (virErrorLogPriorityFilter) priority = virErrorLogPriorityFilter(to, priority); - virLogMessage("error", priority, + virLogMessage(virErrorLogPriorityFilter ? VIR_LOG_FROM_FILE : VIR_LOG_FROM_ERROR, + priority, filename, linenr, funcname, - virErrorLogPriorityFilter ? 0 : 1, "%s", str); errno = save_errno; diff --git a/tests/testutils.c b/tests/testutils.c index 244db43..0c52e12 100644 --- a/tests/testutils.c +++ b/tests/testutils.c @@ -480,7 +480,7 @@ struct virtTestLogData { static struct virtTestLogData testLog = { VIR_BUFFER_INITIALIZER }; static void -virtTestLogOutput(const char *category ATTRIBUTE_UNUSED, +virtTestLogOutput(virLogSource source ATTRIBUTE_UNUSED, virLogPriority priority ATTRIBUTE_UNUSED, const char *filename ATTRIBUTE_UNUSED, size_t lineno ATTRIBUTE_UNUSED, -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
The 'const char *category' parameter only has a few possible values now that the filename has been separated. Turn this parameter into an enum instead.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/internal.h | 6 +++-- src/node_device/node_device_udev.c | 2 +- src/uml/uml_conf.c | 3 --- src/util/logging.c | 49 ++++++++++++++++++--------------- src/util/logging.h | 55 ++++++++++++++++++++++---------------- src/util/viraudit.c | 9 ++++--- src/util/viraudit.h | 6 ++--- src/util/virterror.c | 5 ++-- tests/testutils.c | 2 +- 9 files changed, 76 insertions(+), 61 deletions(-)
diff --git a/src/internal.h b/src/internal.h index a1d46b9..2d378fd 100644 --- a/src/internal.h +++ b/src/internal.h @@ -349,7 +349,8 @@
# define PROBE_EXPAND(NAME, ARGS) NAME(ARGS) # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace", __FILE__ , __LINE__, __func__, \ + VIR_DEBUG_INT(VIR_LOG_FROM_TRACE, \ + __FILE__ , __LINE__, __func__, \ #NAME ": " FMT, __VA_ARGS__); \ if (LIBVIRT_ ## NAME ## _ENABLED()) { \ PROBE_EXPAND(LIBVIRT_ ## NAME, \ @@ -357,7 +358,8 @@ } # else # define PROBE(NAME, FMT, ...) \ - VIR_DEBUG_INT("trace", __FILE__, __LINE__, __func__, \ + VIR_DEBUG_INT(VIR_LOG_FROM_TRACE, \ + __FILE__ , __LINE__, __func__, \
Funky alignment of \ (depending on how you resolve my comments on 5/9, you may already have fixed this while resolving minor merge conflicts).
@@ -879,9 +885,8 @@ virLogStackTraceToFd(int fd) #undef STRIP_DEPTH }
- static void -virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
Spurious whitespace change. ACK with that fixed. -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
From: "Daniel P. Berrange" <berrange@redhat.com> Add support for logging to the systemd journal, using its simple client library. The benefit over syslog is that it accepts structured log data, so the journald can store individual items like code file/line/func separately from the string message. Tools which require structured log data can then query the journal to extract exactly what they desire without resorting to string parsing While systemd provides a simple client library for logging, it is more convenient for libvirt to directly write its own client code. This lets us build up the iovec's on the stack, avoiding the need to alloc memory when writing log messages. Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- cfg.mk | 2 +- src/util/logging.c | 177 +++++++++++++++++++++++++++++++++++++++++++++++++++++ src/util/logging.h | 1 + 3 files changed, 179 insertions(+), 1 deletion(-) diff --git a/cfg.mk b/cfg.mk index bbfd4a2..4482d70 100644 --- a/cfg.mk +++ b/cfg.mk @@ -771,7 +771,7 @@ exclude_file_name_regexp--sc_prohibit_asprintf = \ ^(bootstrap.conf$$|src/util/util\.c$$|examples/domain-events/events-c/event-test\.c$$) exclude_file_name_regexp--sc_prohibit_close = \ - (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c)$$) + (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c|src/util/logging\.c)$$) exclude_file_name_regexp--sc_prohibit_empty_lines_at_EOF = \ (^tests/(qemuhelp|nodeinfo)data/|\.(gif|ico|png|diff)$$) diff --git a/src/util/logging.c b/src/util/logging.c index fef4577..367c8e1 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -35,6 +35,10 @@ #if HAVE_SYSLOG_H # include <syslog.h> #endif +#include <sys/socket.h> +#if HAVE_SYS_UN_H +# include <sys/un.h> +#endif #include "virterror_internal.h" #include "logging.h" @@ -44,6 +48,7 @@ #include "threads.h" #include "virfile.h" #include "virtime.h" +#include "intprops.h" #define VIR_FROM_THIS VIR_FROM_NONE @@ -146,6 +151,8 @@ virLogOutputString(virLogDestination ldest) return "syslog"; case VIR_LOG_TO_FILE: return "file"; + case VIR_LOG_TO_JOURNALD: + return "journald"; } return "unknown"; } @@ -1020,6 +1027,170 @@ virLogAddOutputToSyslog(virLogPriority priority, } return 0; } + + +# define IOVEC_SET_STRING(iov, str) \ + do { \ + struct iovec *_i = &(iov); \ + _i->iov_base = (char*)str; \ + _i->iov_len = strlen(str); \ + } while (0) + +# define IOVEC_SET_INT(iov, buf, fmt, val) \ + do { \ + struct iovec *_i = &(iov); \ + snprintf(buf, sizeof(buf), fmt, val); \ + _i->iov_base = buf; \ + _i->iov_len = strlen(buf); \ + } while (0) + +static int journalfd = -1; + +static void +virLogOutputToJournald(virLogSource source, + virLogPriority priority, + const char *filename, + size_t linenr, + const char *funcname, + const char *timestamp ATTRIBUTE_UNUSED, + unsigned int flags, + const char *rawstr, + const char *str ATTRIBUTE_UNUSED, + void *data ATTRIBUTE_UNUSED) +{ + virCheckFlags(VIR_LOG_STACK_TRACE,); + int buffd = -1; + size_t niov = 0; + struct msghdr mh; + struct sockaddr_un sa; + union { + struct cmsghdr cmsghdr; + uint8_t buf[CMSG_SPACE(sizeof(int))]; + } control; + struct cmsghdr *cmsg; + /* We use /dev/shm instead of /tmp here, since we want this to + * be a tmpfs, and one that is available from early boot on + * and where unprivileged users can create files. */ + char path[] = "/dev/shm/journal.XXXXXX"; + char priostr[INT_BUFSIZE_BOUND(priority)]; + char linestr[INT_BUFSIZE_BOUND(priority)]; + + /* First message takes upto 4 iovecs, and each + * other field needs 3, assuming they don't have + * newlines in them + */ +# define IOV_SIZE (4 + (5 * 3)) + struct iovec iov[IOV_SIZE]; + + if (strchr(rawstr, '\n')) { + uint64_t nstr; + /* If 'str' containes a newline, then we must + * encode the string length, since we can't + * rely on the newline for the field separator + */ + IOVEC_SET_STRING(iov[niov++], "MESSAGE\n"); + nstr = htole64(strlen(rawstr)); + iov[niov].iov_base = (char*)&nstr; + iov[niov].iov_len = sizeof(nstr); + niov++; + } else { + IOVEC_SET_STRING(iov[niov++], "MESSAGE="); + } + IOVEC_SET_STRING(iov[niov++], rawstr); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "PRIORITY="); + IOVEC_SET_INT(iov[niov++], priostr, "%d", priority); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "LIBVIRT_SOURCE="); + IOVEC_SET_STRING(iov[niov++], virLogSourceTypeToString(source)); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_FILE="); + IOVEC_SET_STRING(iov[niov++], filename); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_LINE="); + IOVEC_SET_INT(iov[niov++], linestr, "%zu", linenr); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_FUNC="); + IOVEC_SET_STRING(iov[niov++], funcname); + IOVEC_SET_STRING(iov[niov++], "\n"); + + memset(&sa, 0, sizeof(sa)); + sa.sun_family = AF_UNIX; + if (virStrcpy(sa.sun_path, "/run/systemd/journal/socket", sizeof(sa.sun_path)) < 0) + return; + + memset(&mh, 0, sizeof(mh)); + mh.msg_name = &sa; + mh.msg_namelen = offsetof(struct sockaddr_un, sun_path) + strlen(sa.sun_path); + mh.msg_iov = iov; + mh.msg_iovlen = niov; + + if (sendmsg(journalfd, &mh, MSG_NOSIGNAL) >= 0) + return; + + if (errno != EMSGSIZE && errno != ENOBUFS) + return; + + /* Message was too large, so dump to temporary file + * and pass an FD to the journal + */ + + if ((buffd = mkostemp(path, O_CLOEXEC|O_RDWR)) < 0) + return; + + if (unlink(path) < 0) + goto cleanup; + + if (writev(buffd, iov, niov) < 0) + goto cleanup; + + mh.msg_iov = NULL; + mh.msg_iovlen = 0; + + memset(&control, 0, sizeof(control)); + mh.msg_control = &control; + mh.msg_controllen = sizeof(control); + + cmsg = CMSG_FIRSTHDR(&mh); + cmsg->cmsg_level = SOL_SOCKET; + cmsg->cmsg_type = SCM_RIGHTS; + cmsg->cmsg_len = CMSG_LEN(sizeof(int)); + memcpy(CMSG_DATA(cmsg), &buffd, sizeof(int)); + + mh.msg_controllen = cmsg->cmsg_len; + + sendmsg(journalfd, &mh, MSG_NOSIGNAL); + +cleanup: + close(buffd); +} + + +static void virLogCloseJournald(void *data ATTRIBUTE_UNUSED) +{ + close(journalfd); +} + + +static int virLogAddOutputToJournald(int priority) +{ + if ((journalfd = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0) + return -1; + if (virSetInherit(journalfd, false) < 0) { + close(journalfd); + return -1; + } + if (virLogDefineOutput(virLogOutputToJournald, virLogCloseJournald, NULL, + priority, VIR_LOG_TO_JOURNALD, NULL, 0) < 0) { + return -1; + } + return 0; +} #endif /* HAVE_SYSLOG_H */ #define IS_SPACE(cur) \ @@ -1114,6 +1285,12 @@ virLogParseOutputs(const char *outputs) count++; VIR_FREE(name); VIR_FREE(abspath); + } else if (STREQLEN(cur, "journald", 8)) { + cur += 8; +#if HAVE_SYSLOG_H + if (virLogAddOutputToJournald(prio) == 0) + count++; +#endif /* HAVE_SYSLOG_H */ } else { goto cleanup; } diff --git a/src/util/logging.h b/src/util/logging.h index e5918db..d4aa62b 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -80,6 +80,7 @@ typedef enum { VIR_LOG_TO_STDERR = 1, VIR_LOG_TO_SYSLOG, VIR_LOG_TO_FILE, + VIR_LOG_TO_JOURNALD, } virLogDestination; typedef enum { -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
Add support for logging to the systemd journal, using its simple client library. The benefit over syslog is that it accepts structured log data, so the journald can store individual items like code file/line/func separately from the string message. Tools which require structured log data can then query the journal to extract exactly what they desire without resorting to string parsing
While systemd provides a simple client library for logging, it is more convenient for libvirt to directly write its own client code. This lets us build up the iovec's on the stack, avoiding the need to alloc memory when writing log messages.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- cfg.mk | 2 +- src/util/logging.c | 177 +++++++++++++++++++++++++++++++++++++++++++++++++++++ src/util/logging.h | 1 + 3 files changed, 179 insertions(+), 1 deletion(-)
I'll need a v2 on this one. Fails to compile: util/logging.c: In function 'virLogOutputToJournald': util/logging.c:1124:84: error: ordered comparison of pointer with integer zero [-Werror=extra] util/logging.c:1124:18: error: ignoring return value of 'virStrcpy', declared with attribute warn_unused_result [-Werror=unused-result] cc1: all warnings being treated as errors
diff --git a/cfg.mk b/cfg.mk index bbfd4a2..4482d70 100644 --- a/cfg.mk +++ b/cfg.mk @@ -771,7 +771,7 @@ exclude_file_name_regexp--sc_prohibit_asprintf = \ ^(bootstrap.conf$$|src/util/util\.c$$|examples/domain-events/events-c/event-test\.c$$)
exclude_file_name_regexp--sc_prohibit_close = \ - (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c)$$) + (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c|src/util/logging\.c)$$)
That's a bit of a heavy hammer, just to avoid a recursively-logged close(). I'd rather omit this and use VIR_LOG_CLOSE().
+ + +# define IOVEC_SET_STRING(iov, str) \ + do { \ + struct iovec *_i = &(iov); \ + _i->iov_base = (char*)str; \ + _i->iov_len = strlen(str); \ + } while (0) + +# define IOVEC_SET_INT(iov, buf, fmt, val) \ + do { \ + struct iovec *_i = &(iov); \ + snprintf(buf, sizeof(buf), fmt, val); \
Technically, snprintf is not async-signal safe, which kind of goes against the idea of using it in our logging functions. I'd much rather see us do a hand-rolled conversion of int to %d or %zu (which appear to be the only formats you ever pass here).
+ _i->iov_base = buf; \ + _i->iov_len = strlen(buf); \
[Pedantic - even strlen() is not async-signal safe, but that appears to be a bug in POSIX and I have no qualms about using it here; on the other hand, since snprintf() can malloc() (gasp!) POSIX really is correct in listing it as non-safe, and we really shouldn't be using it in this context]
+ } while (0) + +static int journalfd = -1; + +static void +virLogOutputToJournald(virLogSource source, + virLogPriority priority, + const char *filename, + size_t linenr, + const char *funcname, + const char *timestamp ATTRIBUTE_UNUSED, + unsigned int flags, + const char *rawstr, + const char *str ATTRIBUTE_UNUSED, + void *data ATTRIBUTE_UNUSED) +{ + virCheckFlags(VIR_LOG_STACK_TRACE,);
This looks odd, until you remember it is a macro, and doing the correct thing.
+ int buffd = -1; + size_t niov = 0; + struct msghdr mh; + struct sockaddr_un sa; + union { + struct cmsghdr cmsghdr; + uint8_t buf[CMSG_SPACE(sizeof(int))]; + } control; + struct cmsghdr *cmsg; + /* We use /dev/shm instead of /tmp here, since we want this to + * be a tmpfs, and one that is available from early boot on + * and where unprivileged users can create files. */ + char path[] = "/dev/shm/journal.XXXXXX"; + char priostr[INT_BUFSIZE_BOUND(priority)]; + char linestr[INT_BUFSIZE_BOUND(priority)]; + + /* First message takes upto 4 iovecs, and each
s/upto/up to/
+ * other field needs 3, assuming they don't have + * newlines in them + */ +# define IOV_SIZE (4 + (5 * 3)) + struct iovec iov[IOV_SIZE]; + + if (strchr(rawstr, '\n')) {
[Pedantic - strchr() is another one of those functions surprisingly omitted from the async-safe list, but I have no qualms in using it]
+ uint64_t nstr; + /* If 'str' containes a newline, then we must
s/containes/contains/
+ * encode the string length, since we can't + * rely on the newline for the field separator + */ + IOVEC_SET_STRING(iov[niov++], "MESSAGE\n"); + nstr = htole64(strlen(rawstr));
htole64() is a glibc extension which does not exist on mingw, and has not (yet) been ported to gnulib. Then again, this code is inside #ifdef HAVE_SYSLOG_H, so you can probably get away with it (although I'm not sure whether all platforms that provide <syslog.h> happen to also provide htole64(), I at least know that it will exclude mingw).
+ iov[niov].iov_base = (char*)&nstr; + iov[niov].iov_len = sizeof(nstr); + niov++; + } else { + IOVEC_SET_STRING(iov[niov++], "MESSAGE="); + } + IOVEC_SET_STRING(iov[niov++], rawstr); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "PRIORITY="); + IOVEC_SET_INT(iov[niov++], priostr, "%d", priority); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "LIBVIRT_SOURCE="); + IOVEC_SET_STRING(iov[niov++], virLogSourceTypeToString(source)); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_FILE="); + IOVEC_SET_STRING(iov[niov++], filename); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_LINE="); + IOVEC_SET_INT(iov[niov++], linestr, "%zu", linenr);
You know, my earlier comments about linenr always fitting in 'int' mean you could use %u instead of %zu here, making my goal of replacing snprintf with a hand-rolled async-safe converter a bit easier.
+ IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_FUNC="); + IOVEC_SET_STRING(iov[niov++], funcname); + IOVEC_SET_STRING(iov[niov++], "\n"); + + memset(&sa, 0, sizeof(sa)); + sa.sun_family = AF_UNIX; + if (virStrcpy(sa.sun_path, "/run/systemd/journal/socket", sizeof(sa.sun_path)) < 0) + return; + + memset(&mh, 0, sizeof(mh)); + mh.msg_name = &sa; + mh.msg_namelen = offsetof(struct sockaddr_un, sun_path) + strlen(sa.sun_path); + mh.msg_iov = iov; + mh.msg_iovlen = niov; + + if (sendmsg(journalfd, &mh, MSG_NOSIGNAL) >= 0) + return; + + if (errno != EMSGSIZE && errno != ENOBUFS) + return; + + /* Message was too large, so dump to temporary file + * and pass an FD to the journal + */ + + if ((buffd = mkostemp(path, O_CLOEXEC|O_RDWR)) < 0)
Is mkostemp async-signal safe? But if it isn't, I don't know how else to generate a safe file name. Maybe we create ourselves a safe temporary directory at process start where we don't care about the async safety issues, and then in this function, we track a static counter that we increment each time we create a new file within that directory.
+ return; + + if (unlink(path) < 0) + goto cleanup; + + if (writev(buffd, iov, niov) < 0)
Again, mingw and gnulib lacks writev(), but this function isn't compiled on mingw, so we're safe for now.
+ goto cleanup; + + mh.msg_iov = NULL; + mh.msg_iovlen = 0; + + memset(&control, 0, sizeof(control)); + mh.msg_control = &control; + mh.msg_controllen = sizeof(control); + + cmsg = CMSG_FIRSTHDR(&mh); + cmsg->cmsg_level = SOL_SOCKET; + cmsg->cmsg_type = SCM_RIGHTS; + cmsg->cmsg_len = CMSG_LEN(sizeof(int)); + memcpy(CMSG_DATA(cmsg), &buffd, sizeof(int)); + + mh.msg_controllen = cmsg->cmsg_len; + + sendmsg(journalfd, &mh, MSG_NOSIGNAL); + +cleanup: + close(buffd);
VIR_LOG_CLOSE() works just fine here (but not VIR_FORCE_CLOSE, as that is an accident waiting to trigger recursive logging)
+} + + +static void virLogCloseJournald(void *data ATTRIBUTE_UNUSED) +{ + close(journalfd); +} + + +static int virLogAddOutputToJournald(int priority) +{ + if ((journalfd = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0) + return -1; + if (virSetInherit(journalfd, false) < 0) {
Why not use SOCK_DGRAM | SOCK_CLOEXEC in the socket() call?
+ close(journalfd); + return -1; + } + if (virLogDefineOutput(virLogOutputToJournald, virLogCloseJournald, NULL, + priority, VIR_LOG_TO_JOURNALD, NULL, 0) < 0) { + return -1; + } + return 0; +} #endif /* HAVE_SYSLOG_H */
#define IS_SPACE(cur) \ @@ -1114,6 +1285,12 @@ virLogParseOutputs(const char *outputs) count++; VIR_FREE(name); VIR_FREE(abspath); + } else if (STREQLEN(cur, "journald", 8)) { + cur += 8; +#if HAVE_SYSLOG_H
Do we really want to silently parse and ignore 'journald' on systems that lack syslog.h?
+ if (virLogAddOutputToJournald(prio) == 0) + count++; +#endif /* HAVE_SYSLOG_H */ } else { goto cleanup; } diff --git a/src/util/logging.h b/src/util/logging.h index e5918db..d4aa62b 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -80,6 +80,7 @@ typedef enum { VIR_LOG_TO_STDERR = 1, VIR_LOG_TO_SYSLOG, VIR_LOG_TO_FILE, + VIR_LOG_TO_JOURNALD, } virLogDestination;
typedef enum {
Here's a minimum of what I propose squashing in: diff --git i/cfg.mk w/cfg.mk index 4482d70..bbfd4a2 100644 --- i/cfg.mk +++ w/cfg.mk @@ -771,7 +771,7 @@ exclude_file_name_regexp--sc_prohibit_asprintf = \ ^(bootstrap.conf$$|src/util/util\.c$$|examples/domain-events/events-c/event-test\.c$$) exclude_file_name_regexp--sc_prohibit_close = \ - (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c|src/util/logging\.c)$$) + (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c)$$) exclude_file_name_regexp--sc_prohibit_empty_lines_at_EOF = \ (^tests/(qemuhelp|nodeinfo)data/|\.(gif|ico|png|diff)$$) diff --git i/src/util/logging.c w/src/util/logging.c index 367c8e1..32ade71 100644 --- i/src/util/logging.c +++ w/src/util/logging.c @@ -1121,7 +1121,7 @@ virLogOutputToJournald(virLogSource source, memset(&sa, 0, sizeof(sa)); sa.sun_family = AF_UNIX; - if (virStrcpy(sa.sun_path, "/run/systemd/journal/socket", sizeof(sa.sun_path)) < 0) + if (virStrcpyStatic(sa.sun_path, "/run/systemd/journal/socket") == NULL) return; memset(&mh, 0, sizeof(mh)); @@ -1167,13 +1167,13 @@ virLogOutputToJournald(virLogSource source, sendmsg(journalfd, &mh, MSG_NOSIGNAL); cleanup: - close(buffd); + VIR_LOG_CLOSE(buffd); } static void virLogCloseJournald(void *data ATTRIBUTE_UNUSED) { - close(journalfd); + VIR_LOG_CLOSE(journalfd); } @@ -1182,7 +1182,7 @@ static int virLogAddOutputToJournald(int priority) if ((journalfd = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0) return -1; if (virSetInherit(journalfd, false) < 0) { - close(journalfd); + VIR_LOG_CLOSE(journalfd); return -1; } if (virLogDefineOutput(virLogOutputToJournald, virLogCloseJournald, NULL, -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On Thu, Sep 27, 2012 at 02:51:35PM -0600, Eric Blake wrote:
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
Add support for logging to the systemd journal, using its simple client library. The benefit over syslog is that it accepts structured log data, so the journald can store individual items like code file/line/func separately from the string message. Tools which require structured log data can then query the journal to extract exactly what they desire without resorting to string parsing
While systemd provides a simple client library for logging, it is more convenient for libvirt to directly write its own client code. This lets us build up the iovec's on the stack, avoiding the need to alloc memory when writing log messages.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- cfg.mk | 2 +- src/util/logging.c | 177 +++++++++++++++++++++++++++++++++++++++++++++++++++++ src/util/logging.h | 1 + 3 files changed, 179 insertions(+), 1 deletion(-)
I'll need a v2 on this one.
Fails to compile:
util/logging.c: In function 'virLogOutputToJournald': util/logging.c:1124:84: error: ordered comparison of pointer with integer zero [-Werror=extra] util/logging.c:1124:18: error: ignoring return value of 'virStrcpy', declared with attribute warn_unused_result [-Werror=unused-result] cc1: all warnings being treated as errors
diff --git a/cfg.mk b/cfg.mk index bbfd4a2..4482d70 100644 --- a/cfg.mk +++ b/cfg.mk @@ -771,7 +771,7 @@ exclude_file_name_regexp--sc_prohibit_asprintf = \ ^(bootstrap.conf$$|src/util/util\.c$$|examples/domain-events/events-c/event-test\.c$$)
exclude_file_name_regexp--sc_prohibit_close = \ - (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c)$$) + (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c|src/util/logging\.c)$$)
That's a bit of a heavy hammer, just to avoid a recursively-logged close(). I'd rather omit this and use VIR_LOG_CLOSE().
Ahhh, I didn't notice VIR_LOG_CLOSE. I did indeed hit a recursively logging close :-)
+ + +# define IOVEC_SET_STRING(iov, str) \ + do { \ + struct iovec *_i = &(iov); \ + _i->iov_base = (char*)str; \ + _i->iov_len = strlen(str); \ + } while (0) + +# define IOVEC_SET_INT(iov, buf, fmt, val) \ + do { \ + struct iovec *_i = &(iov); \ + snprintf(buf, sizeof(buf), fmt, val); \
Technically, snprintf is not async-signal safe, which kind of goes against the idea of using it in our logging functions. I'd much rather see us do a hand-rolled conversion of int to %d or %zu (which appear to be the only formats you ever pass here).
Ok, should be easy enough, although I notice that the code we use for generating the timestamp string also uses snprintf(), so we should fix that sometime too.
+ * encode the string length, since we can't + * rely on the newline for the field separator + */ + IOVEC_SET_STRING(iov[niov++], "MESSAGE\n"); + nstr = htole64(strlen(rawstr));
htole64() is a glibc extension which does not exist on mingw, and has not (yet) been ported to gnulib. Then again, this code is inside #ifdef HAVE_SYSLOG_H, so you can probably get away with it (although I'm not sure whether all platforms that provide <syslog.h> happen to also provide htole64(), I at least know that it will exclude mingw).
I think I'll #ifdef __linux__ the whole block just to be sure, since systemd is only ever going to be Linux based
+ /* Message was too large, so dump to temporary file + * and pass an FD to the journal + */ + + if ((buffd = mkostemp(path, O_CLOEXEC|O_RDWR)) < 0)
Is mkostemp async-signal safe? But if it isn't, I don't know how else to generate a safe file name. Maybe we create ourselves a safe temporary directory at process start where we don't care about the async safety issues, and then in this function, we track a static counter that we increment each time we create a new file within that directory.
Yep, we never need multiple concurrent temp files, so I can just create one when we initialize logging, and hold open its file descriptor.
+ return; + + if (unlink(path) < 0) + goto cleanup; + + if (writev(buffd, iov, niov) < 0)
Again, mingw and gnulib lacks writev(), but this function isn't compiled on mingw, so we're safe for now.
+ goto cleanup; + + mh.msg_iov = NULL; + mh.msg_iovlen = 0; + + memset(&control, 0, sizeof(control)); + mh.msg_control = &control; + mh.msg_controllen = sizeof(control); + + cmsg = CMSG_FIRSTHDR(&mh); + cmsg->cmsg_level = SOL_SOCKET; + cmsg->cmsg_type = SCM_RIGHTS; + cmsg->cmsg_len = CMSG_LEN(sizeof(int)); + memcpy(CMSG_DATA(cmsg), &buffd, sizeof(int)); + + mh.msg_controllen = cmsg->cmsg_len; + + sendmsg(journalfd, &mh, MSG_NOSIGNAL); + +cleanup: + close(buffd);
VIR_LOG_CLOSE() works just fine here (but not VIR_FORCE_CLOSE, as that is an accident waiting to trigger recursive logging)
+} + + +static void virLogCloseJournald(void *data ATTRIBUTE_UNUSED) +{ + close(journalfd); +} + + +static int virLogAddOutputToJournald(int priority) +{ + if ((journalfd = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0) + return -1; + if (virSetInherit(journalfd, false) < 0) {
Why not use SOCK_DGRAM | SOCK_CLOEXEC in the socket() call?
It wasn't clear to me whether GNULIB provides compat for SOCK_CLOEXEC or not. Even though we're only Linux, older glibc won't provide that
@@ -1114,6 +1285,12 @@ virLogParseOutputs(const char *outputs) count++; VIR_FREE(name); VIR_FREE(abspath); + } else if (STREQLEN(cur, "journald", 8)) { + cur += 8; +#if HAVE_SYSLOG_H
Do we really want to silently parse and ignore 'journald' on systems that lack syslog.h?
I just followed the same pattern that we used with the syslog parsing.
+ if (virLogAddOutputToJournald(prio) == 0) + count++; +#endif /* HAVE_SYSLOG_H */ } else { goto cleanup; } diff --git a/src/util/logging.h b/src/util/logging.h index e5918db..d4aa62b 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -80,6 +80,7 @@ typedef enum { VIR_LOG_TO_STDERR = 1, VIR_LOG_TO_SYSLOG, VIR_LOG_TO_FILE, + VIR_LOG_TO_JOURNALD, } virLogDestination;
typedef enum {
Here's a minimum of what I propose squashing in:
I'll re-post this particular patch for more review. 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 :|
On 09/28/2012 02:08 AM, Daniel P. Berrange wrote:
+static int virLogAddOutputToJournald(int priority) +{ + if ((journalfd = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0) + return -1; + if (virSetInherit(journalfd, false) < 0) {
Why not use SOCK_DGRAM | SOCK_CLOEXEC in the socket() call?
It wasn't clear to me whether GNULIB provides compat for SOCK_CLOEXEC or not. Even though we're only Linux, older glibc won't provide that
I looked; gnulib guarantees SOCK_CLOEXEC for accept4(), but has not yet ported it to socket(). I guess we stick with two calls for now.
@@ -1114,6 +1285,12 @@ virLogParseOutputs(const char *outputs) count++; VIR_FREE(name); VIR_FREE(abspath); + } else if (STREQLEN(cur, "journald", 8)) { + cur += 8; +#if HAVE_SYSLOG_H
Do we really want to silently parse and ignore 'journald' on systems that lack syslog.h?
I just followed the same pattern that we used with the syslog parsing.
Reading patch 8/9 makes me concur - there, we try a log style, then if is it silently ignored, virLogGetNbOutputs() returns 0, so we try the next log style. This is fine after all. -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On Thu, Sep 27, 2012 at 02:51:35PM -0600, Eric Blake wrote:
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
+ /* Message was too large, so dump to temporary file + * and pass an FD to the journal + */ + + if ((buffd = mkostemp(path, O_CLOEXEC|O_RDWR)) < 0)
Is mkostemp async-signal safe? But if it isn't, I don't know how else to generate a safe file name. Maybe we create ourselves a safe temporary directory at process start where we don't care about the async safety issues, and then in this function, we track a static counter that we increment each time we create a new file within that directory.
I've looked the glibc source and the only functions they use are open() and gettimeofday(), and the latter isn't actually used on most architectures, instead it uses inline asm to read a CPU timesource like the TSC. So IMHO, since this will be protected by a #ifdef __linux__ we will be safe in using it. 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 :|
On 09/28/2012 04:09 AM, Daniel P. Berrange wrote:
On Thu, Sep 27, 2012 at 02:51:35PM -0600, Eric Blake wrote:
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
+ /* Message was too large, so dump to temporary file + * and pass an FD to the journal + */ + + if ((buffd = mkostemp(path, O_CLOEXEC|O_RDWR)) < 0)
Is mkostemp async-signal safe? But if it isn't, I don't know how else to generate a safe file name. Maybe we create ourselves a safe temporary directory at process start where we don't care about the async safety issues, and then in this function, we track a static counter that we increment each time we create a new file within that directory.
I've looked the glibc source and the only functions they use are open() and gettimeofday(), and the latter isn't actually used on most architectures, instead it uses inline asm to read a CPU timesource like the TSC. So IMHO, since this will be protected by a #ifdef __linux__ we will be safe in using it.
Sure, but add a big fat comment explaining our choice, so that people reading the code later remember our discussion :) -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
From: "Daniel P. Berrange" <berrange@redhat.com> Probe to see if the systemd journal is accessible, and if so enable logging to the journal by default, rather than stderr (current default under systemd). Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- daemon/libvirtd.c | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-) diff --git a/daemon/libvirtd.c b/daemon/libvirtd.c index 0151124..e9e2e59 100644 --- a/daemon/libvirtd.c +++ b/daemon/libvirtd.c @@ -636,7 +636,21 @@ daemonSetupLogging(struct daemonConfig *config, virLogParseOutputs(config->log_outputs); /* - * If no defined outputs, then direct to libvirtd.log when running + * If no defined outputs, then first try to direct it + * to the systemd journal (if it exists).... + */ + if (virLogGetNbOutputs() == 0) { + char *tmp; + if (access("/run/systemd/journal/socket", W_OK) >= 0) { + if (virAsprintf(&tmp, "%d:journald", virLogGetDefaultPriority()) < 0) + goto no_memory; + virLogParseOutputs(tmp); + VIR_FREE(tmp); + } + } + + /* + * otherwise direct to libvirtd.log when running * as daemon. Otherwise the default output is stderr. */ if (virLogGetNbOutputs() == 0) { -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
Probe to see if the systemd journal is accessible, and if so enable logging to the journal by default, rather than stderr (current default under systemd).
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- daemon/libvirtd.c | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-)
ACK. -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
From: "Daniel P. Berrange" <berrange@redhat.com> The virInitialize function initializes logging from the env, so there is no need for another call to virLogSetFromEnv Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- daemon/libvirtd.c | 3 --- 1 file changed, 3 deletions(-) diff --git a/daemon/libvirtd.c b/daemon/libvirtd.c index e9e2e59..b49acc5 100644 --- a/daemon/libvirtd.c +++ b/daemon/libvirtd.c @@ -990,9 +990,6 @@ int main(int argc, char **argv) { exit(EXIT_FAILURE); } - /* initialize early logging */ - virLogSetFromEnv(); - if (strstr(argv[0], "lt-libvirtd") || strstr(argv[0], "/daemon/.libs/libvirtd")) { char *tmp = strrchr(argv[0], '/'); -- 1.7.11.4
On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
The virInitialize function initializes logging from the env, so there is no need for another call to virLogSetFromEnv
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- daemon/libvirtd.c | 3 --- 1 file changed, 3 deletions(-)
diff --git a/daemon/libvirtd.c b/daemon/libvirtd.c index e9e2e59..b49acc5 100644 --- a/daemon/libvirtd.c +++ b/daemon/libvirtd.c @@ -990,9 +990,6 @@ int main(int argc, char **argv) { exit(EXIT_FAILURE); }
- /* initialize early logging */ - virLogSetFromEnv(); -
ACK. -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On Thu, Sep 27, 2012 at 11:44 AM, Daniel P. Berrange <berrange@redhat.com> wrote:
The systemd journal provides a highly efficient way for apps to generate structured log messages. Since systemd will be used by default on future Fedora/RHEL distros (and likely many others), we should take advantage of the journal out of the box for improved logging capabilities.
Amongst other things, this allows very easy browsing of the libvirt logs after the fact, filtering on filename / line number / function name and more. This is a big benefit to debugging, compared to current case where we need to decide the filters when starting libvirtd. For example it becomes possible to configure libvirt to include all QEMU logging, and then later ask the journal for only messages related to the QEMU json monitor.
--
Someone else posted a patchset for structured logging via lumberjack which would support systemd as well as the other syslog daemons in an abstract way without directly tying the project to systemd? That seems like a better option IMHO. So I would vote for a NACK for the series. https://www.redhat.com/archives/libvir-list/2012-September/msg01485.html -- Doug Goldstein
On Thu, Sep 27, 2012 at 07:31:41PM -0500, Doug Goldstein wrote:
On Thu, Sep 27, 2012 at 11:44 AM, Daniel P. Berrange <berrange@redhat.com> wrote:
The systemd journal provides a highly efficient way for apps to generate structured log messages. Since systemd will be used by default on future Fedora/RHEL distros (and likely many others), we should take advantage of the journal out of the box for improved logging capabilities.
Amongst other things, this allows very easy browsing of the libvirt logs after the fact, filtering on filename / line number / function name and more. This is a big benefit to debugging, compared to current case where we need to decide the filters when starting libvirtd. For example it becomes possible to configure libvirt to include all QEMU logging, and then later ask the journal for only messages related to the QEMU json monitor.
--
Someone else posted a patchset for structured logging via lumberjack which would support systemd as well as the other syslog daemons in an abstract way without directly tying the project to systemd?
That seems like a better option IMHO. So I would vote for a NACK for the series.
First off, we're not tieing the project to systemd, because this is an entirely optional feature. If you read my response to the lumberjack posting, you'll see that there are a number of serious architectural flaws in the design of lumberjack for use as a structured logging system. Unless they radically change the design, which appears unlikely, it is not going to be suitable as a logging impl for libvirt (or arguably any system daemon) to use. 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 :|
participants (3)
-
Daniel P. Berrange -
Doug Goldstein -
Eric Blake