Re: [PATCH] Rust: Add tracing and logging support for Rust code

["Daniel P. Berrangé" <berrange@redhat.com>]

On Mon, Mar 31, 2025 at 07:26:33PM -0500, saman wrote:
> This change introduces initial support for tracing and logging in Rust-based
> QEMU code. As an example, tracing and logging have been implemented in the
> pl011 device, which is written in Rust.
> 
> - Updated `rust/wrapper.h` to include the `qemu/log.h` and `hw/char/trace.h` header.
> - Added log.rs to wrap `qemu_log_mask` and `qemu_log_mask_and_addr`
> - Modified `tracetool` scripts to move C function implementation from
>   header to .c
> - Added log and trace in rust version of PL011 device
> 
> Future enhancements could include generating idiomatic Rust APIs for tracing
> using the tracetool scripts
> 
> Signed-off-by: saman <saman@enumclass.cc>
> ---
>  include/qemu/log-for-trace.h        |  5 +--
>  rust/hw/char/pl011/src/device.rs    | 34 +++++++++++++++---
>  rust/hw/char/pl011/src/registers.rs | 20 +++++++++++
>  rust/qemu-api/meson.build           |  1 +
>  rust/qemu-api/src/lib.rs            |  1 +
>  rust/qemu-api/src/log.rs            | 54 +++++++++++++++++++++++++++++
>  rust/wrapper.h                      |  2 ++
>  scripts/tracetool/format/c.py       | 16 +++++++++
>  scripts/tracetool/format/h.py       | 11 ++----
>  util/log.c                          |  5 +++
>  10 files changed, 131 insertions(+), 18 deletions(-)
>  create mode 100644 rust/qemu-api/src/log.rs
> 
> diff --git a/scripts/tracetool/format/c.py b/scripts/tracetool/format/c.py
> index 69edf0d588..f2d383f89c 100644
> --- a/scripts/tracetool/format/c.py
> +++ b/scripts/tracetool/format/c.py
> @@ -43,6 +43,22 @@ def generate(events, backend, group):
>              sstate = "TRACE_%s_ENABLED" % e.name.upper(),
>              dstate = e.api(e.QEMU_DSTATE))
>  
> +        cond = "true"
> +
> +        out('',
> +            'void %(api)s(%(args)s)',
> +            '{',
> +            '    if (%(cond)s) {',
> +            '        %(api_nocheck)s(%(names)s);',
> +            '    }',
> +            '}',
> +            api=e.api(),
> +            api_nocheck=e.api(e.QEMU_TRACE_NOCHECK),
> +            args=e.args,
> +            names=", ".join(e.args.names()),
> +            cond=cond
> +            )
> +
>      out('TraceEvent *%(group)s_trace_events[] = {',
>          group = group.lower())
>  
> diff --git a/scripts/tracetool/format/h.py b/scripts/tracetool/format/h.py
> index ea126b07ea..16b360ae49 100644
> --- a/scripts/tracetool/format/h.py
> +++ b/scripts/tracetool/format/h.py
> @@ -74,17 +74,10 @@ def generate(events, backend, group):
>          cond = "true"
>  
>          out('',
> -            'static inline void %(api)s(%(args)s)',
> -            '{',
> -            '    if (%(cond)s) {',
> -            '        %(api_nocheck)s(%(names)s);',
> -            '    }',
> -            '}',
> +            'void %(api)s(%(args)s);',
>              api=e.api(),
> -            api_nocheck=e.api(e.QEMU_TRACE_NOCHECK),
>              args=e.args,
> -            names=", ".join(e.args.names()),
> -            cond=cond)
> +            )
>  
>      backend.generate_end(events, group)
>

This is a non-trivial degradation for the tracing code. The code is
generated in an inline function in the header so that when a probe
point is not active, it has as little overhead as possible - with
some backends it will just a 'nop' instruction.  With this change
every probe is turned into a function call with no possiblity to
optimize away this overhead.

IMHO tracing in Rust needs to be done by generating native Rust
code for the (sub)set of trace  backends that we care about, and
not attempt to wrap the C trace code from Rust.

With regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|