From e8c093deb3e5aafdf1a77ec01d2608beeabffc2b Mon Sep 17 00:00:00 2001 From: whitequark Date: Fri, 3 Mar 2017 06:06:26 +0000 Subject: [PATCH] Allow changing runtime log level without recompilation. This shouldn't affect performance much, as the log crate guards every log statement with a branch, adding just two instructions. --- artiq/coredevice/comm_kernel.py | 17 +++++++++++++++++ artiq/firmware/liblogger_artiq/lib.rs | 15 +++++++++++++-- artiq/firmware/libproto/session_proto.rs | 18 ++++++++++++++++++ artiq/firmware/runtime/Cargo.toml | 2 +- artiq/firmware/runtime/session.rs | 6 +++++- artiq/frontend/artiq_corelog.py | 13 ++++++++++++- 6 files changed, 66 insertions(+), 5 deletions(-) diff --git a/artiq/coredevice/comm_kernel.py b/artiq/coredevice/comm_kernel.py index b6a1a00fc..de3c55d9f 100644 --- a/artiq/coredevice/comm_kernel.py +++ b/artiq/coredevice/comm_kernel.py @@ -18,6 +18,7 @@ logger = logging.getLogger(__name__) class _H2DMsgType(Enum): LOG_REQUEST = 1 LOG_CLEAR = 2 + LOG_FILTER = 13 SYSTEM_INFO_REQUEST = 3 SWITCH_CLOCK = 4 @@ -58,6 +59,15 @@ class _D2HMsgType(Enum): CLOCK_FAILURE = 15 +class _LogLevel(Enum): + OFF = 0 + ERROR = 1 + WARN = 2 + INFO = 3 + DEBUG = 4 + TRACE = 5 + + class UnsupportedDevice(Exception): pass @@ -279,6 +289,13 @@ class CommKernel: self._read_empty(_D2HMsgType.LOG_REPLY) + def set_log_level(self, level): + if level not in _LogLevel.__members__: + raise ValueError("invalid log level {}".format(level)) + + self._write_header(_H2DMsgType.LOG_FILTER) + self._write_int8(getattr(_LogLevel, level).value) + def flash_storage_read(self, key): self._write_header(_H2DMsgType.FLASH_READ_REQUEST) self._write_string(key) diff --git a/artiq/firmware/liblogger_artiq/lib.rs b/artiq/firmware/liblogger_artiq/lib.rs index 6a424eae0..19c747c1b 100644 --- a/artiq/firmware/liblogger_artiq/lib.rs +++ b/artiq/firmware/liblogger_artiq/lib.rs @@ -8,12 +8,13 @@ extern crate board; use core::{mem, ptr}; use core::cell::{Cell, RefCell}; use core::fmt::Write; -use log::{Log, LogLevel, LogMetadata, LogRecord, LogLevelFilter}; +use log::{Log, LogLevel, LogMetadata, LogRecord, LogLevelFilter, MaxLogLevelFilter}; use log_buffer::LogBuffer; use board::{Console, clock}; pub struct BufferLogger { buffer: RefCell>, + filter: RefCell>, trace_to_uart: Cell } @@ -23,6 +24,7 @@ impl BufferLogger { pub fn new(buffer: &'static mut [u8]) -> BufferLogger { BufferLogger { buffer: RefCell::new(LogBuffer::new(buffer)), + filter: RefCell::new(None), trace_to_uart: Cell::new(true) } } @@ -33,7 +35,8 @@ impl BufferLogger { // before log::shutdown_logger_raw is called). unsafe { log::set_logger_raw(|max_log_level| { - max_log_level.set(LogLevelFilter::Trace); + max_log_level.set(LogLevelFilter::Info); + *self.filter.borrow_mut() = Some(max_log_level); self as *const Log }).expect("global logger can only be initialized once"); LOGGER = self; @@ -57,6 +60,14 @@ impl BufferLogger { f(self.buffer.borrow_mut().extract()) } + pub fn set_max_log_level(&self, max_level: LogLevelFilter) { + self.filter + .borrow() + .as_ref() + .expect("register the logger before setting maximum log level") + .set(max_level) + } + pub fn disable_trace_to_uart(&self) { if self.trace_to_uart.get() { trace!("disabling tracing to UART; all further trace messages \ diff --git a/artiq/firmware/libproto/session_proto.rs b/artiq/firmware/libproto/session_proto.rs index 5a9955f86..35afbe5fb 100644 --- a/artiq/firmware/libproto/session_proto.rs +++ b/artiq/firmware/libproto/session_proto.rs @@ -1,6 +1,8 @@ use std::io::{self, Read, Write}; use std::vec::Vec; use std::string::String; +#[cfg(feature = "log")] +use log::LogLevelFilter; use {ReadExt, WriteExt}; fn read_sync(reader: &mut Read) -> io::Result<()> { @@ -20,6 +22,8 @@ fn write_sync(writer: &mut Write) -> io::Result<()> { pub enum Request { Log, LogClear, + #[cfg(feature = "log")] + LogFilter(LogLevelFilter), SystemInfo, SwitchClock(u8), @@ -50,6 +54,20 @@ impl Request { Ok(match reader.read_u8()? { 1 => Request::Log, 2 => Request::LogClear, + #[cfg(feature = "log")] + 13 => { + let level = match reader.read_u8()? { + 0 => LogLevelFilter::Off, + 1 => LogLevelFilter::Error, + 2 => LogLevelFilter::Warn, + 3 => LogLevelFilter::Info, + 4 => LogLevelFilter::Debug, + 5 => LogLevelFilter::Trace, + _ => return Err(io::Error::new(io::ErrorKind::InvalidData, + "invalid log level")) + }; + Request::LogFilter(level) + } 3 => Request::SystemInfo, 4 => Request::SwitchClock(reader.read_u8()?), 5 => Request::LoadKernel(reader.read_bytes()?), diff --git a/artiq/firmware/runtime/Cargo.toml b/artiq/firmware/runtime/Cargo.toml index 1c7fcd2b0..69575572f 100644 --- a/artiq/firmware/runtime/Cargo.toml +++ b/artiq/firmware/runtime/Cargo.toml @@ -15,7 +15,7 @@ build_artiq = { path = "../libbuild_artiq" } [dependencies] byteorder = { version = "1.0", default-features = false } cslice = { version = "0.3" } -log = { version = "0.3", default-features = false, features = ["max_level_debug"] } +log = { version = "0.3", default-features = false } fringe = { version = "= 1.1.0", default-features = false, features = ["alloc"] } alloc_artiq = { path = "../liballoc_artiq" } std_artiq = { path = "../libstd_artiq", features = ["alloc"] } diff --git a/artiq/firmware/runtime/session.rs b/artiq/firmware/runtime/session.rs index 9cf7d3759..8e5af82ee 100644 --- a/artiq/firmware/runtime/session.rs +++ b/artiq/firmware/runtime/session.rs @@ -226,11 +226,15 @@ fn process_host_message(io: &Io, }) }) } - host::Request::LogClear => { BufferLogger::with_instance(|logger| logger.clear()); host_write(stream, host::Reply::Log("")) } + host::Request::LogFilter(filter) => { + info!("changing log level to {}", filter); + BufferLogger::with_instance(|logger| logger.set_max_log_level(filter)); + Ok(()) + } // artiq_coreconfig host::Request::FlashRead { ref key } => { diff --git a/artiq/frontend/artiq_corelog.py b/artiq/frontend/artiq_corelog.py index 4842b7d6b..3fcb44f14 100755 --- a/artiq/frontend/artiq_corelog.py +++ b/artiq/frontend/artiq_corelog.py @@ -13,6 +13,14 @@ def get_argparser(): verbosity_args(parser) parser.add_argument("--device-db", default="device_db.pyon", help="device database file (default: '%(default)s')") + + subparsers = parser.add_subparsers(dest="action") + + p_set_level = subparsers.add_parser("set_level", + help="set minimum level for messages to be logged") + p_set_level.add_argument("level", metavar="LEVEL", type=str, + help="log level (one of: OFF ERROR WARN INFO DEBUG TRACE)") + return parser @@ -23,7 +31,10 @@ def main(): try: comm = device_mgr.get("comm") comm.check_system_info() - print(comm.get_log(), end="") + if args.action == "set_level": + comm.set_log_level(args.level) + else: + print(comm.get_log(), end="") finally: device_mgr.close_devices()