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

cu29_log_runtime/
lib.rs
