Re: [Qemu-devel] What's the intended use of log.h logging?

[Markus Armbruster <armbru@redhat.com>]

Peter Maydell <peter.maydell@linaro.org> writes:

> On 16 October 2015 at 13:33, Markus Armbruster <armbru@redhat.com> wrote:
>> We have a couple of related features, and I'd like to get some clarity
>> on how exactly they should be used.
>>
>> 1. Tracing
>>
>>    Documented in docs/tracing.txt.
>>
>>    Each trace event can be individually controlled with -trace and with
>>    monitor command trace-event.  Wildcards work.  Monitor command "info
>>    trace-event" shows their status.
>>
>>    Supports a wealth of tracing backends: nop (compiles out tracing
>>    completely), stderr (prints trace to stderr), "simple", "ftrace",
>>    "dtrace", ...  Range from "trivially easy" to "complex power tool".
>
> The major problem with this is it is a compile time choice
> (especially the choice of backend), and our default backend
> is 'nop'.

I think the default is / has become wrong.  Easy enough to fix.

Let's compare log.h and tracing.

Both let you control stuff on the command line and in the monitor.

log.h's unit of control is a mask bit, which controls a canned group of
related messages.

Tracing's unit of control is the individual message.  To control a group
of messages, use globbing.  As long as we use sane names, this is
strictly more powerful than canned group.  When you don't need the
power, globbing can be harder to use than canned group with sensible
names.

log.h can log to stderr, log to a file, or not log at all (default).

Tracing's capabilities depend on a compile time choice:

* You can pick multiple backends.  They're all simultaneously active.
  If we want to support enabling configured backends selectively at
  runtime, that shouldn't be hard.

* If you compile out tracing (configure only backend 'nop'), you can't
  trace.  That's a feature.

* If you pick 'stderr', you can trace to stderr.  Turning it into a
  backend that could alternatively trace to a file (-trace file=FNAME)
  would be easy.  Picking just 'stderr' would be feature-equivalent to
  log.h then.

>> 2. Ad hoc printing
>>
>>    We have 108 files with some #define DPRINTF(), and probably some more
>>    sailing under different flags.  The ones that aren't useless should
>>    probably be tracepoints.
>>
>> 3. "qemu/log.h" logging
>>
>>    Sports a "mask", where each bit enables a certain set of log
>>    messages.  Control the mask with "-d item,..."  Try "-d help" to see
>>    acceptable items.
>>
>>    Logs to stderr by default, can be redirected with "-D <logfile>".
>
> This, though it is a bit ad-hoc, always exists, always behaves the
> same way, and doesn't require anybody to rebuild QEMU to enable
> tracing.

"Always exists" and "doesn't require rebuild" are the same.

For me, "exists unless you compiled it out" would be a (minor)
improvement over "always exists".  That's how tracing will be once we
fix the default backend.

"Always behaves the same way" I interpret as complaint about tracing
user interface complexity.  Flexibility breeds complexity, and when you
don't need the former, you don't want the latter.

While that's a valid argument for a simpler user interface, it's hardly
one for having two separate subsystems!  Pretty sure we could provide
the existing log.h user interface as sugar for tracing if we wanted.

> I think having a more consistent approach to logging would be great,
> though.

Points I'd like to make:

1. Logging is not tracing.  Logging logs events interesting for the
user.  Tracing logs code execution.  It's a debugging aid.  The two
overlap to a degree, but they're not the same.

2. The current use of log.h seems closer to tracing than to logging.

3. I figure our tracing needs could be served by the tracing subsystem
with a few improvements.  The few things log.h can do that tracing can't
yet do should be easy enough to add.  Why have two separate subsystems
then?

4. Logging would be useful, but I feel it shouldn't be shoehorned into
log.h.