[PATCH 0/2] Initial logging support for Rust

[PATCH 0/2] Initial logging support for Rust

[Bernhard Beschow]

This series introduces a qemu_log_mask!() macro which works similar to the C
version while catering to Rust expectations. It is just a thin wrapper around
qemu_log(). The macro then gets used in the pl011 device which either had its
logging commented out or relied on eprintln!() which can't be silenced by users.

Note that this is my first Rust contribution, so please check if the usage of
`unsafe` is sound.

Bernhard Beschow (2):
  rust/qemu-api: Add initial logging support based on C API
  rust/hw/char/pl011/src/device: Implement logging

 docs/devel/rust.rst              |  1 +
 rust/wrapper.h                   |  2 ++
 rust/hw/char/pl011/src/device.rs | 12 ++++---
 rust/qemu-api/meson.build        |  1 +
 rust/qemu-api/src/lib.rs         |  1 +
 rust/qemu-api/src/log.rs         | 55 ++++++++++++++++++++++++++++++++
 6 files changed, 68 insertions(+), 4 deletions(-)
 create mode 100644 rust/qemu-api/src/log.rs

-- 
2.49.0

[PATCH 1/2] rust/qemu-api: Add initial logging support based on C API

[Bernhard Beschow]

A qemu_log_mask!() macro is provided which expects similar arguments as the C
version. However, the formatting works as one would expect from Rust.

To maximize code reuse the macro is just a thin wrapper around qemu_log().
Also, just the bare minimum of logging masks is provided which should suffice
for the current use case of Rust in QEMU.

Signed-off-by: Bernhard Beschow <shentey@gmail.com>
---
 docs/devel/rust.rst       |  1 +
 rust/wrapper.h            |  2 ++
 rust/qemu-api/meson.build |  1 +
 rust/qemu-api/src/lib.rs  |  1 +
 rust/qemu-api/src/log.rs  | 55 +++++++++++++++++++++++++++++++++++++++
 5 files changed, 60 insertions(+)
 create mode 100644 rust/qemu-api/src/log.rs

diff --git a/docs/devel/rust.rst b/docs/devel/rust.rst
index 88bdec1eb2..bc50216dc6 100644
--- a/docs/devel/rust.rst
+++ b/docs/devel/rust.rst
@@ -187,6 +187,7 @@ module           status
 ``c_str``        complete
 ``errno``        complete
 ``irq``          complete
+``log``          proof of concept
 ``memory``       stable
 ``module``       complete
 ``offset_of``    stable
diff --git a/rust/wrapper.h b/rust/wrapper.h
index d4fec54657..9518face53 100644
--- a/rust/wrapper.h
+++ b/rust/wrapper.h
@@ -48,6 +48,8 @@ typedef enum memory_order {
 #endif /* __CLANG_STDATOMIC_H */
 
 #include "qemu/osdep.h"
+#include "qemu/log.h"
+#include "qemu/log-for-trace.h"
 #include "qemu/module.h"
 #include "qemu-io.h"
 #include "system/system.h"
diff --git a/rust/qemu-api/meson.build b/rust/qemu-api/meson.build
index 858685ddd4..112f6735a9 100644
--- a/rust/qemu-api/meson.build
+++ b/rust/qemu-api/meson.build
@@ -26,6 +26,7 @@ _qemu_api_rs = static_library(
       'src/c_str.rs',
       'src/errno.rs',
       'src/irq.rs',
+      'src/log.rs',
       'src/memory.rs',
       'src/module.rs',
       'src/offset_of.rs',
diff --git a/rust/qemu-api/src/lib.rs b/rust/qemu-api/src/lib.rs
index 05f38b51d3..b54989a243 100644
--- a/rust/qemu-api/src/lib.rs
+++ b/rust/qemu-api/src/lib.rs
@@ -21,6 +21,7 @@
 pub mod chardev;
 pub mod errno;
 pub mod irq;
+pub mod log;
 pub mod memory;
 pub mod module;
 pub mod offset_of;
diff --git a/rust/qemu-api/src/log.rs b/rust/qemu-api/src/log.rs
new file mode 100644
index 0000000000..3103a86efa
--- /dev/null
+++ b/rust/qemu-api/src/log.rs
@@ -0,0 +1,55 @@
+// Copyright 2025 Bernhard Beschow <shentey@gmail.com>
+// SPDX-License-Identifier: GPL-2.0-or-later
+
+pub use crate::bindings::{LOG_GUEST_ERROR, LOG_INVALID_MEM, LOG_UNIMP};
+
+/// A macro to log messages conditionally based on a provided mask.
+///
+/// The `qemu_log_mask` macro checks whether the given mask matches the
+/// current log level and, if so, formats and logs the message.
+///
+/// # Parameters
+///
+/// - `$mask`: The log mask to check. This should be an integer value
+///   indicating the log level mask.
+/// - `$fmt`: A format string following the syntax and rules of the `format!`
+///   macro. It specifies the structure of the log message.
+/// - `$args`: Optional arguments to be interpolated into the format string.
+///
+/// # Example
+///
+/// ```
+/// use qemu_api::log::LOG_GUEST_ERROR;
+///
+/// qemu_log_mask!(
+///     LOG_GUEST_ERROR,
+///     "Address 0x{error_address:x} out of range\n"
+/// );
+/// ```
+///
+/// It is also possible to use printf style:
+///
+/// ```
+/// use qemu_api::log::LOG_GUEST_ERROR;
+///
+/// qemu_log_mask!(
+///     LOG_GUEST_ERROR,
+///     "Address 0x{:x} out of range\n",
+///     error_address
+/// );
+/// ```
+#[macro_export]
+macro_rules! qemu_log_mask {
+    ($mask:expr, $fmt:expr $(, $args:expr)*) => {{
+        if unsafe {
+            (::qemu_api::bindings::qemu_loglevel & ($mask as std::os::raw::c_int)) != 0
+        } {
+            let formatted_string = format!($fmt, $($args),*);
+            let c_string = std::ffi::CString::new(formatted_string).unwrap();
+
+            unsafe {
+                ::qemu_api::bindings::qemu_log(c_string.as_ptr());
+            }
+        }
+    }};
+}
-- 
2.49.0

[PATCH 2/2] rust/hw/char/pl011/src/device: Implement logging

[Bernhard Beschow]

Now that there is logging support in Rust for QEMU, use it in the pl011 device.

Signed-off-by: Bernhard Beschow <shentey@gmail.com>
---
 rust/hw/char/pl011/src/device.rs | 12 ++++++++----
 1 file changed, 8 insertions(+), 4 deletions(-)

diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
index bf88e0b00a..d5470fae11 100644
--- a/rust/hw/char/pl011/src/device.rs
+++ b/rust/hw/char/pl011/src/device.rs
@@ -8,9 +8,11 @@
     chardev::{CharBackend, Chardev, Event},
     impl_vmstate_forward,
     irq::{IRQState, InterruptSource},
+    log::{LOG_GUEST_ERROR, LOG_UNIMP},
     memory::{hwaddr, MemoryRegion, MemoryRegionOps, MemoryRegionOpsBuilder},
     prelude::*,
     qdev::{Clock, ClockEvent, DeviceImpl, DeviceState, Property, ResetType, ResettablePhasesImpl},
+    qemu_log_mask,
     qom::{ObjectImpl, Owned, ParentField},
     static_assert,
     sysbus::{SysBusDevice, SysBusDeviceImpl},
@@ -298,8 +300,7 @@ pub(self) fn write(
             DMACR => {
                 self.dmacr = value;
                 if value & 3 > 0 {
-                    // qemu_log_mask(LOG_UNIMP, "pl011: DMA not implemented\n");
-                    eprintln!("pl011: DMA not implemented");
+                    qemu_log_mask!(LOG_UNIMP, "pl011: DMA not implemented\n");
                 }
             }
         }
@@ -535,7 +536,7 @@ fn read(&self, offset: hwaddr, _size: u32) -> u64 {
                 u64::from(device_id[(offset - 0xfe0) >> 2])
             }
             Err(_) => {
-                // qemu_log_mask(LOG_GUEST_ERROR, "pl011_read: Bad offset 0x%x\n", (int)offset);
+                qemu_log_mask!(LOG_GUEST_ERROR, "pl011_read: Bad offset {offset}\n");
                 0
             }
             Ok(field) => {
@@ -567,7 +568,10 @@ fn write(&self, offset: hwaddr, value: u64, _size: u32) {
                 .borrow_mut()
                 .write(field, value as u32, &self.char_backend);
         } else {
-            eprintln!("write bad offset {offset} value {value}");
+            qemu_log_mask!(
+                LOG_GUEST_ERROR,
+                "pl011_write: Bad offset {offset} value {value}\n"
+            );
         }
         if update_irq {
             self.update();
-- 
2.49.0

Re: [PATCH 2/2] rust/hw/char/pl011/src/device: Implement logging

[Daniel P. Berrangé]

On Sun, Mar 30, 2025 at 10:58:57PM +0200, Bernhard Beschow wrote:
> Now that there is logging support in Rust for QEMU, use it in the pl011 device.
> 
> Signed-off-by: Bernhard Beschow <shentey@gmail.com>
> ---
>  rust/hw/char/pl011/src/device.rs | 12 ++++++++----
>  1 file changed, 8 insertions(+), 4 deletions(-)
> 
> diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
> index bf88e0b00a..d5470fae11 100644
> --- a/rust/hw/char/pl011/src/device.rs
> +++ b/rust/hw/char/pl011/src/device.rs
> @@ -8,9 +8,11 @@
>      chardev::{CharBackend, Chardev, Event},
>      impl_vmstate_forward,
>      irq::{IRQState, InterruptSource},
> +    log::{LOG_GUEST_ERROR, LOG_UNIMP},
>      memory::{hwaddr, MemoryRegion, MemoryRegionOps, MemoryRegionOpsBuilder},
>      prelude::*,
>      qdev::{Clock, ClockEvent, DeviceImpl, DeviceState, Property, ResetType, ResettablePhasesImpl},
> +    qemu_log_mask,
>      qom::{ObjectImpl, Owned, ParentField},
>      static_assert,
>      sysbus::{SysBusDevice, SysBusDeviceImpl},
> @@ -298,8 +300,7 @@ pub(self) fn write(
>              DMACR => {
>                  self.dmacr = value;
>                  if value & 3 > 0 {
> -                    // qemu_log_mask(LOG_UNIMP, "pl011: DMA not implemented\n");
> -                    eprintln!("pl011: DMA not implemented");
> +                    qemu_log_mask!(LOG_UNIMP, "pl011: DMA not implemented\n");
>                  }
>              }
>          }
> @@ -535,7 +536,7 @@ fn read(&self, offset: hwaddr, _size: u32) -> u64 {
>                  u64::from(device_id[(offset - 0xfe0) >> 2])
>              }
>              Err(_) => {
> -                // qemu_log_mask(LOG_GUEST_ERROR, "pl011_read: Bad offset 0x%x\n", (int)offset);
> +                qemu_log_mask!(LOG_GUEST_ERROR, "pl011_read: Bad offset {offset}\n");
>                  0
>              }
>              Ok(field) => {
> @@ -567,7 +568,10 @@ fn write(&self, offset: hwaddr, value: u64, _size: u32) {
>                  .borrow_mut()
>                  .write(field, value as u32, &self.char_backend);
>          } else {
> -            eprintln!("write bad offset {offset} value {value}");
> +            qemu_log_mask!(
> +                LOG_GUEST_ERROR,
> +                "pl011_write: Bad offset {offset} value {value}\n"
> +            );
>          }

General conceptual question .....  I've never understood what the dividing
line is between use of 'qemu_log_mask' and trace points. The latter can be
optionally built to feed into qemu log, as well as the other dynamic trace
backends.

Is there a compelling reason to use 'qemu_log', that isn't acceptable for
trace probe points ?

This is an indirect way of asking whether qemu_log_mask should be exposed
to rust, or would exposing tracing be sufficient ?

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 1/2] rust/qemu-api: Add initial logging support based on C API

[Paolo Bonzini]

On 3/30/25 22:58, Bernhard Beschow wrote:
> A qemu_log_mask!() macro is provided which expects similar arguments as the C
> version. However, the formatting works as one would expect from Rust.
> 
> To maximize code reuse the macro is just a thin wrapper around qemu_log().
> Also, just the bare minimum of logging masks is provided which should suffice
> for the current use case of Rust in QEMU.

It's probably better to use an enum for this.  One possibility is also 
to change the #defines to a C enum, and see which enum translation of 
the several allowed by bindgen is best.

Also, while this is good for now, later on we probably want to 
reimplement logging at a lower level via the std::fmt::Write trait.  But 
that's just for efficiency and your macro is indeed good enough to 
define what the API would look like.  Right now I have a project for 
GSoC that will look at that, and the student can look into it later on.

This means answering the following two questions:

- the mapping the LOG_* constants into Rust

- whether to keep the "qemu" prefix for the API (personal opinion: no)

- whether it makes sense to add more macros such as log_guest_error! or 
log_unimp! for the most common LOG_* values

> +#[macro_export]
> +macro_rules! qemu_log_mask {
> +    ($mask:expr, $fmt:expr $(, $args:expr)*) => {{

Looking at https://doc.rust-lang.org/std/macro.write.html they just use 
$($arg:tt)* for what is passed to format_args! (or in your case 
format!), so we can do the same here too. The main advantage is that it 
allows giving a trailing comma to qemu_log_mask!.

Paolo

> +        if unsafe {
> +            (::qemu_api::bindings::qemu_loglevel & ($mask as std::os::raw::c_int)) != 0
> +        } {
> +            let formatted_string = format!($fmt, $($args),*);
> +            let c_string = std::ffi::CString::new(formatted_string).unwrap();
> +
> +            unsafe {
> +                ::qemu_api::bindings::qemu_log(c_string.as_ptr());
> +            }
> +        }
> +    }};
> +}

Re: [PATCH 1/2] rust/qemu-api: Add initial logging support based on C API

[Bernhard Beschow]

Am 31. März 2025 09:53:41 UTC schrieb Paolo Bonzini <pbonzini@redhat.com>:
>On 3/30/25 22:58, Bernhard Beschow wrote:
>> A qemu_log_mask!() macro is provided which expects similar arguments as the C
>> version. However, the formatting works as one would expect from Rust.
>> 
>> To maximize code reuse the macro is just a thin wrapper around qemu_log().
>> Also, just the bare minimum of logging masks is provided which should suffice
>> for the current use case of Rust in QEMU.
>
>It's probably better to use an enum for this.  One possibility is also to change the #defines to a C enum, and see which enum translation of the several allowed by bindgen is best.

Currently the #defines contain some holes for "private" mask bits. Turning these into an enum without exposing all publicly, and changing the type of qemu_loglevel for consistency, would result in undefined behavior. Or do you suggest to convert just the public #defines into an enum to expose them to Rust, and keep the rest of the C API including the type of qemu_loglevel as is?

There are surely several tradeoffs and/or cleanups possible here, but that's way beyond for what I wanted to achieve -- which is closing a gap between C and Rust. My main goal is just to get my feet wet with Rust.

>
>Also, while this is good for now, later on we probably want to reimplement logging at a lower level via the std::fmt::Write trait.  But that's just for efficiency and your macro is indeed good enough to define what the API would look like.

Can we live with an easy solution then for now? As you suggest below, further abstractions like log_guest_error! can be built on top which further insulates client code from implementation details such as the representation of the mask bits.

> Right now I have a project for GSoC that will look at that, and the student can look into it later on.

Whoops, I didn't intend to spoil the project.

>
>This means answering the following two questions:
>
>- the mapping the LOG_* constants into Rust
>
>- whether to keep the "qemu" prefix for the API (personal opinion: no)
>
>- whether it makes sense to add more macros such as log_guest_error! or log_unimp! for the most common LOG_* values
>
>> +#[macro_export]
>> +macro_rules! qemu_log_mask {
>> +    ($mask:expr, $fmt:expr $(, $args:expr)*) => {{
>
>Looking at https://doc.rust-lang.org/std/macro.write.html they just use $($arg:tt)* for what is passed to format_args! (or in your case format!), so we can do the same here too. The main advantage is that it allows giving a trailing comma to qemu_log_mask!.

Easy to fix. Before proceeding I'd like to see a solution for the topic above.

Best regards,
Bernhard

>
>Paolo
>
>> +        if unsafe {
>> +            (::qemu_api::bindings::qemu_loglevel & ($mask as std::os::raw::c_int)) != 0
>> +        } {
>> +            let formatted_string = format!($fmt, $($args),*);
>> +            let c_string = std::ffi::CString::new(formatted_string).unwrap();
>> +
>> +            unsafe {
>> +                ::qemu_api::bindings::qemu_log(c_string.as_ptr());
>> +            }
>> +        }
>> +    }};
>> +}
>

Re: [PATCH 2/2] rust/hw/char/pl011/src/device: Implement logging

[Bernhard Beschow]

Am 31. März 2025 09:18:05 UTC schrieb "Daniel P. Berrangé" <berrange@redhat.com>:
>On Sun, Mar 30, 2025 at 10:58:57PM +0200, Bernhard Beschow wrote:
>> Now that there is logging support in Rust for QEMU, use it in the pl011 device.
>> 
>> Signed-off-by: Bernhard Beschow <shentey@gmail.com>
>> ---
>>  rust/hw/char/pl011/src/device.rs | 12 ++++++++----
>>  1 file changed, 8 insertions(+), 4 deletions(-)
>> 
>> diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
>> index bf88e0b00a..d5470fae11 100644
>> --- a/rust/hw/char/pl011/src/device.rs
>> +++ b/rust/hw/char/pl011/src/device.rs
>> @@ -8,9 +8,11 @@
>>      chardev::{CharBackend, Chardev, Event},
>>      impl_vmstate_forward,
>>      irq::{IRQState, InterruptSource},
>> +    log::{LOG_GUEST_ERROR, LOG_UNIMP},
>>      memory::{hwaddr, MemoryRegion, MemoryRegionOps, MemoryRegionOpsBuilder},
>>      prelude::*,
>>      qdev::{Clock, ClockEvent, DeviceImpl, DeviceState, Property, ResetType, ResettablePhasesImpl},
>> +    qemu_log_mask,
>>      qom::{ObjectImpl, Owned, ParentField},
>>      static_assert,
>>      sysbus::{SysBusDevice, SysBusDeviceImpl},
>> @@ -298,8 +300,7 @@ pub(self) fn write(
>>              DMACR => {
>>                  self.dmacr = value;
>>                  if value & 3 > 0 {
>> -                    // qemu_log_mask(LOG_UNIMP, "pl011: DMA not implemented\n");
>> -                    eprintln!("pl011: DMA not implemented");
>> +                    qemu_log_mask!(LOG_UNIMP, "pl011: DMA not implemented\n");
>>                  }
>>              }
>>          }
>> @@ -535,7 +536,7 @@ fn read(&self, offset: hwaddr, _size: u32) -> u64 {
>>                  u64::from(device_id[(offset - 0xfe0) >> 2])
>>              }
>>              Err(_) => {
>> -                // qemu_log_mask(LOG_GUEST_ERROR, "pl011_read: Bad offset 0x%x\n", (int)offset);
>> +                qemu_log_mask!(LOG_GUEST_ERROR, "pl011_read: Bad offset {offset}\n");
>>                  0
>>              }
>>              Ok(field) => {
>> @@ -567,7 +568,10 @@ fn write(&self, offset: hwaddr, value: u64, _size: u32) {
>>                  .borrow_mut()
>>                  .write(field, value as u32, &self.char_backend);
>>          } else {
>> -            eprintln!("write bad offset {offset} value {value}");
>> +            qemu_log_mask!(
>> +                LOG_GUEST_ERROR,
>> +                "pl011_write: Bad offset {offset} value {value}\n"
>> +            );
>>          }
>
>General conceptual question .....  I've never understood what the dividing
>line is between use of 'qemu_log_mask' and trace points.

I *think* it's the perspective: If you want to see any issues, regardless of which device, use the -l option, i.e. qemu_log_mask(). If, however, you want to see what a particular device does, use tracepoints.

>The latter can be
>optionally built to feed into qemu log, as well as the other dynamic trace
>backends.

The use of qemu_log() in qemu_log_mask() seems like an implementation detail to me. Theoretically, qemu_log_mask() could use a different backend if this got implemented, and wouldn't require code changes throughout QEMU.

Best regards,
Bernhard

>
>Is there a compelling reason to use 'qemu_log', that isn't acceptable for
>trace probe points ?
>
>This is an indirect way of asking whether qemu_log_mask should be exposed
>to rust, or would exposing tracing be sufficient ?
>
>With regards,
>Daniel

Re: [PATCH 2/2] rust/hw/char/pl011/src/device: Implement logging

[Daniel P. Berrangé]

On Wed, Apr 02, 2025 at 09:33:16AM +0000, Bernhard Beschow wrote:
> 
> 
> Am 31. März 2025 09:18:05 UTC schrieb "Daniel P. Berrangé" <berrange@redhat.com>:
> >On Sun, Mar 30, 2025 at 10:58:57PM +0200, Bernhard Beschow wrote:
> >> Now that there is logging support in Rust for QEMU, use it in the pl011 device.
> >> 
> >> Signed-off-by: Bernhard Beschow <shentey@gmail.com>
> >> ---
> >>  rust/hw/char/pl011/src/device.rs | 12 ++++++++----
> >>  1 file changed, 8 insertions(+), 4 deletions(-)
> >> 
> >> diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
> >> index bf88e0b00a..d5470fae11 100644
> >> --- a/rust/hw/char/pl011/src/device.rs
> >> +++ b/rust/hw/char/pl011/src/device.rs
> >> @@ -8,9 +8,11 @@
> >>      chardev::{CharBackend, Chardev, Event},
> >>      impl_vmstate_forward,
> >>      irq::{IRQState, InterruptSource},
> >> +    log::{LOG_GUEST_ERROR, LOG_UNIMP},
> >>      memory::{hwaddr, MemoryRegion, MemoryRegionOps, MemoryRegionOpsBuilder},
> >>      prelude::*,
> >>      qdev::{Clock, ClockEvent, DeviceImpl, DeviceState, Property, ResetType, ResettablePhasesImpl},
> >> +    qemu_log_mask,
> >>      qom::{ObjectImpl, Owned, ParentField},
> >>      static_assert,
> >>      sysbus::{SysBusDevice, SysBusDeviceImpl},
> >> @@ -298,8 +300,7 @@ pub(self) fn write(
> >>              DMACR => {
> >>                  self.dmacr = value;
> >>                  if value & 3 > 0 {
> >> -                    // qemu_log_mask(LOG_UNIMP, "pl011: DMA not implemented\n");
> >> -                    eprintln!("pl011: DMA not implemented");
> >> +                    qemu_log_mask!(LOG_UNIMP, "pl011: DMA not implemented\n");
> >>                  }
> >>              }
> >>          }
> >> @@ -535,7 +536,7 @@ fn read(&self, offset: hwaddr, _size: u32) -> u64 {
> >>                  u64::from(device_id[(offset - 0xfe0) >> 2])
> >>              }
> >>              Err(_) => {
> >> -                // qemu_log_mask(LOG_GUEST_ERROR, "pl011_read: Bad offset 0x%x\n", (int)offset);
> >> +                qemu_log_mask!(LOG_GUEST_ERROR, "pl011_read: Bad offset {offset}\n");
> >>                  0
> >>              }
> >>              Ok(field) => {
> >> @@ -567,7 +568,10 @@ fn write(&self, offset: hwaddr, value: u64, _size: u32) {
> >>                  .borrow_mut()
> >>                  .write(field, value as u32, &self.char_backend);
> >>          } else {
> >> -            eprintln!("write bad offset {offset} value {value}");
> >> +            qemu_log_mask!(
> >> +                LOG_GUEST_ERROR,
> >> +                "pl011_write: Bad offset {offset} value {value}\n"
> >> +            );
> >>          }
> >
> >General conceptual question .....  I've never understood what the dividing
> >line is between use of 'qemu_log_mask' and trace points.
> 
> I *think* it's the perspective: If you want to see any issues, regardless
> of which device, use the -l option, i.e. qemu_log_mask(). If, however,
> you want to see what a particular device does, use tracepoints.

I guess I'd say that the latter ought to be capable of satisfying the
former use case too, given a suitable trace point selection. If it
can't, then perhaps that's telling us the way we select trace points
is insufficiently expressive ?

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 2/2] rust/hw/char/pl011/src/device: Implement logging

[BALATON Zoltan]

[-- Attachment #1: Type: text/plain, Size: 2005 bytes --]

On Wed, 2 Apr 2025, Bernhard Beschow wrote:
> Am 31. März 2025 09:18:05 UTC schrieb "Daniel P. Berrangé" <berrange@redhat.com>:
>> General conceptual question .....  I've never understood what the dividing
>> line is between use of 'qemu_log_mask' and trace points.
>
> I *think* it's the perspective: If you want to see any issues, 
> regardless of which device, use the -l option, i.e. qemu_log_mask(). If, 
> however, you want to see what a particular device does, use tracepoints.

I'd say that traces are like debug printfs that you don't normally want to 
see but may be interesting for developers for debugging a specific device 
model or QEMU part so you can enable the relevant ones for that device or 
part. Logs are something you want to notify the user or admin about and is 
not tracing internal operation of a device. But there may be some overlap 
as some logs could be converted to traces but they are under log for 
historical reasons as previously there were debug printfs controlled by 
defines in devices that were later converted to traces and logs that could 
be controlled in run time which were used for some traces before trace 
points existed. Then were probably kept as logs just to not change the 
command line because it's easier to type -d in_asm then say -trace 
enable="tcg_in_asm" or something like that.

Regards,
BALATON Zoltan

>> The latter can be
>> optionally built to feed into qemu log, as well as the other dynamic trace
>> backends.
>
> The use of qemu_log() in qemu_log_mask() seems like an implementation detail to me. Theoretically, qemu_log_mask() could use a different backend if this got implemented, and wouldn't require code changes throughout QEMU.
>
> Best regards,
> Bernhard
>
>>
>> Is there a compelling reason to use 'qemu_log', that isn't acceptable for
>> trace probe points ?
>>
>> This is an indirect way of asking whether qemu_log_mask should be exposed
>> to rust, or would exposing tracing be sufficient ?
>>
>> With regards,
>> Daniel
>
>

Re: [PATCH 2/2] rust/hw/char/pl011/src/device: Implement logging

[Bernhard Beschow]

Am 2. April 2025 13:27:53 UTC schrieb "Daniel P. Berrangé" <berrange@redhat.com>:
>On Wed, Apr 02, 2025 at 09:33:16AM +0000, Bernhard Beschow wrote:
>> 
>> 
>> Am 31. März 2025 09:18:05 UTC schrieb "Daniel P. Berrangé" <berrange@redhat.com>:
>> >On Sun, Mar 30, 2025 at 10:58:57PM +0200, Bernhard Beschow wrote:
>> >> Now that there is logging support in Rust for QEMU, use it in the pl011 device.
>> >> 
>> >> Signed-off-by: Bernhard Beschow <shentey@gmail.com>
>> >> ---
>> >>  rust/hw/char/pl011/src/device.rs | 12 ++++++++----
>> >>  1 file changed, 8 insertions(+), 4 deletions(-)
>> >> 
>> >> diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
>> >> index bf88e0b00a..d5470fae11 100644
>> >> --- a/rust/hw/char/pl011/src/device.rs
>> >> +++ b/rust/hw/char/pl011/src/device.rs
>> >> @@ -8,9 +8,11 @@
>> >>      chardev::{CharBackend, Chardev, Event},
>> >>      impl_vmstate_forward,
>> >>      irq::{IRQState, InterruptSource},
>> >> +    log::{LOG_GUEST_ERROR, LOG_UNIMP},
>> >>      memory::{hwaddr, MemoryRegion, MemoryRegionOps, MemoryRegionOpsBuilder},
>> >>      prelude::*,
>> >>      qdev::{Clock, ClockEvent, DeviceImpl, DeviceState, Property, ResetType, ResettablePhasesImpl},
>> >> +    qemu_log_mask,
>> >>      qom::{ObjectImpl, Owned, ParentField},
>> >>      static_assert,
>> >>      sysbus::{SysBusDevice, SysBusDeviceImpl},
>> >> @@ -298,8 +300,7 @@ pub(self) fn write(
>> >>              DMACR => {
>> >>                  self.dmacr = value;
>> >>                  if value & 3 > 0 {
>> >> -                    // qemu_log_mask(LOG_UNIMP, "pl011: DMA not implemented\n");
>> >> -                    eprintln!("pl011: DMA not implemented");
>> >> +                    qemu_log_mask!(LOG_UNIMP, "pl011: DMA not implemented\n");
>> >>                  }
>> >>              }
>> >>          }
>> >> @@ -535,7 +536,7 @@ fn read(&self, offset: hwaddr, _size: u32) -> u64 {
>> >>                  u64::from(device_id[(offset - 0xfe0) >> 2])
>> >>              }
>> >>              Err(_) => {
>> >> -                // qemu_log_mask(LOG_GUEST_ERROR, "pl011_read: Bad offset 0x%x\n", (int)offset);
>> >> +                qemu_log_mask!(LOG_GUEST_ERROR, "pl011_read: Bad offset {offset}\n");
>> >>                  0
>> >>              }
>> >>              Ok(field) => {
>> >> @@ -567,7 +568,10 @@ fn write(&self, offset: hwaddr, value: u64, _size: u32) {
>> >>                  .borrow_mut()
>> >>                  .write(field, value as u32, &self.char_backend);
>> >>          } else {
>> >> -            eprintln!("write bad offset {offset} value {value}");
>> >> +            qemu_log_mask!(
>> >> +                LOG_GUEST_ERROR,
>> >> +                "pl011_write: Bad offset {offset} value {value}\n"
>> >> +            );
>> >>          }
>> >
>> >General conceptual question .....  I've never understood what the dividing
>> >line is between use of 'qemu_log_mask' and trace points.
>> 
>> I *think* it's the perspective: If you want to see any issues, regardless
>> of which device, use the -l option, i.e. qemu_log_mask(). If, however,
>> you want to see what a particular device does, use tracepoints.
>
>I guess I'd say that the latter ought to be capable of satisfying the
>former use case too, given a suitable trace point selection. If it
>can't, then perhaps that's telling us the way we select trace points
>is insufficiently expressive ?

Tracepoints often encode some context in the function name, e.g. the device name and the operation being performed. One could give up this context information in the function names and pass it as arguments to generic trace_unimp() and trace_guest_error() functions. The drawback is that this doesn't provide any advantage over the current logging functionality such as device filtering. That could be achieved by  trace_$device_$operation_{unimp,guest_error} functions which is a convention that has to be enforced manually.

Best regards,
Bernhard

>
>With regards,
>Daniel

Re: [PATCH 1/2] rust/qemu-api: Add initial logging support based on C API

[Bernhard Beschow]

Am 1. April 2025 10:51:06 UTC schrieb Bernhard Beschow <shentey@gmail.com>:
>
>
>Am 31. März 2025 09:53:41 UTC schrieb Paolo Bonzini <pbonzini@redhat.com>:
>>On 3/30/25 22:58, Bernhard Beschow wrote:
>>> A qemu_log_mask!() macro is provided which expects similar arguments as the C
>>> version. However, the formatting works as one would expect from Rust.
>>> 
>>> To maximize code reuse the macro is just a thin wrapper around qemu_log().
>>> Also, just the bare minimum of logging masks is provided which should suffice
>>> for the current use case of Rust in QEMU.
>>
>>It's probably better to use an enum for this.  One possibility is also to change the #defines to a C enum, and see which enum translation of the several allowed by bindgen is best.
>
>Currently the #defines contain some holes for "private" mask bits. Turning these into an enum without exposing all publicly, and changing the type of qemu_loglevel for consistency, would result in undefined behavior. Or do you suggest to convert just the public #defines into an enum to expose them to Rust, and keep the rest of the C API including the type of qemu_loglevel as is?
>
>There are surely several tradeoffs and/or cleanups possible here, but that's way beyond for what I wanted to achieve -- which is closing a gap between C and Rust. My main goal is just to get my feet wet with Rust.
>
>>
>>Also, while this is good for now, later on we probably want to reimplement logging at a lower level via the std::fmt::Write trait.  But that's just for efficiency and your macro is indeed good enough to define what the API would look like.
>
>Can we live with an easy solution then for now? As you suggest below, further abstractions like log_guest_error! can be built on top which further insulates client code from implementation details such as the representation of the mask bits.

Ping

>
>> Right now I have a project for GSoC that will look at that, and the student can look into it later on.
>
>Whoops, I didn't intend to spoil the project.
>
>>
>>This means answering the following two questions:
>>
>>- the mapping the LOG_* constants into Rust
>>
>>- whether to keep the "qemu" prefix for the API (personal opinion: no)
>>
>>- whether it makes sense to add more macros such as log_guest_error! or log_unimp! for the most common LOG_* values
>>
>>> +#[macro_export]
>>> +macro_rules! qemu_log_mask {
>>> +    ($mask:expr, $fmt:expr $(, $args:expr)*) => {{
>>
>>Looking at https://doc.rust-lang.org/std/macro.write.html they just use $($arg:tt)* for what is passed to format_args! (or in your case format!), so we can do the same here too. The main advantage is that it allows giving a trailing comma to qemu_log_mask!.
>
>Easy to fix. Before proceeding I'd like to see a solution for the topic above.
>
>Best regards,
>Bernhard
>
>>
>>Paolo
>>
>>> +        if unsafe {
>>> +            (::qemu_api::bindings::qemu_loglevel & ($mask as std::os::raw::c_int)) != 0
>>> +        } {
>>> +            let formatted_string = format!($fmt, $($args),*);
>>> +            let c_string = std::ffi::CString::new(formatted_string).unwrap();
>>> +
>>> +            unsafe {
>>> +                ::qemu_api::bindings::qemu_log(c_string.as_ptr());
>>> +            }
>>> +        }
>>> +    }};
>>> +}
>>

Re: [PATCH 2/2] rust/hw/char/pl011/src/device: Implement logging

[Peter Maydell]

On Wed, 2 Apr 2025 at 14:28, Daniel P. Berrangé <berrange@redhat.com> wrote:
> On Wed, Apr 02, 2025 at 09:33:16AM +0000, Bernhard Beschow wrote:
> > Am 31. März 2025 09:18:05 UTC schrieb "Daniel P. Berrangé" <berrange@redhat.com>:
> > >General conceptual question .....  I've never understood what the dividing
> > >line is between use of 'qemu_log_mask' and trace points.
> >
> > I *think* it's the perspective: If you want to see any issues, regardless
> > of which device, use the -l option, i.e. qemu_log_mask(). If, however,
> > you want to see what a particular device does, use tracepoints.
>
> I guess I'd say that the latter ought to be capable of satisfying the
> former use case too, given a suitable trace point selection. If it
> can't, then perhaps that's telling us the way we select trace points
> is insufficiently expressive ?

Yeah; you can turn on and off a tracepoint, and you can select
them by wildcard, but there's no categorization of them
(into eg "this is basically the equivalent of a debug printf"
vs "this is something that is a guest error you probably
want to know about"). There's also no way to say "turn on
this logging with one switch, and it will print multiple lines
or more than one thing" (at least not in the spirit of what
the tracepoint API expects; you could have a trace_in_asm
tracepoint that took a "%s" and output whatever you liked as
the string, of course). And debug-logging is more documented:
'-d help' shows what you can turn on and off and has at least
a brief description of what it is you're getting. For tracepoints
you're hoping that the name is vaguely descriptive and also
hoping that the device/subsystem/etc named its tracepoints in
a way that lets you usefully wildcard them.

Also, the qemu_log() logging assumes "we're sending text to
a logfile, we can format e.g. register dumps and disassembly
as arbitrary laid out plaintext". That's fine if your tracepoint
backend is also "we just send the text to a logfile/etc", but
I don't know if all of the tracepoint backends would be so happy
with that.

thanks
-- PMM

Re: [PATCH 2/2] rust/hw/char/pl011/src/device: Implement logging

[Daniel P. Berrangé]

On Fri, May 02, 2025 at 05:48:02PM +0100, Peter Maydell wrote:
> On Wed, 2 Apr 2025 at 14:28, Daniel P. Berrangé <berrange@redhat.com> wrote:
> > On Wed, Apr 02, 2025 at 09:33:16AM +0000, Bernhard Beschow wrote:
> > > Am 31. März 2025 09:18:05 UTC schrieb "Daniel P. Berrangé" <berrange@redhat.com>:
> > > >General conceptual question .....  I've never understood what the dividing
> > > >line is between use of 'qemu_log_mask' and trace points.
> > >
> > > I *think* it's the perspective: If you want to see any issues, regardless
> > > of which device, use the -l option, i.e. qemu_log_mask(). If, however,
> > > you want to see what a particular device does, use tracepoints.
> >
> > I guess I'd say that the latter ought to be capable of satisfying the
> > former use case too, given a suitable trace point selection. If it
> > can't, then perhaps that's telling us the way we select trace points
> > is insufficiently expressive ?
> 
> Yeah; you can turn on and off a tracepoint, and you can select
> them by wildcard, but there's no categorization of them
> (into eg "this is basically the equivalent of a debug printf"
> vs "this is something that is a guest error you probably
> want to know about").

I wonder if there's any value in enhancing the trace support to
let us tag certain probes with some kind of "severity"/"level"
concept, such that when the 'log' trace backend is enabled we
can wire them through to the logging backend with useful
categorization ?

>                        There's also no way to say "turn on
> this logging with one switch, and it will print multiple lines
> or more than one thing" (at least not in the spirit of what
> the tracepoint API expects; you could have a trace_in_asm
> tracepoint that took a "%s" and output whatever you liked as
> the string, of course). And debug-logging is more documented:
> '-d help' shows what you can turn on and off and has at least
> a brief description of what it is you're getting.

IMHO the documentation benefit of '-d help' is somewhat
inconsistent.

I tried a crude grep for different usage of logging

      2 CPU_LOG_EXEC
    122 CPU_LOG_INT
    103 CPU_LOG_MMU
      6 CPU_LOG_PAGE
      1 CPU_LOG_PLUGIN
      8 CPU_LOG_RESET
     10 CPU_LOG_TB_IN_ASM
      4 CPU_LOG_TB_OP
   1715 LOG_GUEST_ERROR
      4 LOG_INVALID_MEM
    753 LOG_UNIMP

So the overwhealming majority of usage is accumulated under
two "catch all" categories - "guest error" and "unimplemented"
with no ability to filter - its all or nothing.

We ought to be able to do a better job at documentation the
trace events than we do today, given we have them in an
easily extractable format and can associate them with
particular files easily.

The 'qemu-trace-stap list' command can list all available
probes in a binary, but it only works for the systemtap
backend. We ought to do better with other backends.

>                                                   For tracepoints
> you're hoping that the name is vaguely descriptive and also
> hoping that the device/subsystem/etc named its tracepoints in
> a way that lets you usefully wildcard them.

Yep, we're somewhat inconsistent in our prefix naming
conventions. It would be nice to try to enforce some
greater standard there, but its hard to do programmatically.

> Also, the qemu_log() logging assumes "we're sending text to
> a logfile, we can format e.g. register dumps and disassembly
> as arbitrary laid out plaintext". That's fine if your tracepoint
> backend is also "we just send the text to a logfile/etc", but
> I don't know if all of the tracepoint backends would be so happy
> with that.

I think emitting multi-line blocks of text probably ought to be
considered out of scope for tracing. The 'log' backend is the
only one where that would be a reasonable semantic match.

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 2/2] rust/hw/char/pl011/src/device: Implement logging

[Peter Maydell]

On Thu, 8 May 2025 at 18:14, Daniel P. Berrangé <berrange@redhat.com> wrote:
>
> On Fri, May 02, 2025 at 05:48:02PM +0100, Peter Maydell wrote:
> > On Wed, 2 Apr 2025 at 14:28, Daniel P. Berrangé <berrange@redhat.com> wrote:
> > > On Wed, Apr 02, 2025 at 09:33:16AM +0000, Bernhard Beschow wrote:
> > > > Am 31. März 2025 09:18:05 UTC schrieb "Daniel P. Berrangé" <berrange@redhat.com>:
> > > > >General conceptual question .....  I've never understood what the dividing
> > > > >line is between use of 'qemu_log_mask' and trace points.
> > > >
> > > > I *think* it's the perspective: If you want to see any issues, regardless
> > > > of which device, use the -l option, i.e. qemu_log_mask(). If, however,
> > > > you want to see what a particular device does, use tracepoints.
> > >
> > > I guess I'd say that the latter ought to be capable of satisfying the
> > > former use case too, given a suitable trace point selection. If it
> > > can't, then perhaps that's telling us the way we select trace points
> > > is insufficiently expressive ?
> >
> > Yeah; you can turn on and off a tracepoint, and you can select
> > them by wildcard, but there's no categorization of them
> > (into eg "this is basically the equivalent of a debug printf"
> > vs "this is something that is a guest error you probably
> > want to know about").
>
> I wonder if there's any value in enhancing the trace support to
> let us tag certain probes with some kind of "severity"/"level"
> concept, such that when the 'log' trace backend is enabled we
> can wire them through to the logging backend with useful
> categorization ?

If we wanted to merge the two subsystems I think we'd need that;
and also a "kind of log" tagging.

> >                        There's also no way to say "turn on
> > this logging with one switch, and it will print multiple lines
> > or more than one thing" (at least not in the spirit of what
> > the tracepoint API expects; you could have a trace_in_asm
> > tracepoint that took a "%s" and output whatever you liked as
> > the string, of course). And debug-logging is more documented:
> > '-d help' shows what you can turn on and off and has at least
> > a brief description of what it is you're getting.
>
> IMHO the documentation benefit of '-d help' is somewhat
> inconsistent.
>
> I tried a crude grep for different usage of logging
>
>       2 CPU_LOG_EXEC
>     122 CPU_LOG_INT
>     103 CPU_LOG_MMU
>       6 CPU_LOG_PAGE
>       1 CPU_LOG_PLUGIN
>       8 CPU_LOG_RESET
>      10 CPU_LOG_TB_IN_ASM
>       4 CPU_LOG_TB_OP
>    1715 LOG_GUEST_ERROR
>       4 LOG_INVALID_MEM
>     753 LOG_UNIMP
>
> So the overwhealming majority of usage is accumulated under
> two "catch all" categories - "guest error" and "unimplemented"
> with no ability to filter - its all or nothing.

True, but both those categories are for log messages that
are "in normal operation never happens". So it's not like
the message you're interested in is buried under a ton of
irrelevant logging.

> We ought to be able to do a better job at documentation the
> trace events than we do today, given we have them in an
> easily extractable format and can associate them with
> particular files easily.
>
> The 'qemu-trace-stap list' command can list all available
> probes in a binary, but it only works for the systemtap
> backend. We ought to do better with other backends.

The '-d' backend also lets you list them all with
  qemu-system-arm -d trace:help

> >                                                   For tracepoints
> > you're hoping that the name is vaguely descriptive and also
> > hoping that the device/subsystem/etc named its tracepoints in
> > a way that lets you usefully wildcard them.
>
> Yep, we're somewhat inconsistent in our prefix naming
> conventions. It would be nice to try to enforce some
> greater standard there, but its hard to do programmatically.
>
> > Also, the qemu_log() logging assumes "we're sending text to
> > a logfile, we can format e.g. register dumps and disassembly
> > as arbitrary laid out plaintext". That's fine if your tracepoint
> > backend is also "we just send the text to a logfile/etc", but
> > I don't know if all of the tracepoint backends would be so happy
> > with that.
>
> I think emitting multi-line blocks of text probably ought to be
> considered out of scope for tracing. The 'log' backend is the
> only one where that would be a reasonable semantic match.

But it's one of the key things -d does: "-d in_asm" for listing
the input guest instructions is a super common use case, for instance.
If we want to merge qemu_log with tracepoint logs then we need
to have some answer to this.

(Of course, we could leave the two logging/tracing subsystems
the way they are now: there's not really a super strong
motivation for refactoring everything to be able to drop the
qemu_log stuff.)

thanks
-- PMM

Re: [PATCH 1/2] rust/qemu-api: Add initial logging support based on C API

[Paolo Bonzini]

Hi, now that GSoC selection is over I'm back. Sorry for the delay;
Tanish Desai will work mostly on tracing, so logging can remain yours.

On Tue, Apr 8, 2025 at 10:59 PM Bernhard Beschow <shentey@gmail.com> wrote:
> >Currently the #defines contain some holes for "private" mask bits. Turning these into an
> >enum without exposing all publicly, and changing the type of qemu_loglevel for
> >consistency, would result in undefined behavior. Or do you suggest to convert just
> >the public #defines into an enum to expose them to Rust, and keep the rest of
> >the C API including the type of qemu_loglevel as is?

Yes, only in Rust.

> >There are surely several tradeoffs and/or cleanups possible here, but that's way beyond for
> >what I wanted to achieve -- which is closing a gap between C and Rust. My main goal is just
> >to get my feet wet with Rust.

I understand, however there is no point in defining an API and then changing it.

So we need to answer the questions I wrote a few messages ago, namely:

- the mapping the LOG_* constants into Rust (e.g. whether to keep the
uppercase SNAKE_CASE or switch to something like Log::GuestError).

- whether to keep the "qemu" prefix for the API (personal opinion: no)

I agree with not having macros such as log_guest_error! for now, or
not wrapping functions like qemu_log_trylock/qemu_log_unlock that
would be implemented as RAII (i.e. returning a "guard" object) in
Rust.

> >>Also, while this is good for now, later on we probably want to reimplement logging at a lower level via the std::fmt::Write trait.  But that's just for efficiency and your macro is indeed good enough to define what the API would look like.
> >
> >Can we live with an easy solution then for now? As you suggest below, further abstractions like log_guest_error! can be built on top which further insulates client code from implementation details such as the representation of the mask bits.

Yes, of course.

Paolo

Re: [PATCH 1/2] rust/qemu-api: Add initial logging support based on C API

[Manos Pitsidianakis]

Hello Paolo, Bernhard,

On Mon, May 12, 2025 at 6:32 PM Paolo Bonzini <pbonzini@redhat.com> wrote:
>
> Hi, now that GSoC selection is over I'm back. Sorry for the delay;
> Tanish Desai will work mostly on tracing, so logging can remain yours.
>
> On Tue, Apr 8, 2025 at 10:59 PM Bernhard Beschow <shentey@gmail.com> wrote:
> > >Currently the #defines contain some holes for "private" mask bits. Turning these into an
> > >enum without exposing all publicly, and changing the type of qemu_loglevel for
> > >consistency, would result in undefined behavior. Or do you suggest to convert just
> > >the public #defines into an enum to expose them to Rust, and keep the rest of
> > >the C API including the type of qemu_loglevel as is?
>
> Yes, only in Rust.
>
> > >There are surely several tradeoffs and/or cleanups possible here, but that's way beyond for
> > >what I wanted to achieve -- which is closing a gap between C and Rust. My main goal is just
> > >to get my feet wet with Rust.
>
> I understand, however there is no point in defining an API and then changing it.
>
> So we need to answer the questions I wrote a few messages ago, namely:
>
> - the mapping the LOG_* constants into Rust (e.g. whether to keep the
> uppercase SNAKE_CASE or switch to something like Log::GuestError).
>
> - whether to keep the "qemu" prefix for the API (personal opinion: no)
>
> I agree with not having macros such as log_guest_error! for now, or
> not wrapping functions like qemu_log_trylock/qemu_log_unlock that
> would be implemented as RAII (i.e. returning a "guard" object) in
> Rust.
>
> > >>Also, while this is good for now, later on we probably want to reimplement logging at a lower level via the std::fmt::Write trait.  But that's just for efficiency and your macro is indeed good enough to define what the API would look like.
> > >
> > >Can we live with an easy solution then for now? As you suggest below, further abstractions like log_guest_error! can be built on top which further insulates client code from implementation details such as the representation of the mask bits.
>
> Yes, of course.
>
> Paolo


There's also the `tracing` framework
https://docs.rs/tracing/latest/tracing/ that is quite nice for
defining tracing events **and** spans for logs. I find it confusing
that it still ties tracing events with log level filters though
(info/warn/error/debug/trace).

Perhaps this is also a good opportunity to restructure QEMU's logging
in general. As was said in other threads about tracing, most log items
are essentially traces, except guest_error, unimp and maybe I'm
missing a few others.

If we align QEMU's general logging to use log levels, we can convert
guest error logs to "Error" level logs of type: "guest", and unimp
logs to "Error" logs of type "unimplemented". Or, "Warn" instead of
"Error". Then, all trace_* items become straightforwardly Trace level
log items.

Then, all we have to do in the Rust side is implement a `tracing`
subscriber that consumes these traces and pushes them into QEMU's C
implementation.


-- 
Manos Pitsidianakis
Emulation and Virtualization Engineer at Linaro Ltd

Re: [PATCH 1/2] rust/qemu-api: Add initial logging support based on C API

[Paolo Bonzini]

On Mon, May 19, 2025 at 10:14 AM Manos Pitsidianakis
<manos.pitsidianakis@linaro.org> wrote:
> There's also the `tracing` framework
> https://docs.rs/tracing/latest/tracing/ that is quite nice for
> defining tracing events **and** spans for logs. I find it confusing
> that it still ties tracing events with log level filters though
> (info/warn/error/debug/trace).

I like the overall look of the tracing crate API a lot. One thing that
I don't like is that it's very string-heavy. In general it seems to
have more overhead than tracetool if you use `Interest::Sometimes`; it
uses Strings for event names and targets but not ids (the default
event name is even "event FILE:LINE" which is not really usable except
for development), making matches (especially "enabled()" checks) slow.
Secondarily, built-in support for fmt::Debug/fmt::Display lets you get
away with not thinking of *which* fields you want to record. But it's
powerful, easy to use and it also has very few dependencies, which is
nice.

> Perhaps this is also a good opportunity to restructure QEMU's logging
> in general. [...]
> If we align QEMU's general logging to use log levels, we can convert
> guest error logs to "Error" level logs of type: "guest", and unimp
> logs to "Error" logs of type "unimplemented". Or, "Warn" instead of
> "Error". Then, all trace_* items become straightforwardly Trace level
> log items.

Focusing for a second on guest and unimp items, do you think that
there would be macros like `guest_error!` and `unimp!` (similar to how
`tracing` has shortcuts `error!` or `warn!`)? If so, we could add them
even now, so that any future changes to the implementation would be
transparent.

> Then, all we have to do in the Rust side is implement a `tracing`
> subscriber that consumes these traces and pushes them into QEMU's C
> implementation.

As I said above, I am a bit worried about performance implications of
having Strings for event names and targets but yes, using the tracing
crate is definitely something to think about! As you say, it provides
an opportunity to add structure to QEMU's logging and maybe we can get
the best of both worlds from both `tracing` and tracetool. Do you
think util/log.c could become a wrapper around event!() and
tracing_subscriber::FmtSubscriber (with log levels based on LOG_*
constants, as you mentioned)? Then the `log` backend for tracetool
could generate Rust code that calls trace!() instead of C code that
calls qemu_log().

Or you could do the same thing to the error_vprintf/error_printf
implementations, and then Rust code could use error! and warn! where C
code uses error_report() and warn_report(). It's a common complaint
that error_report() and warn_report() get lost in logs for example,
and `tracing` could add some structure there.

It could also be a very good starting point for thinking about C->Rust
FFI (i.e. implementing in Rust functionality that is used by C code).

In the meanwhile, another thing that could be done is take inspiration
from the `tracing` API, for example adding an #[instrument] macro to
qemu_api_macros:

impl PL011Registers {
    #[instrument(target = "hw_char", name = "pl011_write",
        fields(offset = offset as u32, value))
    pub(self) fn write(...) { }
}

This way, even if tracetool and trace-events file remain part of the
architecture, the API is more familiar to Rust developers. It'd be a
nice addition to Tanish's work (he's my student that's working on Rust
tracepoints.

Paolo

Re: [PATCH 1/2] rust/qemu-api: Add initial logging support based on C API

[Bernhard Beschow]

Am 12. Mai 2025 15:32:08 UTC schrieb Paolo Bonzini <pbonzini@redhat.com>:
>Hi, now that GSoC selection is over I'm back. Sorry for the delay;
>Tanish Desai will work mostly on tracing, so logging can remain yours.
>
>On Tue, Apr 8, 2025 at 10:59 PM Bernhard Beschow <shentey@gmail.com> wrote:
>> >Currently the #defines contain some holes for "private" mask bits. Turning these into an
>> >enum without exposing all publicly, and changing the type of qemu_loglevel for
>> >consistency, would result in undefined behavior. Or do you suggest to convert just
>> >the public #defines into an enum to expose them to Rust, and keep the rest of
>> >the C API including the type of qemu_loglevel as is?
>
>Yes, only in Rust.
>
>> >There are surely several tradeoffs and/or cleanups possible here, but that's way beyond for
>> >what I wanted to achieve -- which is closing a gap between C and Rust. My main goal is just
>> >to get my feet wet with Rust.
>
>I understand, however there is no point in defining an API and then changing it.
>
>So we need to answer the questions I wrote a few messages ago, namely:
>
>- the mapping the LOG_* constants into Rust (e.g. whether to keep the
>uppercase SNAKE_CASE or switch to something like Log::GuestError).
>
>- whether to keep the "qemu" prefix for the API (personal opinion: no)

Sorry for the long delay, the imx8mp desired my attention.

Paolo, I tried both of your suggestions and found them to be convincing enough that I sent a v2: <https://lore.kernel.org/qemu-devel/20250610202110.2243-1-shentey@gmail.com/T/#t>

Best regards,
Bernhard

>
>I agree with not having macros such as log_guest_error! for now, or
>not wrapping functions like qemu_log_trylock/qemu_log_unlock that
>would be implemented as RAII (i.e. returning a "guard" object) in
>Rust.
>
>> >>Also, while this is good for now, later on we probably want to reimplement logging at a lower level via the std::fmt::Write trait.  But that's just for efficiency and your macro is indeed good enough to define what the API would look like.
>> >
>> >Can we live with an easy solution then for now? As you suggest below, further abstractions like log_guest_error! can be built on top which further insulates client code from implementation details such as the representation of the mask bits.
>
>Yes, of course.
>
>Paolo
>