Skip to main content

cu29_log/
lib.rs

1#![cfg_attr(not(feature = "std"), no_std)]
2#[cfg(not(feature = "std"))]
3extern crate alloc;
4extern crate core;
5
6use bincode::{Decode, Encode};
7use cu29_clock::CuTime;
8use cu29_value::Value;
9use serde::{Deserialize, Serialize};
10use smallvec::SmallVec;
11
12#[cfg(not(feature = "std"))]
13mod imp {
14    pub use core::fmt::Display;
15    pub use core::fmt::Formatter;
16    pub use core::fmt::Result as FmtResult;
17}
18
19#[cfg(feature = "defmt")]
20extern crate defmt;
21
22#[cfg(feature = "std")]
23mod imp {
24    pub use core::fmt::Display;
25    pub use cu29_traits::CuResult;
26    // strfmt forces hashmap from std
27    pub use std::collections::HashMap;
28    pub use std::fmt::Formatter;
29    pub use std::fmt::Result as FmtResult;
30    // This is a blocker for no_std, so no live logging in no_std for now.
31    pub use strfmt::strfmt;
32}
33
34use imp::*;
35
36/// Log levels for Copper.
37#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Serialize, Deserialize)]
38pub enum CuLogLevel {
39    /// Detailed information useful during development
40    Debug = 0,
41    /// General information about system operation
42    Info = 1,
43    /// Indication of potential issues that don't prevent normal operation
44    Warning = 2,
45    /// Issues that might disrupt normal operation but don't cause system failure
46    Error = 3,
47    /// Critical errors requiring immediate attention, usually resulting in system failure
48    Critical = 4,
49}
50
51impl CuLogLevel {
52    /// Returns true if this log level is enabled for the given max level
53    ///
54    /// The log level is enabled if it is greater than or equal to the max level.
55    /// For example, if max_level is Info, then Info, Warning, Error and Critical are enabled,
56    /// but Debug is not.
57    #[inline]
58    pub const fn enabled(self, max_level: CuLogLevel) -> bool {
59        self as u8 >= max_level as u8
60    }
61}
62
63#[allow(dead_code)]
64pub const ANONYMOUS: u32 = 0;
65
66pub const MAX_LOG_PARAMS_ON_STACK: usize = 10;
67
68/// Runtime origin metadata attached to a structured log entry when available.
69#[derive(Debug, Clone, Copy, Default, Serialize, Deserialize, PartialEq, Eq, Encode, Decode)]
70pub struct CuLogOrigin {
71    /// CopperList id of the callback that emitted this log line.
72    pub culistid: Option<u64>,
73    /// Runtime component id recorded for the active callback.
74    pub component_id: Option<u32>,
75    /// Current task index when the emitting callback belongs to a task.
76    pub task_index: Option<u32>,
77}
78
79/// This is the basic structure for a log entry in Copper.
80#[derive(Debug, Clone, Serialize, Deserialize, PartialEq)]
81pub struct CuLogEntry {
82    // Approximate time when the log entry was created.
83    pub time: CuTime,
84
85    // Log level of this entry
86    pub level: CuLogLevel,
87
88    // Runtime origin metadata when the log was emitted from a Copper callback.
89    pub origin: CuLogOrigin,
90
91    // interned index of the message
92    pub msg_index: u32,
93
94    // interned indexes of the parameter names
95    pub paramname_indexes: SmallVec<[u32; MAX_LOG_PARAMS_ON_STACK]>,
96
97    // Serializable values for the parameters (Values are acting like an Any Value).
98    pub params: SmallVec<[Value; MAX_LOG_PARAMS_ON_STACK]>,
99}
100
101impl Encode for CuLogEntry {
102    fn encode<E: bincode::enc::Encoder>(
103        &self,
104        encoder: &mut E,
105    ) -> Result<(), bincode::error::EncodeError> {
106        self.time.encode(encoder)?;
107        (self.level as u8).encode(encoder)?;
108        self.origin.encode(encoder)?;
109        self.msg_index.encode(encoder)?;
110
111        (self.paramname_indexes.len() as u64).encode(encoder)?;
112        for &index in &self.paramname_indexes {
113            index.encode(encoder)?;
114        }
115
116        (self.params.len() as u64).encode(encoder)?;
117        for param in &self.params {
118            param.encode(encoder)?;
119        }
120
121        Ok(())
122    }
123}
124
125impl<Context> Decode<Context> for CuLogEntry {
126    fn decode<D: bincode::de::Decoder>(
127        decoder: &mut D,
128    ) -> Result<Self, bincode::error::DecodeError> {
129        let time = CuTime::decode(decoder)?;
130        let level_raw = u8::decode(decoder)?;
131        let level = match level_raw {
132            0 => CuLogLevel::Debug,
133            1 => CuLogLevel::Info,
134            2 => CuLogLevel::Warning,
135            3 => CuLogLevel::Error,
136            4 => CuLogLevel::Critical,
137            _ => CuLogLevel::Debug, // Fallback for malformed data
138        };
139        let origin = CuLogOrigin::decode(decoder)?;
140        let msg_index = u32::decode(decoder)?;
141
142        let paramname_len = usize::try_from(u64::decode(decoder)?).map_err(|_| {
143            bincode::error::DecodeError::Other("log parameter name count exceeds usize")
144        })?;
145        decoder.claim_container_read::<u32>(paramname_len)?;
146        let mut paramname_indexes = SmallVec::with_capacity(paramname_len);
147        for _ in 0..paramname_len {
148            decoder.unclaim_bytes_read(core::mem::size_of::<u32>());
149            paramname_indexes.push(u32::decode(decoder)?);
150        }
151
152        let params_len = usize::try_from(u64::decode(decoder)?)
153            .map_err(|_| bincode::error::DecodeError::Other("log parameter count exceeds usize"))?;
154        decoder.claim_container_read::<Value>(params_len)?;
155        let mut params = SmallVec::with_capacity(params_len);
156        for _ in 0..params_len {
157            decoder.unclaim_bytes_read(core::mem::size_of::<Value>());
158            params.push(Value::decode(decoder)?);
159        }
160
161        Ok(CuLogEntry {
162            time,
163            level,
164            origin,
165            msg_index,
166            paramname_indexes,
167            params,
168        })
169    }
170}
171
172// This is for internal debug purposes.
173impl Display for CuLogEntry {
174    fn fmt(&self, f: &mut Formatter<'_>) -> FmtResult {
175        write!(
176            f,
177            "CuLogEntry {{ level: {:?}, origin: {:?}, msg_index: {}, paramname_indexes: {:?}, params: {:?} }}",
178            self.level, self.origin, self.msg_index, self.paramname_indexes, self.params
179        )
180    }
181}
182
183impl CuLogEntry {
184    /// msg_index is the interned index of the message.
185    pub fn new(msg_index: u32, level: CuLogLevel) -> Self {
186        CuLogEntry {
187            time: 0.into(), // We have no clock at that point it is called from random places
188            // the clock will be set at actual log time from clock source provided
189            level,
190            origin: CuLogOrigin::default(),
191            msg_index,
192            paramname_indexes: SmallVec::new(),
193            params: SmallVec::new(),
194        }
195    }
196
197    /// Attach runtime origin metadata to this log entry.
198    pub fn set_origin(
199        &mut self,
200        culistid: Option<u64>,
201        component_id: Option<u32>,
202        task_index: Option<u32>,
203    ) {
204        self.origin = CuLogOrigin {
205            culistid,
206            component_id,
207            task_index,
208        };
209    }
210
211    /// Add a parameter to the log entry.
212    /// paramname_index is the interned index of the parameter name.
213    pub fn add_param(&mut self, paramname_index: u32, param: Value) {
214        self.paramname_indexes.push(paramname_index);
215        self.params.push(param);
216    }
217}
218
219/// Text log line formatter.
220/// Only available on std. TODO(gbin): Maybe reconsider that at some point
221#[inline]
222#[cfg(feature = "std")]
223pub fn format_logline(
224    time: CuTime,
225    level: CuLogLevel,
226    format_str: &str,
227    params: &[String],
228    named_params: &HashMap<String, String>,
229) -> CuResult<String> {
230    // If the format string uses positional placeholders (`{}`), fill them in order using the
231    // anonymous params first, then any named params (sorted for determinism) if needed.
232    if format_str.contains("{}") {
233        let mut formatted = format_str.to_string();
234        for param in params.iter() {
235            if !formatted.contains("{}") {
236                break;
237            }
238            formatted = formatted.replacen("{}", param, 1);
239        }
240        if !named_params.is_empty() {
241            let mut named = named_params.iter().collect::<Vec<_>>();
242            named.sort_by(|a, b| a.0.cmp(b.0));
243            for (name, value) in named {
244                if formatted.contains("{}") {
245                    formatted = formatted.replacen("{}", value, 1);
246                }
247                formatted = formatted.replace(&format!("{{{name}}}"), value);
248            }
249        }
250        return Ok(format!("{time} [{level:?}]: {formatted}"));
251    }
252
253    // Otherwise rely on named formatting.
254    let logline = strfmt(format_str, named_params).map_err(|e| {
255        cu29_traits::CuError::new_with_cause(
256            format!("Failed to format log line: {format_str:?} with variables [{named_params:?}]")
257                .as_str(),
258            e,
259        )
260    })?;
261    Ok(format!("{time} [{level:?}]: {logline}"))
262}
263
264/// Rebuild a log line from the interned strings and the CuLogEntry.
265/// This basically translates the world of copper logs to text logs.
266#[cfg(feature = "std")]
267pub fn rebuild_logline(all_interned_strings: &[String], entry: &CuLogEntry) -> CuResult<String> {
268    let format_string = all_interned_strings
269        .get(entry.msg_index as usize)
270        .ok_or_else(|| {
271            cu29_traits::CuError::from(format!(
272                "Invalid message index {} (interned strings length {})",
273                entry.msg_index,
274                all_interned_strings.len()
275            ))
276        })?;
277    if entry.paramname_indexes.len() != entry.params.len() {
278        return Err(cu29_traits::CuError::from(format!(
279            "Mismatched parameter metadata: {} names for {} params",
280            entry.paramname_indexes.len(),
281            entry.params.len()
282        )));
283    }
284
285    let mut anon_params = Vec::with_capacity(entry.params.len());
286    let mut named_params = HashMap::with_capacity(entry.params.len());
287
288    for (i, param) in entry.params.iter().enumerate() {
289        let param_as_string = format!("{param}");
290        if entry.paramname_indexes[i] == 0 {
291            // Anonymous parameter
292            anon_params.push(param_as_string);
293        } else {
294            // Named parameter
295            let name = all_interned_strings
296                .get(entry.paramname_indexes[i] as usize)
297                .ok_or_else(|| {
298                    cu29_traits::CuError::from(format!(
299                        "Invalid parameter name index {} (interned strings length {})",
300                        entry.paramname_indexes[i],
301                        all_interned_strings.len()
302                    ))
303                })?
304                .clone();
305            named_params.insert(name, param_as_string);
306        }
307    }
308    format_logline(
309        entry.time,
310        entry.level,
311        format_string,
312        &anon_params,
313        &named_params,
314    )
315}
316
317// ---- defmt shims, selected at cu29-log compile time ----
318#[cfg(all(feature = "defmt", not(feature = "std")))]
319#[macro_export]
320macro_rules! __cu29_defmt_debug {
321    ($fmt:literal $(, $arg:expr)* $(,)?) => {
322        ::defmt::debug!($fmt $(, $arg)*);
323    }
324}
325#[cfg(not(all(feature = "defmt", not(feature = "std"))))]
326#[macro_export]
327macro_rules! __cu29_defmt_debug {
328    ($($tt:tt)*) => {{}};
329}
330
331#[cfg(all(feature = "defmt", not(feature = "std")))]
332#[macro_export]
333macro_rules! __cu29_defmt_info {
334    ($fmt:literal $(, $arg:expr)* $(,)?) => {
335        ::defmt::info!($fmt $(, $arg)*);
336    }
337}
338#[cfg(not(all(feature = "defmt", not(feature = "std"))))]
339#[macro_export]
340macro_rules! __cu29_defmt_info {
341    ($($tt:tt)*) => {{}};
342}
343
344#[cfg(all(feature = "defmt", not(feature = "std")))]
345#[macro_export]
346macro_rules! __cu29_defmt_warn {
347    ($fmt:literal $(, $arg:expr)* $(,)?) => {
348        ::defmt::warn!($fmt $(, $arg)*);
349    }
350}
351#[cfg(not(all(feature = "defmt", not(feature = "std"))))]
352#[macro_export]
353macro_rules! __cu29_defmt_warn {
354    ($($tt:tt)*) => {{}};
355}
356
357#[cfg(all(feature = "defmt", not(feature = "std")))]
358#[macro_export]
359macro_rules! __cu29_defmt_error {
360    ($fmt:literal $(, $arg:expr)* $(,)?) => {
361        ::defmt::error!($fmt $(, $arg)*);
362    }
363}
364#[cfg(not(all(feature = "defmt", not(feature = "std"))))]
365#[macro_export]
366macro_rules! __cu29_defmt_error {
367    ($($tt:tt)*) => {{}};
368}
369
370#[macro_export]
371macro_rules! defmt_debug {
372    ($($tt:tt)*) => { $crate::__cu29_defmt_debug!($($tt)*) };
373}
374
375#[macro_export]
376macro_rules! defmt_info {
377    ($($tt:tt)*) => { $crate::__cu29_defmt_info!($($tt)*) };
378}
379
380#[macro_export]
381macro_rules! defmt_warn {
382    ($($tt:tt)*) => { $crate::__cu29_defmt_warn!($($tt)*) };
383}
384
385#[macro_export]
386macro_rules! defmt_error {
387    ($($tt:tt)*) => { $crate::__cu29_defmt_error!($($tt)*) };
388}
389
390#[cfg(test)]
391mod tests {
392    use super::*;
393
394    #[test]
395    fn decode_budget_rejects_untrusted_parameter_counts() {
396        let config = bincode::config::standard().with_limit::<4096>();
397        let prefix = (CuTime::from(0), 0u8, CuLogOrigin::default(), 0u32);
398        for names in [true, false] {
399            let mut bytes = bincode::encode_to_vec(prefix, config).unwrap();
400            if !names {
401                bytes.extend(bincode::encode_to_vec(0u64, config).unwrap());
402            }
403            bytes.extend(bincode::encode_to_vec(u64::MAX, config).unwrap());
404            assert!(bincode::decode_from_slice::<CuLogEntry, _>(&bytes, config).is_err());
405        }
406        let entry = CuLogEntry::new(42, CuLogLevel::Warning);
407        let bytes = bincode::encode_to_vec(&entry, config).unwrap();
408        let (decoded, used) = bincode::decode_from_slice::<CuLogEntry, _>(&bytes, config).unwrap();
409        assert_eq!(decoded, entry);
410        assert_eq!(used, bytes.len());
411    }
412
413    #[test]
414    fn test_log_level_ordering() {
415        assert!(CuLogLevel::Critical > CuLogLevel::Error);
416        assert!(CuLogLevel::Error > CuLogLevel::Warning);
417        assert!(CuLogLevel::Warning > CuLogLevel::Info);
418        assert!(CuLogLevel::Info > CuLogLevel::Debug);
419
420        assert!(CuLogLevel::Debug < CuLogLevel::Info);
421        assert!(CuLogLevel::Info < CuLogLevel::Warning);
422        assert!(CuLogLevel::Warning < CuLogLevel::Error);
423        assert!(CuLogLevel::Error < CuLogLevel::Critical);
424    }
425
426    #[test]
427    fn test_log_level_enabled() {
428        // When min level is Debug (0), all logs are enabled
429        assert!(CuLogLevel::Debug.enabled(CuLogLevel::Debug));
430        assert!(CuLogLevel::Info.enabled(CuLogLevel::Debug));
431        assert!(CuLogLevel::Warning.enabled(CuLogLevel::Debug));
432        assert!(CuLogLevel::Error.enabled(CuLogLevel::Debug));
433        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Debug));
434
435        // When min level is Info (1), only Info and above are enabled
436        assert!(!CuLogLevel::Debug.enabled(CuLogLevel::Info));
437        assert!(CuLogLevel::Info.enabled(CuLogLevel::Info));
438        assert!(CuLogLevel::Warning.enabled(CuLogLevel::Info));
439        assert!(CuLogLevel::Error.enabled(CuLogLevel::Info));
440        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Info));
441
442        // When min level is Warning (2), only Warning and above are enabled
443        assert!(!CuLogLevel::Debug.enabled(CuLogLevel::Warning));
444        assert!(!CuLogLevel::Info.enabled(CuLogLevel::Warning));
445        assert!(CuLogLevel::Warning.enabled(CuLogLevel::Warning));
446        assert!(CuLogLevel::Error.enabled(CuLogLevel::Warning));
447        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Warning));
448
449        // When min level is Error (3), only Error and above are enabled
450        assert!(!CuLogLevel::Debug.enabled(CuLogLevel::Error));
451        assert!(!CuLogLevel::Info.enabled(CuLogLevel::Error));
452        assert!(!CuLogLevel::Warning.enabled(CuLogLevel::Error));
453        assert!(CuLogLevel::Error.enabled(CuLogLevel::Error));
454        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Error));
455
456        // When min level is Critical (4), only Critical is enabled
457        assert!(!CuLogLevel::Debug.enabled(CuLogLevel::Critical));
458        assert!(!CuLogLevel::Info.enabled(CuLogLevel::Critical));
459        assert!(!CuLogLevel::Warning.enabled(CuLogLevel::Critical));
460        assert!(!CuLogLevel::Error.enabled(CuLogLevel::Critical));
461        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Critical));
462    }
463
464    #[test]
465    fn test_cu_log_entry_with_level() {
466        let entry = CuLogEntry::new(42, CuLogLevel::Warning);
467        assert_eq!(entry.level, CuLogLevel::Warning);
468        assert_eq!(entry.origin, CuLogOrigin::default());
469        assert_eq!(entry.msg_index, 42);
470    }
471
472    #[cfg(feature = "std")]
473    #[test]
474    fn test_rebuild_logline_mixes_named_and_positional_placeholders() {
475        let all_interned_strings = vec![
476            "File closed after hash was calculated Hash: {hash}, size: {size};\n{}".to_string(),
477            "hash".to_string(),
478            "size".to_string(),
479        ];
480        let mut entry = CuLogEntry::new(0, CuLogLevel::Debug);
481        entry.add_param(ANONYMOUS, Value::String("event payload".to_string()));
482        entry.add_param(1, Value::String("0x000000000".to_string()));
483        entry.add_param(2, Value::U64(420));
484
485        let line = rebuild_logline(&all_interned_strings, &entry).unwrap();
486
487        assert_eq!(
488            line,
489            "0 ns [Debug]: File closed after hash was calculated Hash: 0x000000000, size: 420;\nevent payload"
490        );
491    }
492}