Logging with timestamps and module info #44
+17
-11
@@ -1,15 +1,19 @@
|
|||||||
[package]
|
[package]
|
||||||
edition = "2024"
|
edition = "2024"
|
||||||
name = "creaturedex"
|
name = "creaturedex"
|
||||||
rust-version = "1.88"
|
rust-version = "1.88"
|
||||||
version = "0.1.0"
|
version = "0.1.0"
|
||||||
|
|
||||||
[[bin]]
|
[[bin]]
|
||||||
name = "creaturedex"
|
name = "creaturedex"
|
||||||
path = "./src/bin/main.rs"
|
path = "./src/bin/main.rs"
|
||||||
|
|
||||||
[dependencies]
|
[dependencies]
|
||||||
esp-hal = { version = "~1.1.0", features = ["esp32s3", "log-04", "unstable"] } #, "embassy", "embassy-time-timg0", "embassy-executor-thread"] }
|
esp-hal = { version = "~1.1.0", features = [
|
||||||
|
"esp32s3",
|
||||||
|
"log-04",
|
||||||
|
"unstable",
|
||||||
|
] } #, "embassy", "embassy-time-timg0", "embassy-executor-thread"] }
|
||||||
|
|
||||||
esp-rtos = { version = "0.3.0", features = [
|
esp-rtos = { version = "0.3.0", features = [
|
||||||
"embassy",
|
"embassy",
|
||||||
@@ -20,12 +24,11 @@ esp-rtos = { version = "0.3.0", features = [
|
|||||||
] }
|
] }
|
||||||
|
|
||||||
esp-bootloader-esp-idf = { version = "0.5.0", features = ["esp32s3", "log-04"] }
|
esp-bootloader-esp-idf = { version = "0.5.0", features = ["esp32s3", "log-04"] }
|
||||||
log = "0.4.27"
|
log = "0.4.27"
|
||||||
|
|
||||||
critical-section = "1.2.0"
|
critical-section = "1.2.0"
|
||||||
embedded-io = "0.7.1"
|
embedded-io = "0.7.1"
|
||||||
embassy-executor = { version = "0.10.0", features = [
|
embassy-executor = { version = "0.10.0", features = [] }
|
||||||
] }
|
|
||||||
embassy-time = { version = "0.5.1", default-features = false }
|
embassy-time = { version = "0.5.1", default-features = false }
|
||||||
embassy-futures = "0.1.2"
|
embassy-futures = "0.1.2"
|
||||||
esp-alloc = "0.10.0"
|
esp-alloc = "0.10.0"
|
||||||
@@ -48,6 +51,9 @@ embedded-hal-async = "1.0.0"
|
|||||||
i2c-character-display = "0.5.1"
|
i2c-character-display = "0.5.1"
|
||||||
ch1115 = { version = "0.1.2", features = ["graphics"] }
|
ch1115 = { version = "0.1.2", features = ["graphics"] }
|
||||||
|
|
||||||
|
[build-dependencies]
|
||||||
|
log = "0.4.27"
|
||||||
|
|
||||||
|
|
||||||
[patch.crates-io]
|
[patch.crates-io]
|
||||||
ch1115 = { git = "https://github.com/ede1998/ch1115.git", rev = "2d3a3ba38050efe012e6a210afe3e125ec280c37" }
|
ch1115 = { git = "https://github.com/ede1998/ch1115.git", rev = "2d3a3ba38050efe012e6a210afe3e125ec280c37" }
|
||||||
@@ -64,10 +70,10 @@ opt-level = 3
|
|||||||
debug = 0
|
debug = 0
|
||||||
|
|
||||||
[profile.release]
|
[profile.release]
|
||||||
codegen-units = 1 # LLVM can perform better optimizations using a single thread
|
codegen-units = 1 # LLVM can perform better optimizations using a single thread
|
||||||
debug = 2 # prefer slower builds but better debugging experience
|
debug = 2 # prefer slower builds but better debugging experience
|
||||||
lto = 'fat'
|
lto = 'fat'
|
||||||
opt-level = 's'
|
opt-level = 's'
|
||||||
|
|
||||||
[features]
|
[features]
|
||||||
default = []
|
default = []
|
||||||
|
|||||||
@@ -1,4 +1,5 @@
|
|||||||
fn main() {
|
fn main() {
|
||||||
|
generate_filter_snippet();
|
||||||
linker_be_nice();
|
linker_be_nice();
|
||||||
// make sure linkall.x is the last linker script (otherwise might cause problems with flip-link)
|
// make sure linkall.x is the last linker script (otherwise might cause problems with flip-link)
|
||||||
println!("cargo:rustc-link-arg=-Tlinkall.x");
|
println!("cargo:rustc-link-arg=-Tlinkall.x");
|
||||||
@@ -68,3 +69,165 @@ fn linker_be_nice() {
|
|||||||
std::env::current_exe().unwrap().display()
|
std::env::current_exe().unwrap().display()
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// Taken over from esp_println because impossible to just extend their existing env logger.
|
||||||
|
// https://github.com/esp-rs/esp-hal/blob/8fa6d7e985e724d6ad998e34307429b0920da370/esp-println/build.rs
|
||||||
|
fn generate_filter_snippet() {
|
||||||
|
use log::LevelFilter;
|
||||||
|
use std::{env, path::Path};
|
||||||
|
|
||||||
|
let out_dir = env::var_os("OUT_DIR").unwrap();
|
||||||
|
let dest_path = Path::new(&out_dir).join("log_filter.rs");
|
||||||
|
|
||||||
|
let filter = env::var("ESP_LOG");
|
||||||
|
let snippet = if let Ok(filter) = filter {
|
||||||
|
let res = parse_spec(&filter);
|
||||||
|
|
||||||
|
if !res.errors.is_empty() {
|
||||||
|
panic!("Error parsing `ESP_LOG`: {:?}", res.errors);
|
||||||
|
} else {
|
||||||
|
let max = res
|
||||||
|
.directives
|
||||||
|
.iter()
|
||||||
|
.map(|v| v.level)
|
||||||
|
.max()
|
||||||
|
.unwrap_or(LevelFilter::Off);
|
||||||
|
let max = match max {
|
||||||
|
LevelFilter::Off => "Off",
|
||||||
|
LevelFilter::Error => "Error",
|
||||||
|
LevelFilter::Warn => "Warn",
|
||||||
|
LevelFilter::Info => "Info",
|
||||||
|
LevelFilter::Debug => "Debug",
|
||||||
|
LevelFilter::Trace => "Trace",
|
||||||
|
};
|
||||||
|
|
||||||
|
let mut snippet = String::new();
|
||||||
|
|
||||||
|
snippet.push_str(&format!(
|
||||||
|
"pub(crate) const FILTER_MAX: log::LevelFilter = log::LevelFilter::{max};"
|
||||||
|
));
|
||||||
|
|
||||||
|
snippet
|
||||||
|
.push_str("pub(crate) fn is_enabled(level: log::Level, _target: &str) -> bool {");
|
||||||
|
|
||||||
|
let mut global_level = None;
|
||||||
|
for directive in res.directives {
|
||||||
|
let level = match directive.level {
|
||||||
|
LevelFilter::Off => "Off",
|
||||||
|
LevelFilter::Error => "Error",
|
||||||
|
LevelFilter::Warn => "Warn",
|
||||||
|
LevelFilter::Info => "Info",
|
||||||
|
LevelFilter::Debug => "Debug",
|
||||||
|
LevelFilter::Trace => "Trace",
|
||||||
|
};
|
||||||
|
|
||||||
|
if let Some(name) = directive.name {
|
||||||
|
// If a prefix matches, don't continue to the next directive
|
||||||
|
snippet.push_str(&format!(
|
||||||
|
"if _target.starts_with(\"{name}\") {{ return level <= log::LevelFilter::{level}; }}"
|
||||||
|
));
|
||||||
|
} else {
|
||||||
|
if global_level.is_some() {
|
||||||
|
panic!("Multiple global log levels specified in `ESP_LOG`");
|
||||||
|
}
|
||||||
|
global_level = Some(level);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// Place the fallback rule at the end
|
||||||
|
if let Some(level) = global_level {
|
||||||
|
snippet.push_str(&format!("level <= log::LevelFilter::{level}"));
|
||||||
|
} else {
|
||||||
|
snippet.push_str(" false");
|
||||||
|
}
|
||||||
|
snippet.push('}');
|
||||||
|
snippet
|
||||||
|
}
|
||||||
|
} else {
|
||||||
|
"pub(crate) const FILTER_MAX: log::LevelFilter = log::LevelFilter::Off; pub(crate) fn is_enabled(_level: log::Level, _target: &str) -> bool { true }".to_string()
|
||||||
|
};
|
||||||
|
|
||||||
|
std::fs::write(&dest_path, &snippet).unwrap();
|
||||||
|
}
|
||||||
|
|
||||||
|
#[derive(Default, Debug)]
|
||||||
|
struct ParseResult {
|
||||||
|
pub(crate) directives: Vec<Directive>,
|
||||||
|
pub(crate) errors: Vec<String>,
|
||||||
|
}
|
||||||
|
|
||||||
|
impl ParseResult {
|
||||||
|
fn add_directive(&mut self, directive: Directive) {
|
||||||
|
self.directives.push(directive);
|
||||||
|
}
|
||||||
|
|
||||||
|
fn add_error(&mut self, message: String) {
|
||||||
|
self.errors.push(message);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
#[derive(Debug)]
|
||||||
|
struct Directive {
|
||||||
|
pub(crate) name: Option<String>,
|
||||||
|
pub(crate) level: log::LevelFilter,
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Parse a logging specification string (e.g:
|
||||||
|
/// `crate1,crate2::mod3,crate3::x=error/foo`) and return a vector with log
|
||||||
|
/// directives.
|
||||||
|
fn parse_spec(spec: &str) -> ParseResult {
|
||||||
|
use log::LevelFilter;
|
||||||
|
|
||||||
|
let mut result = ParseResult::default();
|
||||||
|
|
||||||
|
let mut parts = spec.split('/');
|
||||||
|
let mods = parts.next();
|
||||||
|
|
||||||
|
if let Some(m) = mods {
|
||||||
|
for s in m.split(',').map(|ss| ss.trim()) {
|
||||||
|
if s.is_empty() {
|
||||||
|
continue;
|
||||||
|
}
|
||||||
|
let mut parts = s.split('=');
|
||||||
|
let (log_level, name) =
|
||||||
|
match (parts.next(), parts.next().map(|s| s.trim()), parts.next()) {
|
||||||
|
(Some(part0), None, None) => {
|
||||||
|
// if the single argument is a log-level string or number,
|
||||||
|
// treat that as a global fallback
|
||||||
|
match part0.parse() {
|
||||||
|
Ok(num) => (num, None),
|
||||||
|
Err(_) => (LevelFilter::max(), Some(part0)),
|
||||||
|
}
|
||||||
|
}
|
||||||
|
(Some(part0), Some(""), None) => (LevelFilter::max(), Some(part0)),
|
||||||
|
(Some(part0), Some(part1), None) => {
|
||||||
|
if let Ok(num) = part1.parse() {
|
||||||
|
(num, Some(part0))
|
||||||
|
} else {
|
||||||
|
result.add_error(format!("invalid logging spec '{part1}'"));
|
||||||
|
continue;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
_ => {
|
||||||
|
result.add_error(format!("invalid logging spec '{s}'"));
|
||||||
|
continue;
|
||||||
|
}
|
||||||
|
};
|
||||||
|
|
||||||
|
result.add_directive(Directive {
|
||||||
|
name: name.map(|s| s.to_owned()),
|
||||||
|
level: log_level,
|
||||||
|
});
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// Sort by length so that the most specific prefixes come first
|
||||||
|
result
|
||||||
|
.directives
|
||||||
|
.sort_by(|a, b| match (a.name.as_ref(), b.name.as_ref()) {
|
||||||
|
(Some(a), Some(b)) => b.len().cmp(&a.len()),
|
||||||
|
_ => std::cmp::Ordering::Equal,
|
||||||
|
});
|
||||||
|
|
||||||
|
result
|
||||||
|
}
|
||||||
|
|||||||
+4
-2
@@ -52,7 +52,7 @@ esp_bootloader_esp_idf::esp_app_desc!();
|
|||||||
)]
|
)]
|
||||||
#[esp_rtos::main]
|
#[esp_rtos::main]
|
||||||
async fn main(spawner: Spawner) {
|
async fn main(spawner: Spawner) {
|
||||||
esp_println::logger::init_logger_from_env();
|
creaturedex::logging::init();
|
||||||
|
|
||||||
let config = esp_hal::Config::default().with_cpu_clock(CpuClock::max());
|
let config = esp_hal::Config::default().with_cpu_clock(CpuClock::max());
|
||||||
let peripherals = esp_hal::init(config);
|
let peripherals = esp_hal::init(config);
|
||||||
@@ -94,7 +94,9 @@ async fn main(spawner: Spawner) {
|
|||||||
let h = EXAMPLE[HEART];
|
let h = EXAMPLE[HEART];
|
||||||
let e = EXAMPLE[EMPTY];
|
let e = EXAMPLE[EMPTY];
|
||||||
let b = EXAMPLE[BOX];
|
let b = EXAMPLE[BOX];
|
||||||
if let Err(e) = lcd.write(&alloc::format!("Custom symbols: {h}{e}{b} And more stuff to wrap and cut off please.")) {
|
if let Err(e) = lcd.write(&alloc::format!(
|
||||||
|
"Custom symbols: {h}{e}{b} And more stuff to wrap and cut off please."
|
||||||
|
)) {
|
||||||
log::error!(
|
log::error!(
|
||||||
"Tertiary LCD startup text write failed over shared I2C bus; check the shared bus, wiring, and device responses: {e}"
|
"Tertiary LCD startup text write failed over shared I2C bus; check the shared bus, wiring, and device responses: {e}"
|
||||||
);
|
);
|
||||||
|
|||||||
@@ -6,6 +6,7 @@ pub mod background_tasks;
|
|||||||
pub mod card;
|
pub mod card;
|
||||||
pub mod display;
|
pub mod display;
|
||||||
pub mod drivers;
|
pub mod drivers;
|
||||||
|
pub mod logging;
|
||||||
pub mod navigation;
|
pub mod navigation;
|
||||||
pub mod network;
|
pub mod network;
|
||||||
pub mod storage;
|
pub mod storage;
|
||||||
|
|||||||
@@ -0,0 +1,83 @@
|
|||||||
|
mod logging_config {
|
||||||
|
include!(concat!(env!("OUT_DIR"), "/log_filter.rs"));
|
||||||
|
}
|
||||||
|
|
||||||
|
struct EnvLogger;
|
||||||
|
|
||||||
|
impl log::Log for EnvLogger {
|
||||||
|
fn enabled(&self, metadata: &log::Metadata) -> bool {
|
||||||
|
let level = metadata.level();
|
||||||
|
let target = metadata.target();
|
||||||
|
logging_config::is_enabled(level, target)
|
||||||
|
}
|
||||||
|
|
||||||
|
fn log(&self, record: &log::Record) {
|
||||||
|
if !self.enabled(record.metadata()) {
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
|
||||||
|
// print with color? default to true if env var unset or set but empty.
|
||||||
|
let with_color = 1
|
||||||
|
== option_env!("ESP_LOG_COLOR")
|
||||||
|
.unwrap_or("1")
|
||||||
|
.parse()
|
||||||
|
.unwrap_or(1);
|
||||||
|
let (color, reset) = if with_color {
|
||||||
|
const RESET: &str = "\u{001B}[0m";
|
||||||
|
const RED: &str = "\u{001B}[31m";
|
||||||
|
const GREEN: &str = "\u{001B}[32m";
|
||||||
|
const YELLOW: &str = "\u{001B}[33m";
|
||||||
|
const BLUE: &str = "\u{001B}[34m";
|
||||||
|
const CYAN: &str = "\u{001B}[35m";
|
||||||
|
|
||||||
|
let color = match record.level() {
|
||||||
|
log::Level::Error => RED,
|
||||||
|
log::Level::Warn => YELLOW,
|
||||||
|
log::Level::Info => GREEN,
|
||||||
|
log::Level::Debug => BLUE,
|
||||||
|
log::Level::Trace => CYAN,
|
||||||
|
};
|
||||||
|
let reset = RESET;
|
||||||
|
(color, reset)
|
||||||
|
} else {
|
||||||
|
("", "")
|
||||||
|
};
|
||||||
|
|
||||||
|
let [now_s, now_ms] = {
|
||||||
|
let now = esp_hal::time::Instant::now()
|
||||||
|
.duration_since_epoch()
|
||||||
|
.as_millis();
|
||||||
|
|
||||||
|
[now / 1000, now % 1000]
|
||||||
|
};
|
||||||
|
|
||||||
|
let level = match record.level() {
|
||||||
|
log::Level::Error => "E",
|
||||||
|
log::Level::Warn => "W",
|
||||||
|
log::Level::Info => "I",
|
||||||
|
log::Level::Debug => "D",
|
||||||
|
log::Level::Trace => "T",
|
||||||
|
};
|
||||||
|
let args = record.args();
|
||||||
|
let line = record.line().unwrap_or(0);
|
||||||
|
let target = record.target();
|
||||||
|
let module = record.module_path().unwrap_or("???");
|
||||||
|
|
||||||
|
let (module, divider) = if module == target {
|
||||||
|
("", "")
|
||||||
|
} else {
|
||||||
|
(module, " ")
|
||||||
|
};
|
||||||
|
|
||||||
|
esp_println::println!(
|
||||||
|
"{color}{now_s:>4}.{now_ms:03}s {level} {target}{divider}{module}:{line} - {args}{reset}"
|
||||||
|
);
|
||||||
|
}
|
||||||
|
|
||||||
|
fn flush(&self) {}
|
||||||
|
}
|
||||||
|
|
||||||
|
pub fn init() {
|
||||||
|
log::set_logger(&EnvLogger).expect("Failed to init logger.");
|
||||||
|
log::set_max_level(logging_config::FILTER_MAX);
|
||||||
|
}
|
||||||
Reference in New Issue
Block a user