[libvirt] [PATCH 0/3] Yet another attempt at cleaning libvirtd error logging

THe previous changes commit 04bd0360f32ec628ecf7943b3fd1468d6eb2dde5 Author: Daniel P. Berrange <berrange@redhat.com> Date: Thu Nov 18 13:14:08 2010 +0000 Log all errors at level INFO to stop polluting syslog commit abff683f78ffd01df5005fb7a457c0b38b8eb6e1 Author: Matthias Bolte <matthias.bolte@googlemail.com> Date: Tue Nov 30 14:10:42 2010 +0100 Log client errors in libvirtd at debug priority Are both sub-optimal since they result in all errors in libvirtd becoming hidden. THis includes errors that are not related to public APIs a remote client app is invoking. This has made debugging / troubleshooting significantly more difficult. This reverts both those patches, and applies a tightly targetted filter at a couple of error codes we don't want to see

Remove use of brackets around following return statement. Fix indentation of two switch statements --- src/util/logging.c | 102 ++++++++++++++++++++++++++-------------------------- 1 files changed, 51 insertions(+), 51 deletions(-) diff --git a/src/util/logging.c b/src/util/logging.c index 83cc358..a80c3e3 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -145,28 +145,28 @@ void virLogUnlock(void) static const char *virLogOutputString(virLogDestination ldest) { switch (ldest) { - case VIR_LOG_TO_STDERR: - return("stderr"); - case VIR_LOG_TO_SYSLOG: - return("syslog"); - case VIR_LOG_TO_FILE: - return("file"); + case VIR_LOG_TO_STDERR: + return "stderr"; + case VIR_LOG_TO_SYSLOG: + return "syslog"; + case VIR_LOG_TO_FILE: + return "file"; } - return("unknown"); + return "unknown"; } static const char *virLogPriorityString(virLogPriority lvl) { switch (lvl) { - case VIR_LOG_DEBUG: - return("debug"); - case VIR_LOG_INFO: - return("info"); - case VIR_LOG_WARN: - return("warning"); - case VIR_LOG_ERROR: - return("error"); + case VIR_LOG_DEBUG: + return "debug"; + case VIR_LOG_INFO: + return "info"; + case VIR_LOG_WARN: + return "warning"; + case VIR_LOG_ERROR: + return "error"; } - return("unknown"); + return "unknown"; } static int virLogInitialized = 0; @@ -180,7 +180,7 @@ static int virLogInitialized = 0; */ int virLogStartup(void) { if (virLogInitialized) - return(-1); + return -1; if (virMutexInit(&virLogMutex) < 0) return -1; @@ -192,7 +192,7 @@ int virLogStartup(void) { virLogEnd = 0; virLogDefaultPriority = VIR_LOG_DEFAULT; virLogUnlock(); - return(0); + return 0; } /** @@ -204,7 +204,7 @@ int virLogStartup(void) { */ int virLogReset(void) { if (!virLogInitialized) - return(virLogStartup()); + return virLogStartup(); virLogLock(); virLogResetFilters(); @@ -214,7 +214,7 @@ int virLogReset(void) { virLogEnd = 0; virLogDefaultPriority = VIR_LOG_DEFAULT; virLogUnlock(); - return(0); + return 0; } /** * virLogShutdown: @@ -282,7 +282,7 @@ static int virLogDump(void *data, virLogOutputFunc f) { int ret = 0, tmp; if ((virLogLen == 0) || (f == NULL)) - return(0); + return 0; virLogLock(); if (virLogStart + virLogLen < LOG_BUFFER_SIZE) { push_end: @@ -315,7 +315,7 @@ push_end: } error: virLogUnlock(); - return(ret); + return ret; } #endif @@ -332,12 +332,12 @@ error: int virLogSetDefaultPriority(int priority) { if ((priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) { VIR_WARN0("Ignoring invalid log level setting."); - return(-1); + return -1; } if (!virLogInitialized) virLogStartup(); virLogDefaultPriority = priority; - return(0); + return 0; } /** @@ -354,7 +354,7 @@ static int virLogResetFilters(void) { VIR_FREE(virLogFilters[i].match); VIR_FREE(virLogFilters); virLogNbFilters = 0; - return(i); + return i; } /** @@ -377,7 +377,7 @@ int virLogDefineFilter(const char *match, int priority, if ((match == NULL) || (priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) - return(-1); + return -1; virLogLock(); for (i = 0;i < virLogNbFilters;i++) { @@ -403,7 +403,7 @@ int virLogDefineFilter(const char *match, int priority, virLogNbFilters++; cleanup: virLogUnlock(); - return(i); + return i; } /** @@ -428,7 +428,7 @@ static int virLogFiltersCheck(const char *input) { } } virLogUnlock(); - return(ret); + return ret; } /** @@ -449,7 +449,7 @@ static int virLogResetOutputs(void) { VIR_FREE(virLogOutputs); i = virLogNbOutputs; virLogNbOutputs = 0; - return(i); + return i; } /** @@ -474,14 +474,14 @@ int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, char *ndup = NULL; if (f == NULL) - return(-1); + return -1; if (dest == VIR_LOG_TO_SYSLOG || dest == VIR_LOG_TO_FILE) { if (name == NULL) - return(-1); + return -1; ndup = strdup(name); if (ndup == NULL) - return(-1); + return -1; } virLogLock(); @@ -498,7 +498,7 @@ int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, virLogOutputs[ret].name = ndup; cleanup: virLogUnlock(); - return(ret); + return ret; } /** @@ -598,9 +598,9 @@ static int virLogOutputToFd(const char *category ATTRIBUTE_UNUSED, int ret; if (fd < 0) - return(-1); + return -1; ret = safewrite(fd, str, len); - return(ret); + return ret; } static void virLogCloseFd(void *data) { @@ -612,8 +612,8 @@ static void virLogCloseFd(void *data) { static int virLogAddOutputToStderr(int priority) { if (virLogDefineOutput(virLogOutputToFd, NULL, (void *)2L, priority, VIR_LOG_TO_STDERR, NULL, 0) < 0) - return(-1); - return(0); + return -1; + return 0; } static int virLogAddOutputToFile(int priority, const char *file) { @@ -621,13 +621,13 @@ static int virLogAddOutputToFile(int priority, const char *file) { fd = open(file, O_CREAT | O_APPEND | O_WRONLY, S_IRUSR | S_IWUSR); if (fd < 0) - return(-1); + return -1; if (virLogDefineOutput(virLogOutputToFd, virLogCloseFd, (void *)(long)fd, priority, VIR_LOG_TO_FILE, file, 0) < 0) { VIR_FORCE_CLOSE(fd); - return(-1); + return -1; } - return(0); + return 0; } #if HAVE_SYSLOG_H @@ -656,7 +656,7 @@ static int virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED, prio = LOG_ERR; } syslog(prio, "%s", str); - return(len); + return len; } static char *current_ident = NULL; @@ -673,16 +673,16 @@ static int virLogAddOutputToSyslog(int priority, const char *ident) { VIR_FREE(current_ident); current_ident = strdup(ident); if (current_ident == NULL) - return(-1); + return -1; openlog(current_ident, 0, 0); if (virLogDefineOutput(virLogOutputToSyslog, virLogCloseSyslog, NULL, priority, VIR_LOG_TO_SYSLOG, ident, 0) < 0) { closelog(); VIR_FREE(current_ident); - return(-1); + return -1; } - return(0); + return 0; } #endif /* HAVE_SYSLOG_H */ @@ -722,7 +722,7 @@ int virLogParseOutputs(const char *outputs) { int count = 0; if (cur == NULL) - return(-1); + return -1; virSkipSpaces(&cur); while (*cur != 0) { @@ -784,7 +784,7 @@ int virLogParseOutputs(const char *outputs) { cleanup: if (ret == -1) VIR_WARN0("Ignoring invalid log output setting."); - return(ret); + return ret; } /** @@ -813,7 +813,7 @@ int virLogParseFilters(const char *filters) { int count = 0; if (cur == NULL) - return(-1); + return -1; virSkipSpaces(&cur); while (*cur != 0) { @@ -840,7 +840,7 @@ int virLogParseFilters(const char *filters) { cleanup: if (ret == -1) VIR_WARN0("Ignoring invalid log filter setting."); - return(ret); + return ret; } /** @@ -849,7 +849,7 @@ cleanup: * Returns the current logging priority level. */ int virLogGetDefaultPriority(void) { - return (virLogDefaultPriority); + return virLogDefaultPriority; } /** @@ -924,7 +924,7 @@ char *virLogGetOutputs(void) { * Returns the current number of defined log filters. */ int virLogGetNbFilters(void) { - return (virLogNbFilters); + return virLogNbFilters; } /** @@ -933,7 +933,7 @@ int virLogGetNbFilters(void) { * Returns the current number of defined log outputs. */ int virLogGetNbOutputs(void) { - return (virLogNbOutputs); + return virLogNbOutputs; } /** -- 1.7.3.4

On 01/21/2011 10:30 AM, Daniel P. Berrange wrote:
Remove use of brackets around following return statement. Fix indentation of two switch statements
ACK - just cosmetic. -- Eric Blake eblake@redhat.com +1-801-349-2682 Libvirt virtualization library http://libvirt.org

This reverts the additions in commit abff683f78ffd01df5005fb7a457c0b38b8eb6e1 taking us back to state where all errors are fully logged in both libvirtd and normal clients. THe intent was to stop VIR_ERR_NO_DOMAIN (No such domain with UUID XXXX) messages from client apps polluting syslog The change affected all error codes, but more seriously, it also impacted errors from internal libvirtd infrastructure For example guest autostart no longer logged errors. The libvirtd network code no longer logged some errors. This makes debugging incredibly hard * daemon/libvirtd.c: Remove error log priority filter * src/util/virterror.c, src/util/virterror_internal.h: Remove callback for overriding log priority --- daemon/libvirtd.c | 4 ---- src/libvirt_private.syms | 1 - src/util/virterror.c | 14 +------------- src/util/virterror_internal.h | 1 - 4 files changed, 1 insertions(+), 19 deletions(-) diff --git a/daemon/libvirtd.c b/daemon/libvirtd.c index b1539b1..e6d73cc 100644 --- a/daemon/libvirtd.c +++ b/daemon/libvirtd.c @@ -3103,10 +3103,6 @@ int main(int argc, char **argv) { exit(EXIT_FAILURE); } - /* Set error logging priority to debug, so client errors don't - * show up as errors in the daemon log */ - virErrorSetLogPriority(VIR_LOG_DEBUG); - while (1) { int optidx = 0; int c; diff --git a/src/libvirt_private.syms b/src/libvirt_private.syms index f60489c..18fb3b2 100644 --- a/src/libvirt_private.syms +++ b/src/libvirt_private.syms @@ -917,7 +917,6 @@ virAuditSend; # virterror_internal.h virDispatchError; virErrorMsg; -virErrorSetLogPriority; virRaiseErrorFull; virReportErrorHelper; virReportOOMErrorFull; diff --git a/src/util/virterror.c b/src/util/virterror.c index 3dd6256..9130284 100644 --- a/src/util/virterror.c +++ b/src/util/virterror.c @@ -26,7 +26,6 @@ virThreadLocal virLastErr; virErrorFunc virErrorHandler = NULL; /* global error handler */ void *virUserData = NULL; /* associated data */ -static int virErrorLogPriority = -1; /* * Macro used to format the message as a string in virRaiseError @@ -725,13 +724,8 @@ virRaiseErrorFull(virConnectPtr conn ATTRIBUTE_UNUSED, /* * Hook up the error or warning to the logging facility * XXXX should we include filename as 'category' instead of domain name ? - * - * When an explicit error log priority is set then use it, otherwise - * translate the error level to the log priority. This is used by libvirtd - * to log client errors at debug priority. */ - priority = virErrorLogPriority == -1 ? virErrorLevelPriority(level) - : virErrorLogPriority; + priority = virErrorLevelPriority(level); virLogMessage(virErrorDomainName(domain), priority, funcname, linenr, 1, "%s", str); @@ -1341,9 +1335,3 @@ void virReportOOMErrorFull(int domcode, domcode, VIR_ERR_NO_MEMORY, VIR_ERR_ERROR, virerr, NULL, NULL, -1, -1, virerr, NULL); } - -void -virErrorSetLogPriority(int priority) -{ - virErrorLogPriority = priority; -} diff --git a/src/util/virterror_internal.h b/src/util/virterror_internal.h index 2dd2b4a..601a884 100644 --- a/src/util/virterror_internal.h +++ b/src/util/virterror_internal.h @@ -89,6 +89,5 @@ void virReportOOMErrorFull(int domcode, int virSetError(virErrorPtr newerr); void virDispatchError(virConnectPtr conn); const char *virStrerror(int theerrno, char *errBuf, size_t errBufLen); -void virErrorSetLogPriority(int priority); #endif -- 1.7.3.4

On 01/21/2011 10:30 AM, Daniel P. Berrange wrote:
This reverts the additions in commit
abff683f78ffd01df5005fb7a457c0b38b8eb6e1
taking us back to state where all errors are fully logged in both libvirtd and normal clients.
THe intent was to stop VIR_ERR_NO_DOMAIN (No such domain with UUID XXXX) messages from client apps polluting syslog The change affected all error codes, but more seriously, it also impacted errors from internal libvirtd infrastructure For example guest autostart no longer logged errors. The libvirtd network code no longer logged some errors. This makes debugging incredibly hard
ACK. -- Eric Blake eblake@redhat.com +1-801-349-2682 Libvirt virtualization library http://libvirt.org

Add a hook to the error reporting APIs to allow specific error messages to be filtered out. Wire up libvirtd to remove VIR_ERR_NO_DOMAIN & similar error codes from the logs. THey are still logged at DEBUG level. * daemon/libvirtd.c: Filter VIR_ERR_NO_DOMAIN and friends * src/libvirt_private.syms, src/util/virterror.c, src/util/virterror_internal.h: Hook for changing error reporting level --- daemon/libvirtd.c | 25 +++++++++++++++++++++++++ src/libvirt_private.syms | 1 + src/util/virterror.c | 26 ++++++++++++++++++-------- src/util/virterror_internal.h | 3 +++ 4 files changed, 47 insertions(+), 8 deletions(-) diff --git a/daemon/libvirtd.c b/daemon/libvirtd.c index e6d73cc..afc5c08 100644 --- a/daemon/libvirtd.c +++ b/daemon/libvirtd.c @@ -825,6 +825,30 @@ static void virshErrorHandler(void *opaque ATTRIBUTE_UNUSED, virErrorPtr err ATT * took care of reporting the error */ } +static int daemonErrorLogFilter(virErrorPtr err, int priority) +{ + /* These error codes don't really reflect real errors. They + * are expected events that occur when an app tries to check + * whether a particular guest already exists. This filters + * them to a lower log level to prevent pollution of syslog + */ + switch (err->code) { + case VIR_ERR_NO_DOMAIN: + case VIR_ERR_NO_NETWORK: + case VIR_ERR_NO_STORAGE_POOL: + case VIR_ERR_NO_STORAGE_VOL: + case VIR_ERR_NO_NODE_DEVICE: + case VIR_ERR_NO_INTERFACE: + case VIR_ERR_NO_NWFILTER: + case VIR_ERR_NO_SECRET: + case VIR_ERR_NO_DOMAIN_SNAPSHOT: + return VIR_LOG_DEBUG; + } + + return priority; +} + + static struct qemud_server *qemudInitialize(void) { struct qemud_server *server; @@ -3258,6 +3282,7 @@ int main(int argc, char **argv) { /* Disable error func, now logging is setup */ virSetErrorFunc(NULL, virshErrorHandler); + virSetErrorLogPriorityFunc(daemonErrorLogFilter); /* * Call the daemon startup hook diff --git a/src/libvirt_private.syms b/src/libvirt_private.syms index 18fb3b2..cb0214e 100644 --- a/src/libvirt_private.syms +++ b/src/libvirt_private.syms @@ -922,6 +922,7 @@ virReportErrorHelper; virReportOOMErrorFull; virReportSystemErrorFull; virSetError; +virSetErrorLogPriorityFunc; virStrerror; diff --git a/src/util/virterror.c b/src/util/virterror.c index 9130284..e45b582 100644 --- a/src/util/virterror.c +++ b/src/util/virterror.c @@ -26,6 +26,7 @@ virThreadLocal virLastErr; virErrorFunc virErrorHandler = NULL; /* global error handler */ void *virUserData = NULL; /* associated data */ +virErrorLogPriorityFunc virErrorLogPriorityFilter = NULL; /* * Macro used to format the message as a string in virRaiseError @@ -722,14 +723,6 @@ virRaiseErrorFull(virConnectPtr conn 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); - virLogMessage(virErrorDomainName(domain), priority, - funcname, linenr, 1, "%s", str); - - /* * Save the information about the error */ /* @@ -749,6 +742,18 @@ virRaiseErrorFull(virConnectPtr conn ATTRIBUTE_UNUSED, to->int1 = int1; to->int2 = int2; + /* + * 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(filename, priority, + funcname, linenr, + virErrorLogPriorityFilter ? 0 : 1, + "%s", str); + errno = save_errno; } @@ -1335,3 +1340,8 @@ void virReportOOMErrorFull(int domcode, domcode, VIR_ERR_NO_MEMORY, VIR_ERR_ERROR, virerr, NULL, NULL, -1, -1, virerr, NULL); } + +void virSetErrorLogPriorityFunc(virErrorLogPriorityFunc func) +{ + virErrorLogPriorityFilter = func; +} diff --git a/src/util/virterror_internal.h b/src/util/virterror_internal.h index 601a884..8f32f41 100644 --- a/src/util/virterror_internal.h +++ b/src/util/virterror_internal.h @@ -90,4 +90,7 @@ int virSetError(virErrorPtr newerr); void virDispatchError(virConnectPtr conn); const char *virStrerror(int theerrno, char *errBuf, size_t errBufLen); +typedef int (*virErrorLogPriorityFunc)(virErrorPtr, int); +void virSetErrorLogPriorityFunc(virErrorLogPriorityFunc func); + #endif -- 1.7.3.4

On 01/21/2011 10:30 AM, Daniel P. Berrange wrote:
Add a hook to the error reporting APIs to allow specific error messages to be filtered out. Wire up libvirtd to remove VIR_ERR_NO_DOMAIN & similar error codes from the logs. THey are still logged at DEBUG level.
s/THey/They/
* daemon/libvirtd.c: Filter VIR_ERR_NO_DOMAIN and friends * src/libvirt_private.syms, src/util/virterror.c, src/util/virterror_internal.h: Hook for changing error reporting level --- daemon/libvirtd.c | 25 +++++++++++++++++++++++++ src/libvirt_private.syms | 1 + src/util/virterror.c | 26 ++++++++++++++++++-------- src/util/virterror_internal.h | 3 +++ 4 files changed, 47 insertions(+), 8 deletions(-)
ACK, looks like a reasonable compromise over the full pollution vs. too little information. -- Eric Blake eblake@redhat.com +1-801-349-2682 Libvirt virtualization library http://libvirt.org
participants (2)
-
Daniel P. Berrange
-
Eric Blake