* [PATCH] Rust: Add tracing and logging support for Rust code
@ 2025-04-01 0:26 saman
2025-04-01 1:00 ` Saman Dehghan
` (2 more replies)
0 siblings, 3 replies; 5+ messages in thread
From: saman @ 2025-04-01 0:26 UTC (permalink / raw)
To: qemu-devel
Cc: Stefan Hajnoczi, qemu-rust, Mads Ynddal, Manos Pitsidianakis,
saman
This change introduces initial support for tracing and logging in Rust-based
QEMU code. As an example, tracing and logging have been implemented in the
pl011 device, which is written in Rust.
- Updated `rust/wrapper.h` to include the `qemu/log.h` and `hw/char/trace.h` header.
- Added log.rs to wrap `qemu_log_mask` and `qemu_log_mask_and_addr`
- Modified `tracetool` scripts to move C function implementation from
header to .c
- Added log and trace in rust version of PL011 device
Future enhancements could include generating idiomatic Rust APIs for tracing
using the tracetool scripts
Signed-off-by: saman <saman@enumclass.cc>
---
include/qemu/log-for-trace.h | 5 +--
rust/hw/char/pl011/src/device.rs | 34 +++++++++++++++---
rust/hw/char/pl011/src/registers.rs | 20 +++++++++++
rust/qemu-api/meson.build | 1 +
rust/qemu-api/src/lib.rs | 1 +
rust/qemu-api/src/log.rs | 54 +++++++++++++++++++++++++++++
rust/wrapper.h | 2 ++
scripts/tracetool/format/c.py | 16 +++++++++
scripts/tracetool/format/h.py | 11 ++----
util/log.c | 5 +++
10 files changed, 131 insertions(+), 18 deletions(-)
create mode 100644 rust/qemu-api/src/log.rs
diff --git a/include/qemu/log-for-trace.h b/include/qemu/log-for-trace.h
index d47c9cd446..ad5cd0dd24 100644
--- a/include/qemu/log-for-trace.h
+++ b/include/qemu/log-for-trace.h
@@ -24,10 +24,7 @@ extern int qemu_loglevel;
#define LOG_TRACE (1 << 15)
/* Returns true if a bit is set in the current loglevel mask */
-static inline bool qemu_loglevel_mask(int mask)
-{
- return (qemu_loglevel & mask) != 0;
-}
+bool qemu_loglevel_mask(int mask);
/* main logging function */
void G_GNUC_PRINTF(1, 2) qemu_log(const char *fmt, ...);
diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
index bf88e0b00a..42385a7bf6 100644
--- a/rust/hw/char/pl011/src/device.rs
+++ b/rust/hw/char/pl011/src/device.rs
@@ -2,15 +2,21 @@
// Author(s): Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
// SPDX-License-Identifier: GPL-2.0-or-later
-use std::{ffi::CStr, mem::size_of, ptr::addr_of_mut};
+use std::{
+ ffi::{CStr, CString},
+ mem::size_of,
+ ptr::addr_of_mut,
+};
use qemu_api::{
chardev::{CharBackend, Chardev, Event},
impl_vmstate_forward,
irq::{IRQState, InterruptSource},
+ log::Mask,
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,7 +304,7 @@ pub(self) fn write(
DMACR => {
self.dmacr = value;
if value & 3 > 0 {
- // qemu_log_mask(LOG_UNIMP, "pl011: DMA not implemented\n");
+ qemu_log_mask!(Mask::log_unimp, "pl011: DMA not implemented\n");
eprintln!("pl011: DMA not implemented");
}
}
@@ -535,11 +541,21 @@ 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!(
+ Mask::log_guest_error,
+ "pl011_read: Bad offset 0x%x\n",
+ offset as i32
+ );
0
}
Ok(field) => {
+ let regname = field.as_str();
let (update_irq, result) = self.regs.borrow_mut().read(field);
+ let c_string = CString::new(regname).expect("CString::new failed");
+ let name_ptr = c_string.as_ptr();
+ unsafe {
+ qemu_api::bindings::trace_pl011_read(offset as u32, result, name_ptr);
+ }
if update_irq {
self.update();
self.char_backend.accept_input();
@@ -576,8 +592,16 @@ 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);
- u32::from(regs.read_count < regs.fifo_depth())
+ let fifo_available = u32::from(regs.read_count < regs.fifo_depth());
+ unsafe {
+ qemu_api::bindings::trace_pl011_can_receive(
+ u32::from(regs.line_control),
+ regs.read_count,
+ regs.fifo_depth().try_into().unwrap(),
+ fifo_available,
+ );
+ }
+ fifo_available
}
fn receive(&self, buf: &[u8]) {
diff --git a/rust/hw/char/pl011/src/registers.rs b/rust/hw/char/pl011/src/registers.rs
index cd92fa2c30..11c085030d 100644
--- a/rust/hw/char/pl011/src/registers.rs
+++ b/rust/hw/char/pl011/src/registers.rs
@@ -72,6 +72,26 @@ pub enum RegisterOffset {
//Reserved = 0x04C,
}
+impl RegisterOffset {
+ pub fn as_str(&self) -> &'static str {
+ match self {
+ RegisterOffset::DR => "DR",
+ RegisterOffset::RSR => "RSR",
+ RegisterOffset::FR => "FR",
+ RegisterOffset::FBRD => "FBRD",
+ RegisterOffset::ILPR => "ILPR",
+ RegisterOffset::IBRD => "IBRD",
+ RegisterOffset::LCR_H => "LCR_H",
+ RegisterOffset::CR => "CR",
+ RegisterOffset::FLS => "FLS",
+ RegisterOffset::IMSC => "IMSC",
+ RegisterOffset::RIS => "RIS",
+ RegisterOffset::MIS => "MIS",
+ RegisterOffset::ICR => "ICR",
+ RegisterOffset::DMACR => "DMACR",
+ }
+ }
+}
/// Receive Status Register / Data Register common error bits
///
/// The `UARTRSR` register is updated only when a read occurs
diff --git a/rust/qemu-api/meson.build b/rust/qemu-api/meson.build
index 858685ddd4..f8eddf7887 100644
--- a/rust/qemu-api/meson.build
+++ b/rust/qemu-api/meson.build
@@ -34,6 +34,7 @@ _qemu_api_rs = static_library(
'src/qom.rs',
'src/sysbus.rs',
'src/timer.rs',
+ 'src/log.rs',
'src/vmstate.rs',
'src/zeroable.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..07e8bceb34
--- /dev/null
+++ b/rust/qemu-api/src/log.rs
@@ -0,0 +1,54 @@
+#[allow(non_camel_case_types)]
+#[repr(u32)]
+pub enum Mask {
+ cpu_log_tb_out_asm = crate::bindings::CPU_LOG_TB_OUT_ASM,
+ cpu_log_tb_in_asm = crate::bindings::CPU_LOG_TB_IN_ASM,
+ cpu_log_tb_op = crate::bindings::CPU_LOG_TB_OP,
+ cpu_log_tb_op_opt = crate::bindings::CPU_LOG_TB_OP_OPT,
+ cpu_log_int = crate::bindings::CPU_LOG_INT,
+ cpu_log_exec = crate::bindings::CPU_LOG_EXEC,
+ cpu_log_pcall = crate::bindings::CPU_LOG_PCALL,
+ cpu_log_tb_cpu = crate::bindings::CPU_LOG_TB_CPU,
+ cpu_log_reset = crate::bindings::CPU_LOG_RESET,
+ log_unimp = crate::bindings::LOG_UNIMP,
+ log_guest_error = crate::bindings::LOG_GUEST_ERROR,
+ cpu_log_mmu = crate::bindings::CPU_LOG_MMU,
+ cpu_log_tb_nochain = crate::bindings::CPU_LOG_TB_NOCHAIN,
+ cpu_log_page = crate::bindings::CPU_LOG_PAGE,
+ cpu_log_tb_op_ind = crate::bindings::CPU_LOG_TB_OP_IND,
+ cpu_log_tb_fpu = crate::bindings::CPU_LOG_TB_FPU,
+ cpu_log_plugin = crate::bindings::CPU_LOG_PLUGIN,
+ log_strace = crate::bindings::LOG_STRACE,
+ log_per_thread = crate::bindings::LOG_PER_THREAD,
+ cpu_log_tb_vpu = crate::bindings::CPU_LOG_TB_VPU,
+ log_tb_op_plugin = crate::bindings::LOG_TB_OP_PLUGIN,
+ log_invalid_mem = crate::bindings::LOG_INVALID_MEM,
+}
+
+#[macro_export]
+macro_rules! qemu_log_mask {
+ ($mask:expr, $fmt:expr $(, $arg:expr)*) => {{
+ let mask: Mask = $mask;
+ unsafe {
+ if $crate::bindings::qemu_loglevel_mask(mask as std::os::raw::c_int) {
+ let format_str = std::ffi::CString::new($fmt).expect("CString::new failed");
+ $crate::bindings::qemu_log(format_str.as_ptr() $(, $arg)*);
+ }
+ }
+ }};
+}
+
+#[macro_export]
+macro_rules! qemu_log_mask_and_addr {
+ ($mask:expr, $addr:expr, $fmt:expr $(, $arg:expr)*) => {{
+ let mask: Mask = $mask;
+ let addr: $crate::bindings::hwaddr = $addr;
+ unsafe {
+ if $crate::bindings::qemu_loglevel_mask(mask as std::os::raw::c_int) &&
+ $crate::bindings::qemu_log_in_addr_range(addr) {
+ let format_str = std::ffi::CString::new($fmt).expect("CString::new failed");
+ $crate::bindings::qemu_log(format_str.as_ptr() $(, $arg)*);
+ }
+ }
+ }};
+}
diff --git a/rust/wrapper.h b/rust/wrapper.h
index d4fec54657..cd2f311d71 100644
--- a/rust/wrapper.h
+++ b/rust/wrapper.h
@@ -64,5 +64,7 @@ typedef enum memory_order {
#include "chardev/char-serial.h"
#include "exec/memattrs.h"
#include "qemu/timer.h"
+#include "qemu/log.h"
#include "exec/address-spaces.h"
#include "hw/char/pl011.h"
+#include "hw/char/trace.h"
diff --git a/scripts/tracetool/format/c.py b/scripts/tracetool/format/c.py
index 69edf0d588..f2d383f89c 100644
--- a/scripts/tracetool/format/c.py
+++ b/scripts/tracetool/format/c.py
@@ -43,6 +43,22 @@ def generate(events, backend, group):
sstate = "TRACE_%s_ENABLED" % e.name.upper(),
dstate = e.api(e.QEMU_DSTATE))
+ cond = "true"
+
+ out('',
+ 'void %(api)s(%(args)s)',
+ '{',
+ ' if (%(cond)s) {',
+ ' %(api_nocheck)s(%(names)s);',
+ ' }',
+ '}',
+ api=e.api(),
+ api_nocheck=e.api(e.QEMU_TRACE_NOCHECK),
+ args=e.args,
+ names=", ".join(e.args.names()),
+ cond=cond
+ )
+
out('TraceEvent *%(group)s_trace_events[] = {',
group = group.lower())
diff --git a/scripts/tracetool/format/h.py b/scripts/tracetool/format/h.py
index ea126b07ea..16b360ae49 100644
--- a/scripts/tracetool/format/h.py
+++ b/scripts/tracetool/format/h.py
@@ -74,17 +74,10 @@ def generate(events, backend, group):
cond = "true"
out('',
- 'static inline void %(api)s(%(args)s)',
- '{',
- ' if (%(cond)s) {',
- ' %(api_nocheck)s(%(names)s);',
- ' }',
- '}',
+ 'void %(api)s(%(args)s);',
api=e.api(),
- api_nocheck=e.api(e.QEMU_TRACE_NOCHECK),
args=e.args,
- names=", ".join(e.args.names()),
- cond=cond)
+ )
backend.generate_end(events, group)
diff --git a/util/log.c b/util/log.c
index b87d399e4c..51f659be0a 100644
--- a/util/log.c
+++ b/util/log.c
@@ -143,6 +143,11 @@ void qemu_log_unlock(FILE *logfile)
}
}
+bool qemu_loglevel_mask(int mask)
+{
+ return (qemu_loglevel & mask) != 0;
+}
+
void qemu_log(const char *fmt, ...)
{
FILE *f = qemu_log_trylock();
--
2.43.0
^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH] Rust: Add tracing and logging support for Rust code
2025-04-01 0:26 [PATCH] Rust: Add tracing and logging support for Rust code saman
@ 2025-04-01 1:00 ` Saman Dehghan
2025-04-01 8:27 ` Daniel P. Berrangé
2025-04-01 19:21 ` Stefan Hajnoczi
2 siblings, 0 replies; 5+ messages in thread
From: Saman Dehghan @ 2025-04-01 1:00 UTC (permalink / raw)
To: qemu-devel
[-- Attachment #1: Type: text/plain, Size: 11986 bytes --]
I saw that `Bernhard Beschow` is working on the same thing. So, please feel free to close my pull request. Thank you :)
---
Saman Dehghan
Replying to qemu-devel@nongnu.org on March 31, 2025, 7:26 PM
From: saman@enumclass.cc
To: qemu-devel@nongnu.org
CC: stefanha@redhat.com, qemu-rust@nongnu.org, mads@ynddal.dk, manos.pitsidianakis@linaro.org, saman@enumclass.cc
Date: March 31, 2025, 7:26 PM
Subject: [PATCH] Rust: Add tracing and logging support for Rust code
This change introduces initial support for tracing and logging in Rust-based
QEMU code. As an example, tracing and logging have been implemented in the
pl011 device, which is written in Rust.
- Updated `rust/wrapper.h` to include the `qemu/log.h` and `hw/char/trace.h` header.
- Added log.rs to wrap `qemu_log_mask` and `qemu_log_mask_and_addr`
- Modified `tracetool` scripts to move C function implementation from
header to .c
- Added log and trace in rust version of PL011 device
Future enhancements could include generating idiomatic Rust APIs for tracing
using the tracetool scripts
Signed-off-by: saman <saman@enumclass.cc>
---
include/qemu/log-for-trace.h | 5 +--
rust/hw/char/pl011/src/device.rs | 34 +++++++++++++++---
rust/hw/char/pl011/src/registers.rs | 20 +++++++++++
rust/qemu-api/meson.build | 1 +
rust/qemu-api/src/lib.rs | 1 +
rust/qemu-api/src/log.rs | 54 +++++++++++++++++++++++++++++
rust/wrapper.h | 2 ++
scripts/tracetool/format/c.py | 16 +++++++++
scripts/tracetool/format/h.py | 11 ++----
util/log.c | 5 +++
10 files changed, 131 insertions(+), 18 deletions(-)
create mode 100644 rust/qemu-api/src/log.rs
diff --git a/include/qemu/log-for-trace.h b/include/qemu/log-for-trace.h
index d47c9cd446..ad5cd0dd24 100644
--- a/include/qemu/log-for-trace.h
+++ b/include/qemu/log-for-trace.h
@@ -24,10 +24,7 @@ extern int qemu_loglevel;
#define LOG_TRACE (1 << 15)
/* Returns true if a bit is set in the current loglevel mask */
-static inline bool qemu_loglevel_mask(int mask)
-{
- return (qemu_loglevel & mask) != 0;
-}
+bool qemu_loglevel_mask(int mask);
/* main logging function */
void G_GNUC_PRINTF(1, 2) qemu_log(const char *fmt, ...);
diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
index bf88e0b00a..42385a7bf6 100644
--- a/rust/hw/char/pl011/src/device.rs
+++ b/rust/hw/char/pl011/src/device.rs
@@ -2,15 +2,21 @@
// Author(s): Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
// SPDX-License-Identifier: GPL-2.0-or-later
-use std::{ffi::CStr, mem::size_of, ptr::addr_of_mut};
+use std::{
+ ffi::{CStr, CString},
+ mem::size_of,
+ ptr::addr_of_mut,
+};
use qemu_api::{
chardev::{CharBackend, Chardev, Event},
impl_vmstate_forward,
irq::{IRQState, InterruptSource},
+ log::Mask,
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,7 +304,7 @@ pub(self) fn write(
DMACR => {
self.dmacr = value;
if value & 3 > 0 {
- // qemu_log_mask(LOG_UNIMP, "pl011: DMA not implemented\n");
+ qemu_log_mask!(Mask::log_unimp, "pl011: DMA not implemented\n");
eprintln!("pl011: DMA not implemented");
}
}
@@ -535,11 +541,21 @@ 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!(
+ Mask::log_guest_error,
+ "pl011_read: Bad offset 0x%x\n",
+ offset as i32
+ );
0
}
Ok(field) => {
+ let regname = field.as_str();
let (update_irq, result) = self.regs.borrow_mut().read(field);
+ let c_string = CString::new(regname).expect("CString::new failed");
+ let name_ptr = c_string.as_ptr();
+ unsafe {
+ qemu_api::bindings::trace_pl011_read(offset as u32, result, name_ptr);
+ }
if update_irq {
self.update();
self.char_backend.accept_input();
@@ -576,8 +592,16 @@ 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);
- u32::from(regs.read_count < regs.fifo_depth())
+ let fifo_available = u32::from(regs.read_count < regs.fifo_depth());
+ unsafe {
+ qemu_api::bindings::trace_pl011_can_receive(
+ u32::from(regs.line_control),
+ regs.read_count,
+ regs.fifo_depth().try_into().unwrap(),
+ fifo_available,
+ );
+ }
+ fifo_available
}
fn receive(&self, buf: &[u8]) {
diff --git a/rust/hw/char/pl011/src/registers.rs b/rust/hw/char/pl011/src/registers.rs
index cd92fa2c30..11c085030d 100644
--- a/rust/hw/char/pl011/src/registers.rs
+++ b/rust/hw/char/pl011/src/registers.rs
@@ -72,6 +72,26 @@ pub enum RegisterOffset {
//Reserved = 0x04C,
}
+impl RegisterOffset {
+ pub fn as_str(&self) -> &'static str {
+ match self {
+ RegisterOffset::DR => "DR",
+ RegisterOffset::RSR => "RSR",
+ RegisterOffset::FR => "FR",
+ RegisterOffset::FBRD => "FBRD",
+ RegisterOffset::ILPR => "ILPR",
+ RegisterOffset::IBRD => "IBRD",
+ RegisterOffset::LCR_H => "LCR_H",
+ RegisterOffset::CR => "CR",
+ RegisterOffset::FLS => "FLS",
+ RegisterOffset::IMSC => "IMSC",
+ RegisterOffset::RIS => "RIS",
+ RegisterOffset::MIS => "MIS",
+ RegisterOffset::ICR => "ICR",
+ RegisterOffset::DMACR => "DMACR",
+ }
+ }
+}
/// Receive Status Register / Data Register common error bits
///
/// The `UARTRSR` register is updated only when a read occurs
diff --git a/rust/qemu-api/meson.build b/rust/qemu-api/meson.build
index 858685ddd4..f8eddf7887 100644
--- a/rust/qemu-api/meson.build
+++ b/rust/qemu-api/meson.build
@@ -34,6 +34,7 @@ _qemu_api_rs = static_library(
'src/qom.rs',
'src/sysbus.rs',
'src/timer.rs',
+ 'src/log.rs',
'src/vmstate.rs',
'src/zeroable.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..07e8bceb34
--- /dev/null
+++ b/rust/qemu-api/src/log.rs
@@ -0,0 +1,54 @@
+#[allow(non_camel_case_types)]
+#[repr(u32)]
+pub enum Mask {
+ cpu_log_tb_out_asm = crate::bindings::CPU_LOG_TB_OUT_ASM,
+ cpu_log_tb_in_asm = crate::bindings::CPU_LOG_TB_IN_ASM,
+ cpu_log_tb_op = crate::bindings::CPU_LOG_TB_OP,
+ cpu_log_tb_op_opt = crate::bindings::CPU_LOG_TB_OP_OPT,
+ cpu_log_int = crate::bindings::CPU_LOG_INT,
+ cpu_log_exec = crate::bindings::CPU_LOG_EXEC,
+ cpu_log_pcall = crate::bindings::CPU_LOG_PCALL,
+ cpu_log_tb_cpu = crate::bindings::CPU_LOG_TB_CPU,
+ cpu_log_reset = crate::bindings::CPU_LOG_RESET,
+ log_unimp = crate::bindings::LOG_UNIMP,
+ log_guest_error = crate::bindings::LOG_GUEST_ERROR,
+ cpu_log_mmu = crate::bindings::CPU_LOG_MMU,
+ cpu_log_tb_nochain = crate::bindings::CPU_LOG_TB_NOCHAIN,
+ cpu_log_page = crate::bindings::CPU_LOG_PAGE,
+ cpu_log_tb_op_ind = crate::bindings::CPU_LOG_TB_OP_IND,
+ cpu_log_tb_fpu = crate::bindings::CPU_LOG_TB_FPU,
+ cpu_log_plugin = crate::bindings::CPU_LOG_PLUGIN,
+ log_strace = crate::bindings::LOG_STRACE,
+ log_per_thread = crate::bindings::LOG_PER_THREAD,
+ cpu_log_tb_vpu = crate::bindings::CPU_LOG_TB_VPU,
+ log_tb_op_plugin = crate::bindings::LOG_TB_OP_PLUGIN,
+ log_invalid_mem = crate::bindings::LOG_INVALID_MEM,
+}
+
+#[macro_export]
+macro_rules! qemu_log_mask {
+ ($mask:expr, $fmt:expr $(, $arg:expr)*) => {{
+ let mask: Mask = $mask;
+ unsafe {
+ if $crate::bindings::qemu_loglevel_mask(mask as std::os::raw::c_int) {
+ let format_str = std::ffi::CString::new($fmt).expect("CString::new failed");
+ $crate::bindings::qemu_log(format_str.as_ptr() $(, $arg)*);
+ }
+ }
+ }};
+}
+
+#[macro_export]
+macro_rules! qemu_log_mask_and_addr {
+ ($mask:expr, $addr:expr, $fmt:expr $(, $arg:expr)*) => {{
+ let mask: Mask = $mask;
+ let addr: $crate::bindings::hwaddr = $addr;
+ unsafe {
+ if $crate::bindings::qemu_loglevel_mask(mask as std::os::raw::c_int) &&
+ $crate::bindings::qemu_log_in_addr_range(addr) {
+ let format_str = std::ffi::CString::new($fmt).expect("CString::new failed");
+ $crate::bindings::qemu_log(format_str.as_ptr() $(, $arg)*);
+ }
+ }
+ }};
+}
diff --git a/rust/wrapper.h b/rust/wrapper.h
index d4fec54657..cd2f311d71 100644
--- a/rust/wrapper.h
+++ b/rust/wrapper.h
@@ -64,5 +64,7 @@ typedef enum memory_order {
#include "chardev/char-serial.h"
#include "exec/memattrs.h"
#include "qemu/timer.h"
+#include "qemu/log.h"
#include "exec/address-spaces.h"
#include "hw/char/pl011.h"
+#include "hw/char/trace.h"
diff --git a/scripts/tracetool/format/c.py b/scripts/tracetool/format/c.py
index 69edf0d588..f2d383f89c 100644
--- a/scripts/tracetool/format/c.py
+++ b/scripts/tracetool/format/c.py
@@ -43,6 +43,22 @@ def generate(events, backend, group):
sstate = "TRACE_%s_ENABLED" % e.name.upper(),
dstate = e.api(e.QEMU_DSTATE))
+ cond = "true"
+
+ out('',
+ 'void %(api)s(%(args)s)',
+ '{',
+ ' if (%(cond)s) {',
+ ' %(api_nocheck)s(%(names)s);',
+ ' }',
+ '}',
+ api=e.api(),
+ api_nocheck=e.api(e.QEMU_TRACE_NOCHECK),
+ args=e.args,
+ names=", ".join(e.args.names()),
+ cond=cond
+ )
+
out('TraceEvent *%(group)s_trace_events[] = {',
group = group.lower())
diff --git a/scripts/tracetool/format/h.py b/scripts/tracetool/format/h.py
index ea126b07ea..16b360ae49 100644
--- a/scripts/tracetool/format/h.py
+++ b/scripts/tracetool/format/h.py
@@ -74,17 +74,10 @@ def generate(events, backend, group):
cond = "true"
out('',
- 'static inline void %(api)s(%(args)s)',
- '{',
- ' if (%(cond)s) {',
- ' %(api_nocheck)s(%(names)s);',
- ' }',
- '}',
+ 'void %(api)s(%(args)s);',
api=e.api(),
- api_nocheck=e.api(e.QEMU_TRACE_NOCHECK),
args=e.args,
- names=", ".join(e.args.names()),
- cond=cond)
+ )
backend.generate_end(events, group)
diff --git a/util/log.c b/util/log.c
index b87d399e4c..51f659be0a 100644
--- a/util/log.c
+++ b/util/log.c
@@ -143,6 +143,11 @@ void qemu_log_unlock(FILE *logfile)
}
}
+bool qemu_loglevel_mask(int mask)
+{
+ return (qemu_loglevel & mask) != 0;
+}
+
void qemu_log(const char *fmt, ...)
{
FILE *f = qemu_log_trylock();
--
2.43.0
[-- Attachment #2: Type: text/html, Size: 15004 bytes --]
^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH] Rust: Add tracing and logging support for Rust code
2025-04-01 0:26 [PATCH] Rust: Add tracing and logging support for Rust code saman
2025-04-01 1:00 ` Saman Dehghan
@ 2025-04-01 8:27 ` Daniel P. Berrangé
2025-04-01 8:39 ` Paolo Bonzini
2025-04-01 19:21 ` Stefan Hajnoczi
2 siblings, 1 reply; 5+ messages in thread
From: Daniel P. Berrangé @ 2025-04-01 8:27 UTC (permalink / raw)
To: saman
Cc: qemu-devel, Stefan Hajnoczi, qemu-rust, Mads Ynddal,
Manos Pitsidianakis
On Mon, Mar 31, 2025 at 07:26:33PM -0500, saman wrote:
> This change introduces initial support for tracing and logging in Rust-based
> QEMU code. As an example, tracing and logging have been implemented in the
> pl011 device, which is written in Rust.
>
> - Updated `rust/wrapper.h` to include the `qemu/log.h` and `hw/char/trace.h` header.
> - Added log.rs to wrap `qemu_log_mask` and `qemu_log_mask_and_addr`
> - Modified `tracetool` scripts to move C function implementation from
> header to .c
> - Added log and trace in rust version of PL011 device
>
> Future enhancements could include generating idiomatic Rust APIs for tracing
> using the tracetool scripts
>
> Signed-off-by: saman <saman@enumclass.cc>
> ---
> include/qemu/log-for-trace.h | 5 +--
> rust/hw/char/pl011/src/device.rs | 34 +++++++++++++++---
> rust/hw/char/pl011/src/registers.rs | 20 +++++++++++
> rust/qemu-api/meson.build | 1 +
> rust/qemu-api/src/lib.rs | 1 +
> rust/qemu-api/src/log.rs | 54 +++++++++++++++++++++++++++++
> rust/wrapper.h | 2 ++
> scripts/tracetool/format/c.py | 16 +++++++++
> scripts/tracetool/format/h.py | 11 ++----
> util/log.c | 5 +++
> 10 files changed, 131 insertions(+), 18 deletions(-)
> create mode 100644 rust/qemu-api/src/log.rs
>
> diff --git a/scripts/tracetool/format/c.py b/scripts/tracetool/format/c.py
> index 69edf0d588..f2d383f89c 100644
> --- a/scripts/tracetool/format/c.py
> +++ b/scripts/tracetool/format/c.py
> @@ -43,6 +43,22 @@ def generate(events, backend, group):
> sstate = "TRACE_%s_ENABLED" % e.name.upper(),
> dstate = e.api(e.QEMU_DSTATE))
>
> + cond = "true"
> +
> + out('',
> + 'void %(api)s(%(args)s)',
> + '{',
> + ' if (%(cond)s) {',
> + ' %(api_nocheck)s(%(names)s);',
> + ' }',
> + '}',
> + api=e.api(),
> + api_nocheck=e.api(e.QEMU_TRACE_NOCHECK),
> + args=e.args,
> + names=", ".join(e.args.names()),
> + cond=cond
> + )
> +
> out('TraceEvent *%(group)s_trace_events[] = {',
> group = group.lower())
>
> diff --git a/scripts/tracetool/format/h.py b/scripts/tracetool/format/h.py
> index ea126b07ea..16b360ae49 100644
> --- a/scripts/tracetool/format/h.py
> +++ b/scripts/tracetool/format/h.py
> @@ -74,17 +74,10 @@ def generate(events, backend, group):
> cond = "true"
>
> out('',
> - 'static inline void %(api)s(%(args)s)',
> - '{',
> - ' if (%(cond)s) {',
> - ' %(api_nocheck)s(%(names)s);',
> - ' }',
> - '}',
> + 'void %(api)s(%(args)s);',
> api=e.api(),
> - api_nocheck=e.api(e.QEMU_TRACE_NOCHECK),
> args=e.args,
> - names=", ".join(e.args.names()),
> - cond=cond)
> + )
>
> backend.generate_end(events, group)
>
This is a non-trivial degradation for the tracing code. The code is
generated in an inline function in the header so that when a probe
point is not active, it has as little overhead as possible - with
some backends it will just a 'nop' instruction. With this change
every probe is turned into a function call with no possiblity to
optimize away this overhead.
IMHO tracing in Rust needs to be done by generating native Rust
code for the (sub)set of trace backends that we care about, and
not attempt to wrap the C trace code from Rust.
With regards,
Daniel
--
|: https://berrange.com -o- https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org -o- https://fstop138.berrange.com :|
|: https://entangle-photo.org -o- https://www.instagram.com/dberrange :|
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] Rust: Add tracing and logging support for Rust code
2025-04-01 8:27 ` Daniel P. Berrangé
@ 2025-04-01 8:39 ` Paolo Bonzini
0 siblings, 0 replies; 5+ messages in thread
From: Paolo Bonzini @ 2025-04-01 8:39 UTC (permalink / raw)
To: Daniel P. Berrangé
Cc: saman, qemu-devel, Stefan Hajnoczi, qemu-rust, Mads Ynddal,
Manos Pitsidianakis
[-- Attachment #1: Type: text/plain, Size: 1480 bytes --]
Il mar 1 apr 2025, 10:27 Daniel P. Berrangé <berrange@redhat.com> ha
scritto:
> This is a non-trivial degradation for the tracing code. The code is
> generated in an inline function in the header so that when a probe
> point is not active, it has as little overhead as possible - with
> some backends it will just a 'nop' instruction. With this change
> every probe is turned into a function call with no possiblity to
> optimize away this overhead.
>
> IMHO tracing in Rust needs to be done by generating native Rust
> code for the (sub)set of trace backends that we care about, and
> not attempt to wrap the C trace code from Rust.
>
A little bit of both. Moving the body of the tracing to a C out-of-line
function is okay: easier than converting printf strings to Rust format
strings and possibly *more* efficient. The condition must remain inline
though.
Also, the focus should be on what the Rust API should look like, not on
throwing some code on the other side of the fence. Introducing a second
language has the risk of introducing massive technical debt, and therefore
requires some design work. Tracing and logging is certainly not a one-patch
task.
Paolo
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 :|
>
>
>
[-- Attachment #2: Type: text/html, Size: 2750 bytes --]
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] Rust: Add tracing and logging support for Rust code
2025-04-01 0:26 [PATCH] Rust: Add tracing and logging support for Rust code saman
2025-04-01 1:00 ` Saman Dehghan
2025-04-01 8:27 ` Daniel P. Berrangé
@ 2025-04-01 19:21 ` Stefan Hajnoczi
2 siblings, 0 replies; 5+ messages in thread
From: Stefan Hajnoczi @ 2025-04-01 19:21 UTC (permalink / raw)
To: saman; +Cc: qemu-devel, qemu-rust, Mads Ynddal, Manos Pitsidianakis
[-- Attachment #1: Type: text/plain, Size: 4949 bytes --]
On Mon, Mar 31, 2025 at 07:26:33PM -0500, saman wrote:
> This change introduces initial support for tracing and logging in Rust-based
> QEMU code. As an example, tracing and logging have been implemented in the
> pl011 device, which is written in Rust.
>
> - Updated `rust/wrapper.h` to include the `qemu/log.h` and `hw/char/trace.h` header.
> - Added log.rs to wrap `qemu_log_mask` and `qemu_log_mask_and_addr`
> - Modified `tracetool` scripts to move C function implementation from
> header to .c
> - Added log and trace in rust version of PL011 device
>
> Future enhancements could include generating idiomatic Rust APIs for tracing
> using the tracetool scripts
>
> Signed-off-by: saman <saman@enumclass.cc>
> ---
> include/qemu/log-for-trace.h | 5 +--
> rust/hw/char/pl011/src/device.rs | 34 +++++++++++++++---
> rust/hw/char/pl011/src/registers.rs | 20 +++++++++++
> rust/qemu-api/meson.build | 1 +
> rust/qemu-api/src/lib.rs | 1 +
> rust/qemu-api/src/log.rs | 54 +++++++++++++++++++++++++++++
> rust/wrapper.h | 2 ++
> scripts/tracetool/format/c.py | 16 +++++++++
> scripts/tracetool/format/h.py | 11 ++----
> util/log.c | 5 +++
> 10 files changed, 131 insertions(+), 18 deletions(-)
> create mode 100644 rust/qemu-api/src/log.rs
>
> diff --git a/include/qemu/log-for-trace.h b/include/qemu/log-for-trace.h
> index d47c9cd446..ad5cd0dd24 100644
> --- a/include/qemu/log-for-trace.h
> +++ b/include/qemu/log-for-trace.h
> @@ -24,10 +24,7 @@ extern int qemu_loglevel;
> #define LOG_TRACE (1 << 15)
>
> /* Returns true if a bit is set in the current loglevel mask */
> -static inline bool qemu_loglevel_mask(int mask)
> -{
> - return (qemu_loglevel & mask) != 0;
> -}
> +bool qemu_loglevel_mask(int mask);
>
> /* main logging function */
> void G_GNUC_PRINTF(1, 2) qemu_log(const char *fmt, ...);
> diff --git a/rust/hw/char/pl011/src/device.rs b/rust/hw/char/pl011/src/device.rs
> index bf88e0b00a..42385a7bf6 100644
> --- a/rust/hw/char/pl011/src/device.rs
> +++ b/rust/hw/char/pl011/src/device.rs
> @@ -2,15 +2,21 @@
> // Author(s): Manos Pitsidianakis <manos.pitsidianakis@linaro.org>
> // SPDX-License-Identifier: GPL-2.0-or-later
>
> -use std::{ffi::CStr, mem::size_of, ptr::addr_of_mut};
> +use std::{
> + ffi::{CStr, CString},
> + mem::size_of,
> + ptr::addr_of_mut,
> +};
>
> use qemu_api::{
> chardev::{CharBackend, Chardev, Event},
> impl_vmstate_forward,
> irq::{IRQState, InterruptSource},
> + log::Mask,
> 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,7 +304,7 @@ pub(self) fn write(
> DMACR => {
> self.dmacr = value;
> if value & 3 > 0 {
> - // qemu_log_mask(LOG_UNIMP, "pl011: DMA not implemented\n");
> + qemu_log_mask!(Mask::log_unimp, "pl011: DMA not implemented\n");
> eprintln!("pl011: DMA not implemented");
> }
> }
> @@ -535,11 +541,21 @@ 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!(
> + Mask::log_guest_error,
> + "pl011_read: Bad offset 0x%x\n",
> + offset as i32
> + );
> 0
> }
> Ok(field) => {
> + let regname = field.as_str();
> let (update_irq, result) = self.regs.borrow_mut().read(field);
> + let c_string = CString::new(regname).expect("CString::new failed");
> + let name_ptr = c_string.as_ptr();
> + unsafe {
> + qemu_api::bindings::trace_pl011_read(offset as u32, result, name_ptr);
> + }
I didn't look closely to see whether CString::new(field.as_str()) boils
down to allocating a new string or just pointing to a NUL-terminated
string constant in the .rodata section of the binary, but this looks
suspicious.
It has the pattern:
...do work to produce trace event arguments...
trace_foo(arg1, arg2, arg3);
Tracing is intended to be as low-overhead as possible when trace events
are disabled but compiled in. The work to produce event arguments must
be done only when the trace event is enabled.
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2025-04-02 0:18 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-04-01 0:26 [PATCH] Rust: Add tracing and logging support for Rust code saman
2025-04-01 1:00 ` Saman Dehghan
2025-04-01 8:27 ` Daniel P. Berrangé
2025-04-01 8:39 ` Paolo Bonzini
2025-04-01 19:21 ` Stefan Hajnoczi
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).