* [PATCH proxmox v2 1/4] log: replace per layer filtering by one global filter
2026-09-23 11:57 [RFC datacenter-manager/proxmox v2 0/4] log: allow finegrained control logging levels Thomas Ellmenreich
@ 2026-09-23 11:57 ` Thomas Ellmenreich
2026-09-23 11:58 ` [PATCH proxmox v2 2/4] fix #6081: log: replace simple level filter with env filter Thomas Ellmenreich
` (2 subsequent siblings)
3 siblings, 0 replies; 5+ messages in thread
From: Thomas Ellmenreich @ 2026-09-23 11:57 UTC (permalink / raw)
To: pdm-devel; +Cc: Thomas Ellmenreich
Instead of filtering with the global filter on every layer, provide one
global filter once, as described here: [0]
This is also in preparation for filters that either have to be cloned or
cannot be cloned at all, like EnvFilters* [1].
* EnvFilter can be cloned from tracing_subscriber version 0.3.20 onwards.
[0]: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/layer/index.html#global-filtering
[1]: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html
Signed-off-by: Thomas Ellmenreich <t.ellmenreich@proxmox.com>
---
proxmox-log/src/builder.rs | 48 +++++++++------------------
proxmox-log/src/pve_task_formatter.rs | 2 +-
2 files changed, 17 insertions(+), 33 deletions(-)
diff --git a/proxmox-log/src/builder.rs b/proxmox-log/src/builder.rs
index 6fcf1cc9..3108ea29 100644
--- a/proxmox-log/src/builder.rs
+++ b/proxmox-log/src/builder.rs
@@ -1,8 +1,9 @@
use tracing::Level;
use tracing::Metadata;
use tracing::level_filters::LevelFilter;
-use tracing_log::{AsLog, LogTracer};
+use tracing_log::LogTracer;
use tracing_subscriber::Layer;
+use tracing_subscriber::Registry;
use tracing_subscriber::layer::Context;
use tracing_subscriber::layer::Filter;
use tracing_subscriber::layer::SubscriberExt;
@@ -55,9 +56,7 @@ impl<S> Filter<S> for NoWorkerTask {
/// ```
pub struct Logger {
global_log_level: LevelFilter,
- layer: Vec<
- Box<dyn tracing_subscriber::Layer<tracing_subscriber::Registry> + Send + Sync + 'static>,
- >,
+ layer: Vec<Box<dyn Layer<Registry> + Send + Sync + 'static>>,
}
impl Logger {
@@ -76,11 +75,7 @@ impl Logger {
///
/// If the journal cannot be opened, print to stderr instead.
pub fn journald(mut self) -> Logger {
- self.layer.push(
- journald_or_stderr_layer()
- .with_filter(self.global_log_level)
- .boxed(),
- );
+ self.layer.push(journald_or_stderr_layer().boxed());
self
}
@@ -90,12 +85,8 @@ impl Logger {
/// no LogContext exists – which means we are not in a PBS workertask – or the level of the
/// log message is 'ERROR'.
pub fn journald_on_no_workertask(mut self) -> Logger {
- self.layer.push(
- journald_or_stderr_layer()
- .with_filter(NoWorkerTask)
- .with_filter(self.global_log_level)
- .boxed(),
- );
+ self.layer
+ .push(journald_or_stderr_layer().with_filter(NoWorkerTask).boxed());
self
}
@@ -103,8 +94,7 @@ impl Logger {
///
/// Check if a LogContext exists and if it does, print to the corresponding task log file.
pub fn tasklog_pbs(mut self) -> Logger {
- self.layer
- .push(TasklogLayer {}.with_filter(self.global_log_level).boxed());
+ self.layer.push(TasklogLayer.boxed());
self
}
@@ -112,11 +102,7 @@ impl Logger {
///
/// Prints all the events to stderr with the compact format (no level, no timestamp).
pub fn stderr(mut self) -> Logger {
- self.layer.push(
- plain_stderr_layer()
- .with_filter(self.global_log_level)
- .boxed(),
- );
+ self.layer.push(plain_stderr_layer().boxed());
self
}
@@ -126,12 +112,8 @@ impl Logger {
/// triggered if no workertask could be found (no LogContext exists) or the event level is
/// `ERROR`.
pub fn stderr_on_no_workertask(mut self) -> Logger {
- self.layer.push(
- plain_stderr_layer()
- .with_filter(NoWorkerTask)
- .with_filter(self.global_log_level)
- .boxed(),
- );
+ self.layer
+ .push(plain_stderr_layer().with_filter(NoWorkerTask).boxed());
self
}
@@ -141,9 +123,8 @@ impl Logger {
/// e.g.: `DEBUG: event message`.
pub fn stderr_pve(mut self) -> Logger {
let layer = tracing_subscriber::fmt::layer()
- .event_format(PveTaskFormatter {})
+ .event_format(PveTaskFormatter)
.with_writer(std::io::stderr)
- .with_filter(self.global_log_level)
.boxed();
self.layer.push(layer);
self
@@ -153,10 +134,13 @@ impl Logger {
///
/// Also configures the `LogTracer` which will convert all `log` events to tracing events.
pub fn init(self) -> Result<(), anyhow::Error> {
- let registry = tracing_subscriber::registry().with(self.layer);
+ let registry = tracing_subscriber::registry()
+ .with(self.layer)
+ .with(self.global_log_level);
+
tracing::subscriber::set_global_default(registry)?;
- LogTracer::init_with_filter(self.global_log_level.as_log())?;
+ LogTracer::init()?;
Ok(())
}
}
diff --git a/proxmox-log/src/pve_task_formatter.rs b/proxmox-log/src/pve_task_formatter.rs
index e9866a4b..12bc33c8 100644
--- a/proxmox-log/src/pve_task_formatter.rs
+++ b/proxmox-log/src/pve_task_formatter.rs
@@ -8,7 +8,7 @@ use tracing_subscriber::registry::LookupSpan;
/// This custom formatter outputs logs as they are visible in the PVE task log.
///
/// e.g.: "DEBUG: sample message"
-pub struct PveTaskFormatter {}
+pub struct PveTaskFormatter;
impl<C, N> FormatEvent<C, N> for PveTaskFormatter
where
--
2.47.3
^ permalink raw reply related [flat|nested] 5+ messages in thread* [PATCH proxmox v2 2/4] fix #6081: log: replace simple level filter with env filter
2026-09-23 11:57 [RFC datacenter-manager/proxmox v2 0/4] log: allow finegrained control logging levels Thomas Ellmenreich
2026-09-23 11:57 ` [PATCH proxmox v2 1/4] log: replace per layer filtering by one global filter Thomas Ellmenreich
@ 2026-09-23 11:58 ` Thomas Ellmenreich
2026-09-23 11:58 ` [PATCH proxmox v2 3/4] log: add tests to the logger Thomas Ellmenreich
2026-09-23 11:58 ` [PATCH datacenter-manager v2 4/4] api: set REST server debug level based on actual log level Thomas Ellmenreich
3 siblings, 0 replies; 5+ messages in thread
From: Thomas Ellmenreich @ 2026-09-23 11:58 UTC (permalink / raw)
To: pdm-devel; +Cc: Thomas Ellmenreich
Instead of parsing the contents of the environment variable passed to the
Logger as a simple LevelFilter, parse them as an EnvFilter [0]. This is
backwards compatible, as a simple LevelFilter [1] string is parsable as
an EnvFilter.
[0]: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html
[1]: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.LevelFilter.html
Suggested-by: Gabriel Goller <g.goller@proxmox.com>
Fixes: https://bugzilla.proxmox.com/show_bug.cgi?id=6081
Signed-off-by: Thomas Ellmenreich <t.ellmenreich@proxmox.com>
---
proxmox-log/Cargo.toml | 2 +-
proxmox-log/src/builder.rs | 38 ++++++++++++++++++++++++++++++++------
proxmox-log/src/lib.rs | 16 ----------------
3 files changed, 33 insertions(+), 23 deletions(-)
diff --git a/proxmox-log/Cargo.toml b/proxmox-log/Cargo.toml
index 25c36fc4..4abe1b11 100644
--- a/proxmox-log/Cargo.toml
+++ b/proxmox-log/Cargo.toml
@@ -16,7 +16,7 @@ anyhow.workspace = true
nix.workspace = true
tracing.workspace = true
tracing-journald.workspace = true
-tracing-subscriber.workspace = true
+tracing-subscriber = { workspace = true, features = ["env-filter"] }
tracing-log = { workspace = true, features = ["std"] }
tokio = { workspace = true, features = ["rt-multi-thread"] }
diff --git a/proxmox-log/src/builder.rs b/proxmox-log/src/builder.rs
index 3108ea29..9b545603 100644
--- a/proxmox-log/src/builder.rs
+++ b/proxmox-log/src/builder.rs
@@ -2,6 +2,7 @@ use tracing::Level;
use tracing::Metadata;
use tracing::level_filters::LevelFilter;
use tracing_log::LogTracer;
+use tracing_subscriber::EnvFilter;
use tracing_subscriber::Layer;
use tracing_subscriber::Registry;
use tracing_subscriber::layer::Context;
@@ -9,7 +10,7 @@ use tracing_subscriber::layer::Filter;
use tracing_subscriber::layer::SubscriberExt;
use crate::{
- LogContext, get_env_variable, journald_or_stderr_layer, plain_stderr_layer,
+ LogContext, journald_or_stderr_layer, plain_stderr_layer,
pve_task_formatter::PveTaskFormatter, tasklog_layer::TasklogLayer,
};
///
@@ -55,16 +56,17 @@ impl<S> Filter<S> for NoWorkerTask {
/// # func().expect("failed to init logger");
/// ```
pub struct Logger {
- global_log_level: LevelFilter,
+ global_log_level: EnvFilter,
layer: Vec<Box<dyn Layer<Registry> + Send + Sync + 'static>>,
}
impl Logger {
- /// Create a new LogBuilder with no layers and a default loglevel retrieved from an env
- /// variable. If the env variable cannot be retrieved or the content is not parsable, fallback
- /// to the default_log_level passed.
+ /// Create a new Logger with no layers and a default loglevel retrieved from an env
+ /// variable. If the env variable cannot be retrieved or the content is not parsable,
+ /// fallback to the default_log_level passed.
pub fn from_env(env_var: &str, default_log_level: LevelFilter) -> Logger {
- let log_level = get_env_variable(env_var, default_log_level);
+ let var_content = std::env::var(env_var).ok();
+ let log_level = Self::apply_default_log_level(var_content, default_log_level);
Logger {
global_log_level: log_level,
layer: vec![],
@@ -143,4 +145,28 @@ impl Logger {
LogTracer::init()?;
Ok(())
}
+
+ /// If present, tries to parse the `env_filter_str` as a [`EnvFilter`],
+ /// otherwiese falls back to the provided default log level.
+ ///
+ /// The provided default log level is a application default defined by us.
+ /// The user can define their own default as part of the [`EnvFilter`]
+ ///
+ /// * `env_filter_str` - The log settings that would usually be written into
+ /// a environment variable and then extracted by [`get_env_variable`]
+ /// * `default_log_level` - Default log level used by the [`Logger`] in
+ /// case the log settings are empty.
+ fn apply_default_log_level(
+ env_filter_str: Option<String>,
+ default_log_level: LevelFilter,
+ ) -> EnvFilter {
+ if let Some(env_filter_str) = env_filter_str {
+ match EnvFilter::try_new(env_filter_str) {
+ Ok(filter) => return filter,
+ Err(e) => eprintln!("unable to parse the log env variable: {e:#}"),
+ }
+ }
+ EnvFilter::default().add_directive(default_log_level.into())
+ }
}
+
diff --git a/proxmox-log/src/lib.rs b/proxmox-log/src/lib.rs
index 2d321f20..32c10e27 100644
--- a/proxmox-log/src/lib.rs
+++ b/proxmox-log/src/lib.rs
@@ -1,7 +1,6 @@
#![cfg_attr(docsrs, feature(doc_cfg, doc_auto_cfg))]
#![deny(unsafe_op_in_unsafe_fn)]
-use std::env;
use std::future::Future;
use std::sync::{Arc, Mutex};
@@ -147,21 +146,6 @@ where
.with_writer(std::io::stderr)
}
-fn get_env_variable(env_var: &str, default_log_level: LevelFilter) -> LevelFilter {
- let mut log_level = default_log_level;
- if let Ok(v) = env::var(env_var) {
- match v.parse::<LevelFilter>() {
- Ok(l) => {
- log_level = l;
- }
- Err(e) => {
- eprintln!("env variable {env_var} found, but parsing failed: {e:?}");
- }
- }
- }
- log_level
-}
-
/// Initialize tracing logger that prints to journald or stderr depending on if we are in a pbs
/// task.
///
--
2.47.3
^ permalink raw reply related [flat|nested] 5+ messages in thread* [PATCH proxmox v2 3/4] log: add tests to the logger
2026-09-23 11:57 [RFC datacenter-manager/proxmox v2 0/4] log: allow finegrained control logging levels Thomas Ellmenreich
2026-09-23 11:57 ` [PATCH proxmox v2 1/4] log: replace per layer filtering by one global filter Thomas Ellmenreich
2026-09-23 11:58 ` [PATCH proxmox v2 2/4] fix #6081: log: replace simple level filter with env filter Thomas Ellmenreich
@ 2026-09-23 11:58 ` Thomas Ellmenreich
2026-09-23 11:58 ` [PATCH datacenter-manager v2 4/4] api: set REST server debug level based on actual log level Thomas Ellmenreich
3 siblings, 0 replies; 5+ messages in thread
From: Thomas Ellmenreich @ 2026-09-23 11:58 UTC (permalink / raw)
To: pdm-devel; +Cc: Thomas Ellmenreich
Add tests to ensure consistent functionality when setting the logging
environment variable, as well as global filtering of logs.
Although the EnvFilter itself is not something we should be testing, we are
adding some additional machinery, on top of the extensive functionality
provided by tracing/tracing_subscriber, which does need testing.
Signed-off-by: Thomas Ellmenreich <t.ellmenreich@proxmox.com>
---
proxmox-log/src/builder.rs | 296 ++++++++++++++++++++++++++++++++++++-
1 file changed, 291 insertions(+), 5 deletions(-)
diff --git a/proxmox-log/src/builder.rs b/proxmox-log/src/builder.rs
index 9b545603..05da3643 100644
--- a/proxmox-log/src/builder.rs
+++ b/proxmox-log/src/builder.rs
@@ -1,5 +1,6 @@
use tracing::Level;
use tracing::Metadata;
+use tracing::Subscriber;
use tracing::level_filters::LevelFilter;
use tracing_log::LogTracer;
use tracing_subscriber::EnvFilter;
@@ -10,8 +11,8 @@ use tracing_subscriber::layer::Filter;
use tracing_subscriber::layer::SubscriberExt;
use crate::{
- LogContext, journald_or_stderr_layer, plain_stderr_layer,
- pve_task_formatter::PveTaskFormatter, tasklog_layer::TasklogLayer,
+ LogContext, journald_or_stderr_layer, plain_stderr_layer, pve_task_formatter::PveTaskFormatter,
+ tasklog_layer::TasklogLayer,
};
///
/// Filter yielding `true` *outside* of worker tasks, *unless* the level is `ERROR`.
@@ -136,9 +137,7 @@ impl Logger {
///
/// Also configures the `LogTracer` which will convert all `log` events to tracing events.
pub fn init(self) -> Result<(), anyhow::Error> {
- let registry = tracing_subscriber::registry()
- .with(self.layer)
- .with(self.global_log_level);
+ let registry = self.create_subscriber();
tracing::subscriber::set_global_default(registry)?;
@@ -146,6 +145,15 @@ impl Logger {
Ok(())
}
+ /// Creates the subscriber to be used for the Logger
+ ///
+ /// Placed in its own method to allow easier testing of the subscriber
+ fn create_subscriber(self) -> impl Subscriber {
+ tracing_subscriber::registry()
+ .with(self.layer)
+ .with(self.global_log_level)
+ }
+
/// If present, tries to parse the `env_filter_str` as a [`EnvFilter`],
/// otherwiese falls back to the provided default log level.
///
@@ -170,3 +178,281 @@ impl Logger {
}
}
+#[cfg(test)]
+mod tests {
+ use std::sync::{Arc, Mutex};
+
+ use tracing::level_filters::LevelFilter;
+ use tracing_log::log;
+ use tracing_subscriber::{Layer, util::SubscriberInitExt};
+
+ use crate::Logger;
+
+ /// Modules created for testing purposes. Specifically, to test filtering
+ /// of logs in different modules.
+ mod test_module {
+ pub mod nested_module {
+ pub fn info(message: &'static str) {
+ tracing_log::log::info!("{message}");
+ }
+ }
+ pub fn info(message: &'static str) {
+ tracing_log::log::info!("{message}");
+ }
+ }
+
+ macro_rules! assert_logs {
+ ($events:expr, [$($expected:expr),* $(,)?]) => {{
+ let events = $events.lock().unwrap();
+
+ assert_eq!(events.as_slice(), [$($expected),*]);
+ }};
+ }
+
+ #[test]
+ fn logger_builder_correctly_applies_filter() {
+ // Arrange
+ let (events, builder) = create_logger(Some("WARN"), LevelFilter::INFO);
+ let _guard = builder.create_subscriber().set_default();
+
+ // Act
+ log::info!("log1");
+ log::warn!("log2");
+
+ // Assert
+ assert_logs!(events, ["log2"]);
+ }
+
+ #[test]
+ fn simple_log_is_registered() {
+ // Arrange
+ let (events, _guard) = setup_logging(None, LevelFilter::TRACE);
+
+ // Act
+ log::info!("log1");
+
+ // Assert
+ assert_logs!(events, ["log1"]);
+ }
+
+ #[test]
+ fn env_filter_is_backwards_compatible() {
+ // Arrange
+ let (events, _guard) = setup_logging(Some("ERROR"), LevelFilter::INFO);
+
+ // Act
+ test_module::info("log1");
+ test_module::nested_module::info("log2");
+ log::error!("log3");
+
+ // Assert
+ assert_logs!(events, ["log3"]);
+ }
+
+ #[test]
+ fn only_module_filter_disables_other_logging() {
+ // Arrange
+ let (events, _guard) = setup_logging(
+ Some("proxmox_log::builder::tests::test_module=INFO"),
+ LevelFilter::INFO,
+ );
+
+ // Act
+ test_module::info("log1");
+ test_module::nested_module::info("log2");
+ log::info!("log3");
+
+ // Assert
+ assert_logs!(events, ["log1", "log2"]);
+ }
+
+ #[test]
+ fn nested_module_filter_correctly_removes_logs_from_nested_module() {
+ // Arrange
+ let (events, _guard) = setup_logging(
+ Some(
+ "proxmox_log::builder::tests::test_module=INFO,proxmox_log::builder::tests::test_module::nested_module=ERROR",
+ ),
+ LevelFilter::INFO,
+ );
+
+ // Act
+ test_module::info("log1");
+ test_module::nested_module::info("log2");
+
+ // Assert
+ assert_logs!(events, ["log1",]);
+ }
+
+ #[test]
+ fn empty_variable_turns_off_all_logging() {
+ // Arrange
+ let (events, _guard) = setup_logging(Some(""), LevelFilter::TRACE);
+
+ // Act
+ log::trace!("log1");
+ log::debug!("log2");
+ log::info!("log3");
+ log::warn!("log4");
+ log::error!("log5");
+
+ // Assert
+ let list = events.lock().unwrap();
+ assert!(list.is_empty());
+ }
+
+ #[test]
+ fn gibberish_filter_allows_use_of_fallback() {
+ // Arrange
+ let (events, _guard) = setup_logging(
+ Some("SNERROR,::_interesting*Üpath::we;HAVE=QUARNING"),
+ LevelFilter::ERROR,
+ );
+
+ // Act
+ log::info!("log1");
+ log::error!("log2");
+
+ // Assert
+ assert_logs!(events, ["log2"]);
+ }
+
+ #[test]
+ fn setting_default_in_variable_is_adopted_as_default() {
+ // Arrange
+ let (events, _guard) = setup_logging(
+ Some("ERROR,proxmox_log::builder::tests::test_module::nested_module=INFO"),
+ LevelFilter::INFO,
+ );
+
+ // Act
+ test_module::info("log1");
+ test_module::nested_module::info("log2");
+ log::error!("log3");
+
+ assert_logs!(events, ["log2", "log3"]);
+ }
+
+ /// Creates a [`Logger`] with a [`crate::builder::tests::TestLayer`]
+ /// inserted so that any logs received can be monitored through the
+ /// returned Vec of strings.
+ /// * `var_filter` - The log settings that would usually be written into
+ /// a environment variable and then extracted by the [`Logger`]
+ /// * `default_log_level` - Default log level used by the [`Logger`] in
+ /// case the log settings are empty.
+ fn create_logger(
+ var_filter: Option<&'static str>,
+ default_log_level: LevelFilter,
+ ) -> (Arc<Mutex<Vec<String>>>, Logger) {
+ let (events, test_layer) = TestLayer::no_filter();
+ (
+ events,
+ Logger {
+ global_log_level: Logger::apply_default_log_level(
+ var_filter.map(str::to_string),
+ default_log_level,
+ ),
+ layer: vec![test_layer.boxed()],
+ },
+ )
+ }
+
+ /// Sets up logging in a way that allows the filter to act, and then
+ /// records every log that is let through in a Vec of strings. Returns
+ /// said Vec of strings as well as a guard that allows tracing to capture
+ /// logs while it's not dropped.
+ /// * `var_filter` - The log settings that would usually be written into
+ /// a environment variable and then extracted by the [`Logger`]
+ /// * `default_log_level` - Default log level used by the [`Logger`] in
+ /// case the log settings are empty.
+ fn setup_logging(
+ var_filter: Option<&'static str>,
+ default_log_level: LevelFilter,
+ ) -> (Arc<Mutex<Vec<String>>>, tracing::subscriber::DefaultGuard) {
+ use tracing_subscriber::layer::SubscriberExt;
+
+ let filter =
+ Logger::apply_default_log_level(var_filter.map(str::to_string), default_log_level);
+
+ let (events, filter) = TestLayer::new(filter);
+ let guard = tracing_subscriber::Registry::default()
+ .with(filter)
+ .set_default();
+ (events, guard)
+ }
+
+ pub(crate) struct TestLayer {
+ events: Arc<Mutex<Vec<String>>>,
+ filter: Option<tracing_subscriber::EnvFilter>,
+ }
+
+ impl TestLayer {
+ pub(crate) fn no_filter() -> (Arc<Mutex<Vec<String>>>, Self) {
+ let events = Arc::new(Mutex::new(vec![]));
+ (
+ Arc::clone(&events),
+ Self {
+ events,
+ filter: None,
+ },
+ )
+ }
+
+ pub(crate) fn new(
+ filter: tracing_subscriber::EnvFilter,
+ ) -> (Arc<Mutex<Vec<String>>>, Self) {
+ let events = Arc::new(Mutex::new(vec![]));
+ (
+ Arc::clone(&events),
+ Self {
+ events,
+ filter: Some(filter),
+ },
+ )
+ }
+ }
+
+ impl<S> tracing_subscriber::Layer<S> for TestLayer
+ where
+ S: tracing::Subscriber,
+ {
+ /// adds events to the Vec of Strings
+ fn on_event(
+ &self,
+ event: &tracing::Event<'_>,
+ _: tracing_subscriber::layer::Context<'_, S>,
+ ) {
+ struct Visitor(Option<String>);
+
+ impl tracing::field::Visit for Visitor {
+ fn record_debug(
+ &mut self,
+ field: &tracing::field::Field,
+ value: &dyn std::fmt::Debug,
+ ) {
+ if field.name() == "message" {
+ self.0 = Some(format!("{value:?}"));
+ }
+ }
+ }
+
+ let mut visitor = Visitor(None);
+ event.record(&mut visitor);
+ let message = visitor.0.unwrap_or_default();
+
+ self.events.lock().unwrap().push(message);
+ }
+
+ /// applies the filter to the logs
+ fn enabled(
+ &self,
+ metadata: &tracing::Metadata<'_>,
+ ctx: tracing_subscriber::layer::Context<'_, S>,
+ ) -> bool {
+ self.filter
+ .as_ref()
+ .map(|filter| filter.enabled(metadata, ctx))
+ .unwrap_or(true)
+ }
+ }
+}
--
2.47.3
^ permalink raw reply related [flat|nested] 5+ messages in thread