cu29-log 0.15.0

This is part of the text logging runtime for Copper. It cannot be used independently from the copper project.
Documentation
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
#![cfg_attr(not(feature = "std"), no_std)]
#[cfg(not(feature = "std"))]
extern crate alloc;
extern crate core;

use bincode::{Decode, Encode};
use cu29_clock::CuTime;
use cu29_value::Value;
use serde::{Deserialize, Serialize};
use smallvec::SmallVec;

#[cfg(not(feature = "std"))]
mod imp {
    pub use core::fmt::Display;
    pub use core::fmt::Formatter;
    pub use core::fmt::Result as FmtResult;
}

#[cfg(feature = "defmt")]
extern crate defmt;

#[cfg(feature = "std")]
mod imp {
    pub use core::fmt::Display;
    pub use cu29_traits::CuResult;
    // strfmt forces hashmap from std
    pub use std::collections::HashMap;
    pub use std::fmt::Formatter;
    pub use std::fmt::Result as FmtResult;
    // This is a blocker for no_std, so no live logging in no_std for now.
    pub use strfmt::strfmt;
}

use imp::*;

/// Log levels for Copper.
#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Serialize, Deserialize)]
pub enum CuLogLevel {
    /// Detailed information useful during development
    Debug = 0,
    /// General information about system operation
    Info = 1,
    /// Indication of potential issues that don't prevent normal operation
    Warning = 2,
    /// Issues that might disrupt normal operation but don't cause system failure
    Error = 3,
    /// Critical errors requiring immediate attention, usually resulting in system failure
    Critical = 4,
}

impl CuLogLevel {
    /// Returns true if this log level is enabled for the given max level
    ///
    /// The log level is enabled if it is greater than or equal to the max level.
    /// For example, if max_level is Info, then Info, Warning, Error and Critical are enabled,
    /// but Debug is not.
    #[inline]
    pub const fn enabled(self, max_level: CuLogLevel) -> bool {
        self as u8 >= max_level as u8
    }
}

#[allow(dead_code)]
pub const ANONYMOUS: u32 = 0;

pub const MAX_LOG_PARAMS_ON_STACK: usize = 10;

/// This is the basic structure for a log entry in Copper.
#[derive(Debug, Clone, Serialize, Deserialize, PartialEq)]
pub struct CuLogEntry {
    // Approximate time when the log entry was created.
    pub time: CuTime,

    // Log level of this entry
    pub level: CuLogLevel,

    // interned index of the message
    pub msg_index: u32,

    // interned indexes of the parameter names
    pub paramname_indexes: SmallVec<[u32; MAX_LOG_PARAMS_ON_STACK]>,

    // Serializable values for the parameters (Values are acting like an Any Value).
    pub params: SmallVec<[Value; MAX_LOG_PARAMS_ON_STACK]>,
}

impl Encode for CuLogEntry {
    fn encode<E: bincode::enc::Encoder>(
        &self,
        encoder: &mut E,
    ) -> Result<(), bincode::error::EncodeError> {
        self.time.encode(encoder)?;
        (self.level as u8).encode(encoder)?;
        self.msg_index.encode(encoder)?;

        (self.paramname_indexes.len() as u64).encode(encoder)?;
        for &index in &self.paramname_indexes {
            index.encode(encoder)?;
        }

        (self.params.len() as u64).encode(encoder)?;
        for param in &self.params {
            param.encode(encoder)?;
        }

        Ok(())
    }
}

impl<Context> Decode<Context> for CuLogEntry {
    fn decode<D: bincode::de::Decoder>(
        decoder: &mut D,
    ) -> Result<Self, bincode::error::DecodeError> {
        let time = CuTime::decode(decoder)?;
        let level_raw = u8::decode(decoder)?;
        let level = match level_raw {
            0 => CuLogLevel::Debug,
            1 => CuLogLevel::Info,
            2 => CuLogLevel::Warning,
            3 => CuLogLevel::Error,
            4 => CuLogLevel::Critical,
            _ => CuLogLevel::Debug, // Default to Debug for compatibility with older logs
        };
        let msg_index = u32::decode(decoder)?;

        let paramname_len = u64::decode(decoder)? as usize;
        let mut paramname_indexes = SmallVec::with_capacity(paramname_len);
        for _ in 0..paramname_len {
            paramname_indexes.push(u32::decode(decoder)?);
        }

        let params_len = u64::decode(decoder)? as usize;
        let mut params = SmallVec::with_capacity(params_len);
        for _ in 0..params_len {
            params.push(Value::decode(decoder)?);
        }

        Ok(CuLogEntry {
            time,
            level,
            msg_index,
            paramname_indexes,
            params,
        })
    }
}

// This is for internal debug purposes.
impl Display for CuLogEntry {
    fn fmt(&self, f: &mut Formatter<'_>) -> FmtResult {
        write!(
            f,
            "CuLogEntry {{ level: {:?}, msg_index: {}, paramname_indexes: {:?}, params: {:?} }}",
            self.level, self.msg_index, self.paramname_indexes, self.params
        )
    }
}

impl CuLogEntry {
    /// msg_index is the interned index of the message.
    pub fn new(msg_index: u32, level: CuLogLevel) -> Self {
        CuLogEntry {
            time: 0.into(), // We have no clock at that point it is called from random places
            // the clock will be set at actual log time from clock source provided
            level,
            msg_index,
            paramname_indexes: SmallVec::new(),
            params: SmallVec::new(),
        }
    }

    /// Add a parameter to the log entry.
    /// paramname_index is the interned index of the parameter name.
    pub fn add_param(&mut self, paramname_index: u32, param: Value) {
        self.paramname_indexes.push(paramname_index);
        self.params.push(param);
    }
}

/// Text log line formatter.
/// Only available on std. TODO(gbin): Maybe reconsider that at some point
#[inline]
#[cfg(feature = "std")]
pub fn format_logline(
    time: CuTime,
    level: CuLogLevel,
    format_str: &str,
    params: &[String],
    named_params: &HashMap<String, String>,
) -> CuResult<String> {
    // If the format string uses positional placeholders (`{}`), fill them in order using the
    // anonymous params first, then any named params (sorted for determinism) if needed.
    if format_str.contains("{}") {
        let mut formatted = format_str.to_string();
        for param in params.iter() {
            if !formatted.contains("{}") {
                break;
            }
            formatted = formatted.replacen("{}", param, 1);
        }
        if formatted.contains("{}") && !named_params.is_empty() {
            let mut named = named_params.iter().collect::<Vec<_>>();
            named.sort_by(|a, b| a.0.cmp(b.0));
            for (_, value) in named {
                if !formatted.contains("{}") {
                    break;
                }
                formatted = formatted.replacen("{}", value, 1);
            }
        }
        return Ok(format!("{time} [{level:?}]: {formatted}"));
    }

    // Otherwise rely on named formatting.
    let logline = strfmt(format_str, named_params).map_err(|e| {
        cu29_traits::CuError::new_with_cause(
            format!("Failed to format log line: {format_str:?} with variables [{named_params:?}]")
                .as_str(),
            e,
        )
    })?;
    Ok(format!("{time} [{level:?}]: {logline}"))
}

/// Rebuild a log line from the interned strings and the CuLogEntry.
/// This basically translates the world of copper logs to text logs.
#[cfg(feature = "std")]
pub fn rebuild_logline(all_interned_strings: &[String], entry: &CuLogEntry) -> CuResult<String> {
    let format_string = all_interned_strings
        .get(entry.msg_index as usize)
        .ok_or_else(|| {
            cu29_traits::CuError::from(format!(
                "Invalid message index {} (interned strings length {})",
                entry.msg_index,
                all_interned_strings.len()
            ))
        })?;
    if entry.paramname_indexes.len() != entry.params.len() {
        return Err(cu29_traits::CuError::from(format!(
            "Mismatched parameter metadata: {} names for {} params",
            entry.paramname_indexes.len(),
            entry.params.len()
        )));
    }

    let mut anon_params = Vec::with_capacity(entry.params.len());
    let mut named_params = HashMap::with_capacity(entry.params.len());

    for (i, param) in entry.params.iter().enumerate() {
        let param_as_string = format!("{param}");
        if entry.paramname_indexes[i] == 0 {
            // Anonymous parameter
            anon_params.push(param_as_string);
        } else {
            // Named parameter
            let name = all_interned_strings
                .get(entry.paramname_indexes[i] as usize)
                .ok_or_else(|| {
                    cu29_traits::CuError::from(format!(
                        "Invalid parameter name index {} (interned strings length {})",
                        entry.paramname_indexes[i],
                        all_interned_strings.len()
                    ))
                })?
                .clone();
            named_params.insert(name, param_as_string);
        }
    }
    format_logline(
        entry.time,
        entry.level,
        format_string,
        &anon_params,
        &named_params,
    )
}

// ---- defmt shims, selected at cu29-log compile time ----
#[cfg(all(feature = "defmt", not(feature = "std")))]
#[macro_export]
macro_rules! __cu29_defmt_debug {
    ($fmt:literal $(, $arg:expr)* $(,)?) => {
        ::defmt::debug!($fmt $(, $arg)*);
    }
}
#[cfg(not(all(feature = "defmt", not(feature = "std"))))]
#[macro_export]
macro_rules! __cu29_defmt_debug {
    ($($tt:tt)*) => {{}};
}

#[cfg(all(feature = "defmt", not(feature = "std")))]
#[macro_export]
macro_rules! __cu29_defmt_info {
    ($fmt:literal $(, $arg:expr)* $(,)?) => {
        ::defmt::info!($fmt $(, $arg)*);
    }
}
#[cfg(not(all(feature = "defmt", not(feature = "std"))))]
#[macro_export]
macro_rules! __cu29_defmt_info {
    ($($tt:tt)*) => {{}};
}

#[cfg(all(feature = "defmt", not(feature = "std")))]
#[macro_export]
macro_rules! __cu29_defmt_warn {
    ($fmt:literal $(, $arg:expr)* $(,)?) => {
        ::defmt::warn!($fmt $(, $arg)*);
    }
}
#[cfg(not(all(feature = "defmt", not(feature = "std"))))]
#[macro_export]
macro_rules! __cu29_defmt_warn {
    ($($tt:tt)*) => {{}};
}

#[cfg(all(feature = "defmt", not(feature = "std")))]
#[macro_export]
macro_rules! __cu29_defmt_error {
    ($fmt:literal $(, $arg:expr)* $(,)?) => {
        ::defmt::error!($fmt $(, $arg)*);
    }
}
#[cfg(not(all(feature = "defmt", not(feature = "std"))))]
#[macro_export]
macro_rules! __cu29_defmt_error {
    ($($tt:tt)*) => {{}};
}

#[macro_export]
macro_rules! defmt_debug {
    ($($tt:tt)*) => { $crate::__cu29_defmt_debug!($($tt)*) };
}

#[macro_export]
macro_rules! defmt_info {
    ($($tt:tt)*) => { $crate::__cu29_defmt_info!($($tt)*) };
}

#[macro_export]
macro_rules! defmt_warn {
    ($($tt:tt)*) => { $crate::__cu29_defmt_warn!($($tt)*) };
}

#[macro_export]
macro_rules! defmt_error {
    ($($tt:tt)*) => { $crate::__cu29_defmt_error!($($tt)*) };
}

#[cfg(test)]
mod tests {
    use super::*;

    #[test]
    fn test_log_level_ordering() {
        assert!(CuLogLevel::Critical > CuLogLevel::Error);
        assert!(CuLogLevel::Error > CuLogLevel::Warning);
        assert!(CuLogLevel::Warning > CuLogLevel::Info);
        assert!(CuLogLevel::Info > CuLogLevel::Debug);

        assert!(CuLogLevel::Debug < CuLogLevel::Info);
        assert!(CuLogLevel::Info < CuLogLevel::Warning);
        assert!(CuLogLevel::Warning < CuLogLevel::Error);
        assert!(CuLogLevel::Error < CuLogLevel::Critical);
    }

    #[test]
    fn test_log_level_enabled() {
        // When min level is Debug (0), all logs are enabled
        assert!(CuLogLevel::Debug.enabled(CuLogLevel::Debug));
        assert!(CuLogLevel::Info.enabled(CuLogLevel::Debug));
        assert!(CuLogLevel::Warning.enabled(CuLogLevel::Debug));
        assert!(CuLogLevel::Error.enabled(CuLogLevel::Debug));
        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Debug));

        // When min level is Info (1), only Info and above are enabled
        assert!(!CuLogLevel::Debug.enabled(CuLogLevel::Info));
        assert!(CuLogLevel::Info.enabled(CuLogLevel::Info));
        assert!(CuLogLevel::Warning.enabled(CuLogLevel::Info));
        assert!(CuLogLevel::Error.enabled(CuLogLevel::Info));
        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Info));

        // When min level is Warning (2), only Warning and above are enabled
        assert!(!CuLogLevel::Debug.enabled(CuLogLevel::Warning));
        assert!(!CuLogLevel::Info.enabled(CuLogLevel::Warning));
        assert!(CuLogLevel::Warning.enabled(CuLogLevel::Warning));
        assert!(CuLogLevel::Error.enabled(CuLogLevel::Warning));
        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Warning));

        // When min level is Error (3), only Error and above are enabled
        assert!(!CuLogLevel::Debug.enabled(CuLogLevel::Error));
        assert!(!CuLogLevel::Info.enabled(CuLogLevel::Error));
        assert!(!CuLogLevel::Warning.enabled(CuLogLevel::Error));
        assert!(CuLogLevel::Error.enabled(CuLogLevel::Error));
        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Error));

        // When min level is Critical (4), only Critical is enabled
        assert!(!CuLogLevel::Debug.enabled(CuLogLevel::Critical));
        assert!(!CuLogLevel::Info.enabled(CuLogLevel::Critical));
        assert!(!CuLogLevel::Warning.enabled(CuLogLevel::Critical));
        assert!(!CuLogLevel::Error.enabled(CuLogLevel::Critical));
        assert!(CuLogLevel::Critical.enabled(CuLogLevel::Critical));
    }

    #[test]
    fn test_cu_log_entry_with_level() {
        let entry = CuLogEntry::new(42, CuLogLevel::Warning);
        assert_eq!(entry.level, CuLogLevel::Warning);
        assert_eq!(entry.msg_index, 42);
    }
}