[PATCH RFC 0/5] rust: implement tracing

[PATCH RFC 0/5] rust: implement tracing

[Manos Pitsidianakis]

This RFC series contains some simple patches I've been sitting on for
some months to allow tracing in rust devices in a similar matter to C,
only it's done via a proc-macro codegen instead of using tracetool
script or equivalent.

It also adds the same tracepoints as C in the pl011 device (cc: Philippe)

TODOS:
- Do not allocate string when calling ::qemu_api::log::LogGuard::log_fmt
  (See commit message)
- Properly handle&report errors in proc-macro
- Clean up proc-macro code
- Add test for proc-macro
- Add dev documentation

Signed-off-by: Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
---
Manos Pitsidianakis (5):
      rust/bindings: add trace headers
      rust/qemu-api/log: add Log::Trace variant
      rust/qemu-api-macros: Add #[trace_events] macro
      rust/pl011: impl Copy, Clone for RegisterOffset
      rust/pl011: add trace events

 rust/hw/char/pl011/src/device.rs    |  28 +++++++-
 rust/hw/char/pl011/src/lib.rs       |  43 +++++++++++
 rust/hw/char/pl011/src/registers.rs |   2 +-
 rust/qemu-api-macros/src/lib.rs     | 140 +++++++++++++++++++++++++++++++++++-
 rust/qemu-api/src/bindings.rs       |   3 +
 rust/qemu-api/src/log.rs            |   4 ++
 rust/qemu-api/wrapper.h             |   2 +
 7 files changed, 215 insertions(+), 7 deletions(-)
---
base-commit: e5859141b9b6aec9e0a14dacedc9f02fe2f15844
change-id: 20250804-rust_trace-8558fc98ec88

--
γαῖα πυρί μιχθήτω

[PATCH RFC 1/5] rust/bindings: add trace headers

[Manos Pitsidianakis]

Signed-off-by: Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
---
 rust/qemu-api/src/bindings.rs | 3 +++
 rust/qemu-api/wrapper.h       | 2 ++
 2 files changed, 5 insertions(+)

diff --git a/rust/qemu-api/src/bindings.rs b/rust/qemu-api/src/bindings.rs
index b8104dea8bea4348987978d5041cfc58e4d15a8f..d863b8bd7ecd449b5fe5c6f1be3bd7b4251b2883 100644
--- a/rust/qemu-api/src/bindings.rs
+++ b/rust/qemu-api/src/bindings.rs
@@ -56,3 +56,6 @@ unsafe impl Sync for VMStateField {}
 
 unsafe impl Send for VMStateInfo {}
 unsafe impl Sync for VMStateInfo {}
+
+unsafe impl Send for TraceEvent {}
+unsafe impl Sync for TraceEvent {}
diff --git a/rust/qemu-api/wrapper.h b/rust/qemu-api/wrapper.h
index 15a1b19847f2f2ab1a1a856621abb64f757070ea..540ef5eeac840deadd2e9a6f0dcd154f8dc1487a 100644
--- a/rust/qemu-api/wrapper.h
+++ b/rust/qemu-api/wrapper.h
@@ -69,3 +69,5 @@ typedef enum memory_order {
 #include "qemu/timer.h"
 #include "system/address-spaces.h"
 #include "hw/char/pl011.h"
+#include "trace/event-internal.h"
+#include "trace/control-internal.h"

-- 
2.47.2

[PATCH RFC 2/5] rust/qemu-api/log: add Log::Trace variant

[Manos Pitsidianakis]

Signed-off-by: Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
---
 rust/qemu-api/src/log.rs | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/rust/qemu-api/src/log.rs b/rust/qemu-api/src/log.rs
index a441b8c1f2e61b6aba95a3679ca9c426ab890c19..750ff4b4d878fabeac0bc2b28d291db4b824c760 100644
--- a/rust/qemu-api/src/log.rs
+++ b/rust/qemu-api/src/log.rs
@@ -23,6 +23,10 @@ pub enum Log {
     /// Log guest access of unimplemented functionality.
     /// Corresponds to `LOG_UNIMP` in the C implementation.
     Unimp = bindings::LOG_UNIMP,
+
+    /// Log trace item.
+    /// Corresponds to `LOG_TRACE` in the C implementation.
+    Trace = bindings::LOG_TRACE,
 }
 
 /// A RAII guard for QEMU's logging infrastructure.  Creating the guard

-- 
2.47.2

[PATCH RFC 3/5] rust/qemu-api-macros: Add #[trace_events] macro

[Manos Pitsidianakis]

WIP

Add attribute macro that converts a module definition into trace events.

Currently it allocates a string to pass to
::qemu_api::log::LogGuard::log_fmt. If you pass format_args! directly
the arguments are not properly written, might be a bug in the
qemu_api::log implementation.

Signed-off-by: Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
---
 rust/qemu-api-macros/src/lib.rs | 140 +++++++++++++++++++++++++++++++++++++++-
 1 file changed, 137 insertions(+), 3 deletions(-)

diff --git a/rust/qemu-api-macros/src/lib.rs b/rust/qemu-api-macros/src/lib.rs
index b525d89c09e496a1f7f5582dc6d994e318f62bca..7d13b1c195085f1d153514cc01ec5c389160916a 100644
--- a/rust/qemu-api-macros/src/lib.rs
+++ b/rust/qemu-api-macros/src/lib.rs
@@ -3,10 +3,15 @@
 // SPDX-License-Identifier: GPL-2.0-or-later
 
 use proc_macro::TokenStream;
-use quote::quote;
+use quote::{format_ident, quote};
 use syn::{
-    parse_macro_input, parse_quote, punctuated::Punctuated, spanned::Spanned, token::Comma, Data,
-    DeriveInput, Error, Field, Fields, FieldsUnnamed, Ident, Meta, Path, Token, Variant,
+    parse::{Parse, ParseStream},
+    parse_macro_input, parse_quote,
+    punctuated::Punctuated,
+    spanned::Spanned,
+    token::Comma,
+    Data, DeriveInput, Error, Field, Fields, FieldsUnnamed, FnArg, Ident, LitCStr, LitStr, Meta,
+    Path, Token, Variant,
 };
 mod bits;
 use bits::BitsConstInternal;
@@ -263,3 +268,132 @@ pub fn bits_const_internal(ts: TokenStream) -> TokenStream {
         .unwrap_or_else(syn::Error::into_compile_error)
         .into()
 }
+
+#[derive(Debug)]
+struct TraceModule {
+    module_name: syn::Ident,
+    trace_events: Vec<(proc_macro2::TokenStream, syn::Ident)>,
+}
+
+impl Parse for TraceModule {
+    fn parse(input: ParseStream) -> syn::Result<Self> {
+        if input.peek(Token![pub]) {
+            input.parse::<Token![pub]>()?;
+        }
+        input.parse::<Token![mod]>()?;
+        let module_name: Ident = input.parse()?;
+        let braced;
+        _ = syn::braced!(braced in input);
+        let mut trace_events = vec![];
+        while !braced.is_empty() {
+            braced.parse::<Token![fn]>()?;
+            let name = braced.parse::<Ident>()?;
+            let name_cstr = LitCStr::new(
+                &std::ffi::CString::new(name.to_string()).unwrap(),
+                name.span(),
+            );
+            let name_cstr_ident = format_ident!("trace_{name}_name");
+            let arguments_inner;
+            _ = syn::parenthesized!(arguments_inner in braced);
+            let fn_arguments: Punctuated<FnArg, Token![,]> =
+                Punctuated::parse_terminated(&arguments_inner)?;
+            let body;
+            _ = syn::braced!(body in braced);
+            let trace_event_format_str: LitStr = body.parse()?;
+            assert!(body.is_empty(), "{body:?}");
+
+            let trace_macro_ident = format_ident!("trace_{name}");
+            let name_ident = format_ident!("trace_{name}_EVENT");
+            let dstate = format_ident!("TRACE_{name}_DSTATE");
+            let enabled = format_ident!("TRACE_{name}_ENABLED");
+            trace_events.push(
+                (
+                    quote! {
+                        static mut #dstate: u16 = 0;
+                        const #enabled: bool = true;
+                        const #name_cstr_ident: &::std::ffi::CStr = #name_cstr;
+
+                        static mut #name_ident: ::qemu_api::bindings::TraceEvent = ::qemu_api::bindings::TraceEvent {
+                            id: 0,
+                            name: #name_cstr_ident.as_ptr(),
+                            sstate: #enabled,
+                            dstate: &raw mut #dstate,
+                        };
+
+                        macro_rules! #trace_macro_ident {
+                            ($($args:tt)*) => {{
+                                crate::#module_name::#name($($args)*);
+                            }};
+                        }
+                        pub(crate) use #trace_macro_ident;
+
+                        pub fn #name(#fn_arguments) {
+                            if #enabled
+                                && unsafe { ::qemu_api::bindings::trace_events_enabled_count > 0 }
+                            && unsafe { #dstate > 0 }
+                            && unsafe {
+                                (::qemu_api::bindings::qemu_loglevel & (::qemu_api::log::Log::Trace as std::os::raw::c_int)) != 0
+                            } {
+                                _ = ::qemu_api::log::LogGuard::log_fmt(
+                                    format_args!("{}", format!("{} {}\n", stringify!(#name), format_args!(#trace_event_format_str)))
+                                );
+                            }
+                        }
+                    },
+                    name_ident,
+                )
+            );
+        }
+
+        Ok(Self {
+            module_name,
+            trace_events,
+        })
+    }
+}
+
+#[proc_macro_attribute]
+pub fn trace_events(_attr: TokenStream, item: TokenStream) -> TokenStream {
+    let input = parse_macro_input!(item as TraceModule);
+    let TraceModule {
+        module_name,
+        trace_events,
+    } = input;
+    let mut event_names = quote! {};
+    let mut trace_event_impl = quote! {};
+    let tracevents_len = trace_events.len() + 1;
+    for (body, event_name) in trace_events {
+        event_names = quote! {
+            #event_names
+            &raw mut #event_name,
+        };
+        trace_event_impl = quote! {
+            #trace_event_impl
+            #body
+        };
+    }
+
+    quote! {
+        #[macro_use]
+        mod #module_name {
+            #![allow(static_mut_refs)]
+            #![allow(non_upper_case_globals)]
+
+            #trace_event_impl
+
+            #[used]
+            static mut TRACE_EVENTS: [*mut ::qemu_api::bindings::TraceEvent; #tracevents_len] = unsafe {
+                [
+                    #event_names
+                    ::core::ptr::null_mut(),
+                ]
+            };
+
+            ::qemu_api::module_init!(
+                MODULE_INIT_TRACE => unsafe {
+                    ::qemu_api::bindings::trace_event_register_group(TRACE_EVENTS.as_mut_ptr())
+                }
+            );
+        }
+    }.into()
+}

-- 
2.47.2

[PATCH RFC 4/5] rust/pl011: impl Copy, Clone for RegisterOffset

[Manos Pitsidianakis]

Signed-off-by: Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
---
 rust/hw/char/pl011/src/registers.rs | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/rust/hw/char/pl011/src/registers.rs b/rust/hw/char/pl011/src/registers.rs
index 7ececd39f8616e0b1dee999bbe31dc5dc70e209e..3201932daf8f4a71d95374073c4c259698dec2bb 100644
--- a/rust/hw/char/pl011/src/registers.rs
+++ b/rust/hw/char/pl011/src/registers.rs
@@ -16,7 +16,7 @@
 #[doc(alias = "offset")]
 #[allow(non_camel_case_types)]
 #[repr(u64)]
-#[derive(Debug, Eq, PartialEq, qemu_api_macros::TryInto)]
+#[derive(Copy, Clone, Debug, Eq, PartialEq, qemu_api_macros::TryInto)]
 pub enum RegisterOffset {
     /// Data Register
     ///

-- 
2.47.2

[PATCH RFC 5/5] rust/pl011: add trace events

[Manos Pitsidianakis]

Add all C trace events (missing: baudrate)

Signed-off-by: Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
---
 rust/hw/char/pl011/src/device.rs | 28 +++++++++++++++++++++++---
 rust/hw/char/pl011/src/lib.rs    | 43 ++++++++++++++++++++++++++++++++++++++++
 2 files changed, 68 insertions(+), 3 deletions(-)

diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
index ceb71dd99b661b9f4da98f2dbabe18e82142035b..dabb4ffb5ed0b2df388ca266d3b549fe9cf6d7bc 100644
--- a/rust/hw/char/pl011/src/device.rs
+++ b/rust/hw/char/pl011/src/device.rs
@@ -27,7 +27,14 @@
     zeroable::Zeroable,
 };
 
-use crate::registers::{self, Interrupt, RegisterOffset};
+use crate::{
+    registers::{self, Interrupt, RegisterOffset},
+    trace_events::{
+        trace_pl011_can_receive, trace_pl011_fifo_rx_full, trace_pl011_fifo_rx_put,
+        trace_pl011_irq_state, trace_pl011_read, trace_pl011_read_fifo, trace_pl011_receive,
+        trace_pl011_write,
+    },
+};
 
 // TODO: You must disable the UART before any of the control registers are
 // reprogrammed. When the UART is disabled in the middle of transmission or
@@ -305,6 +312,7 @@ fn read_data_register(&mut self, update: &mut bool) -> u32 {
         }
         self.receive_status_error_clear.set_from_data(c);
         *update = true;
+        trace_pl011_read_fifo!(self.read_count, self.fifo_depth());
         u32::from(c)
     }
 
@@ -458,7 +466,9 @@ pub fn fifo_rx_put(&mut self, value: registers::Data) -> bool {
         self.read_fifo[slot] = value;
         self.read_count += 1;
         self.flags.set_receive_fifo_empty(false);
+        trace_pl011_fifo_rx_put!(value.into(), self.read_count, depth);
         if self.read_count == depth {
+            trace_pl011_fifo_rx_full!();
             self.flags.set_receive_fifo_full(true);
         }
 
@@ -554,6 +564,7 @@ fn read(&self, offset: hwaddr, _size: u32) -> u64 {
                     self.update();
                     self.char_backend.accept_input();
                 }
+                trace_pl011_read!(offset, result, field);
                 result.into()
             }
         }
@@ -562,6 +573,7 @@ fn read(&self, offset: hwaddr, _size: u32) -> u64 {
     fn write(&self, offset: hwaddr, value: u64, _size: u32) {
         let mut update_irq = false;
         if let Ok(field) = RegisterOffset::try_from(offset) {
+            trace_pl011_write!(offset, value, field);
             // qemu_chr_fe_write_all() calls into the can_receive
             // callback, so handle writes before entering PL011Registers.
             if field == RegisterOffset::DR {
@@ -589,11 +601,20 @@ fn write(&self, offset: hwaddr, value: u64, _size: u32) {
 
     fn can_receive(&self) -> u32 {
         let regs = self.regs.borrow();
-        // trace_pl011_can_receive(s->lcr, s->read_count, r);
-        regs.fifo_depth() - regs.read_count
+        let fifo_depth = regs.fifo_depth();
+        let fifo_available = fifo_depth - regs.read_count;
+
+        trace_pl011_can_receive!(
+            regs.line_control.into(),
+            regs.read_count,
+            fifo_depth,
+            fifo_available
+        );
+        fifo_available
     }
 
     fn receive(&self, buf: &[u8]) {
+        trace_pl011_receive!(buf.len());
         let mut regs = self.regs.borrow_mut();
         if regs.loopback_enabled() {
             // In loopback mode, the RX input signal is internally disconnected
@@ -642,6 +663,7 @@ fn reset_hold(&self, _type: ResetType) {
     fn update(&self) {
         let regs = self.regs.borrow();
         let flags = regs.int_level & regs.int_enabled;
+        trace_pl011_irq_state!((flags != 0).into());
         for (irq, i) in self.interrupts.iter().zip(IRQMASK) {
             irq.set(flags.any_set(i));
         }
diff --git a/rust/hw/char/pl011/src/lib.rs b/rust/hw/char/pl011/src/lib.rs
index 2b70d2ff5604179b367b91cbcfdbf9480fa30180..ecfbad27c80fc551a2ced2f9cfe2109b9142e26a 100644
--- a/rust/hw/char/pl011/src/lib.rs
+++ b/rust/hw/char/pl011/src/lib.rs
@@ -19,3 +19,46 @@
 
 pub const TYPE_PL011: &::std::ffi::CStr = c"pl011";
 pub const TYPE_PL011_LUMINARY: &::std::ffi::CStr = c"pl011_luminary";
+
+#[qemu_api_macros::trace_events]
+pub mod trace_events {
+    fn pl011_irq_state(level: u32) {
+        "irq state {level}"
+    }
+
+    fn pl011_read(
+        addr: qemu_api::memory::hwaddr,
+        value: u32,
+        regname: crate::registers::RegisterOffset,
+    ) {
+        "addr {addr:#x} value {value:#x} reg {regname:?}"
+    }
+
+    fn pl011_read_fifo(rx_fifo_used: u32, rx_fifo_depth: u32) {
+        "RX FIFO read, used {rx_fifo_used}/{rx_fifo_depth}"
+    }
+
+    fn pl011_write(
+        addr: qemu_api::memory::hwaddr,
+        value: u64,
+        regname: crate::registers::RegisterOffset,
+    ) {
+        "addr {addr:#x} value {value:#x} reg {regname:?}"
+    }
+
+    fn pl011_can_receive(lcr: u32, rx_fifo_used: u32, rx_fifo_depth: u32, rx_fifo_available: u32) {
+        "LCR {lcr:#x}, RX FIFO used {rx_fifo_used}/{rx_fifo_depth}, can_receive {rx_fifo_available} chars"
+    }
+
+    fn pl011_fifo_rx_put(c: u32, read_count: u32, rx_fifo_depth: u32) {
+        "RX FIFO push char [{c:#x}] {read_count}/{rx_fifo_depth} depth used"
+    }
+
+    fn pl011_fifo_rx_full() {
+        "RX FIFO now full, RXFF set"
+    }
+
+    fn pl011_receive(size: usize) {
+        "recv {size} chars"
+    }
+}

-- 
2.47.2

Re: [PATCH RFC 0/5] rust: implement tracing

[Daniel P. Berrangé]

On Mon, Aug 04, 2025 at 04:47:13PM +0300, Manos Pitsidianakis wrote:
> This RFC series contains some simple patches I've been sitting on for
> some months to allow tracing in rust devices in a similar matter to C,
> only it's done via a proc-macro codegen instead of using tracetool
> script or equivalent.

IIUC, this series is only emitting the traces events via the
qemu_log function, and so feels like it is missing the benefit
of tracing, vs the traditional logging framework.

In our RHEL & Fedora distro builds we disable the log backend
and enable dtrace, so that we have fully dynamic tracing and
observability across the kernel, qemu, libvirt and other
components with dtrace integration.



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 :|

Re: [PATCH RFC 0/5] rust: implement tracing

[Manos Pitsidianakis]

On Tue, Aug 5, 2025 at 7:05 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
>
> On Mon, Aug 04, 2025 at 04:47:13PM +0300, Manos Pitsidianakis wrote:
> > This RFC series contains some simple patches I've been sitting on for
> > some months to allow tracing in rust devices in a similar matter to C,
> > only it's done via a proc-macro codegen instead of using tracetool
> > script or equivalent.
>
> IIUC, this series is only emitting the traces events via the
> qemu_log function, and so feels like it is missing the benefit
> of tracing, vs the traditional logging framework.
>
> In our RHEL & Fedora distro builds we disable the log backend
> and enable dtrace, so that we have fully dynamic tracing and
> observability across the kernel, qemu, libvirt and other
> components with dtrace integration.

Hi Daniel,

Thanks for the insight! Do you have any points where I should look at
the trace implementation for how the different backends are supported?

So I think there's already work in progress to support proper tracing
for Rust, I only sent this as a temporary fixup to provide some kind
of parity between C and Rust implementations until a proper, better
solution is available that can replace it.


-- 
Manos Pitsidianakis
Emulation and Virtualization Engineer at Linaro Ltd

Re: [PATCH RFC 0/5] rust: implement tracing

[Daniel P. Berrangé]

On Tue, Aug 05, 2025 at 07:25:39PM +0300, Manos Pitsidianakis wrote:
> On Tue, Aug 5, 2025 at 7:05 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
> >
> > On Mon, Aug 04, 2025 at 04:47:13PM +0300, Manos Pitsidianakis wrote:
> > > This RFC series contains some simple patches I've been sitting on for
> > > some months to allow tracing in rust devices in a similar matter to C,
> > > only it's done via a proc-macro codegen instead of using tracetool
> > > script or equivalent.
> >
> > IIUC, this series is only emitting the traces events via the
> > qemu_log function, and so feels like it is missing the benefit
> > of tracing, vs the traditional logging framework.
> >
> > In our RHEL & Fedora distro builds we disable the log backend
> > and enable dtrace, so that we have fully dynamic tracing and
> > observability across the kernel, qemu, libvirt and other
> > components with dtrace integration.
> 
> Hi Daniel,
> 
> Thanks for the insight! Do you have any points where I should look at
> the trace implementation for how the different backends are supported?
> 
> So I think there's already work in progress to support proper tracing
> for Rust, I only sent this as a temporary fixup to provide some kind
> of parity between C and Rust implementations until a proper, better
> solution is available that can replace it.

Can the rust code not easily consume the existing functions in the
trace.h files generated for the C code as a short-term solution ?

It would not benefit from the code inlining in the same way as C
would, but it would at least give feature parity for tracing with
all the trace backends are available.

Then, we can look at optimizing with a pure rust impl of some
backends at a later date, to regain what we lost from lack of
inlining ?

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 :|

Re: [PATCH RFC 0/5] rust: implement tracing

[Manos Pitsidianakis]

On Tue, Aug 5, 2025 at 7:43 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
>
> On Tue, Aug 05, 2025 at 07:25:39PM +0300, Manos Pitsidianakis wrote:
> > On Tue, Aug 5, 2025 at 7:05 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
> > >
> > > On Mon, Aug 04, 2025 at 04:47:13PM +0300, Manos Pitsidianakis wrote:
> > > > This RFC series contains some simple patches I've been sitting on for
> > > > some months to allow tracing in rust devices in a similar matter to C,
> > > > only it's done via a proc-macro codegen instead of using tracetool
> > > > script or equivalent.
> > >
> > > IIUC, this series is only emitting the traces events via the
> > > qemu_log function, and so feels like it is missing the benefit
> > > of tracing, vs the traditional logging framework.
> > >
> > > In our RHEL & Fedora distro builds we disable the log backend
> > > and enable dtrace, so that we have fully dynamic tracing and
> > > observability across the kernel, qemu, libvirt and other
> > > components with dtrace integration.
> >
> > Hi Daniel,
> >
> > Thanks for the insight! Do you have any points where I should look at
> > the trace implementation for how the different backends are supported?
> >
> > So I think there's already work in progress to support proper tracing
> > for Rust, I only sent this as a temporary fixup to provide some kind
> > of parity between C and Rust implementations until a proper, better
> > solution is available that can replace it.
>
> Can the rust code not easily consume the existing functions in the
> trace.h files generated for the C code as a short-term solution ?
>
> It would not benefit from the code inlining in the same way as C
> would, but it would at least give feature parity for tracing with
> all the trace backends are available.
>
> Then, we can look at optimizing with a pure rust impl of some
> backends at a later date, to regain what we lost from lack of
> inlining ?

It can, but we'd need to add extra intermediate steps to convert the
trace headers into Rust equivalent code, so it's not ideal.

I tried to generate code exactly like the generated trace headers
though, so I'm not sure what is missing to be honest (hence my
previous email question). The generated code generates TraceEvents and
registers them with trace_event_register_group. What else is missing
to support e.g. dtrace?

Thanks in advance,

-- 
Manos Pitsidianakis
Emulation and Virtualization Engineer at Linaro Ltd

Re: [PATCH RFC 0/5] rust: implement tracing

[Daniel P. Berrangé]

On Tue, Aug 05, 2025 at 07:47:39PM +0300, Manos Pitsidianakis wrote:
> On Tue, Aug 5, 2025 at 7:43 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
> >
> > On Tue, Aug 05, 2025 at 07:25:39PM +0300, Manos Pitsidianakis wrote:
> > > On Tue, Aug 5, 2025 at 7:05 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
> > > >
> > > > On Mon, Aug 04, 2025 at 04:47:13PM +0300, Manos Pitsidianakis wrote:
> > > > > This RFC series contains some simple patches I've been sitting on for
> > > > > some months to allow tracing in rust devices in a similar matter to C,
> > > > > only it's done via a proc-macro codegen instead of using tracetool
> > > > > script or equivalent.
> > > >
> > > > IIUC, this series is only emitting the traces events via the
> > > > qemu_log function, and so feels like it is missing the benefit
> > > > of tracing, vs the traditional logging framework.
> > > >
> > > > In our RHEL & Fedora distro builds we disable the log backend
> > > > and enable dtrace, so that we have fully dynamic tracing and
> > > > observability across the kernel, qemu, libvirt and other
> > > > components with dtrace integration.
> > >
> > > Hi Daniel,
> > >
> > > Thanks for the insight! Do you have any points where I should look at
> > > the trace implementation for how the different backends are supported?
> > >
> > > So I think there's already work in progress to support proper tracing
> > > for Rust, I only sent this as a temporary fixup to provide some kind
> > > of parity between C and Rust implementations until a proper, better
> > > solution is available that can replace it.
> >
> > Can the rust code not easily consume the existing functions in the
> > trace.h files generated for the C code as a short-term solution ?
> >
> > It would not benefit from the code inlining in the same way as C
> > would, but it would at least give feature parity for tracing with
> > all the trace backends are available.
> >
> > Then, we can look at optimizing with a pure rust impl of some
> > backends at a later date, to regain what we lost from lack of
> > inlining ?
> 
> It can, but we'd need to add extra intermediate steps to convert the
> trace headers into Rust equivalent code, so it's not ideal.
> 
> I tried to generate code exactly like the generated trace headers
> though, so I'm not sure what is missing to be honest (hence my
> previous email question). The generated code generates TraceEvents and
> registers them with trace_event_register_group. What else is missing
> to support e.g. dtrace?

'trace_event_register_group' is essentially irrelevant for the
fully dynamic trace backends like dtrace - that's only used for
the backends whose output is controlled by QEMU monitor commands
/ command line arguments.

In the dtrace case the binary gets instructions which are a squence
of nops normally, and dtrace tool gets the kernel to live patch the
binary at runtime to put in a jump for any probes that are being
watched.

Take a look at the generated files <build-dir>/trace/trace-*.h when
using the different '--enable-trace-backends=...' options.

eg taking the trace-crypto.h header, with 'log' backend we see it
emits

   if (trace_event_get_state(TRACE_QCRYPTO_TLS_SESSION_CHECK_CREDS) && qemu_loglevel_mask(LOG_TRACE)) {
#line 23 "../crypto/trace-events"
        qemu_log("qcrypto_tls_session_check_creds " "TLS session check creds session=%p status=%s" "\n", session, status);
#line 372 "trace/trace-crypto.h"
    }

but with dtrace it emits

    QEMU_QCRYPTO_TLS_SESSION_CHECK_CREDS(session, status);

which is a referencing a macro created by the external 'dtrace' binary,
which in the Linux case ends up looking like

  #if defined STAP_SDT_V1
  #define QEMU_QCRYPTO_TLS_SESSION_CHECK_CREDS_ENABLED() __builtin_expect (qcrypto_tls_session_check_creds_semaphore, 0)
  #define qemu_qcrypto_tls_session_check_creds_semaphore qcrypto_tls_session_check_creds_semaphore
  #else
  #define QEMU_QCRYPTO_TLS_SESSION_CHECK_CREDS_ENABLED() __builtin_expect (qemu_qcrypto_tls_session_check_creds_semaphore, 0)
  #endif
  __extension__ extern unsigned short qemu_qcrypto_tls_session_check_creds_semaphore __attribute__ ((unused)) __attribute__ ((section (".probes")));
  #define QEMU_QCRYPTO_TLS_SESSION_CHECK_CREDS(arg1, arg2) \
  DTRACE_PROBE2 (qemu, qcrypto_tls_session_check_creds, arg1, arg2)

you can end up enabling multiple trace backends concurrently too.

If you're thinking this is all rather complicated, you'd be right,
which is why for initial feature parity I figured the simplest is
likely to just wrap the existing QEMU inline probe function, so
Rust doesn't need to know about the different backends... yet...

FWIW, the original DTrace authors created a Rust crate with native
rust integration of dynamic probes.

  https://github.com/oxidecomputer/usdt

I think that (somehow) we probably want to integrate that with QEMU
and its tracetool.

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 :|

Re: [PATCH RFC 0/5] rust: implement tracing

[Manos Pitsidianakis]

Hello Daniel,


Thanks very much for the write up, I think I understand it a lot better now :)

On Tue, Aug 5, 2025 at 8:54 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
>
> On Tue, Aug 05, 2025 at 07:47:39PM +0300, Manos Pitsidianakis wrote:
> > On Tue, Aug 5, 2025 at 7:43 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
> > >
> > > On Tue, Aug 05, 2025 at 07:25:39PM +0300, Manos Pitsidianakis wrote:
> > > > On Tue, Aug 5, 2025 at 7:05 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
> > > > >
> > > > > On Mon, Aug 04, 2025 at 04:47:13PM +0300, Manos Pitsidianakis wrote:
> > > > > > This RFC series contains some simple patches I've been sitting on for
> > > > > > some months to allow tracing in rust devices in a similar matter to C,
> > > > > > only it's done via a proc-macro codegen instead of using tracetool
> > > > > > script or equivalent.
> > > > >
> > > > > IIUC, this series is only emitting the traces events via the
> > > > > qemu_log function, and so feels like it is missing the benefit
> > > > > of tracing, vs the traditional logging framework.
> > > > >
> > > > > In our RHEL & Fedora distro builds we disable the log backend
> > > > > and enable dtrace, so that we have fully dynamic tracing and
> > > > > observability across the kernel, qemu, libvirt and other
> > > > > components with dtrace integration.
> > > >
> > > > Hi Daniel,
> > > >
> > > > Thanks for the insight! Do you have any points where I should look at
> > > > the trace implementation for how the different backends are supported?
> > > >
> > > > So I think there's already work in progress to support proper tracing
> > > > for Rust, I only sent this as a temporary fixup to provide some kind
> > > > of parity between C and Rust implementations until a proper, better
> > > > solution is available that can replace it.
> > >
> > > Can the rust code not easily consume the existing functions in the
> > > trace.h files generated for the C code as a short-term solution ?
> > >
> > > It would not benefit from the code inlining in the same way as C
> > > would, but it would at least give feature parity for tracing with
> > > all the trace backends are available.
> > >
> > > Then, we can look at optimizing with a pure rust impl of some
> > > backends at a later date, to regain what we lost from lack of
> > > inlining ?
> >
> > It can, but we'd need to add extra intermediate steps to convert the
> > trace headers into Rust equivalent code, so it's not ideal.
> >
> > I tried to generate code exactly like the generated trace headers
> > though, so I'm not sure what is missing to be honest (hence my
> > previous email question). The generated code generates TraceEvents and
> > registers them with trace_event_register_group. What else is missing
> > to support e.g. dtrace?
>
> 'trace_event_register_group' is essentially irrelevant for the
> fully dynamic trace backends like dtrace - that's only used for
> the backends whose output is controlled by QEMU monitor commands
> / command line arguments.
>
> In the dtrace case the binary gets instructions which are a squence
> of nops normally, and dtrace tool gets the kernel to live patch the
> binary at runtime to put in a jump for any probes that are being
> watched.
>
> Take a look at the generated files <build-dir>/trace/trace-*.h when
> using the different '--enable-trace-backends=...' options.
>
> eg taking the trace-crypto.h header, with 'log' backend we see it
> emits
>
>    if (trace_event_get_state(TRACE_QCRYPTO_TLS_SESSION_CHECK_CREDS) && qemu_loglevel_mask(LOG_TRACE)) {
> #line 23 "../crypto/trace-events"
>         qemu_log("qcrypto_tls_session_check_creds " "TLS session check creds session=%p status=%s" "\n", session, status);
> #line 372 "trace/trace-crypto.h"
>     }
>
> but with dtrace it emits
>
>     QEMU_QCRYPTO_TLS_SESSION_CHECK_CREDS(session, status);
>
> which is a referencing a macro created by the external 'dtrace' binary,
> which in the Linux case ends up looking like
>
>   #if defined STAP_SDT_V1
>   #define QEMU_QCRYPTO_TLS_SESSION_CHECK_CREDS_ENABLED() __builtin_expect (qcrypto_tls_session_check_creds_semaphore, 0)
>   #define qemu_qcrypto_tls_session_check_creds_semaphore qcrypto_tls_session_check_creds_semaphore
>   #else
>   #define QEMU_QCRYPTO_TLS_SESSION_CHECK_CREDS_ENABLED() __builtin_expect (qemu_qcrypto_tls_session_check_creds_semaphore, 0)
>   #endif
>   __extension__ extern unsigned short qemu_qcrypto_tls_session_check_creds_semaphore __attribute__ ((unused)) __attribute__ ((section (".probes")));
>   #define QEMU_QCRYPTO_TLS_SESSION_CHECK_CREDS(arg1, arg2) \
>   DTRACE_PROBE2 (qemu, qcrypto_tls_session_check_creds, arg1, arg2)
>
> you can end up enabling multiple trace backends concurrently too.
>
> If you're thinking this is all rather complicated, you'd be right,
> which is why for initial feature parity I figured the simplest is
> likely to just wrap the existing QEMU inline probe function, so
> Rust doesn't need to know about the different backends... yet...

Yes, that indeed makes sense.  Generated C trace headers statically
linked to a standalone trace crate library for each subsystem, that
rust qemu crates can link to in return is the cleanest solution for
this approach IMHO, because doing this kind of codegen via macros
needs interaction with meson to generate the C sources and then run
bindgen all while compiling this one crate which is a single meson lib
target.

It might be possible to generate the equivalent of the C code for each
backend just like this RFC generates only the log backend code, I'll
take a look out of curiosity...

>
> FWIW, the original DTrace authors created a Rust crate with native
> rust integration of dynamic probes.
>
>   https://github.com/oxidecomputer/usdt
>
> I think that (somehow) we probably want to integrate that with QEMU
> and its tracetool.

Re: [PATCH RFC 0/5] rust: implement tracing

[Paolo Bonzini]

On 8/5/25 22:06, Manos Pitsidianakis wrote:
>> If you're thinking this is all rather complicated, you'd be right,
>> which is why for initial feature parity I figured the simplest is
>> likely to just wrap the existing QEMU inline probe function, so
>> Rust doesn't need to know about the different backends... yet...

It's not too hard to add individual backends (other than dtrace---see 
below--and ust which doesn't build for me(*) and I wanted to deprecate). 
  Tanish is pretty close to being able to post initial work.

> Yes, that indeed makes sense.  Generated C trace headers statically
> linked to a standalone trace crate library for each subsystem, that
> rust qemu crates can link to in return is the cleanest solution for
> this approach IMHO, because doing this kind of codegen via macros
> needs interaction with meson to generate the C sources and then run
> bindgen all while compiling this one crate which is a single meson lib
> target.
> 
> It might be possible to generate the equivalent of the C code for each
> backend just like this RFC generates only the log backend code, I'll
> take a look out of curiosity...
>
>> FWIW, the original DTrace authors created a Rust crate with native
>> rust integration of dynamic probes.
>>
>>    https://github.com/oxidecomputer/usdt
>>
>> I think that (somehow) we probably want to integrate that with QEMU
>> and its tracetool.

This unfortunately only works for macOS and Solaris.  It also has quite 
a few dependencies (~25) on other crates.  There is also a "probe" crate 
(https://github.com/cuviper/probe-rs) that is minimal and (currently) 
specific to Linux, which is what I planned to use.

By the way, while I like the idea of using Rust format strings, there 
are parts of tracetool (e.g. format/log_stap.py) that need the printf 
strings, and also backends (e.g. backend/syslog.py) that call into libc 
and therefore need to use printf format strings.  So I think we're stuck.

Paolo

(*) that's because this tracepoint:

visit_type_str(void *v, const char *name, char **obj) "v=%p name=%s obj=%p

incorrectly handles 'char **' as a string.  The breakage has been there 
since 2016, though probably it's only more recent versions of ust that 
actually fail to compile and until then the bug was latent until you 
enabled this tracepoint.  But it seems unlikely that anyone has used the 
ust backend recently.

Re: [PATCH RFC 0/5] rust: implement tracing

[Daniel P. Berrangé]

On Wed, Aug 06, 2025 at 11:02:53AM +0200, Paolo Bonzini wrote:
> On 8/5/25 22:06, Manos Pitsidianakis wrote:
> > > If you're thinking this is all rather complicated, you'd be right,
> > > which is why for initial feature parity I figured the simplest is
> > > likely to just wrap the existing QEMU inline probe function, so
> > > Rust doesn't need to know about the different backends... yet...
> 
> It's not too hard to add individual backends (other than dtrace---see
> below--and ust which doesn't build for me(*) and I wanted to deprecate).
> Tanish is pretty close to being able to post initial work.

If we want to drop some backends that's fine, as IMHO we've got
needlessly many there.

> > Yes, that indeed makes sense.  Generated C trace headers statically
> > linked to a standalone trace crate library for each subsystem, that
> > rust qemu crates can link to in return is the cleanest solution for
> > this approach IMHO, because doing this kind of codegen via macros
> > needs interaction with meson to generate the C sources and then run
> > bindgen all while compiling this one crate which is a single meson lib
> > target.
> > 
> > It might be possible to generate the equivalent of the C code for each
> > backend just like this RFC generates only the log backend code, I'll
> > take a look out of curiosity...
> > 
> > > FWIW, the original DTrace authors created a Rust crate with native
> > > rust integration of dynamic probes.
> > > 
> > >    https://github.com/oxidecomputer/usdt
> > > 
> > > I think that (somehow) we probably want to integrate that with QEMU
> > > and its tracetool.
> 
> This unfortunately only works for macOS and Solaris.  It also has quite a
> few dependencies (~25) on other crates.  There is also a "probe" crate
> (https://github.com/cuviper/probe-rs) that is minimal and (currently)
> specific to Linux, which is what I planned to use.
> 
> By the way, while I like the idea of using Rust format strings, there are
> parts of tracetool (e.g. format/log_stap.py) that need the printf strings,
> and also backends (e.g. backend/syslog.py) that call into libc and therefore
> need to use printf format strings.  So I think we're stuck.

Note, I would describe our format strings as printf-like/light. We certainly
do NOT allow the full range of C library formats, because we need to be able
to pass the format strings to systemtap, which is likewise merely printf-like.

Do don't really do any significant upfront validation on the format specifiers
beyond checking for invalid %m and newlines. In practical terms though the
only things we can use are

  %x %u %d %s %p

with optional 'l', 'll' or 'z' modifiers and digit precision for the int
formats. Anything beyond that will likely fail with systemtap. We ought
to move validation for this to the parsing phase to strongly enforce this
limited syntax.

IOW, in any tracetool format generator for rust, we could fairly easily
translate the format string from printf-like to rust style.

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 :|

Re: [PATCH RFC 0/5] rust: implement tracing

[Manos Pitsidianakis]

On Wed, Aug 6, 2025 at 12:21 PM Daniel P. Berrangé <berrange@redhat.com> wrote:
>
> On Wed, Aug 06, 2025 at 11:02:53AM +0200, Paolo Bonzini wrote:
> > On 8/5/25 22:06, Manos Pitsidianakis wrote:
> > > > If you're thinking this is all rather complicated, you'd be right,
> > > > which is why for initial feature parity I figured the simplest is
> > > > likely to just wrap the existing QEMU inline probe function, so
> > > > Rust doesn't need to know about the different backends... yet...
> >
> > It's not too hard to add individual backends (other than dtrace---see
> > below--and ust which doesn't build for me(*) and I wanted to deprecate).
> > Tanish is pretty close to being able to post initial work.
>
> If we want to drop some backends that's fine, as IMHO we've got
> needlessly many there.
>
> > > Yes, that indeed makes sense.  Generated C trace headers statically
> > > linked to a standalone trace crate library for each subsystem, that
> > > rust qemu crates can link to in return is the cleanest solution for
> > > this approach IMHO, because doing this kind of codegen via macros
> > > needs interaction with meson to generate the C sources and then run
> > > bindgen all while compiling this one crate which is a single meson lib
> > > target.
> > >
> > > It might be possible to generate the equivalent of the C code for each
> > > backend just like this RFC generates only the log backend code, I'll
> > > take a look out of curiosity...
> > >
> > > > FWIW, the original DTrace authors created a Rust crate with native
> > > > rust integration of dynamic probes.
> > > >
> > > >    https://github.com/oxidecomputer/usdt
> > > >
> > > > I think that (somehow) we probably want to integrate that with QEMU
> > > > and its tracetool.
> >
> > This unfortunately only works for macOS and Solaris.  It also has quite a
> > few dependencies (~25) on other crates.  There is also a "probe" crate
> > (https://github.com/cuviper/probe-rs) that is minimal and (currently)
> > specific to Linux, which is what I planned to use.
> >
> > By the way, while I like the idea of using Rust format strings, there are
> > parts of tracetool (e.g. format/log_stap.py) that need the printf strings,
> > and also backends (e.g. backend/syslog.py) that call into libc and thereforepar
> > need to use printf format strings.  So I think we're stuck.
>
> Note, I would describe our format strings as printf-like/light. We certainly
> do NOT allow the full range of C library formats, because we need to be able
> to pass the format strings to systemtap, which is likewise merely printf-like.

That simplifies things in a major way (printf specifiers are so
complex they are turing complete). It'd be trivial to parse and
convert into equivalent Rust formatting if you constraint specifiers
like you say.

>
> Do don't really do any significant upfront validation on the format specifiers
> beyond checking for invalid %m and newlines. In practical terms though the
> only things we can use are
>
>   %x %u %d %s %p
>
> with optional 'l', 'll' or 'z' modifiers and digit precision for the int
> formats. Anything beyond that will likely fail with systemtap. We ought
> to move validation for this to the parsing phase to strongly enforce this
> limited syntax.
>
> IOW, in any tracetool format generator for rust, we could fairly easily
> translate the format string from printf-like to rust style.
>
> 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 :|
>

Re: [PATCH RFC 0/5] rust: implement tracing

[Manos Pitsidianakis]

Hello Paolo,

On Wed, Aug 6, 2025 at 12:03 PM Paolo Bonzini <pbonzini@redhat.com> wrote:
>
> On 8/5/25 22:06, Manos Pitsidianakis wrote:
> >> If you're thinking this is all rather complicated, you'd be right,
> >> which is why for initial feature parity I figured the simplest is
> >> likely to just wrap the existing QEMU inline probe function, so
> >> Rust doesn't need to know about the different backends... yet...
>
> It's not too hard to add individual backends (other than dtrace---see
> below--and ust which doesn't build for me(*) and I wanted to deprecate).
>   Tanish is pretty close to being able to post initial work.

Ack, I look forward to it :) I hope my RFC provides them some
inspiration on what things (not) to do.

Thanks,

>
> > Yes, that indeed makes sense.  Generated C trace headers statically
> > linked to a standalone trace crate library for each subsystem, that
> > rust qemu crates can link to in return is the cleanest solution for
> > this approach IMHO, because doing this kind of codegen via macros
> > needs interaction with meson to generate the C sources and then run
> > bindgen all while compiling this one crate which is a single meson lib
> > target.
> >
> > It might be possible to generate the equivalent of the C code for each
> > backend just like this RFC generates only the log backend code, I'll
> > take a look out of curiosity...
> >
> >> FWIW, the original DTrace authors created a Rust crate with native
> >> rust integration of dynamic probes.
> >>
> >>    https://github.com/oxidecomputer/usdt
> >>
> >> I think that (somehow) we probably want to integrate that with QEMU
> >> and its tracetool.
>
> This unfortunately only works for macOS and Solaris.  It also has quite
> a few dependencies (~25) on other crates.  There is also a "probe" crate
> (https://github.com/cuviper/probe-rs) that is minimal and (currently)
> specific to Linux, which is what I planned to use.
>
> By the way, while I like the idea of using Rust format strings, there
> are parts of tracetool (e.g. format/log_stap.py) that need the printf
> strings, and also backends (e.g. backend/syslog.py) that call into libc
> and therefore need to use printf format strings.  So I think we're stuck.
>
> Paolo
>
> (*) that's because this tracepoint:
>
> visit_type_str(void *v, const char *name, char **obj) "v=%p name=%s obj=%p
>
> incorrectly handles 'char **' as a string.  The breakage has been there
> since 2016, though probably it's only more recent versions of ust that
> actually fail to compile and until then the bug was latent until you
> enabled this tracepoint.  But it seems unlikely that anyone has used the
> ust backend recently.
>

-- 
Manos Pitsidianakis
Emulation and Virtualization Engineer at Linaro Ltd