log-server: refactor to remove rkyv and custom Strings

This removes all custom string formatting from the `log-server`.

This should improve performance, because we're not roundtripping between
various archive formats. We instead do a single copy and operate
directly on that buffer. We also now write bytes directly, as opposed to
creating intermediate strings.

This fixes a memory issue that was introduced recently.

Signed-off-by: Sean Cross <sean@xobs.io>

services/log-server/Cargo.toml

@@ -9,7 +9,6 @@ version = "0.1.0"
 log = "0.4"
 num-derive = {version = "0.3", default-features = false}
 num-traits = {version = "0.2", default-features = false}
-rkyv = {version = "0.4.3", features = ["const_generics"], default-features = false}
 xous = {path = "../../xous-rs"}
 xous-ipc = {path = "../../xous-ipc"}
 

services/log-server/src/api.rs

@@ -1,10 +1,14 @@
-#[derive(Debug, rkyv::Archive, rkyv::Serialize, rkyv::Deserialize)]
+// #[derive(Debug, rkyv::Archive, rkyv::Serialize, rkyv::Deserialize)]
+#[repr(C)]
 pub struct LogRecord {
-    pub file: xous_ipc::String<128>,
+    pub file_length: u32,
+    pub file: [u8; 128],
     pub line: Option<u32>,
-    pub module: xous_ipc::String<128>,
+    pub module_length: u32,
+    pub module: [u8; 128],
     pub level: u32,
-    pub args: xous_ipc::String<2800>,
+    pub args_length: u32,
+    pub args: [u8; 3000],
 }
 
 #[derive(Debug, PartialEq, num_derive::FromPrimitive, num_derive::ToPrimitive)]

services/log-server/src/cursor.rs

@@ -0,0 +1,43 @@
+/// no_std replacement for Cursor.
+
+pub struct BufferWrapper<'a> {
+    buf: &'a mut [u8],
+    offset: usize,
+}
+
+impl<'a> BufferWrapper<'a> {
+    pub fn new(buf: &'a mut [u8]) -> Self {
+        BufferWrapper {
+            buf: buf,
+            offset: 0,
+        }
+    }
+    pub fn len(&self) -> usize {
+        self.offset
+    }
+}
+
+impl<'a> core::fmt::Write for BufferWrapper<'a> {
+    fn write_str(&mut self, s: &str) -> core::fmt::Result {
+        let bytes = s.as_bytes();
+
+        // Skip over already-copied data
+        let remainder = &mut self.buf[self.offset..];
+
+        // Check if there is space remaining (return error instead of panicking)
+        if remainder.len() < bytes.len() {
+            return Err(core::fmt::Error);
+        }
+
+        // Make the two slices the same length
+        let remainder = &mut remainder[..bytes.len()];
+
+        // Copy
+        remainder.copy_from_slice(bytes);
+
+        // Update offset to avoid overwriting
+        self.offset += bytes.len();
+
+        Ok(())
+    }
+}

services/log-server/src/lib.rs

@@ -2,9 +2,10 @@
 use core::fmt::Write;
 use core::sync::atomic::{AtomicBool, Ordering};
 use num_traits::ToPrimitive;
-use xous_ipc::{Buffer, String};
+use xous_ipc::Buffer;
 
 pub mod api;
+mod cursor;
 
 #[derive(Debug)]
 pub enum LogError {
@@ -20,12 +21,7 @@ struct XousLogger {
     locked: AtomicBool,
 }
 
-// static mut XOUS_LOGGER_BACKING: XousLoggerBacking = XousLoggerBacking {
-//     conn: 0,
-//     initialized: false,
-//     buffer: None,
-// };
-
+const BUFFER_SIZE: usize = 4096;
 static mut XOUS_LOGGER_BACKING: Option<XousLoggerBacking> = None;
 
 struct XousLoggerBacking<'a> {
@@ -37,8 +33,7 @@ impl<'a> XousLoggerBacking<'a> {
     pub fn new() -> Result<Self, xous::Error> {
         Ok(XousLoggerBacking {
             conn: xous::connect(xous::SID::from_bytes(b"xous-log-server ").unwrap())?,
-            // why 4000? tests non-power of 2 sizes in rkyv APIs. Could make it 4096 as well...
-            buffer: Buffer::new(4000),
+            buffer: Buffer::new(BUFFER_SIZE),
         })
     }
 }
@@ -47,25 +42,37 @@ impl Default for XousLoggerBacking<'_> {
     fn default() -> Self {
         XousLoggerBacking {
             conn: xous::connect(xous::SID::from_bytes(b"xous-log-server ").unwrap()).unwrap(),
-            // why 4000? tests non-power of 2 sizes in rkyv APIs. Could make it 4096 as well...
-            buffer: Buffer::new(4000),
+            buffer: Buffer::new(BUFFER_SIZE),
         }
     }
 }
 
 impl XousLoggerBacking<'_> {
     fn log_impl(&mut self, record: &log::Record) {
-        let mut args = String::<2800>::new();
-        write!(args, "{}", record.args()).unwrap();
-        let lr = api::LogRecord {
-            file: String::from_str(record.file().unwrap_or("")),
-            line: record.line(),
-            module: String::from_str(record.module_path().unwrap_or("")),
-            level: record.level() as u32,
-            args,
-        };
+        {
+            assert!(core::mem::size_of::<api::LogRecord>() < BUFFER_SIZE);
+            let log_record = unsafe { &mut *(self.buffer.as_mut_ptr() as *mut api::LogRecord) };
+
+            log_record.line = record.line();
+            log_record.level = record.level() as u32;
+
+            let file = record.file().unwrap_or_default().as_bytes();
+            log_record.file_length = file.len() as u32;
+            for (dest, src) in log_record.file.iter_mut().zip(file) {
+                *dest = *src;
+            }
+
+            let module = record.module_path().unwrap_or_default().as_bytes();
+            log_record.module_length = module.len() as u32;
+            for (dest, src) in log_record.module.iter_mut().zip(module) {
+                *dest = *src;
+            }
+
+            let mut wrapper = cursor::BufferWrapper::new(&mut log_record.args);
+            write!(wrapper, "{}", record.args()).unwrap();
+            log_record.args_length = wrapper.len() as u32;
+        }
 
-        self.buffer.rewrite(lr).unwrap();
         self.buffer
             .lend(self.conn, crate::api::Opcode::LogRecord.to_u32().unwrap())
             .unwrap();

services/log-server/src/main.rs

@@ -281,7 +281,7 @@ fn handle_opcode(
         match opcode {
             api::Opcode::LogRecord => {
                 let buffer = unsafe { xous_ipc::Buffer::from_memory_message(mem) };
-                let lr: LogRecord = buffer.to_original::<LogRecord, _>().unwrap();
+                let lr = unsafe { &*(buffer.as_ptr() as *const LogRecord) };
                 let level = if log::Level::Error as u32 == lr.level {
                     "ERR "
                 } else if log::Level::Warn as u32 == lr.level {
@@ -295,16 +295,39 @@ fn handle_opcode(
                 } else {
                     "UNKNOWN"
                 };
-                if let Some(line) = lr.line {
-                    writeln!(
-                        output,
-                        "{}:{}: {} ({}:{})",
-                        level, lr.module, lr.args, lr.file, line
-                    )
-                    .unwrap();
-                } else {
-                    writeln!(output, "{}:{}: {} ({})", level, lr.module, lr.args, lr.file).unwrap();
+                if lr.file_length as usize >= lr.file.len() {
+                    return;
                 }
+                if lr.args_length as usize >= lr.args.len() {
+                    return;
+                }
+                if lr.module_length as usize > lr.module.len() {
+                    return;
+                }
+
+                let file_slice = &lr.file[0..lr.file_length as usize];
+
+                let args_slice = &lr.args[0..lr.args_length as usize];
+
+                let module_slice = &lr.module[0..lr.module_length as usize];
+
+                write!(output, "{}:", level).ok();
+                for c in module_slice {
+                    output.putc(*c);
+                }
+                write!(output, ": ").ok();
+                for c in args_slice {
+                    output.putc(*c);
+                }
+
+                write!(output, " (").ok();
+                for c in file_slice {
+                    output.putc(*c);
+                }
+                if let Some(line) = lr.line {
+                    write!(output, ":{}", line).ok();
+                }
+                writeln!(output, ")").ok();
             }
             api::Opcode::StandardOutput | api::Opcode::StandardError => {
                 // let mut buffer_start_offset = mem.offset.map(|o| o.get()).unwrap_or(0);