Skip to main content

dada_util/
log.rs

1use std::{fs::File, panic::Location, thread::ThreadId};
2
3use serde::ser::SerializeStruct;
4
5thread_local! {
6    static INDENT_LEVEL: std::cell::Cell<usize> = const { std::cell::Cell::new(0) };
7}
8
9/// A log state is a snapshot of the current indent level and other thread-sensitive state.
10///
11/// It is used to restore the state when a task is left.
12pub struct LogState {
13    indent_level: usize,
14}
15
16impl LogState {
17    /// Get the current log state.
18    pub fn get() -> Self {
19        Self {
20            indent_level: INDENT_LEVEL.with(|level| level.get()),
21        }
22    }
23
24    /// Set the current log state back to what it was.
25    fn set(&self) {
26        INDENT_LEVEL.with(|level| level.set(self.indent_level));
27    }
28}
29
30enum LogKind {
31    Human(std::fs::File),
32    Json(std::fs::File),
33}
34
35#[derive(Copy, Clone, serde::Serialize)]
36enum MessageKind {
37    Normal,
38    Indent,
39    Undent,
40    EnterTask(u64, #[serde(skip)] &'static Location<'static>),
41    LeaveTask(u64),
42}
43
44impl std::fmt::Debug for MessageKind {
45    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
46        match self {
47            MessageKind::Normal => write!(f, "- "),
48            MessageKind::Indent => write!(f, "> "),
49            MessageKind::Undent => write!(f, "< "),
50            MessageKind::EnterTask(id, location) => {
51                write!(f, "> task {id} (spawned at {location:?})")
52            }
53            MessageKind::LeaveTask(id) => write!(f, "< task {id}"),
54        }
55    }
56}
57
58/// True if debug logging is enabled for this execution.
59pub fn is_enabled() -> bool {
60    enabled().is_some()
61}
62
63fn enabled() -> &'static Option<LogKind> {
64    lazy_static::lazy_static! {
65        static ref ENABLED: Option<LogKind> = match std::env::var("DADA_DEBUG").as_deref() {
66            Ok("json") => Some(LogKind::Json(File::create("dada_debug.json").unwrap())),
67            Ok("human") => Some(LogKind::Human(File::create("dada_debug.txt").unwrap())),
68            Ok("1") => Some(LogKind::Human(File::create("dada_debug.txt").unwrap())),
69            Ok(value) => panic!("invalid value for DADA_DEBUG: expected `json` or `human`, found {value}"),
70            Err(_) => None,
71        };
72    }
73    &ENABLED
74}
75
76#[macro_export]
77macro_rules! debug {
78    ($message:literal $(, $args:expr)* $(,)?) => {
79        $crate::log::debug($message, |op| op(&[$($crate::log::LogArgument { label: stringify!($args), value: &$args },)*]));
80    };
81}
82
83#[macro_export]
84macro_rules! debug_heading {
85    ($message:literal $(, $args:expr)* $(,)?) => {
86        let _log = $crate::log::debug_heading($message, |op| op(&[$($crate::log::LogArgument { label: stringify!($args), value: &$args },)*]));
87    };
88}
89
90/// Enter a task during type-checking and other async bits of the code.
91///
92/// # Parameters
93///
94/// * `id`, the task ID.
95/// * `log_state`, the log state of the task when it was suspended.
96pub fn enter_task(
97    id: u64,
98    location: &'static Location<'static>,
99    log_state: LogState,
100) -> TaskUndent {
101    let old_state = LogState::get();
102    if let Some(kind) = enabled() {
103        debug_cold(kind, MessageKind::EnterTask(id, location), "", &[])
104    }
105    log_state.set();
106    TaskUndent(id, old_state)
107}
108
109pub struct TaskUndent(u64, LogState);
110
111impl Drop for TaskUndent {
112    fn drop(&mut self) {
113        if let Some(kind) = enabled() {
114            debug_cold(kind, MessageKind::LeaveTask(self.0), "", &[])
115        }
116        self.1.set();
117    }
118}
119
120#[inline]
121pub fn debug(message: &'static str, make_args: impl FnOnce(&dyn Fn(&[LogArgument<'_>]))) {
122    if let Some(kind) = enabled() {
123        make_args(&|args| debug_cold(kind, MessageKind::Normal, message, args));
124    }
125}
126
127#[inline]
128pub fn debug_heading(
129    message: &'static str,
130    make_args: impl FnOnce(&dyn Fn(&[LogArgument<'_>])),
131) -> impl Sized {
132    match enabled() {
133        Some(kind) => {
134            make_args(&|args| debug_cold(kind, MessageKind::Indent, message, args));
135            Some(Undent)
136        }
137        None => None,
138    }
139}
140
141struct Undent;
142
143impl Drop for Undent {
144    fn drop(&mut self) {
145        if let Some(kind) = enabled() {
146            debug_cold(kind, MessageKind::Undent, "", &[]);
147        }
148    }
149}
150
151pub trait DebugArgument: std::fmt::Debug {}
152
153impl<T: std::fmt::Debug> DebugArgument for T {}
154
155struct LogMessage<'a> {
156    message_text: &'a str,
157    message_kind: MessageKind,
158    thread_id: ThreadId,
159    args: &'a [LogArgument<'a>],
160}
161
162pub struct LogArgument<'a> {
163    pub label: &'a str,
164    pub value: &'a dyn DebugArgument,
165}
166
167impl serde::Serialize for LogMessage<'_> {
168    fn serialize<S: serde::Serializer>(&self, serializer: S) -> Result<S::Ok, S::Error> {
169        let mut s = serializer.serialize_struct("LogMessage", 4)?;
170        s.serialize_field("message_text", self.message_text)?;
171        s.serialize_field("message_kind", &self.message_kind)?;
172        s.serialize_field("thread_id", &format!("{:?}", self.thread_id))?;
173        s.serialize_field("args", &self.args)?;
174        s.end()
175    }
176}
177
178impl serde::Serialize for LogArgument<'_> {
179    fn serialize<S: serde::Serializer>(&self, serializer: S) -> Result<S::Ok, S::Error> {
180        let mut s = serializer.serialize_struct("LogArgument", 2)?;
181        s.serialize_field("label", self.label)?;
182        s.serialize_field("value", &format!("{:?}", self.value))?;
183        s.end()
184    }
185}
186
187#[cold]
188fn debug_cold(
189    log_kind: &LogKind,
190    message_kind: MessageKind,
191    message_text: &'static str,
192    args: &[LogArgument<'_>],
193) {
194    match log_kind {
195        LogKind::Human(file) => {
196            use std::io::Write;
197            let indent_level = INDENT_LEVEL.with(|level| level.get());
198
199            let mut writer = std::io::BufWriter::new(file);
200            write!(
201                writer,
202                "{:width$}{thread_id:?} {message_kind:?}",
203                "",
204                thread_id = std::thread::current().id(),
205                width = indent_level * 2
206            )
207            .unwrap();
208            write!(writer, "{message_text}").unwrap();
209            for arg in args {
210                write!(
211                    writer,
212                    " {label}={value:?}",
213                    label = arg.label,
214                    value = arg.value
215                )
216                .unwrap();
217            }
218
219            writeln!(writer).unwrap();
220            drop(writer);
221
222            match message_kind {
223                MessageKind::Undent => {
224                    INDENT_LEVEL.with(|level| level.set(indent_level - 1));
225                }
226                MessageKind::Indent => {
227                    INDENT_LEVEL.with(|level| level.set(indent_level + 1));
228                }
229                MessageKind::Normal | MessageKind::EnterTask(..) | MessageKind::LeaveTask(_) => (),
230            }
231        }
232        LogKind::Json(file) => {
233            let message = LogMessage {
234                message_text,
235                message_kind,
236                thread_id: std::thread::current().id(),
237                args,
238            };
239            let writer = std::io::BufWriter::new(file);
240            serde_json::to_writer_pretty(writer, &message).unwrap();
241        }
242    }
243}