feat(logging): add extended log filtering

Allows log filters of different levels to be applied on a per module
basis. It also allows filtering by regex.

Author: cagatay-y

Cargo.lock

@@ -298,14 +298,15 @@ document-features = { version = "0.2", optional = true }
 embedded-io = { version = "0.7", features = ["alloc"] }
 endian-num = { version = "0.2", optional = true, features = ["linux-types"] }
 enum_dispatch = "0.3"
+env_filter = { version = "1.0.0", default-features = false }
 fdt = { version = "0.1", features = ["pretty-printing"] }
 free-list = "0.3"
 fuse-abi = { version = "0.2", optional = true, features = ["linux"] }
 hashbrown = { version = "0.16", default-features = false }
 heapless = "0.9"
 hermit-entry = { version = "0.10.9", features = ["kernel"] }
 hermit-sync = "0.1"
-log = { version = "0.4", default-features = false }
+log = { version = "0.4", default-features = false, features = ["kv"] }
 mem-barrier = { version = "0.1.0", optional = true, features = ["nightly"] }
 num_enum = { version = "0.7", default-features = false }
 pci-ids = { version = "0.2", optional = true }
@@ -413,6 +414,7 @@ unreadable_literal = "warn"
 
 [patch.crates-io]
 safe-mmio = { git = "https://github.com/hermit-os/safe-mmio", branch = "be" }
+env_filter = { git = "https://github.com/cagatay-y/env_logger", branch = "feature/filter-no_std" }
 
 [profile.profiling]
 inherits = "release"

Cargo.toml

@@ -37,13 +37,18 @@ If you want to build the kernel for riscv64, please use `riscv64`.
 
 ### Control the kernel messages verbosity
 
-This kernel uses the lightweight logging crate [log](https://github.com/rust-lang/log) to print kernel messages.
-The environment variable `HERMIT_LOG_LEVEL_FILTER` controls the verbosity. 
-You can change it by setting it at compile time to a string matching the name of a [LevelFilter](https://docs.rs/log/0.4.8/log/enum.LevelFilter.html).
-If the variable is not set, or the name doesn't match, then `LevelFilter::Info` is used by default.
+This kernel uses the lightweight logging crate [log](https://github.com/rust-lang/log) to print kernel messages. The
+environment variable `HERMIT_LOG_LEVEL_FILTER` controls the verbosity and follows [the env_logger
+format](https://docs.rs/env_logger/latest/env_logger/) but without the regex support. You can change it per module by
+setting it at compile time to a string in the format `[target][=level][,...]`, where the level is a string matching the
+name of a [LevelFilter](https://docs.rs/log/0.4.8/log/enum.LevelFilter.html). If the target is omitted, the level is set
+as the global level. If the level is omitted, logs of all levels are printed for the target.
+
+If the variable is not set, or it does not provide a global level, then `LevelFilter::Info` is used as the global level
+by default.
 
 ```sh
-$ HERMIT_LOG_LEVEL_FILTER=Debug cargo xtask build --arch x86_64
+HERMIT_LOG_LEVEL_FILTER='smoltcp,virtio=info' cargo xtask build --arch x86_64
 ```
 
 ## Credits

README.md

@@ -3,22 +3,27 @@ use core::sync::atomic::{AtomicBool, Ordering};
 use core::time::Duration;
 
 use anstyle::AnsiColor;
+use hermit_sync::OnceCell;
 use log::{Level, LevelFilter, Metadata, Record};
 
 pub static KERNEL_LOGGER: KernelLogger = KernelLogger::new();
+const ARENA_SIZE: usize = 4096;
+static mut ARENA: [u8; ARENA_SIZE] = [0; _];
 
 const TIME_SEC_WIDTH: usize = 5;
 const TIME_SUBSEC_WIDTH: usize = 6;
 
 /// Data structure to filter kernel messages
 pub struct KernelLogger {
 	time: AtomicBool,
+	filter: OnceCell<env_filter::Filter>,
 }
 
 impl KernelLogger {
 	pub const fn new() -> Self {
 		Self {
 			time: AtomicBool::new(false),
+			filter: OnceCell::new(),
 		}
 	}
 
@@ -45,6 +50,23 @@ impl log::Log for KernelLogger {
 			return;
 		}
 
+		let target = record.target();
+		let (crate_, modules) = target.split_once("::").unwrap_or((target, ""));
+		let (_modules, module) = modules.rsplit_once("::").unwrap_or(("", modules));
+		let target = if !module.is_empty() && crate_ == "hermit" {
+			module
+		} else {
+			crate_
+		};
+
+		if self.filter.get().is_some_and(|filter| {
+			// We want the target that we match against to match the target we display.
+			let record = record.to_builder().target(target).build();
+			!filter.matches(&record)
+		}) {
+			return;
+		}
+
 		let format_time = if self.time() {
 			let time = Duration::from_micros(crate::processor::get_timer_ticks());
 			format_args!(
@@ -58,14 +80,6 @@ impl log::Log for KernelLogger {
 		let core_id = crate::arch::core_local::core_id();
 		let level = ColorLevel(record.level());
 
-		let target = record.target();
-		let (crate_, modules) = target.split_once("::").unwrap_or((target, ""));
-		let (_modules, module) = modules.rsplit_once("::").unwrap_or(("", modules));
-		let target = if !module.is_empty() && crate_ == "hermit" {
-			module
-		} else {
-			crate_
-		};
 		let format_target = format_args!(" {target:<10}");
 
 		let args = record.args();
@@ -101,29 +115,29 @@ fn no_color() -> bool {
 }
 
 pub unsafe fn init() {
+	#[cfg(target_os = "none")]
+	unsafe {
+		crate::mm::ALLOCATOR
+			.lock()
+			.claim((&raw mut ARENA).cast(), ARENA_SIZE)
+			.unwrap()
+	};
+
 	log::set_logger(&KERNEL_LOGGER).expect("Can't initialize logger");
 	// Determines LevelFilter at compile time
 	let log_level: Option<&'static str> = option_env!("HERMIT_LOG_LEVEL_FILTER");
-	let mut max_level = LevelFilter::Info;
-
-	if let Some(log_level) = log_level {
-		max_level = if log_level.eq_ignore_ascii_case("off") {
-			LevelFilter::Off
-		} else if log_level.eq_ignore_ascii_case("error") {
-			LevelFilter::Error
-		} else if log_level.eq_ignore_ascii_case("warn") {
-			LevelFilter::Warn
-		} else if log_level.eq_ignore_ascii_case("info") {
-			LevelFilter::Info
-		} else if log_level.eq_ignore_ascii_case("debug") {
-			LevelFilter::Debug
-		} else if log_level.eq_ignore_ascii_case("trace") {
-			LevelFilter::Trace
-		} else {
-			error!("Could not parse HERMIT_LOG_LEVEL_FILTER, falling back to `info`.");
-			LevelFilter::Info
-		};
-	}
+	let max_level = if let Some(log_level) = log_level {
+		let filter = env_filter::Builder::new()
+			// The default. It may get overwritten by the parsed filter if it has a global level.
+			.filter_level(LevelFilter::Info)
+			.parse(log_level)
+			.build();
+		let max_level = filter.filter();
+		KERNEL_LOGGER.filter.set(filter).unwrap();
+		max_level
+	} else {
+		LevelFilter::Info
+	};
 
 	log::set_max_level(max_level);
 }