diff --git a/Cargo.lock b/Cargo.lock index caa9b3a8..2caa18d4 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -111,11 +111,12 @@ dependencies = [ "gimli", "libc", "llvm-sys", - "log", "regex", "rustc-build-sysroot", - "simplelog", "thiserror", + "tracing", + "tracing-appender", + "tracing-subscriber", "which", ] @@ -233,11 +234,29 @@ dependencies = [ "winapi", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "176dc175b78f56c0f321911d9c8eb2b77a78a4860b9c19db83835fea1a46649b" +dependencies = [ + "crossbeam-utils", +] + +[[package]] +name = "crossbeam-utils" +version = "0.8.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "248e3bacc7dc6baa3b21e405ee045c3047101a49145e7e9eca583ab4c2ca5345" + [[package]] name = "deranged" -version = "0.3.8" +version = "0.3.11" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f2696e8a945f658fd14dc3b87242e6b80cd0f36ff04ea560fa39082368847946" +checksum = "b42b6fa04a440b495c8b04d0e71b707c585f83cb9cb28cf8cd0d976c315e31b4" +dependencies = [ + "powerfmt", +] [[package]] name = "diff" @@ -445,6 +464,15 @@ version = "0.4.20" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b5e6163cb8c49088c2c36f57875e58ccd8c87c7427f7fbd50ea6710b2f3f2e8f" +[[package]] +name = "matchers" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" +dependencies = [ + "regex-automata 0.1.10", +] + [[package]] name = "memchr" version = "2.6.3" @@ -461,21 +489,22 @@ dependencies = [ ] [[package]] -name = "num_cpus" -version = "1.16.0" +name = "nu-ansi-term" +version = "0.46.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4161fcb6d602d4d2081af7c3a45852d875a03dd337a6bfdd6e06407b61342a43" +checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84" dependencies = [ - "hermit-abi", - "libc", + "overload", + "winapi", ] [[package]] -name = "num_threads" -version = "0.1.6" +name = "num_cpus" +version = "1.16.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2819ce041d2ee131036f4fc9d6ae7ae125a3a40e97ba64d04fe799ad9dabbb44" +checksum = "4161fcb6d602d4d2081af7c3a45852d875a03dd337a6bfdd6e06407b61342a43" dependencies = [ + "hermit-abi", "libc", ] @@ -485,6 +514,24 @@ version = "1.18.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "dd8b5dd2ae5ed71462c540258bedcb51965123ad7e7ccf4b9a8cafaa4a63576d" +[[package]] +name = "overload" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39" + +[[package]] +name = "pin-project-lite" +version = "0.2.13" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8afb450f006bf6385ca15ef45d71d2288452bc3683ce2e2cacc0d18e4be60b58" + +[[package]] +name = "powerfmt" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "439ee305def115ba05938db6eb1644ff94165c5ab5e9420d1c1bcedbba909391" + [[package]] name = "prettyplease" version = "0.2.15" @@ -550,8 +597,17 @@ checksum = "380b951a9c5e80ddfd6136919eef32310721aa4aacd4889a8d39124b026ab343" dependencies = [ "aho-corasick", "memchr", - "regex-automata", - "regex-syntax", + "regex-automata 0.4.3", + "regex-syntax 0.8.2", +] + +[[package]] +name = "regex-automata" +version = "0.1.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132" +dependencies = [ + "regex-syntax 0.6.29", ] [[package]] @@ -562,9 +618,15 @@ checksum = "5f804c7828047e88b2d32e2d7fe5a105da8ee3264f01902f796c8e067dc2483f" dependencies = [ "aho-corasick", "memchr", - "regex-syntax", + "regex-syntax 0.8.2", ] +[[package]] +name = "regex-syntax" +version = "0.6.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1" + [[package]] name = "regex-syntax" version = "0.8.2" @@ -669,16 +731,20 @@ dependencies = [ ] [[package]] -name = "simplelog" -version = "0.12.1" +name = "sharded-slab" +version = "0.1.7" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "acee08041c5de3d5048c8b3f6f13fafb3026b24ba43c6a695a0c76179b844369" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" dependencies = [ - "log", - "termcolor", - "time", + "lazy_static", ] +[[package]] +name = "smallvec" +version = "1.13.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e6ecd384b10a64542d77071bd64bd7b231f4ed5940fba55e98c3de13824cf3d7" + [[package]] name = "stable_deref_trait" version = "1.2.0" @@ -726,15 +792,6 @@ dependencies = [ "winapi", ] -[[package]] -name = "termcolor" -version = "1.1.3" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "bab24d30b911b2376f3a13cc2cd443142f0c81dda04c118693e35b3835757755" -dependencies = [ - "winapi-util", -] - [[package]] name = "tester" version = "0.9.1" @@ -768,16 +825,25 @@ dependencies = [ "syn", ] +[[package]] +name = "thread_local" +version = "1.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3fdd6f064ccff2d6567adcb3873ca630700f00b5ad3f060c25b5dcfd9a4ce152" +dependencies = [ + "cfg-if", + "once_cell", +] + [[package]] name = "time" -version = "0.3.29" +version = "0.3.31" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "426f806f4089c493dcac0d24c29c01e2c38baf8e30f1b716ee37e83d200b18fe" +checksum = "f657ba42c3f86e7680e53c8cd3af8abbe56b5491790b46e22e19c0d57463583e" dependencies = [ "deranged", "itoa", - "libc", - "num_threads", + "powerfmt", "serde", "time-core", "time-macros", @@ -791,13 +857,99 @@ checksum = "ef927ca75afb808a4d64dd374f00a2adf8d0fcff8e7b184af886c3c87ec4a3f3" [[package]] name = "time-macros" -version = "0.2.15" +version = "0.2.16" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "4ad70d68dba9e1f8aceda7aa6711965dfec1cac869f311a51bd08b3a2ccbce20" +checksum = "26197e33420244aeb70c3e8c78376ca46571bc4e701e4791c2cd9f57dcb3a43f" dependencies = [ "time-core", ] +[[package]] +name = "tracing" +version = "0.1.40" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c3523ab5a71916ccf420eebdf5521fcef02141234bbc0b8a49f2fdc4544364ef" +dependencies = [ + "pin-project-lite", + "tracing-attributes", + "tracing-core", +] + +[[package]] +name = "tracing-appender" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3566e8ce28cc0a3fe42519fc80e6b4c943cc4c8cef275620eb8dac2d3d4e06cf" +dependencies = [ + "crossbeam-channel", + "thiserror", + "time", + "tracing-subscriber", +] + +[[package]] +name = "tracing-attributes" +version = "0.1.27" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "34704c8d6ebcbc939824180af020566b01a7c01f80641264eba0999f6c2b6be7" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "tracing-core" +version = "0.1.32" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54" +dependencies = [ + "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-serde" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" +dependencies = [ + "serde", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b" +dependencies = [ + "matchers", + "nu-ansi-term", + "once_cell", + "regex", + "serde", + "serde_json", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log", + "tracing-serde", +] + [[package]] name = "unicode-ident" version = "1.0.12" @@ -816,6 +968,12 @@ version = "0.2.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "711b9620af191e0cdc7468a8d14e709c3dcdb115b36f838e601583af800a370a" +[[package]] +name = "valuable" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" + [[package]] name = "wasi" version = "0.11.0+wasi-snapshot-preview1" @@ -851,15 +1009,6 @@ version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" -[[package]] -name = "winapi-util" -version = "0.1.6" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f29e6f9198ba0d26b4c9f07dbe6f9ed633e1f3d5b8b414090084349e46a52596" -dependencies = [ - "winapi", -] - [[package]] name = "winapi-x86_64-pc-windows-gnu" version = "0.4.0" diff --git a/Cargo.toml b/Cargo.toml index 08f5b59d..a3dc0433 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -18,7 +18,6 @@ edition = "2021" [dependencies] # cli deps clap = { version = "4.4.7", features = ["derive"] } -simplelog = { version = "0.12.1" } # lib deps ar = { version = "0.9.0" } @@ -26,8 +25,10 @@ aya-rustc-llvm-proxy = { version = "0.9.0", optional = true } gimli = { version = "0.28.0" } libc = { version = "0.2.150" } llvm-sys = { version = "170.0.0" } -log = { version = "0.4.20" } thiserror = { version = "1.0.50" } +tracing = "0.1" +tracing-appender = "0.2" +tracing-subscriber = { version = "0.3", features = ["env-filter", "json", "registry"] } [dev-dependencies] compiletest_rs = { version = "0.10.1" } diff --git a/src/bin/bpf-linker.rs b/src/bin/bpf-linker.rs index 19996637..cc2d29fa 100644 --- a/src/bin/bpf-linker.rs +++ b/src/bin/bpf-linker.rs @@ -3,22 +3,14 @@ #[cfg(feature = "rust-llvm")] extern crate aya_rustc_llvm_proxy; -use std::{ - env, - fs::{self, OpenOptions}, - os::fd::AsRawFd, - path::PathBuf, - str::FromStr, -}; +use std::{env, fs, io, path::PathBuf, str::FromStr}; use bpf_linker::{Cpu, Linker, LinkerOptions, OptLevel, OutputType}; use clap::Parser; -use libc::dup2; -use log::info; -use simplelog::{ - ColorChoice, Config, LevelFilter, SimpleLogger, TermLogger, TerminalMode, WriteLogger, -}; use thiserror::Error; +use tracing::{info, Level, Subscriber}; +use tracing_appender::non_blocking::WorkerGuard; +use tracing_subscriber::{fmt, prelude::*, EnvFilter}; #[derive(Debug, Error)] enum CliError { @@ -65,6 +57,43 @@ impl FromStr for CliOutputType { })) } } + +#[derive(Clone, Debug)] +enum LogLevel { + Trace, + Debug, + Info, + Warn, + Error, +} + +impl FromStr for LogLevel { + type Err = &'static str; + + fn from_str(s: &str) -> Result { + match s.to_lowercase().as_str() { + "trace" => Ok(LogLevel::Trace), + "debug" => Ok(LogLevel::Debug), + "info" => Ok(LogLevel::Info), + "warn" => Ok(LogLevel::Warn), + "error" => Ok(LogLevel::Error), + _ => Err("no match"), + } + } +} + +impl From for Level { + fn from(log_level: LogLevel) -> Level { + match log_level { + LogLevel::Trace => Level::TRACE, + LogLevel::Debug => Level::DEBUG, + LogLevel::Info => Level::INFO, + LogLevel::Warn => Level::WARN, + LogLevel::Error => Level::ERROR, + } + } +} + #[derive(Debug, Parser)] struct CommandLine { /// LLVM target triple. When not provided, the target is inferred from the inputs @@ -111,7 +140,7 @@ struct CommandLine { /// Set the log level. Can be one of `off`, `info`, `warn`, `debug`, `trace`. #[clap(long, value_name = "level")] - log_level: Option, + log_level: Option, /// Try hard to unroll loops. Useful when targeting kernels that don't support loops #[clap(long)] @@ -191,51 +220,40 @@ fn main() { error("no input files", clap::error::ErrorKind::TooFewValues); } - let env_log_level = match env::var("RUST_LOG") { - Ok(s) if !s.is_empty() => match s.parse::() { - Ok(l) => Some(l), - Err(e) => error( - &format!("invalid RUST_LOG value: {e}"), - clap::error::ErrorKind::InvalidValue, - ), - }, - _ => None, + // Configure tracing. + let log_level: Level = match log_level { + Some(log_level) => log_level.into(), + None => Level::TRACE, }; - let log_level = log_level.or(env_log_level).unwrap_or(LevelFilter::Warn); - if let Some(log_file) = log_file { - let log_file = match OpenOptions::new().create(true).append(true).open(log_file) { - Ok(f) => { - // Use dup2 to duplicate stderr fd to the log file fd - let result = unsafe { dup2(f.as_raw_fd(), std::io::stderr().as_raw_fd()) }; - - if result == -1 { - error( - &format!( - "failed to duplicate stderr: {}", - std::io::Error::last_os_error() - ), - clap::error::ErrorKind::Io, - ) - } - f - } - Err(e) => { - error( - &format!("failed to open log file: {e:?}"), - clap::error::ErrorKind::Io, - ); - } - }; - WriteLogger::init(log_level, Config::default(), log_file).unwrap(); - } else if TermLogger::init( - log_level, - Config::default(), - TerminalMode::Mixed, - ColorChoice::Auto, - ) - .is_err() - { - SimpleLogger::init(log_level, Config::default()).unwrap(); + let subscriber_registry = tracing_subscriber::registry() + .with(EnvFilter::from_default_env().add_directive(log_level.into())); + let (subscriber, _guard): ( + Box, + Option, + ) = match log_file { + Some(log_file) => { + let file_appender = tracing_appender::rolling::daily( + log_file.parent().unwrap_or_else(|| { + error("invalid log_file", clap::error::ErrorKind::InvalidValue) + }), + log_file.file_name().unwrap_or_else(|| { + error("invalid log_file", clap::error::ErrorKind::InvalidValue) + }), + ); + let (non_blocking, _guard) = tracing_appender::non_blocking(file_appender); + let subscriber = subscriber_registry + .with(fmt::Layer::new().with_writer(io::stdout)) + .with(fmt::Layer::new().with_writer(non_blocking)); + + (Box::new(subscriber), Some(_guard)) + } + None => { + let subscriber = subscriber_registry.with(fmt::Layer::new().with_writer(io::stderr)); + (Box::new(subscriber), None) + } + }; + if let Err(e) = tracing::subscriber::set_global_default(subscriber) { + error(&e.to_string(), clap::error::ErrorKind::Format); } info!( diff --git a/src/linker.rs b/src/linker.rs index 155296ce..fddd6530 100644 --- a/src/linker.rs +++ b/src/linker.rs @@ -22,8 +22,8 @@ use llvm_sys::{ prelude::{LLVMContextRef, LLVMModuleRef}, target_machine::{LLVMCodeGenFileType, LLVMDisposeTargetMachine, LLVMTargetMachineRef}, }; -use log::{debug, error, info, warn}; use thiserror::Error; +use tracing::{debug, error, info, warn}; use crate::llvm; diff --git a/src/llvm/di.rs b/src/llvm/di.rs index ae07dcfb..bb7444dd 100644 --- a/src/llvm/di.rs +++ b/src/llvm/di.rs @@ -8,7 +8,7 @@ use std::{ use gimli::{DW_TAG_pointer_type, DW_TAG_structure_type, DW_TAG_variant_part}; use llvm_sys::{core::*, debuginfo::*, prelude::*}; -use log::{trace, warn}; +use tracing::{span, trace, warn, Level}; use super::types::{ di::DIType, @@ -204,16 +204,13 @@ impl DISanitizer { } // navigate the tree of LLVMValueRefs (DFS-pre-order) - fn visit_item(&mut self, mut item: Item, depth: usize) { + fn visit_item(&mut self, mut item: Item) { let value_ref = item.value_ref(); let value_id = item.value_id(); - let log_prefix = ""; - let log_depth = depth * 4; - trace!( - "{log_prefix:log_depth$}visiting item: {item:?} id: {} value: {value_ref:?}", - item.value_id(), - ); + let item_span = span!(Level::TRACE, "item", value_id); + let _enter = item_span.enter(); + trace!(item = ?item, value = ?value_ref, "visiting item"); let value = match (value_ref, &item) { // An operand with no value is valid and means that the operand is @@ -235,7 +232,7 @@ impl DISanitizer { let first_visit = self.visited_nodes.insert(value_id); if !first_visit { - trace!("{log_prefix:log_depth$}already visited"); + trace!("already visited"); return; } @@ -247,21 +244,18 @@ impl DISanitizer { if let Some(operands) = value.operands() { for (index, operand) in operands.enumerate() { - self.visit_item( - Item::Operand(Operand { - parent: value_ref, - value: operand, - index: index as u32, - }), - depth + 1, - ) + self.visit_item(Item::Operand(Operand { + parent: value_ref, + value: operand, + index: index as u32, + })) } } if let Some(entries) = value.metadata_entries() { for (index, (metadata, kind)) in entries.iter().enumerate() { let metadata_value = unsafe { LLVMMetadataAsValue(self.context, metadata) }; - self.visit_item(Item::MetadataEntry(metadata_value, kind, index), depth + 1); + self.visit_item(Item::MetadataEntry(metadata_value, kind, index)); } } @@ -269,12 +263,12 @@ impl DISanitizer { // those too. if let Value::Function(fun) = value { for param in fun.params() { - self.visit_item(Item::FunctionParam(param), depth + 1); + self.visit_item(Item::FunctionParam(param)); } for basic_block in fun.basic_blocks() { for instruction in basic_block.instructions_iter() { - self.visit_item(Item::Instruction(instruction), depth + 1); + self.visit_item(Item::Instruction(instruction)); } } } @@ -288,14 +282,14 @@ impl DISanitizer { self.replace_operands = self.fix_subprogram_linkage(exported_symbols); for value in module.globals_iter() { - self.visit_item(Item::GlobalVariable(value), 0); + self.visit_item(Item::GlobalVariable(value)); } for value in module.global_aliases_iter() { - self.visit_item(Item::GlobalAlias(value), 0); + self.visit_item(Item::GlobalAlias(value)); } for function in module.functions_iter() { - self.visit_item(Item::Function(function), 0); + self.visit_item(Item::Function(function)); } unsafe { LLVMDisposeDIBuilder(self.builder) }; diff --git a/src/llvm/mod.rs b/src/llvm/mod.rs index da0f2416..86de1b04 100644 --- a/src/llvm/mod.rs +++ b/src/llvm/mod.rs @@ -48,7 +48,7 @@ use llvm_sys::{ }, LLVMAttributeFunctionIndex, LLVMLinkage, LLVMVisibility, }; -use log::{debug, error}; +use tracing::{debug, error}; use crate::OptLevel;