Skip to main content

cu29_log_runtime/
lib.rs

1#![cfg_attr(not(feature = "std"), no_std)]
2#[cfg(not(feature = "std"))]
3extern crate alloc;
4
5use core::sync::atomic::{AtomicUsize, Ordering};
6use cu29_clock::RobotClock;
7use cu29_log::CuLogEntry;
8#[allow(unused_imports)]
9use cu29_log::CuLogLevel;
10use cu29_traits::{CuResult, WriteStream};
11use log::Log;
12
13#[cfg(not(feature = "std"))]
14mod imp {
15    pub use alloc::boxed::Box;
16    pub use spin::Mutex;
17    pub use spin::once::Once as OnceLock;
18}
19
20#[cfg(feature = "std")]
21mod imp {
22    pub use bincode::config::Configuration;
23    pub use bincode::enc::Encode;
24    pub use bincode::enc::Encoder;
25    pub use bincode::enc::EncoderImpl;
26    pub use bincode::enc::write::Writer;
27    pub use bincode::error::EncodeError;
28    pub use std::fmt::{Debug, Formatter};
29    pub use std::fs::File;
30    pub use std::io::{BufWriter, Write};
31    pub use std::path::PathBuf;
32    pub use std::sync::{Mutex, OnceLock};
33
34    #[cfg(debug_assertions)]
35    pub use {std::collections::HashMap, strfmt::strfmt};
36}
37
38use imp::*;
39
40#[allow(dead_code)] // for no_std
41#[derive(Debug)]
42struct DummyWriteStream;
43
44impl WriteStream<CuLogEntry> for DummyWriteStream {
45    #[allow(unused_variables)] // for no_std
46    fn log(&mut self, obj: &CuLogEntry) -> CuResult<()> {
47        #[cfg(feature = "std")]
48        eprintln!("Pending logs got cut: {obj:?}");
49        Ok(())
50    }
51}
52type LogWriter = Box<dyn WriteStream<CuLogEntry> + Send + 'static>;
53
54/// Callback signature: receives the structured entry plus its format string and param names.
55pub type LiveLogListener = Box<dyn Fn(&CuLogEntry, &str, &[&str]) + Send + Sync + 'static>;
56
57#[cfg(feature = "std")]
58fn lock_mutex<T>(m: &Mutex<T>) -> std::sync::MutexGuard<'_, T> {
59    m.lock().unwrap_or_else(|e| e.into_inner())
60}
61
62#[cfg(all(feature = "std", debug_assertions))]
63pub fn format_message_only(
64    format_str: &str,
65    params: &[String],
66    named_params: &HashMap<String, String>,
67) -> CuResult<String> {
68    if format_str.contains("{}") {
69        let mut formatted = format_str.to_string();
70        for param in params.iter() {
71            if !formatted.contains("{}") {
72                break;
73            }
74            formatted = formatted.replacen("{}", param, 1);
75        }
76        if formatted.contains("{}") && !named_params.is_empty() {
77            let mut named = named_params.iter().collect::<Vec<_>>();
78            named.sort_by(|a, b| a.0.cmp(b.0));
79            for (_, value) in named {
80                if !formatted.contains("{}") {
81                    break;
82                }
83                formatted = formatted.replacen("{}", value, 1);
84            }
85        }
86        return Ok(formatted);
87    }
88
89    // Named replacement
90    imp::strfmt(format_str, named_params).map_err(|e| {
91        cu29_traits::CuError::new_with_cause(
92            format!(
93                "Failed to format log message: {format_str:?} with variables [{named_params:?}]"
94            )
95            .as_str(),
96            e,
97        )
98    })
99}
100
101#[cfg(not(feature = "std"))]
102fn lock_mutex<T>(m: &Mutex<T>) -> spin::MutexGuard<'_, T> {
103    m.lock()
104}
105
106/// Shared logging state reachable from the macro-generated calls.
107struct LoggerState {
108    writer: Mutex<LogWriter>,
109    clock: RobotClock,
110    live_listener: Mutex<Option<LiveLogListener>>,
111}
112
113impl core::fmt::Debug for LoggerState {
114    fn fmt(&self, f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
115        f.debug_struct("LoggerState")
116            .field("clock", &self.clock)
117            .finish_non_exhaustive()
118    }
119}
120
121static LOGGER_STATE: OnceLock<LoggerState> = OnceLock::new();
122static STRUCTURED_LOG_BYTES: AtomicUsize = AtomicUsize::new(0);
123
124#[cfg(feature = "std")]
125fn init_logger_state(state: LoggerState) {
126    LOGGER_STATE.set(state).unwrap();
127}
128
129#[cfg(not(feature = "std"))]
130fn init_logger_state(state: LoggerState) {
131    LOGGER_STATE.call_once(|| state);
132}
133
134pub struct NullLog;
135impl Log for NullLog {
136    fn enabled(&self, _metadata: &log::Metadata) -> bool {
137        false
138    }
139
140    fn log(&self, _record: &log::Record) {}
141    fn flush(&self) {}
142}
143
144/// The lifetime of this struct is the lifetime of the logger.
145pub struct LoggerRuntime {}
146
147impl LoggerRuntime {
148    /// destination is the binary stream in which we will log the structured log.
149    /// `extra_text_logger` is the logger that will log the text logs in real time. This is slow and only for debug builds.
150    pub fn init(
151        clock: RobotClock,
152        destination: impl WriteStream<CuLogEntry> + 'static,
153        #[allow(unused_variables)] extra_text_logger: Option<impl Log + 'static>,
154    ) -> Self {
155        STRUCTURED_LOG_BYTES.store(0, Ordering::Relaxed);
156
157        if let Some(state) = LOGGER_STATE.get() {
158            let mut writer_guard = lock_mutex(&state.writer);
159            *writer_guard = Box::new(destination);
160        } else {
161            let state = LoggerState {
162                writer: Mutex::new(Box::new(destination)),
163                clock,
164                live_listener: Mutex::new(None),
165            };
166            init_logger_state(state);
167        }
168
169        // If caller provided a default text logger (std + debug builds), install it as the live listener.
170        #[cfg(all(feature = "std", debug_assertions))]
171        if let Some(logger) = extra_text_logger {
172            register_live_log_listener(move |entry, format_str, param_names| {
173                // Build a text line from structured data—no parsing.
174                let params: Vec<String> = entry.params.iter().map(|v| v.to_string()).collect();
175                let named_params: HashMap<String, String> = param_names
176                    .iter()
177                    .zip(params.iter())
178                    .map(|(name, value)| (name.to_string(), value.clone()))
179                    .collect();
180                if let Ok(line) = format_message_only(format_str, params.as_slice(), &named_params)
181                {
182                    logger.log(
183                        &log::Record::builder()
184                            .args(format_args!("{line}"))
185                            .level(match entry.level {
186                                CuLogLevel::Debug => log::Level::Debug,
187                                CuLogLevel::Info => log::Level::Info,
188                                CuLogLevel::Warning => log::Level::Warn,
189                                CuLogLevel::Error => log::Level::Error,
190                                CuLogLevel::Critical => log::Level::Error,
191                            })
192                            .target("cu29_log")
193                            .module_path_static(Some("cu29_log"))
194                            .file_static(Some("cu29_log"))
195                            .line(Some(0))
196                            .build(),
197                    );
198                }
199            });
200        }
201
202        LoggerRuntime {}
203    }
204
205    pub fn flush(&self) {
206        // no op in no_std TODO(gbin): check if it will be needed in no_std at some point.
207        if let Some(state) = LOGGER_STATE.get() {
208            let mut writer = lock_mutex(&state.writer);
209            let _ = writer.flush(); // ignore errors in no_std
210        } else {
211            #[cfg(feature = "std")]
212            eprintln!("cu29_log: Logger not initialized.");
213        }
214    }
215}
216
217impl Drop for LoggerRuntime {
218    fn drop(&mut self) {
219        self.flush();
220        // Assume on no-std that there is no buffering. TODO(gbin): check if this hold true.
221        if let Some(state) = LOGGER_STATE.get() {
222            let mut writer_guard = lock_mutex(&state.writer);
223            *writer_guard = Box::new(DummyWriteStream);
224        }
225    }
226}
227
228/// Function called from generated code to log data.
229/// It moves entry by design, it will be absorbed in the queue.
230#[inline(always)]
231fn log_inner(
232    entry: &mut CuLogEntry,
233    notify: bool,
234    format_str: &str,
235    param_names: &[&str],
236) -> CuResult<()> {
237    let Some(state) = LOGGER_STATE.get() else {
238        return Err("Logger not initialized.".into());
239    };
240    entry.time = state.clock.now();
241
242    let mut guard = lock_mutex(&state.writer);
243    guard.log(entry)?;
244    if let Some(bytes) = guard.last_log_bytes() {
245        STRUCTURED_LOG_BYTES.fetch_add(bytes, Ordering::Relaxed);
246    }
247
248    // Basic notification; richer context added in log_debug_mode.
249    if notify {
250        notify_live_listeners(entry, format_str, param_names);
251    }
252    Ok(())
253}
254
255/// Public entry point used in release / no-debug paths.
256#[inline(always)]
257pub fn log(entry: &mut CuLogEntry) -> CuResult<()> {
258    log_inner(entry, true, "", &[])
259}
260
261/// Returns the total number of bytes written to the structured log stream.
262pub fn structured_log_bytes_total() -> u64 {
263    STRUCTURED_LOG_BYTES.load(Ordering::Relaxed) as u64
264}
265
266/// This version of log is only compiled in debug mode
267/// This allows a normal logging framework to be bridged.
268#[cfg(debug_assertions)]
269pub fn log_debug_mode(
270    entry: &mut CuLogEntry,
271    _format_str: &str, // this is the missing info at runtime.
272    _param_names: &[&str],
273) -> CuResult<()> {
274    // Write structured log but avoid double-notifying live listeners here.
275    log_inner(entry, false, "", &[])?;
276
277    // and the bridging is only available in std.
278    #[cfg(feature = "std")]
279    extra_log(entry, _format_str, _param_names)?;
280
281    Ok(())
282}
283
284#[cfg(debug_assertions)]
285#[cfg(feature = "std")]
286fn extra_log(entry: &mut CuLogEntry, format_str: &str, param_names: &[&str]) -> CuResult<()> {
287    // Legacy text logging now goes through the live listener; keep this as a thin shim.
288    notify_live_listeners(entry, format_str, param_names);
289
290    Ok(())
291}
292
293/// Register a live log listener; subsequent logs invoke `cb`. No-op if runtime not initialized.
294pub fn register_live_log_listener<F>(cb: F)
295where
296    F: Fn(&CuLogEntry, &str, &[&str]) + Send + Sync + 'static,
297{
298    if let Some(state) = LOGGER_STATE.get() {
299        let mut guard = lock_mutex(&state.live_listener);
300        *guard = Some(Box::new(cb));
301    }
302}
303
304/// Remove any registered live log listener. No-op if runtime not initialized.
305pub fn unregister_live_log_listener() {
306    if let Some(state) = LOGGER_STATE.get() {
307        let mut guard = lock_mutex(&state.live_listener);
308        *guard = None;
309    }
310}
311
312/// Notify registered listener if any.
313#[allow(clippy::collapsible_if)]
314pub(crate) fn notify_live_listeners(entry: &CuLogEntry, format_str: &str, param_names: &[&str]) {
315    if let Some(state) = LOGGER_STATE.get() {
316        if let Some(cb) = lock_mutex(&state.live_listener).as_ref() {
317            cb(entry, format_str, param_names);
318        }
319    }
320}
321// This is an adaptation of the Iowriter from bincode.
322
323#[cfg(feature = "std")]
324pub struct OwningIoWriter<W: Write> {
325    writer: BufWriter<W>,
326    bytes_written: usize,
327}
328
329#[cfg(feature = "std")]
330impl<W: Write> OwningIoWriter<W> {
331    pub fn new(writer: W) -> Self {
332        Self {
333            writer: BufWriter::new(writer),
334            bytes_written: 0,
335        }
336    }
337
338    pub fn bytes_written(&self) -> usize {
339        self.bytes_written
340    }
341
342    pub fn flush(&mut self) -> Result<(), EncodeError> {
343        self.writer.flush().map_err(|inner| EncodeError::Io {
344            inner,
345            index: self.bytes_written,
346        })
347    }
348}
349
350#[cfg(feature = "std")]
351impl<W: Write> Writer for OwningIoWriter<W> {
352    #[inline(always)]
353    fn write(&mut self, bytes: &[u8]) -> Result<(), EncodeError> {
354        self.writer
355            .write_all(bytes)
356            .map_err(|inner| EncodeError::Io {
357                inner,
358                index: self.bytes_written,
359            })?;
360        self.bytes_written += bytes.len();
361        Ok(())
362    }
363}
364
365/// This allows this crate to be used outside of Copper (ie. decoupling it from the unifiedlog.
366#[cfg(feature = "std")]
367pub struct SimpleFileWriter {
368    path: PathBuf,
369    encoder: EncoderImpl<OwningIoWriter<File>, Configuration>,
370}
371
372#[cfg(feature = "std")]
373impl SimpleFileWriter {
374    pub fn new(path: &PathBuf) -> CuResult<Self> {
375        let file = std::fs::OpenOptions::new()
376            .create(true)
377            .truncate(true)
378            .write(true)
379            .open(path)
380            .map_err(|e| format!("Failed to open file: {e:?}"))?;
381
382        let writer = OwningIoWriter::new(file);
383        let encoder = EncoderImpl::new(writer, bincode::config::standard());
384
385        Ok(SimpleFileWriter {
386            path: path.clone(),
387            encoder,
388        })
389    }
390}
391
392#[cfg(feature = "std")]
393impl Debug for SimpleFileWriter {
394    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
395        write!(f, "SimpleFileWriter for path {:?}", self.path)
396    }
397}
398
399#[cfg(feature = "std")]
400impl WriteStream<CuLogEntry> for SimpleFileWriter {
401    #[inline(always)]
402    fn log(&mut self, obj: &CuLogEntry) -> CuResult<()> {
403        obj.encode(&mut self.encoder)
404            .map_err(|e| format!("Failed to write to file: {e:?}"))?;
405        Ok(())
406    }
407
408    fn flush(&mut self) -> CuResult<()> {
409        self.encoder
410            .writer()
411            .flush()
412            .map_err(|e| format!("Failed to flush file: {e:?}"))?;
413        Ok(())
414    }
415}
416
417#[cfg(test)]
418mod tests {
419    use crate::CuLogEntry;
420    use bincode::config::standard;
421    use cu29_log::CuLogLevel;
422    use cu29_value::Value;
423    use smallvec::smallvec;
424
425    #[cfg(not(feature = "std"))]
426    use alloc::string::ToString;
427
428    #[test]
429    fn test_encode_decode_structured_log() {
430        let log_entry = CuLogEntry {
431            time: 0.into(),
432            level: CuLogLevel::Info,
433            msg_index: 1,
434            paramname_indexes: smallvec![2, 3],
435            params: smallvec![Value::String("test".to_string())],
436        };
437        let encoded = bincode::encode_to_vec(&log_entry, standard()).unwrap();
438        let decoded_tuple: (CuLogEntry, usize) =
439            bincode::decode_from_slice(&encoded, standard()).unwrap();
440        assert_eq!(log_entry, decoded_tuple.0);
441    }
442}