[lttng-dev] [LTTng-UST RFC] Tracepoint Loglevels Specification

[Mathieu Desnoyers]

* Aaron Spear (aspear at vmware.com) wrote:
> Hi guys,
> 
> > > > TRACE_SYSTEM   7
> > > > information has system-level scope
> > > >
> > > > TRACE_PROCESS  8
> > > > information has process-level scope
> > > >
> > > > TRACE_MODULE   9
> > > > information has module (executable/library) scope
> > > >
> > > > TRACE_UNIT     10
> > > > information has compilation unit scope
> > > >
> > > > TRACE_CLASS    11
> > > > information has class-level scope
> > > >
> > > > TRACE_OBJECT   12
> > > > information has object-level scope
> > > >
> > > > TRACE_FUNCTION 13
> > > > information has function-level scope
> > > >
> > > First thought: I don't think that these levels (7-13) correspond to
> > > levels.
> > > These divisions sounds more like a part of the namespacing of the
> > > event
> > > and not level.
> 
> I think that I agree with what Yannick said above and didn't see what
> I interpreted as a direct answer to the question.  It does seem to me
> that TRACE_SYSTEM, TRACE_MODULE, etc really are related to
> domain/scope and not related to levels.  It seems conceivable that I
> am only interested in seeing TRACE_INFO from the process level scope
> as opposed to the system level and would like to be able to filter
> using the domain additionally.  What am I missing?

Hi Aaron,

I guess I need to detail my explanation then. Sorry for yesterday, being
on a slow 2G cell phone link did not allow me to type a detailed
explanation. First, before I dig into the explanation, here is the
mapping I currently fixed for LTTng-UST loglevels:

        TRACE_EMERG     = 0,
        TRACE_ALERT     = 1,
        TRACE_CRIT      = 2,
        TRACE_ERR       = 3,
        TRACE_WARNING   = 4,
        TRACE_NOTICE    = 5,
        TRACE_INFO      = 6,
        TRACE_SYSTEM    = 7,
        TRACE_PROGRAM   = 8,
        TRACE_PROCESS   = 9,
        TRACE_MODULE    = 10,
        TRACE_UNIT      = 11,
        TRACE_FUNCTION  = 12,
        TRACE_DEFAULT   = 13,
        TRACE_VERBOSE   = 14,
        TRACE_DEBUG     = 15,

In this example, I will mainly discuss the use the the loglevel 7
through 15, which seems to be non-trivial. I assume there is no problem
with loglevels 0 through 6, since they simply map to syslog loglevels.

Let's use an example. Let's define a use-case with 4 applications:

Apache web server
Xorg
MariaDB
OpenSSH

Each of those applications could have "high-level" events, like
"application starting" / "application exiting" (this would be
TRACE_PROGRAM level), mid-level events like "a new communication session
with a remote computed has started" (could be TRACE_MODULE, since this
information would tell what the communication module is being used to
initiate a new session), and very detailed events like "incoming packet"
(TRACE_UNIT), because those are somewhat frequent.

Now let's say that we experience a problem on this system. The first
step would be to enable a wildcard that almost traces the entire world,
e.g.:

lttng enable-event -u "*"
  ( trace everything in userspace! )

Obviously, this might generate too much data because it selects _every_
tracepoint in the system, due to some of them generating high-throughput
trace data. This is where the loglevels come into play. Instead of doing
the enable-event above, we should do:

lttng enable-event -u "*" --loglevel TRACE_SYSTEM

So we are going to select tracepoints for _all_ applications which
provide information allowing the person analysing the trace to figure
out where in the system seems to come the problematic behavior (first
pass to narrow down the problem). If we find some interesting bit of
information that lets us think that, for instance, Xorg might be the
cause of the problem, then we start tracing again, but this time with a
different scope (wildcard) and a different loglevel (more detailed). We
can afford an higher-throughput loglevel because we are restricting the
scope of the wildcard, so only Xorg will produce data:

lttng enable-event -u "xorg_*" --loglevel TRACE_PROGRAM

and eventually do another go with:

lttng enable-event -u "xorg_somelib_*" --loglevel TRACE_MODULE

and so on until we end up choosing a very restrictive wildcard scope,
and at the same time we select a very verbose loglevel.

The combination of wildcard and loglevel is actually a new to LTTng and,
in my opinion, is a very powerful way to select the scope of tracepoints
to activate to really help in the process of narrowing down a problem.

It's actually on purpose that I used names that match with the
tracepoint naming scheme hierarchy, because those are used together: as
we restrict the scope of the wildcard, we can select a more verbose
loglevel.

Thoughts ?

Thanks,

Mathieu

-- 
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com