Re: [libvirt] [PATCH] dynamic debug patch

On Wed, Nov 05, 2008 at 04:42:21PM +0000, Daniel P. Berrange wrote: > On Wed, Nov 05, 2008 at 04:26:15PM +0100, Daniel Veillard wrote: > > First version of a small patch allowing to gather debug informations > > from a running libvirt daemon. Basically one can send signal USR2 > > to the daemon, the daemon will from that point dump its current internal > > state and all verbose debug output to a file /tmp/libvirt_debug_xxxx. > > When sending back signal USR2 the file is closed and can be looked at > > for analysis, this allow to save extensive debug informations from a > > running daemon. > > Hardcoding a file in /tmp is not very good practice - it'll certainly > not play nicely with SELinux. We should make the logfile name be I don't see why SELinux should object a binary open and write a file into /tmp/ . Also that's a path that a binary linking to libvirt but running under as non-root can still use. /tmp/libvirt_debug_xxxx is of course opened with mkstemp ! > configurable via /etc/libvirt/libvirtd.conf. Which is libvirtd specific. Seems I failed to carry my suggestion that the thing should work work any app linked to libvirt shared lib even if my initial patch didn't do this.

> In parallel with debugging / logging of functional aspects of the > daemon / library, it is also desirable to get the ability to record > a log of operations invoked on objects. eg, I want to record all > operation invoked against a particular driver, so as a support > person I can ask a bug-reporter to send me the log of the operations > they did leading upto the problem. yes that's the goal. > As an application using libvirt API, I'd expect to have ability to > register a callback to receive debug info, and APIs to control the > logging level > > > enum { > VIR_LOG_DEBUG, > VIR_LOG_INFO, > VIR_LOG_WARN, > VIR_LOG_ERROR, > }; > > typedef void (*virLogHandler)(const char *category, > int priority, > const char *msg); > > virLogAddHandler(virLogHandler callback); > > virLogSetDefaultPriority(int priority); > virLogSetPriority(const char *category, > int priority); > Okay, that's an API, expecting the app will use it. What i want is allow debug without the application being modified which is rather different.

> And a semi-public internal API (ie for use by libvirt.so and libvirtd) > > virLogMessage(const char *category, int priority, const char *fmt, ....); That's fine but i would rather structure object dump based on something more neutral, which is why i think the dump to a buffer is more generally useful. that could be reused in various ways. > Currently we toggle between using stderr, and syslog according to > whether the --deamon flag is passed. This isn't particularly > great. We should be configurable independantly of thise. > > I'd expect /etc/libvirt/libvirtd.conf to allow you to set > > # Choice of 'null', 'syslog', 'stderr', 'file' > log.backend = "syslog" > > # If 'file' was chosen, then also allow > log.file = "/var/log/libvirtd.log" > > # or if 'syslog' was chosen, then allow admin to set the > # syslog facility name for openlog() call. > log.syslog = "libvirtd" > > # One of VIR_LOG_XXX constants > log.priority = "WARN" > > # And per category overrides > log.category.events = "DEBUG" > log.category.mdns = "INFO" > > We already have SIGUSR1 hooked up to make it re-read the domain XML > files, so we could extend this to also re-read the master config > file. So if someone wanted to temporarily debug the system they Hum, that's libvirtd specific.

> could just edit 'log.backend' from 'null' to 'file', and send the > 'SIGUSR1'. Or if they already have it logging to a file by default > and just wanted to increase verbosity, they'd edit 'log.priority' > and send SIGUSR1. It's still quite a more complex operation than just sending the signal. It also means reloading the preferences, it's not that neutral

> At any time, they can also send SIGUSR2 as per your patch, and get > a dump listing all active sockets, sent to whatever log.backend > they currently have configured - either syslog, or file, or whateve > else we implement. Yes I still think it fits slightly different uses. The idea of being able to select the parts doing logs is clearly needed in some ways just right now all the event loop logging can be quite verbose. > This comprehensive logging solution is rather alot of work, so for > immediate use I'd suggest just adding the config for 'log.file' and > 'log.backend' choice, and ignore the per-category debug levels for > 0.5.0 release. > > > Also I'm unclear, do we really want to have all the debug strings > > internationalized with _() , that's more work for localization team > > and it's unclear this would benefit 'end users'. > > I think debug messages are potentially important not to localize. They > are not typically intended for end users, but for developers & vendor > support people, where having everything in english may make it easier > to search for similar problems. > > > > > +static FILE *error_out = NULL; > > +static FILE *info_out = NULL; > > +static int debug_activated = 0; > > + > > +#ifdef ENABLE_DEBUG > > + > > +/* > > + * Signal entry point on USR2 we can't do anything at that point except > > + * log the signal and have qemudToggleDebug called when back into the > > + * main loop. > > + */ > > +static void sig_debug(int sig, siginfo_t * siginfo, void* context) { > > + sig_handler(sig, siginfo, context); > > +} > > + > > +/* > > + * Debug the state of a client > > + */ > > +static void qemudDumpDebugClient(struct qemud_client *client) { > > + if (client->magic != QEMUD_CLIENT_MAGIC) { > > + qemudLog(QEMUD_DEBUG, > > + _("\nQEmud client: invalid magic %X, skipping\n"), > > + (unsigned int) client->magic); > > + return; > > + } > > + qemudLog(QEMUD_DEBUG, _("QEmud client: fd %d readonly %d mode %d"), > > + client->fd, client->readonly, client->mode); > > + > > + /* TODO: more complete dump of state, especially the connection */ > > +} > > + > > +/* > > + * Debug the state of a server > > + */ > > +static void qemudDumpDebugServer(struct qemud_server *server) { > > + struct qemud_client *client; > > + > > + if (server == NULL) { > > + qemudLog(QEMUD_DEBUG, "%s", > > + _("QEmud server: NULL pointer\n")); > > + return; > > + } > > + qemudLog(QEMUD_DEBUG, > > + _("QEmud server: listening on %d sockets, %d clients\n"), > > + server->nsockets, server->nclients); > > + > > + client = server->clients; > > + > > + while (client != NULL) { > > + qemudDumpDebugClient(client); > > + client = client->next; > > + } > > +} > > + > > +/* > > + * Toggle the debug status on/off, on on create a new temporary > > + * debug file and start saving the output there > > + * It is called when the signal USR2 is received. > > + */ > > +static void qemudToggleDebug(struct qemud_server *server) { > > + if (debug_activated == 0) { > > + char path[50] = "/tmp/libvirt_debug_XXXXXX"; > > This path needs to be configurable from the /etc/libvirt/libvirtd.conf > file, and default to /var/log to be selinux compliant. drwxr-xr-x 18 root root /var/log doesn't fit my use cases.

> > +/* > > + * Set up the debugging environment > > + */ > > +static void qemudInitDebug(void) { > > +#ifdef ENABLE_DEBUG > > + struct sigaction oldact; > > + struct sigaction sig_action; > > + > > + /* > > + * if there is already an handler, leave it as is to > > + * avoid disturbing the application's behaviour > > + */ > > + if (sigaction (SIGUSR2, NULL, &oldact) == 0) { > > + if (oldact.sa_handler == NULL && oldact.sa_sigaction == NULL) { > > + sig_action.sa_sigaction = sig_debug; > > + sigaction(SIGUSR2, &sig_action, NULL); > > + } > > + } > > Since this is inside the daemon, we already know that no other > SIGUSR2 handler is present, so can ignore that check. I intend to have similar code in the client shared lib.