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

@@ -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)

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<LogBuffer<&'static mut [u8]>>,
+    filter:        RefCell<Option<MaxLogLevelFilter>>,
     trace_to_uart: Cell<bool>
 }
 
@@ -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 \

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()?),

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"] }

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 } => {

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()