Skip to main content

plat/
log.rs

1// log -- the process's log: levels, a ring of the newest lines for crash reports, stderr
2// and a rotating file
3//
4//   LOG_ERROR 1, LOG_WARN 2, LOG_INFO 3, LOG_DEBUG 4, LOG_TRACE 5 (LOG_OFF 0)
5//   log!(LOG_INFO, "net", "{} bytes from {}", n, host)   formats only when the level is on
6//   log_line(level, target, msg)         one line; log_error / log_warn / log_info /
7//                                        log_debug(target, msg) are short forms
8//   log_quiet(level, target, msg)        ring and file only (the text went to stderr already)
9//   log_enabled(level) -> bool           any sink wants this level
10//   log_levels(stderr, file)             the levels of the sinks (default WARN / INFO; the
11//                                        ring keeps everything up to DEBUG); jfgui_LOG=error |
12//                                        warn | info | debug | trace sets both
13//   log_file(Some(path), max_bytes, keep) -> bool   append the lines to path (a vfs name like
14//                                        logs://app.log or an OS path); when it grows
15//                                        beyond max_bytes it moves to path.1 (path.1 to path.2,
16//                                        ... up to keep files) and a new one starts; None stops
17//   log_recent(max_bytes) -> String      the newest whole lines of the ring (a crash report,
18//                                        a "copy log" button)
19//
20// Lines: "2026-10-17 19:58:07.123 WARN  net: text" (Windows local time, elsewhere UTC with a
21// Z); line breaks inside the text become " | ".  The ring holds 64 KiB.  A crash or panic
22// writes the ring to stderr and to the log file before the app's crash hook runs (rt::crash
23// pre-hook, installed with the first line); it takes the locks only if they are free, so a
24// thread that crashed while logging cannot stop the report.
25
26use alloc::string::String;
27use core::fmt::Write as _;
28use core::sync::atomic::{AtomicBool, AtomicU32, Ordering};
29
30use rt::sync::SpinLock;
31
32use crate::{File, FO_RW};
33
34pub const LOG_OFF: u32 = 0;
35pub const LOG_ERROR: u32 = 1;
36pub const LOG_WARN: u32 = 2;
37pub const LOG_INFO: u32 = 3;
38pub const LOG_DEBUG: u32 = 4;
39pub const LOG_TRACE: u32 = 5;
40
41const RING: usize = 64 << 10;
42const LINE_MAX: usize = 4096;
43const NAMES: [&str; 6] = ["OFF  ", "ERROR", "WARN ", "INFO ", "DEBUG", "TRACE"];
44
45struct Ring {
46    buf: [u8; RING],
47    /// bytes written so far (the write position is pos % RING)
48    pos: usize,
49}
50
51struct Sink {
52    file: Option<File>,
53    path: String,
54    size: u64,
55    max: u64,
56    keep: u32,
57}
58
59static RINGBUF: SpinLock<Ring> = SpinLock::new(Ring { buf: [0; RING], pos: 0 });
60static FILE: SpinLock<Sink> = SpinLock::new(Sink { file: None, path: String::new(), size: 0, max: 0, keep: 0 });
61// levels: stderr, file, ring; 0xFF = not read from jfgui_LOG yet
62static LV_ERR: AtomicU32 = AtomicU32::new(0xFF);
63static LV_FILE: AtomicU32 = AtomicU32::new(LOG_INFO);
64static LV_RING: AtomicU32 = AtomicU32::new(LOG_DEBUG);
65static HOOKED: AtomicBool = AtomicBool::new(false);
66
67fn env_level() -> Option<u32> {
68    let v = crate::env("jfgui_LOG")?;
69    let v = v.trim().to_ascii_lowercase();
70    Some(match v.as_str() {
71        "off" | "0" => LOG_OFF,
72        "error" | "1" => LOG_ERROR,
73        "warn" | "warning" | "2" => LOG_WARN,
74        "info" | "3" => LOG_INFO,
75        "debug" | "4" => LOG_DEBUG,
76        "trace" | "5" => LOG_TRACE,
77        _ => return None,
78    })
79}
80
81fn lv_err() -> u32 {
82    let v = LV_ERR.load(Ordering::Relaxed);
83    if v != 0xFF {
84        return v;
85    }
86    let e = env_level();
87    if let Some(l) = e {
88        LV_FILE.store(l, Ordering::Relaxed);
89        LV_RING.store(l.max(LOG_DEBUG), Ordering::Relaxed);
90    }
91    let l = e.unwrap_or(LOG_WARN);
92    LV_ERR.store(l, Ordering::Relaxed);
93    l
94}
95
96/// set the levels of stderr and the file (jfgui_LOG wins over both)
97pub fn log_levels(stderr: u32, file: u32) {
98    let e = env_level();
99    LV_ERR.store(e.unwrap_or(stderr.min(LOG_TRACE)), Ordering::Relaxed);
100    LV_FILE.store(e.unwrap_or(file.min(LOG_TRACE)), Ordering::Relaxed);
101}
102
103/// any sink wants lines of this level
104pub fn log_enabled(level: u32) -> bool {
105    level != LOG_OFF && (level <= lv_err() || level <= LV_RING.load(Ordering::Relaxed) || level <= LV_FILE.load(Ordering::Relaxed))
106}
107
108/// one line to every sink that wants its level
109pub fn log_line(level: u32, target: &str, msg: &str) {
110    emit(level, target, format_args!("{msg}"), true);
111}
112
113/// one line to the ring and the file only (its text went to stderr already)
114pub fn log_quiet(level: u32, target: &str, msg: &str) {
115    emit(level, target, format_args!("{msg}"), false);
116}
117
118/// a LOG_ERROR line
119pub fn log_error(target: &str, msg: &str) {
120    log_line(LOG_ERROR, target, msg);
121}
122/// a LOG_WARN line
123pub fn log_warn(target: &str, msg: &str) {
124    log_line(LOG_WARN, target, msg);
125}
126/// a LOG_INFO line
127pub fn log_info(target: &str, msg: &str) {
128    log_line(LOG_INFO, target, msg);
129}
130/// a LOG_DEBUG line
131pub fn log_debug(target: &str, msg: &str) {
132    log_line(LOG_DEBUG, target, msg);
133}
134
135/// (log!) a formatted line
136#[doc(hidden)]
137pub fn log_fmt(level: u32, target: &str, args: core::fmt::Arguments) {
138    emit(level, target, args, true);
139}
140
141/// log!(LOG_INFO, "target", "format", args...): a line, formatted only when its level is on
142#[macro_export]
143macro_rules! log {
144    ($level:expr, $target:expr, $($arg:tt)*) => {
145        if $crate::log_enabled($level) {
146            $crate::log_fmt($level, $target, format_args!($($arg)*));
147        }
148    };
149}
150
151// the line text: time, level, target, message (line breaks folded)
152fn format_line(level: u32, target: &str, args: core::fmt::Arguments) -> String {
153    let (d, utc) = crate::date();
154    let mut s = String::with_capacity(96);
155    let _ = write!(
156        s,
157        "{:04}-{:02}-{:02} {:02}:{:02}:{:02}.{:03}{} {} {}: ",
158        d.year,
159        d.month,
160        d.day,
161        d.hour,
162        d.min,
163        d.sec,
164        d.ms,
165        if utc { "Z" } else { "" },
166        NAMES[level.min(5) as usize],
167        target
168    );
169    let start = s.len();
170    let _ = s.write_fmt(args);
171    if s[start..].contains(['\n', '\r']) {
172        let body: String = s[start..].trim_end_matches(['\n', '\r']).replace("\r\n", "\n").replace(['\n', '\r'], " | ");
173        s.truncate(start);
174        s.push_str(&body);
175    }
176    if s.len() > LINE_MAX {
177        let mut n = LINE_MAX;
178        while !s.is_char_boundary(n) {
179            n -= 1;
180        }
181        s.truncate(n);
182    }
183    s.push('\n');
184    s
185}
186
187fn emit(level: u32, target: &str, args: core::fmt::Arguments, stderr: bool) {
188    if level == LOG_OFF {
189        return;
190    }
191    let to_err = stderr && level <= lv_err();
192    let to_ring = level <= LV_RING.load(Ordering::Relaxed);
193    let to_file = level <= LV_FILE.load(Ordering::Relaxed);
194    if !(to_err || to_ring || to_file) {
195        return;
196    }
197    if !HOOKED.swap(true, Ordering::Relaxed) {
198        rt::crash::set_pre_hook(Some(crash_dump));
199    }
200    let line = format_line(level, target, args);
201    if to_err {
202        crate::write_stderr(line.as_bytes());
203    }
204    if to_ring {
205        ring_put(line.as_bytes());
206    }
207    if to_file {
208        file_put(line.as_bytes());
209    }
210}
211
212fn ring_put(b: &[u8]) {
213    let mut r = RINGBUF.lock();
214    let b = if b.len() > RING { &b[b.len() - RING..] } else { b };
215    let at = r.pos % RING;
216    let first = b.len().min(RING - at);
217    r.buf[at..at + first].copy_from_slice(&b[..first]);
218    r.buf[..b.len() - first].copy_from_slice(&b[first..]);
219    r.pos += b.len();
220}
221
222// the ring's bytes, oldest first, from its first whole line, to f in at most two pieces
223fn ring_read(r: &Ring, max: usize, f: &mut dyn FnMut(&[u8])) {
224    let n = r.pos.min(RING).min(max);
225    if n == 0 {
226        return;
227    }
228    let start = r.pos - n;
229    let (a, b) = {
230        let s = start % RING;
231        if s + n <= RING { (&r.buf[s..s + n], &r.buf[..0]) } else { (&r.buf[s..], &r.buf[..s + n - RING]) }
232    };
233    // skip a cut first line (unless everything there is was written)
234    let skip = if start == 0 { 0 } else { a.iter().chain(b.iter()).position(|&c| c == b'\n').map_or(n, |p| p + 1) };
235    if skip < a.len() {
236        f(&a[skip..]);
237        f(b);
238    } else {
239        f(&b[skip - a.len()..]);
240    }
241}
242
243/// the newest whole lines of the ring, at most max_bytes
244pub fn log_recent(max_bytes: usize) -> String {
245    let r = RINGBUF.lock();
246    let mut out = alloc::vec::Vec::new();
247    ring_read(&r, max_bytes, &mut |p| out.extend_from_slice(p));
248    String::from_utf8_lossy(&out).into_owned()
249}
250
251/// write the lines to path (rotated at max_bytes, keep older files path.1 .. path.keep);
252/// None stops -> false when the file cannot be opened
253pub fn log_file(path: Option<&str>, max_bytes: u64, keep: u32) -> bool {
254    let mut s = FILE.lock();
255    s.file = None;
256    s.path.clear();
257    let Some(p) = path.filter(|p| !p.is_empty()) else { return true };
258    if let Some(k) = p.rfind(['/', '\\']) {
259        crate::mkdir(&p[..k]);
260    }
261    let Some(f) = File::open(p, FO_RW) else { return false };
262    s.size = f.size().unwrap_or(0);
263    s.file = Some(f);
264    s.path = String::from(p);
265    s.max = max_bytes.max(4096);
266    s.keep = keep.min(20);
267    true
268}
269
270fn file_put(b: &[u8]) {
271    let mut s = FILE.lock();
272    write_file(&mut s, b);
273}
274
275fn write_file(s: &mut Sink, b: &[u8]) {
276    let Some(f) = s.file.as_ref() else { return };
277    if f.write_at(s.size, b).is_some() {
278        s.size += b.len() as u64;
279    }
280    if s.size >= s.max {
281        rotate(s);
282    }
283}
284
285// path -> path.1 -> path.2 ... (the oldest goes), then a new path
286fn rotate(s: &mut Sink) {
287    s.file = None;
288    let p = s.path.clone();
289    if s.keep == 0 {
290        crate::delete(&p);
291    } else {
292        crate::delete(&alloc::format!("{p}.{}", s.keep));
293        for k in (1..s.keep).rev() {
294            crate::rename(&alloc::format!("{p}.{k}"), &alloc::format!("{p}.{}", k + 1));
295        }
296        crate::rename(&p, &alloc::format!("{p}.1"));
297    }
298    s.file = File::open(&p, FO_RW);
299    s.size = s.file.as_ref().and_then(|f| f.size()).unwrap_or(0);
300}
301
302// rt::crash pre-hook: the ring to stderr, the crash to the log file; no allocation, no
303// waiting
304fn crash_dump(info: &rt::crash::CrashInfo) {
305    if let Some(r) = RINGBUF.try_lock() {
306        crate::write_stderr(b"--- the last log lines ---\n");
307        ring_read(&r, RING, &mut |p| crate::write_stderr(p));
308    }
309    if let Some(mut s) = FILE.try_lock() {
310        let mut t = rt::crash::StackText::<512>::new();
311        let _ = write!(t, "--- crash: kind {} code {:#x} ip {:#x}", info.kind, info.code, info.ip);
312        if !info.msg.is_empty() {
313            let _ = write!(t, ": {}", info.msg);
314        }
315        let _ = t.write_str("\n");
316        let n = t.bytes().len();
317        let mut line = [0u8; 512];
318        line[..n].copy_from_slice(t.bytes());
319        write_file(&mut s, &line[..n]);
320    }
321}