tracing_wasm/
lib.rs

1use core::fmt::{self, Write};
2use core::sync::atomic::AtomicUsize;
3
4use tracing::Subscriber;
5use tracing::{
6    dispatcher::SetGlobalDefaultError,
7    field::{Field, Visit},
8};
9use tracing_subscriber::layer::*;
10use tracing_subscriber::registry::*;
11
12use wasm_bindgen::prelude::*;
13
14#[wasm_bindgen]
15extern "C" {
16    #[wasm_bindgen(js_namespace = performance)]
17    fn mark(a: &str);
18    #[wasm_bindgen(catch, js_namespace = performance)]
19    fn measure(name: String, startMark: String) -> Result<(), JsValue>;
20    #[wasm_bindgen(js_namespace = console, js_name = log)]
21    fn log1(message: String);
22    #[wasm_bindgen(js_namespace = console, js_name = log)]
23    fn log2(message1: &str, message2: &str);
24    #[wasm_bindgen(js_namespace = console, js_name = log)]
25    fn log3(message1: &str, message2: &str, message3: &str);
26    #[wasm_bindgen(js_namespace = console, js_name = log)]
27    fn log4(message1: String, message2: &str, message3: &str, message4: &str);
28}
29
30#[cfg(test)]
31mod test {
32    use super::*;
33
34    #[test]
35    fn test_default_built_config() {
36        let builder = WASMLayerConfigBuilder::new();
37
38        let config = builder.build();
39
40        assert_eq!(
41            config,
42            WASMLayerConfig {
43                report_logs_in_timings: true,
44                report_logs_in_console: true,
45                use_console_color: true,
46                max_level: tracing::Level::TRACE,
47            }
48        )
49    }
50
51    #[test]
52    fn test_set_report_logs_in_timings() {
53        let mut builder = WASMLayerConfigBuilder::new();
54        builder.set_report_logs_in_timings(false);
55
56        let config = builder.build();
57
58        assert_eq!(config.report_logs_in_timings, false);
59    }
60
61    #[test]
62    fn test_set_console_config_no_reporting() {
63        let mut builder = WASMLayerConfigBuilder::new();
64        builder.set_console_config(ConsoleConfig::NoReporting);
65
66        let config = builder.build();
67
68        assert_eq!(config.report_logs_in_console, false);
69        assert_eq!(config.use_console_color, false);
70    }
71
72    #[test]
73    fn test_set_console_config_without_color() {
74        let mut builder = WASMLayerConfigBuilder::new();
75        builder.set_console_config(ConsoleConfig::ReportWithoutConsoleColor);
76
77        let config = builder.build();
78
79        assert_eq!(config.report_logs_in_console, true);
80        assert_eq!(config.use_console_color, false);
81    }
82
83    #[test]
84    fn test_set_console_config_with_color() {
85        let mut builder = WASMLayerConfigBuilder::new();
86        builder.set_console_config(ConsoleConfig::ReportWithConsoleColor);
87
88        let config = builder.build();
89
90        assert_eq!(config.report_logs_in_console, true);
91        assert_eq!(config.use_console_color, true);
92    }
93
94    #[test]
95    fn test_default_config_log_level() {
96        let builder = WASMLayerConfigBuilder::new();
97
98        let config = builder.build();
99
100        assert_eq!(config.max_level, tracing::Level::TRACE);
101    }
102
103    #[test]
104    fn test_set_config_log_level_warn() {
105        let mut builder = WASMLayerConfigBuilder::new();
106        builder.set_max_level(tracing::Level::WARN);
107
108        let config = builder.build();
109
110        assert_eq!(config.max_level, tracing::Level::WARN);
111    }
112}
113
114pub enum ConsoleConfig {
115    NoReporting,
116    ReportWithoutConsoleColor,
117    ReportWithConsoleColor,
118}
119
120pub struct WASMLayerConfigBuilder {
121    /// Log events will be marked and measured so they appear in performance Timings
122    report_logs_in_timings: bool,
123    /// Log events will be logged to the browser console
124    report_logs_in_console: bool,
125    /// Only relevant if report_logs_in_console is true, this will use color style strings in the console.
126    use_console_color: bool,
127    /// Log events will be reported from this level -- Default is ALL (TRACE)
128    max_level: tracing::Level,
129}
130
131impl WASMLayerConfigBuilder {
132    pub fn new() -> WASMLayerConfigBuilder {
133        WASMLayerConfigBuilder::default()
134    }
135
136    /// Set whether events should appear in performance Timings
137    pub fn set_report_logs_in_timings(
138        &mut self,
139        report_logs_in_timings: bool,
140    ) -> &mut WASMLayerConfigBuilder {
141        self.report_logs_in_timings = report_logs_in_timings;
142        self
143    }
144
145    /// Set the maximal level on which events should be displayed
146    pub fn set_max_level(&mut self, max_level: tracing::Level) -> &mut WASMLayerConfigBuilder {
147        self.max_level = max_level;
148        self
149    }
150
151    /// Set if and how events should be displayed in the browser console
152    pub fn set_console_config(
153        &mut self,
154        console_config: ConsoleConfig,
155    ) -> &mut WASMLayerConfigBuilder {
156        match console_config {
157            ConsoleConfig::NoReporting => {
158                self.report_logs_in_console = false;
159                self.use_console_color = false;
160            }
161            ConsoleConfig::ReportWithoutConsoleColor => {
162                self.report_logs_in_console = true;
163                self.use_console_color = false;
164            }
165            ConsoleConfig::ReportWithConsoleColor => {
166                self.report_logs_in_console = true;
167                self.use_console_color = true;
168            }
169        }
170
171        self
172    }
173
174    /// Build the WASMLayerConfig
175    pub fn build(&self) -> WASMLayerConfig {
176        WASMLayerConfig {
177            report_logs_in_timings: self.report_logs_in_timings,
178            report_logs_in_console: self.report_logs_in_console,
179            use_console_color: self.use_console_color,
180            max_level: self.max_level,
181        }
182    }
183}
184
185impl Default for WASMLayerConfigBuilder {
186    fn default() -> WASMLayerConfigBuilder {
187        WASMLayerConfigBuilder {
188            report_logs_in_timings: true,
189            report_logs_in_console: true,
190            use_console_color: true,
191            max_level: tracing::Level::TRACE,
192        }
193    }
194}
195
196#[derive(Debug, PartialEq)]
197pub struct WASMLayerConfig {
198    report_logs_in_timings: bool,
199    report_logs_in_console: bool,
200    use_console_color: bool,
201    max_level: tracing::Level,
202}
203
204impl core::default::Default for WASMLayerConfig {
205    fn default() -> Self {
206        WASMLayerConfig {
207            report_logs_in_timings: true,
208            report_logs_in_console: true,
209            use_console_color: true,
210            max_level: tracing::Level::TRACE,
211        }
212    }
213}
214
215/// Implements [tracing_subscriber::layer::Layer] which uses [wasm_bindgen] for marking and measuring with `window.performance`
216pub struct WASMLayer {
217    last_event_id: AtomicUsize,
218    config: WASMLayerConfig,
219}
220
221impl WASMLayer {
222    pub fn new(config: WASMLayerConfig) -> Self {
223        WASMLayer {
224            last_event_id: AtomicUsize::new(0),
225            config,
226        }
227    }
228}
229
230impl core::default::Default for WASMLayer {
231    fn default() -> Self {
232        WASMLayer::new(WASMLayerConfig::default())
233    }
234}
235
236#[cfg(not(feature = "mark-with-rayon-thread-index"))]
237#[inline]
238fn thread_display_suffix() -> &'static str {
239    ""
240}
241#[cfg(feature = "mark-with-rayon-thread-index")]
242fn thread_display_suffix() -> String {
243    let mut message = " #".to_string();
244    match rayon::current_thread_index() {
245        Some(idx) => message.push_str(&format!("{}", idx)),
246        None => message.push_str("main"),
247    }
248    message
249}
250
251#[cfg(not(feature = "mark-with-rayon-thread-index"))]
252fn mark_name(id: &tracing::Id) -> String {
253    format!("t{:x}", id.into_u64())
254}
255#[cfg(feature = "mark-with-rayon-thread-index")]
256fn mark_name(id: &tracing::Id) -> String {
257    format!(
258        "t{:x}-{}",
259        id.into_u64(),
260        rayon::current_thread_index().unwrap_or(999)
261    )
262}
263
264impl<S: Subscriber + for<'a> LookupSpan<'a>> Layer<S> for WASMLayer {
265    fn enabled(&self, metadata: &tracing::Metadata<'_>, _: Context<'_, S>) -> bool {
266        let level = metadata.level();
267        level <= &self.config.max_level
268    }
269
270    fn on_new_span(
271        &self,
272        attrs: &tracing::span::Attributes<'_>,
273        id: &tracing::Id,
274        ctx: Context<'_, S>,
275    ) {
276        let mut new_debug_record = StringRecorder::new();
277        attrs.record(&mut new_debug_record);
278
279        if let Some(span_ref) = ctx.span(id) {
280            span_ref
281                .extensions_mut()
282                .insert::<StringRecorder>(new_debug_record);
283        }
284    }
285
286    /// doc: Notifies this layer that a span with the given Id recorded the given values.
287    fn on_record(&self, id: &tracing::Id, values: &tracing::span::Record<'_>, ctx: Context<'_, S>) {
288        if let Some(span_ref) = ctx.span(id) {
289            if let Some(debug_record) = span_ref.extensions_mut().get_mut::<StringRecorder>() {
290                values.record(debug_record);
291            }
292        }
293    }
294
295    // /// doc: Notifies this layer that a span with the ID span recorded that it follows from the span with the ID follows.
296    // fn on_follows_from(&self, _span: &tracing::Id, _follows: &tracing::Id, ctx: Context<'_, S>) {}
297    /// doc: Notifies this layer that an event has occurred.
298    fn on_event(&self, event: &tracing::Event<'_>, _ctx: Context<'_, S>) {
299        if self.config.report_logs_in_timings || self.config.report_logs_in_console {
300            let mut recorder = StringRecorder::new();
301            event.record(&mut recorder);
302            let meta = event.metadata();
303            let level = meta.level();
304            if self.config.report_logs_in_console {
305                let origin = meta
306                    .file()
307                    .and_then(|file| meta.line().map(|ln| format!("{}:{}", file, ln)))
308                    .unwrap_or_default();
309
310                if self.config.use_console_color {
311                    log4(
312                        format!(
313                            "%c{}%c {}{}%c{}",
314                            level,
315                            origin,
316                            thread_display_suffix(),
317                            recorder,
318                        ),
319                        match *level {
320                            tracing::Level::TRACE => "color: dodgerblue; background: #444",
321                            tracing::Level::DEBUG => "color: lawngreen; background: #444",
322                            tracing::Level::INFO => "color: whitesmoke; background: #444",
323                            tracing::Level::WARN => "color: orange; background: #444",
324                            tracing::Level::ERROR => "color: red; background: #444",
325                        },
326                        "color: gray; font-style: italic",
327                        "color: inherit",
328                    );
329                } else {
330                    log1(format!(
331                        "{} {}{} {}",
332                        level,
333                        origin,
334                        thread_display_suffix(),
335                        recorder,
336                    ));
337                }
338            }
339            if self.config.report_logs_in_timings {
340                let mark_name = format!(
341                    "c{:x}",
342                    self.last_event_id
343                        .fetch_add(1, core::sync::atomic::Ordering::Relaxed)
344                );
345                // mark and measure so you can see a little blip in the profile
346                mark(&mark_name);
347                let _ = measure(
348                    format!(
349                        "{} {}{} {}",
350                        level,
351                        meta.module_path().unwrap_or("..."),
352                        thread_display_suffix(),
353                        recorder,
354                    ),
355                    mark_name,
356                );
357            }
358        }
359    }
360    /// doc: Notifies this layer that a span with the given ID was entered.
361    fn on_enter(&self, id: &tracing::Id, _ctx: Context<'_, S>) {
362        mark(&mark_name(id));
363    }
364    /// doc: Notifies this layer that the span with the given ID was exited.
365    fn on_exit(&self, id: &tracing::Id, ctx: Context<'_, S>) {
366        if let Some(span_ref) = ctx.span(id) {
367            let meta = span_ref.metadata();
368            if let Some(debug_record) = span_ref.extensions().get::<StringRecorder>() {
369                let _ = measure(
370                    format!(
371                        "\"{}\"{} {} {}",
372                        meta.name(),
373                        thread_display_suffix(),
374                        meta.module_path().unwrap_or("..."),
375                        debug_record,
376                    ),
377                    mark_name(id),
378                );
379            } else {
380                let _ = measure(
381                    format!(
382                        "\"{}\"{} {}",
383                        meta.name(),
384                        thread_display_suffix(),
385                        meta.module_path().unwrap_or("..."),
386                    ),
387                    mark_name(id),
388                );
389            }
390        }
391    }
392    // /// doc: Notifies this layer that the span with the given ID has been closed.
393    // /// We can dispose of any data for the span we might have here...
394    // fn on_close(&self, _id: tracing::Id, ctx: Context<'_, S>) {}
395    // /// doc: Notifies this layer that a span ID has been cloned, and that the subscriber returned a different ID.
396    // /// I'm not sure if I need to do something here...
397    // fn on_id_change(&self, _old: &tracing::Id, _new: &tracing::Id, ctx: Context<'_, S>) {}
398}
399
400/// Set the global default with [tracing::subscriber::set_global_default]
401pub fn set_as_global_default() {
402    tracing::subscriber::set_global_default(
403        Registry::default().with(WASMLayer::new(WASMLayerConfig::default())),
404    )
405    .expect("default global");
406}
407
408/// Set the global default with [tracing::subscriber::set_global_default]
409pub fn try_set_as_global_default() -> Result<(), SetGlobalDefaultError> {
410    tracing::subscriber::set_global_default(
411        Registry::default().with(WASMLayer::new(WASMLayerConfig::default())),
412    )
413}
414
415/// Set the global default with [tracing::subscriber::set_global_default]
416pub fn set_as_global_default_with_config(config: WASMLayerConfig) {
417    tracing::subscriber::set_global_default(Registry::default().with(WASMLayer::new(config)))
418        .expect("default global");
419}
420
421struct StringRecorder {
422    display: String,
423    is_following_args: bool,
424}
425impl StringRecorder {
426    fn new() -> Self {
427        StringRecorder {
428            display: String::new(),
429            is_following_args: false,
430        }
431    }
432}
433
434impl Visit for StringRecorder {
435    fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
436        if field.name() == "message" {
437            if !self.display.is_empty() {
438                self.display = format!("{:?}\n{}", value, self.display)
439            } else {
440                self.display = format!("{:?}", value)
441            }
442        } else {
443            if self.is_following_args {
444                // following args
445                writeln!(self.display).unwrap();
446            } else {
447                // first arg
448                write!(self.display, " ").unwrap();
449                self.is_following_args = true;
450            }
451            write!(self.display, "{} = {:?};", field.name(), value).unwrap();
452        }
453    }
454}
455
456impl core::fmt::Display for StringRecorder {
457    fn fmt(&self, mut f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
458        if !self.display.is_empty() {
459            write!(&mut f, " {}", self.display)
460        } else {
461            Ok(())
462        }
463    }
464}
465
466impl core::default::Default for StringRecorder {
467    fn default() -> Self {
468        StringRecorder::new()
469    }
470}