Re: [Libvir] PATCH: make debug builds quiet by default

On Tue, Jan 15, 2008 at 03:02:55PM +0000, Daniel P. Berrange wrote: How about this patch. I define VIR_DEBUG in src/internal.c. Each module which wants to output debug messages adds #define DEBUG(fmt,...) VIR_DEBUG("driver", fmt, __VA_ARGS__) #define DEBUG0(msg) VIR_DEBUG("driver", "%s", msg) Changing 'driver' to whatever their module name wants to be. All log messages get the function name included $ LIBVIRT_DEBUG=1 ./src/virsh --connect xen+ssh://aubergine/system DEBUG: driver: virInitialize (register drivers) DEBUG: driver: do_open (name "xen+ssh://aubergine/system" to URI components: scheme xen+ssh opaque (null) authority (null) server aubergine user (null) port 0 path /system ) DEBUG: driver: do_open (trying driver 0 (Test) ...) DEBUG: driver: do_open (driver 0 Test returned DECLINED) DEBUG: driver: do_open (trying driver 1 (QEMU) ...) DEBUG: driver: do_open (driver 1 QEMU returned DECLINED) DEBUG: driver: do_open (trying driver 2 (Xen) ...) DEBUG: driver: do_open (driver 2 Xen returned DECLINED) DEBUG: driver: do_open (trying driver 3 (remote) ...) DEBUG: remote: doRemoteOpen (proceeding with name = xen:///system?) libvir: Remote error : Cannot allocate memory DEBUG: driver: do_open (driver 3 remote returned ERROR) error: failed to connect to the hypervisor If we want to take this further to allow apps to turn it on/off via their own 'debug' flag instead of an env variable, then we need a logging API and a way for applications to register a callback to receive log messages. eg a variation on this patch: http://www.redhat.com/archives/libvir-list/2007-June/msg00290.html Anyway, the minimal logging patch is: configure.in | 3 + src/internal.h | 13 +++++++ src/libvirt.c | 83 +++++++++++++++++++++++--------------------------- src/remote_internal.c | 83 +++++++++++++++++--------------------------------- src/xen_unified.c | 12 +++---- src/xend_internal.c | 11 +++--- 6 files changed, 93 insertions(+), 112 deletions(-) diff -r 46121d64c276 configure.in --- a/configure.in Tue Jan 15 20:03:02 2008 -0500 +++ b/configure.in Tue Jan 15 20:40:26 2008 -0500 @@ -147,7 +147,7 @@ dnl --enable-debug=(yes|no) dnl --enable-debug=(yes|no) AC_ARG_ENABLE(debug, AC_HELP_STRING([--enable-debug=no/yes], - [enable debugging output]),[],[enable_debug=no]) + [enable debugging output]),[],[enable_debug=yes]) if test x"$enable_debug" = x"yes"; then AC_DEFINE(ENABLE_DEBUG, [], [whether debugging is enabled]) fi @@ -725,5 +725,6 @@ AC_MSG_NOTICE([Miscellaneous]) AC_MSG_NOTICE([Miscellaneous]) AC_MSG_NOTICE([]) AC_MSG_NOTICE([ Debug: $enable_debug]) +AC_MSG_NOTICE([ Warnings: $enable_compile_warnings]) AC_MSG_NOTICE([ Readline: $lv_use_readline]) AC_MSG_NOTICE([]) diff -r 46121d64c276 src/internal.h --- a/src/internal.h Tue Jan 15 20:03:02 2008 -0500 +++ b/src/internal.h Tue Jan 15 20:40:26 2008 -0500 @@ -53,6 +53,19 @@ extern "C" { #define STRCASEEQLEN(a,b,n) (strncasecmp((a),(b),(n)) == 0) #define STRNEQLEN(a,b,n) (strncmp((a),(b),(n)) != 0) #define STRCASENEQLEN(a,b,n) (strncasecmp((a),(b),(n)) != 0) + + +/* If configured with --enable-debug=yes then library calls + * are printed to stderr for debugging. + */ +#ifdef ENABLE_DEBUG +extern int debugFlag; +#define VIR_DEBUG(category, fmt,...) \ + do { if (debugFlag) fprintf (stderr, "DEBUG: %s: %s (" fmt ")\n", category, __func__, __VA_ARGS__); } while (0) +#else +#define VIR_DEBUG(category, fmt,...) + do { } while (0) +#endif /* !ENABLE_DEBUG */ /* C99 uses __func__. __FUNCTION__ is legacy. */ #ifndef __GNUC__ diff -r 46121d64c276 src/libvirt.c --- a/src/libvirt.c Tue Jan 15 20:03:02 2008 -0500 +++ b/src/libvirt.c Tue Jan 15 20:40:26 2008 -0500 @@ -55,18 +55,12 @@ static int virStateDriverTabCount = 0; static int virStateDriverTabCount = 0; static int initialized = 0; -/* If configured with --enable-debug=yes then library calls - * are printed to stderr for debugging. - */ +#define DEBUG(fmt,...) VIR_DEBUG("driver", fmt, __VA_ARGS__) +#define DEBUG0(msg) VIR_DEBUG("driver", "%s", msg) + #ifdef ENABLE_DEBUG -#define DEBUG(fs,...) \ - fprintf (stderr, "libvirt: %s (" fs ")\n", __func__, __VA_ARGS__) -#define DEBUG0 \ - fprintf (stderr, "libvirt: %s ()\n", __func__) -#else -#define DEBUG0 -#define DEBUG(fs,...) -#endif /* !ENABLE_DEBUG */ +int debugFlag = 0; +#endif static int virConnectAuthCallbackDefault(virConnectCredentialPtr cred, unsigned int ncred, @@ -179,10 +173,20 @@ int int virInitialize(void) { - DEBUG0; +#ifdef ENABLE_DEBUG + char *debugEnv; +#endif if (initialized) return(0); initialized = 1; + +#ifdef ENABLE_DEBUG + debugEnv = getenv("LIBVIRT_DEBUG"); + if (debugEnv && *debugEnv && *debugEnv != '0') + debugFlag = 1; +#endif + + DEBUG0("register drivers"); #if HAVE_WINSOCK2_H if (winsock_init () == -1) return -1; @@ -542,20 +546,17 @@ do_open (const char *name, goto failed; } -#ifdef ENABLE_DEBUG - fprintf (stderr, - "libvirt: do_open: name \"%s\" to URI components:\n" - " scheme %s\n" - " opaque %s\n" - " authority %s\n" - " server %s\n" - " user %s\n" - " port %d\n" - " path %s\n", - name, - uri->scheme, uri->opaque, uri->authority, uri->server, - uri->user, uri->port, uri->path); -#endif + DEBUG("name \"%s\" to URI components:\n" + " scheme %s\n" + " opaque %s\n" + " authority %s\n" + " server %s\n" + " user %s\n" + " port %d\n" + " path %s\n", + name, + uri->scheme, uri->opaque, uri->authority, uri->server, + uri->user, uri->port, uri->path); ret->name = strdup (name); if (!ret->name) { @@ -564,18 +565,14 @@ do_open (const char *name, } for (i = 0; i < virDriverTabCount; i++) { -#ifdef ENABLE_DEBUG - fprintf (stderr, "libvirt: do_open: trying driver %d (%s) ...\n", - i, virDriverTab[i]->name); -#endif + DEBUG("trying driver %d (%s) ...", + i, virDriverTab[i]->name); res = virDriverTab[i]->open (ret, uri, auth, flags); -#ifdef ENABLE_DEBUG - fprintf (stderr, "libvirt: do_open: driver %d %s returned %s\n", - i, virDriverTab[i]->name, - res == VIR_DRV_OPEN_SUCCESS ? "SUCCESS" : - (res == VIR_DRV_OPEN_DECLINED ? "DECLINED" : - (res == VIR_DRV_OPEN_ERROR ? "ERROR" : "unknown status"))); -#endif + DEBUG("driver %d %s returned %s", + i, virDriverTab[i]->name, + res == VIR_DRV_OPEN_SUCCESS ? "SUCCESS" : + (res == VIR_DRV_OPEN_DECLINED ? "DECLINED" : + (res == VIR_DRV_OPEN_ERROR ? "ERROR" : "unknown status"))); if (res == VIR_DRV_OPEN_ERROR) goto failed; else if (res == VIR_DRV_OPEN_SUCCESS) { ret->driver = virDriverTab[i]; @@ -591,13 +588,11 @@ do_open (const char *name, for (i = 0; i < virNetworkDriverTabCount; i++) { res = virNetworkDriverTab[i]->open (ret, uri, auth, flags); -#ifdef ENABLE_DEBUG - fprintf (stderr, "libvirt: do_open: network driver %d %s returned %s\n", - i, virNetworkDriverTab[i]->name, - res == VIR_DRV_OPEN_SUCCESS ? "SUCCESS" : - (res == VIR_DRV_OPEN_DECLINED ? "DECLINED" : - (res == VIR_DRV_OPEN_ERROR ? "ERROR" : "unknown status"))); -#endif + DEBUG("network driver %d %s returned %s", + i, virNetworkDriverTab[i]->name, + res == VIR_DRV_OPEN_SUCCESS ? "SUCCESS" : + (res == VIR_DRV_OPEN_DECLINED ? "DECLINED" : + (res == VIR_DRV_OPEN_ERROR ? "ERROR" : "unknown status"))); if (res == VIR_DRV_OPEN_ERROR) { if (STREQ(virNetworkDriverTab[i]->name, "remote")) { virLibConnWarning (NULL, VIR_WAR_NO_NETWORK, diff -r 46121d64c276 src/remote_internal.c --- a/src/remote_internal.c Tue Jan 15 20:03:02 2008 -0500 +++ b/src/remote_internal.c Tue Jan 15 20:40:26 2008 -0500 @@ -72,6 +72,9 @@ #include "remote_internal.h" #include "remote_protocol.h" +#define DEBUG(fmt,...) VIR_DEBUG("remote", fmt,__VA_ARGS__) +#define DEBUG0(msg) VIR_DEBUG("remote", "%s", msg) + /* Per-connection private data. */ #define MAGIC 999 /* private_data->magic if OK */ #define DEAD 998 /* private_data->magic if dead/closed */ @@ -158,22 +161,6 @@ remoteStartup(void) inside_daemon = 1; return 0; } - -#if HAVE_SASL || HAVE_POLKIT -static void -remoteDebug(struct private_data *priv, const char *msg,...) -{ - va_list args; - if (priv->debugLog == NULL) - return; - - va_start(args, msg); - vfprintf(priv->debugLog, msg, args); - va_end(args); - fprintf(priv->debugLog, "\n"); -} -#endif /* HAVE_SASL */ - /** * remoteFindServerPath: @@ -426,14 +413,9 @@ doRemoteOpen (virConnectPtr conn, priv->debugLog = stdout; else priv->debugLog = stderr; - } -#ifdef ENABLE_DEBUG - else - fprintf (stderr, - "remoteOpen: " - "passing through variable '%s' ('%s') to remote end\n", - var->name, var->value); -#endif + } else + DEBUG("passing through variable '%s' ('%s') to remote end", + var->name, var->value); } #ifdef HAVE_XMLURI_QUERY_RAW @@ -478,9 +460,7 @@ doRemoteOpen (virConnectPtr conn, } assert (name); -#ifdef ENABLE_DEBUG - fprintf (stderr, "remoteOpen: proceeding with name = %s\n", name); -#endif + DEBUG("proceeding with name = %s", name); /* Connect to the remote service. */ switch (transport) { @@ -909,9 +889,7 @@ initialise_gnutls (virConnectPtr conn) return -1; /* Set the trusted CA cert. */ -#ifdef ENABLE_DEBUG - fprintf (stderr, "loading CA file %s\n", LIBVIRT_CACERT); -#endif + DEBUG("loading CA file %s", LIBVIRT_CACERT); err = gnutls_certificate_set_x509_trust_file (x509_cred, LIBVIRT_CACERT, GNUTLS_X509_FMT_PEM); @@ -921,10 +899,8 @@ initialise_gnutls (virConnectPtr conn) } /* Set the client certificate and private key. */ -#ifdef ENABLE_DEBUG - fprintf (stderr, "loading client cert and key from files %s and %s\n", - LIBVIRT_CLIENTCERT, LIBVIRT_CLIENTKEY); -#endif + DEBUG("loading client cert and key from files %s and %s", + LIBVIRT_CLIENTCERT, LIBVIRT_CLIENTKEY); err = gnutls_certificate_set_x509_key_file (x509_cred, LIBVIRT_CLIENTCERT, @@ -999,10 +975,9 @@ negotiate_gnutls_on_connection (virConne /* Verify certificate. */ if (verify_certificate (conn, priv, session) == -1) { - fprintf (stderr, - "remote_internal: failed to verify peer's certificate\n"); - if (!no_verify) return NULL; - } + DEBUG0("failed to verify peer's certificate"); + if (!no_verify) return NULL; + } /* At this point, the server is verifying _our_ certificate, IP address, * etc. If we make the grade, it will send us a '\1' byte. @@ -3012,7 +2987,7 @@ remoteAuthSASL (virConnectPtr conn, stru int ret = -1; const char *mechlist; - remoteDebug(priv, "Client initialize SASL authentication"); + DEBUG0("Client initialize SASL authentication"); /* Sets up the SASL library as a whole */ err = sasl_client_init(NULL); if (err != SASL_OK) { @@ -3080,7 +3055,7 @@ remoteAuthSASL (virConnectPtr conn, stru } ssf *= 8; /* key size is bytes, sasl wants bits */ - remoteDebug(priv, "Setting external SSF %d", ssf); + DEBUG("Setting external SSF %d", ssf); err = sasl_setprop(saslconn, SASL_SSF_EXTERNAL, &ssf); if (err != SASL_OK) { __virRaiseError (in_open ? NULL : conn, NULL, NULL, VIR_FROM_REMOTE, @@ -3130,7 +3105,7 @@ remoteAuthSASL (virConnectPtr conn, stru } restart: /* Start the auth negotiation on the client end first */ - remoteDebug(priv, "Client start negotiation mechlist '%s'", mechlist); + DEBUG("Client start negotiation mechlist '%s'", mechlist); err = sasl_client_start(saslconn, mechlist, &interact, @@ -3185,7 +3160,7 @@ remoteAuthSASL (virConnectPtr conn, stru sargs.data.data_val = (char*)clientout; sargs.data.data_len = clientoutlen; sargs.mech = (char*)mech; - remoteDebug(priv, "Server start negotiation with mech %s. Data %d bytes %p", mech, clientoutlen, clientout); + DEBUG("Server start negotiation with mech %s. Data %d bytes %p", mech, clientoutlen, clientout); /* Now send the initial auth data to the server */ memset (&sret, 0, sizeof sret); @@ -3198,8 +3173,8 @@ remoteAuthSASL (virConnectPtr conn, stru /* NB, distinction of NULL vs "" is *critical* in SASL */ serverin = sret.nil ? NULL : sret.data.data_val; serverinlen = sret.data.data_len; - remoteDebug(priv, "Client step result complete: %d. Data %d bytes %p", - complete, serverinlen, serverin); + DEBUG("Client step result complete: %d. Data %d bytes %p", + complete, serverinlen, serverin); /* Loop-the-loop... * Even if the server has completed, the client must *always* do at least one step @@ -3248,7 +3223,7 @@ remoteAuthSASL (virConnectPtr conn, stru free(serverin); serverin = NULL; } - remoteDebug(priv, "Client step result %d. Data %d bytes %p", err, clientoutlen, clientout); + DEBUG("Client step result %d. Data %d bytes %p", err, clientoutlen, clientout); /* Previous server call showed completion & we're now locally complete too */ if (complete && err == SASL_OK) @@ -3260,7 +3235,7 @@ remoteAuthSASL (virConnectPtr conn, stru pargs.nil = clientout ? 0 : 1; pargs.data.data_val = (char*)clientout; pargs.data.data_len = clientoutlen; - remoteDebug(priv, "Server step with %d bytes %p", clientoutlen, clientout); + DEBUG("Server step with %d bytes %p", clientoutlen, clientout); memset (&pret, 0, sizeof pret); if (call (conn, priv, in_open, REMOTE_PROC_AUTH_SASL_STEP, @@ -3273,8 +3248,8 @@ remoteAuthSASL (virConnectPtr conn, stru serverin = pret.nil ? NULL : pret.data.data_val; serverinlen = pret.data.data_len; - remoteDebug(priv, "Client step result complete: %d. Data %d bytes %p", - complete, serverinlen, serverin); + DEBUG("Client step result complete: %d. Data %d bytes %p", + complete, serverinlen, serverin); /* This server call shows complete, and earlier client step was OK */ if (complete && err == SASL_OK) { @@ -3294,7 +3269,7 @@ remoteAuthSASL (virConnectPtr conn, stru goto cleanup; } ssf = *(const int *)val; - remoteDebug(priv, "SASL SSF value %d", ssf); + DEBUG("SASL SSF value %d", ssf); if (ssf < 56) { /* 56 == DES level, good for Kerberos */ __virRaiseError (in_open ? NULL : conn, NULL, NULL, VIR_FROM_REMOTE, VIR_ERR_AUTH_FAILED, VIR_ERR_ERROR, NULL, NULL, NULL, 0, 0, @@ -3303,7 +3278,7 @@ remoteAuthSASL (virConnectPtr conn, stru } } - remoteDebug(priv, "SASL authentication complete"); + DEBUG0("SASL authentication complete"); priv->saslconn = saslconn; ret = 0; @@ -3338,7 +3313,7 @@ remoteAuthPolkit (virConnectPtr conn, st NULL, 0, }; - remoteDebug(priv, "Client initialize PolicyKit authentication"); + DEBUG0("Client initialize PolicyKit authentication"); if (auth && auth->cb) { /* Check if the neccessary credential type for PolicyKit is supported */ @@ -3356,10 +3331,10 @@ remoteAuthPolkit (virConnectPtr conn, st return -1; } } else { - remoteDebug(priv, "Client auth callback does not support PolicyKit"); + DEBUG0("Client auth callback does not support PolicyKit"); } } else { - remoteDebug(priv, "No auth callback provided"); + DEBUG0("No auth callback provided"); } memset (&ret, 0, sizeof ret); @@ -3369,7 +3344,7 @@ remoteAuthPolkit (virConnectPtr conn, st return -1; /* virError already set by call */ } - remoteDebug(priv, "PolicyKit authentication complete"); + DEBUG0("PolicyKit authentication complete"); return 0; } #endif /* HAVE_POLKIT */ diff -r 46121d64c276 src/xen_unified.c --- a/src/xen_unified.c Tue Jan 15 20:03:02 2008 -0500 +++ b/src/xen_unified.c Tue Jan 15 20:40:26 2008 -0500 @@ -39,6 +39,8 @@ #include "xs_internal.h" #include "xm_internal.h" #include "xml.h" + +#define DEBUG(fmt,...) VIR_DEBUG("xen", fmt,__VA_ARGS__) static int xenUnifiedNodeGetInfo (virConnectPtr conn, virNodeInfoPtr info); @@ -271,15 +273,11 @@ xenUnifiedOpen (virConnectPtr conn, xmlU continue; if (drivers[i]->open) { -#ifdef ENABLE_DEBUG - fprintf (stderr, "libvirt: xenUnifiedOpen: trying Xen sub-driver %d\n", i); -#endif + DEBUG("trying Xen sub-driver %d", i); if (drivers[i]->open (conn, uri, auth, flags) == VIR_DRV_OPEN_SUCCESS) priv->opened[i] = 1; -#ifdef ENABLE_DEBUG - fprintf (stderr, "libvirt: xenUnifiedOpen: Xen sub-driver %d open %s\n", - i, priv->opened[i] ? "ok" : "failed"); -#endif + DEBUG("Xen sub-driver %d open %s\n", + i, priv->opened[i] ? "ok" : "failed"); } /* If as root, then all drivers must succeed. diff -r 46121d64c276 src/xend_internal.c --- a/src/xend_internal.c Tue Jan 15 20:03:02 2008 -0500 +++ b/src/xend_internal.c Tue Jan 15 20:40:26 2008 -0500 @@ -47,6 +47,9 @@ /* required for cpumap_t */ #include <xen/dom0_ops.h> + +#define DEBUG(fmt,...) VIR_DEBUG("xend", fmt,__VA_ARGS__) +#define DEBUG0(msg) VIR_DEBUG("xend", "%s", msg) #ifndef PROXY static int xenDaemonListDomains(virConnectPtr conn, int *ids, int maxids); @@ -3410,9 +3413,7 @@ xenDaemonDomainMigratePerform (virDomain } } -#ifdef ENABLE_DEBUG - fprintf (stderr, "hostname = %s, port = %s\n", hostname, port); -#endif + DEBUG("hostname = %s, port = %s", hostname, port); /* Make the call. */ ret = xend_op (domain->conn, domain->name, @@ -3424,9 +3425,7 @@ xenDaemonDomainMigratePerform (virDomain NULL); free (hostname); -#ifdef ENABLE_DEBUG - fprintf (stderr, "migration done\n"); -#endif + DEBUG0("migration done"); return ret; } Dan. -- |=- Red Hat, Engineering, Emerging Technologies, Boston. +1 978 392 2496 -=| |=- Perl modules: http://search.cpan.org/~danberr/ -=| |=- Projects: http://freshmeat.net/~danielpb/ -=| |=- GnuPG: 7D3B9505 F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 -=|