Re: [PATCH v2 2/3] trace: Add support for recorder back-end

[Christophe de Dinechin <dinechin@redhat.com>]

On 2020-06-30 at 15:02 CEST, Daniel P. Berrangé wrote...
> On Fri, Jun 26, 2020 at 06:27:05PM +0200, Christophe de Dinechin wrote:
>> The recorder library provides support for low-cost continuous
>> recording of events, which can then be replayed. This makes it
>> possible to collect data "after the fact",for example to show the
>> events that led to a crash.
>>
>> Recorder support in qemu is implemented using the existing tracing
>> interface. In addition, it is possible to individually enable
>> recorders that are not traces, although this is probably not
>> recommended.
>>
>> HMP COMMAND:
>> The 'recorder' hmp command has been added, which supports two
>> sub-commands:
>> - recorder dump: Dump the current state of the recorder. You can
>> - recorder trace: Set traces using the recorder_trace_set() syntax.
>>   You can use "recorder trace help" to list all available recorders.
>>
>> Signed-off-by: Christophe de Dinechin <dinechin@redhat.com>
>> ---
>>  configure                             |  5 +++
>>  hmp-commands.hx                       | 19 ++++++++--
>>  monitor/misc.c                        | 27 ++++++++++++++
>>  scripts/tracetool/backend/recorder.py | 51 +++++++++++++++++++++++++++
>>  trace/Makefile.objs                   |  2 ++
>>  trace/control.c                       |  7 ++++
>>  trace/recorder.c                      | 22 ++++++++++++
>>  trace/recorder.h                      | 34 ++++++++++++++++++
>>  util/module.c                         |  8 +++++
>>  9 files changed, 173 insertions(+), 2 deletions(-)
>>  create mode 100644 scripts/tracetool/backend/recorder.py
>>  create mode 100644 trace/recorder.c
>>  create mode 100644 trace/recorder.h
>
>> +RECORDER_CONSTRUCTOR
>> +void recorder_trace_init(void)
>> +{
>> +    recorder_trace_set(getenv("RECORDER_TRACES"));
>> +
>> +    // Allow a dump in case we receive some unhandled signal
>> +    // For example, send USR2 to a hung process to get a dump
>> +    if (getenv("RECORDER_TRACES"))
>> +        recorder_dump_on_common_signals(0,0);
>> +}
>
> What is the syntax of this RECORDER_TRACES env variable,

It's basically a colon-separated list of regexps,
e.g. ".*_error:.*_warning", with special syntax for some additional
functionality such as real-time graphing.

Here are a few examples:

- Activate the foo, bar and baz traces:
      foo:bar:baz

- Activate all traces that contain "lock", as well as "recorder" trace:
      *lock.*:recorder

- Deactivate traces ending in _error
      .*_error=0

There are also a few tweaks and special names, for example you can adjust
the output to show the function name and source code location as follows::

- Show source information in the traces
      recorder_function:recorder_location

  As is not very useful in qemu because it sohws the wrapper location:
     % RECORDER_TRACES=vm_state_notify qemu-system-x86_64
     [35225 7.092175] vm_state_notify: running 1 reason 9 (running)

     % RECORDER_TRACES=vm_state_notify:recorder_function:recorder_location qemu-system-x86_64
     /home/ddd/Work/qemu/trace-root.h:346:_nocheck__trace_vm_state_notify:[94277 0.294906] vm_state_notify: running 1 reason 9 (running)

  This is not as good as what you get with "real" record entries:
     % RECORDER_TRACES=recorder_function:recorder_location:recorder qemu-system-x86_64
     recorder.c:2036:recorder_allocate_alt_stack:[29561 0.006434] recorder: Set alt stack to 0x7fc567b87000 size 8192

- Get some help on available traces:
      help

- Enable real-time graphing for trace "perfdata"
      perfdata=bytes,loops

The last one assumes that you would have a record that looks like:

     record(perfdata, "Transferred %lu bytes in %lu iterations",
            bytes, itercount);

You could then have a real-time graph of the values for variables "bytes"
and "itercount" using the recorder_scope program, and using the names you
gave to the channels in your RECORDER_TRACES variable, i.e. bytes and loops:

     recorder_scope bytes loops

See man recorder_trace_set(3), recorder_scope(1) or
https://github.com/c3d/recorder#recorder-tracing for more information.


> and perhaps more importantly should we have this modelled as a command
> line arg instead of an env variable. We've generally been aiming to get
> rid of env variables and have QAPI modelled CLI. QAPI modelling would be
> particularly important if we want to expose the ablity to change settings
> on the fly via QMP.

The rationale for the recorder using an environment variable is that it was
initially designed to be able to trace libraries, notably SPICE or the
recorder library itself. A single environment variable can be used to
activate traces in the main binary as well as in the libraries.

I'm certainly not against adding a command-line option to activate recorder
options specifically, but as I understand, the option -trace already exists,
and its semantics is sufficiently different from the one in recorder
patterns that I decided to not connect the two for now. For example, to
disable trace foo, you'd pass "-foo" to the -trace option, but "foo=0" to
RECORDER_TRACES. The parsing of graphing options and other related
recorder-specific stuff is a bit difficult to integrate with -trace too.

>
>
>> diff --git a/trace/recorder.h b/trace/recorder.h
>> new file mode 100644
>> index 0000000000..00b11a2d2f
>> --- /dev/null
>> +++ b/trace/recorder.h
>> @@ -0,0 +1,34 @@
>> +/*
>> + * Recorder-based trace backend
>> + *
>> + * Copyright Red Hat 2020
>> + *
>> + * This work is licensed under the terms of the GNU GPL, version 2.  See
>> + * the COPYING file in the top-level directory.
>
> Why "version 2" (only), instead of "version 2 or later" ? QEMU generally
> expects the latter for any new code, unless it is derived from existing
> v2-only code in QEMU.

Good catch. I copied that straight from trace/simple.h. No problem changing
it as you suggest. I don't think that whatever inspiration I took from the
existing trace code is sufficient to stick to 2-only.

>
> Regards,
> Daniel


--
Cheers,
Christophe de Dinechin (IRC c3d)