[Spice-devel] RFC: Lightweight tracing mechanism

[Marc-André Lureau]

Hi

On Fri, Jun 9, 2017 at 10:08 PM Jonathon Jongsma <jjongsma at redhat.com>
wrote:

> On Fri, 2017-06-09 at 12:11 -0400, Marc-André Lureau wrote:
> > >
> >
> > ----- Original Message -----
> > >
> > > > On 9 Jun 2017, at 17:16, Jonathon Jongsma <jjongsma at redhat.com>
> > > > wrote:
> > > >
> > > > On Fri, 2017-06-09 at 10:59 +0200, Christophe de Dinechin wrote:
> > > > > > > What I see on the thread:
> > > > > > > - log categorization. This was similar to Djasa bug but I
> > > > > > > think
> > > > > > > he just
> > > > > > >   proposed to use domains in the glib log sense;
> > > > >
> > > > > Punchcard analogy: “Printer sheet categorization. This was
> > > > > similar to
> > > > > the report that Djisktra had taken McCarthy's listing by
> > > > > mistake"
> > > > >
> > > > > I thought it was a good idea to derive glib log domains
> > > > > automatically
> > > > > from spice-traces.def. So it’s there in the branch now. That
> > > > > being
> > > > > said, as noted above, glib does linear searches on domain
> > > > > names, so
> > > > > this does not scale well. In the long term, we may want to have
> > > > > a
> > > > > separate field in a structured log.
> > > >
> > > >
> > > > Responding only to this point for the moment: I don't think using
> > > > multiple glib logging domains is necessarily desirable. We
> > > > already use
> > > > several logging domains, but the vast majority of logging
> > > > statements
> > > > within each project use a single domain. In spice-server, that
> > > > primary
> > > > log domain is "Spice", and in spice-gtk that domain is "GSpice".
> > > > spice-
> > > > server also has some additional domains like "SpiceWorker" and
> > > > "SpiceDispatcher". spice-gtk also has GSpiceController (which
> > > > isn't
> > > > really used much these days).
> > > >
> > > > The problem is that both spice-server and spice-gtk have a way to
> > > > enable debugging with an environment variable. But the code for
> > > > enabling the debugging only actually enables the primary domain.
> > >
> > > The ‘traces’ branch enables all trace-related domains if you enable
> > > debug.
> > >
> > > > So anything that is logged under a different domain does not get
> > > > enabled.
> > > > (In fact, spice-gtk has 2 ways to enable logging with an
> > > > environment
> > > > variable but one of the methods is the same one used for spice-
> > > > server,
> > > > but it doesn't work since it actually enables logging for the
> > > > "Spice"
> > > > domain which spice-gtk doesn't use.) I'm hoping to send some
> > > > patches to
> > > > clean up this mess soon.
> > >
> > > Ah, so I was not the only one thinking this was a mess :-)
> >
> > The mess comes because spice-gtk and spice server used different
> > logging, when spice didn't depend on glib.
> >
> > The cleanup isn't over I suppose (Christophe F. did the move to glog
> > in spice-common).
> >
> > I don't get the problem with spice-gtk logging though.
> >
>
>
> Yes, there are historical reasons. And "mess" was an exaggeration. But
> in the process of consolidating the implementations, we seem to have
> introduced some inconsistencies. I'll send more details soon, I hope.
>

Some of them I just found out by reading spice-common log.c, introduced
when switching to glog:

            debug_env = (char *)g_getenv("G_MESSAGES_DEBUG");
            if (debug_env == NULL) {
                g_setenv("G_MESSAGES_DEBUG", SPICE_LOG_DOMAIN, FALSE);
            } else {
                debug_env = g_strconcat(debug_env, ":", SPICE_LOG_DOMAIN,
NULL);
                g_setenv("G_MESSAGES_DEBUG", SPICE_LOG_DOMAIN, FALSE);
                g_free(debug_env);
            }

- appending to G_MESSAGES_DEBUG is buggy, it's not using the newly built
debug_env.
- this will only append the default "Spice" SPICE_LOG_DOMAIN (not the other
spice sub-domains),
- the variable expects a space-seperated list (you sent a patch for that)
(+ the unnecessary cast, could just use another variable...)

spice-gtk spice_util_enable_debug_messages() seems to be correct, also
handling the "all" case.

All of log.c is mostly to deal with deprecated stuff. I propose we switch
more effectively to glog, use a single domain and add some kind of
categories with structured logging (instead of extra glog domains) & remove
the deprecated code. I will work on a proposal, so we'll have alternatives
to discuss.
-- 
Marc-André Lureau
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/spice-devel/attachments/20170611/5d026420/attachment.html>