cu29_log_runtime/
lib.rs

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

cu29_log_runtime/
lib.rs
