From 3ce1826891e35a25aceb2fd766e44b446cf8a5a5 Mon Sep 17 00:00:00 2001 From: whitequark Date: Sat, 12 Nov 2016 20:16:25 +0000 Subject: [PATCH] runtime: don't print debug messages to the UART. It takes ~4ms to print an empty log line because of how slow the UART is. This makes the log timestamps useless for debugging performance problems. After this commit, it takes ~75us to print an empty log line instead, which pessimizes test_rpc_timing by less than 2ms with tracing enabled. --- artiq/runtime.rs/src/lib.rs | 2 +- artiq/runtime.rs/src/logger.rs | 8 +++++--- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/artiq/runtime.rs/src/lib.rs b/artiq/runtime.rs/src/lib.rs index 48efd5d0d..b3350dfc8 100644 --- a/artiq/runtime.rs/src/lib.rs +++ b/artiq/runtime.rs/src/lib.rs @@ -97,7 +97,7 @@ pub extern "C" fn _Unwind_Resume() -> ! { #[no_mangle] pub unsafe extern fn rust_main() { - static mut LOG_BUFFER: [u8; 4096] = [0; 4096]; + static mut LOG_BUFFER: [u8; 65536] = [0; 65536]; BufferLogger::new(&mut LOG_BUFFER[..]) .register(move || { info!("booting ARTIQ..."); diff --git a/artiq/runtime.rs/src/logger.rs b/artiq/runtime.rs/src/logger.rs index e01248da2..77d1d01d5 100644 --- a/artiq/runtime.rs/src/logger.rs +++ b/artiq/runtime.rs/src/logger.rs @@ -1,6 +1,6 @@ use core::{mem, ptr}; use core::cell::RefCell; -use log::{self, Log, LogMetadata, LogRecord, LogLevelFilter}; +use log::{self, Log, LogLevel, LogMetadata, LogRecord, LogLevelFilter}; use log_buffer::LogBuffer; use clock; @@ -61,8 +61,10 @@ impl Log for BufferLogger { writeln!(self.buffer.borrow_mut(), "[{:12}us] {:>5}({}): {}", clock::get_us(), record.level(), record.target(), record.args()).unwrap(); - println!("[{:12}us] {:>5}({}): {}", - clock::get_us(), record.level(), record.target(), record.args()); + if record.level() <= LogLevel::Info { + println!("[{:12}us] {:>5}({}): {}", + clock::get_us(), record.level(), record.target(), record.args()); + } } } }