|
1 | 1 | use std::cell::RefCell; |
2 | 2 | use std::collections::BTreeSet; |
3 | 3 | use std::ffi::c_char; |
4 | | -use std::slice; |
| 4 | +use std::fmt::Debug; |
5 | 5 | use bitflags::bitflags; |
| 6 | +use tracing::Level; |
| 7 | +use tracing_core::{Event, Field, LevelFilter, Subscriber}; |
| 8 | +use tracing_subscriber::EnvFilter; |
| 9 | +use tracing_subscriber::fmt::{FmtContext, FormatEvent, FormatFields}; |
| 10 | +use tracing_subscriber::fmt::format::Writer; |
| 11 | +use tracing_subscriber::registry::LookupSpan; |
| 12 | +use tracing_subscriber::util::SubscriberInitExt; |
6 | 13 | use ddcommon_ffi::CharSlice; |
7 | 14 | use ddcommon_ffi::slice::AsBytes; |
8 | 15 |
|
9 | 16 | bitflags! { |
10 | 17 | #[derive(Clone, Copy, Debug, PartialEq, Eq, Hash)] |
11 | 18 | #[repr(C)] |
12 | 19 | pub struct Log: u32 { |
13 | | - const None = 0; |
14 | | - const Once = 1 << 0; // I.e. once per request |
15 | | - const Error = 1 << 1; |
16 | | - const Warn = 1 << 2; |
17 | | - const Info = 1 << 3; |
18 | | - const Deprecated = (1 << 4) | 1 /* Once */; |
19 | | - const Startup = 1 << 5; |
20 | | - } |
21 | | -} |
22 | | - |
23 | | -#[macro_export] |
24 | | -macro_rules! log { |
25 | | - ($source:ident, $msg:expr) => { if ($crate::ddog_shall_log($crate::Log::$source)) { $crate::log($crate::Log::$source, $msg) } } |
26 | | -} |
27 | | - |
28 | | -#[allow_internal_unstable(thread_local)] |
29 | | -macro_rules! thread_local { |
30 | | - ($($tokens:tt)*) => { |
31 | | - #[thread_local] |
32 | | - $($tokens)* |
| 20 | + const Error = 1; |
| 21 | + const Warn = 2; |
| 22 | + const Info = 3; |
| 23 | + const Debug = 4; |
| 24 | + const Trace = 5; |
| 25 | + const Once = 1 << 3; // I.e. once per request |
| 26 | + const _Deprecated = 3 | (1 << 4); |
| 27 | + const Deprecated = 3 | (1 << 4) | (1 << 3) /* Once */; |
| 28 | + const Startup = 3 | (2 << 4); |
| 29 | + const Startup_Warn = 1 | (2 << 4); |
| 30 | + const Span = 4 | (3 << 4); |
| 31 | + const Span_Trace = 5 | (3 << 4); |
| 32 | + const Hook_Trace = 5 | (4 << 4); |
33 | 33 | } |
34 | 34 | } |
35 | 35 |
|
36 | 36 | #[no_mangle] |
37 | 37 | #[allow(non_upper_case_globals)] |
38 | | -pub static mut ddog_log_callback: Option<extern "C" fn(Log, CharSlice)> = None; |
| 38 | +pub static mut ddog_log_callback: Option<extern "C" fn(CharSlice)> = None; |
39 | 39 |
|
40 | 40 | // Avoid RefCell for performance |
41 | | -thread_local! { static mut LOG_CATEGORY: Log = Log::Once.union(Log::Error); } |
42 | 41 | std::thread_local! { |
43 | 42 | static LOGGED_MSGS: RefCell<BTreeSet<String>> = RefCell::default(); |
| 43 | + static TRACING_GUARDS: RefCell<Option<tracing_core::dispatcher::DefaultGuard>> = RefCell::default(); |
| 44 | +} |
| 45 | + |
| 46 | +macro_rules! with_target { |
| 47 | + ($cat:ident, tracing::$p:ident!($($t:tt)*)) => { |
| 48 | + match $cat { |
| 49 | + Log::Error => tracing::$p!(target: "ddtrace", Level::ERROR, $($t)*), |
| 50 | + Log::Warn => tracing::$p!(target: "ddtrace", Level::WARN, $($t)*), |
| 51 | + Log::Info => tracing::$p!(target: "ddtrace", Level::INFO, $($t)*), |
| 52 | + Log::Debug => tracing::$p!(target: "ddtrace", Level::DEBUG, $($t)*), |
| 53 | + Log::Trace => tracing::$p!(target: "ddtrace", Level::TRACE, $($t)*), |
| 54 | + Log::_Deprecated => tracing::$p!(target: "deprecated", Level::INFO, $($t)*), |
| 55 | + Log::Startup => tracing::$p!(target: "startup", Level::INFO, $($t)*), |
| 56 | + Log::Span => tracing::$p!(target: "span", Level::DEBUG, $($t)*), |
| 57 | + Log::Span_Trace => tracing::$p!(target: "span", Level::TRACE, $($t)*), |
| 58 | + Log::Hook_Trace => tracing::$p!(target: "hook", Level::TRACE, $($t)*), |
| 59 | + _ => unreachable!() |
| 60 | + } |
| 61 | + } |
44 | 62 | } |
45 | 63 |
|
46 | 64 | #[no_mangle] |
47 | | -pub extern "C" fn ddog_shall_log(level: Log) -> bool { |
48 | | - unsafe { LOG_CATEGORY }.contains(level & !Log::Once) |
| 65 | +pub extern "C" fn ddog_shall_log(category: Log) -> bool { |
| 66 | + let category = category & !Log::Once; |
| 67 | + with_target!(category, tracing::event_enabled!()) |
49 | 68 | } |
50 | 69 |
|
51 | | -pub fn log<S>(level: Log, msg: S) where S: AsRef<str> { |
52 | | - ddog_log(level, CharSlice::from(msg.as_ref())) |
| 70 | +pub fn log<S>(category: Log, msg: S) where S: AsRef<str> + tracing::Value { |
| 71 | + let once = !(category & Log::Once).is_empty(); |
| 72 | + let category = category & !Log::Once; |
| 73 | + if once { |
| 74 | + with_target!(category, tracing::event!(once = true, msg)); |
| 75 | + } else { |
| 76 | + with_target!(category, tracing::event!(msg)); |
| 77 | + } |
53 | 78 | } |
54 | 79 |
|
55 | | -#[no_mangle] |
56 | | -pub extern "C" fn ddog_set_log_category(level: Log) { |
57 | | - unsafe { LOG_CATEGORY = level; } |
| 80 | +struct LogFormatter { |
| 81 | + pub once: bool, |
58 | 82 | } |
59 | 83 |
|
60 | | -#[no_mangle] |
61 | | -pub unsafe extern "C" fn ddog_parse_log_category(category_names: *const CharSlice, num: usize, startup_logs_by_default: bool) { |
62 | | - let mut categories = Log::None; |
63 | | - let category_names = slice::from_raw_parts(category_names, num); |
64 | | - |
65 | | - if category_names.len() == 1 { |
66 | | - let first_level = category_names[0].to_utf8_lossy(); |
67 | | - if first_level == "1" || first_level == "true" || first_level == "On" { |
68 | | - categories = Log::Error | Log::Warn | Log::Info | Log::Deprecated; |
69 | | - if startup_logs_by_default { |
70 | | - categories |= Log::Startup; |
71 | | - } |
72 | | - } |
| 84 | +struct LogVisitor { |
| 85 | + pub msg: Option<String>, |
| 86 | + pub once: bool, |
| 87 | +} |
| 88 | + |
| 89 | +impl tracing_core::field::Visit for LogVisitor { |
| 90 | + fn record_bool(&mut self, _field: &Field, value: bool) { |
| 91 | + self.once = value; |
73 | 92 | } |
74 | 93 |
|
75 | | - for category_name in category_names { |
76 | | - for (name, category) in Log::all().iter_names() { |
77 | | - if name.eq_ignore_ascii_case(&category_name.to_utf8_lossy()) { |
78 | | - categories |= category; |
79 | | - } |
80 | | - } |
| 94 | + fn record_str(&mut self, _field: &Field, msg: &str) { |
| 95 | + self.msg = Some(msg.to_string()); |
81 | 96 | } |
82 | 97 |
|
83 | | - // Info always implies warn |
84 | | - if categories.contains(Log::Info) { |
85 | | - categories |= Log::Warn; |
| 98 | + fn record_debug(&mut self, _field: &Field, value: &dyn Debug) { |
| 99 | + self.msg = Some(format!("{value:?}")); |
86 | 100 | } |
87 | | - // Warn always implies error |
88 | | - if categories.contains(Log::Warn) { |
89 | | - categories |= Log::Error; |
| 101 | +} |
| 102 | + |
| 103 | +impl<S, N> FormatEvent<S, N> for LogFormatter |
| 104 | + where |
| 105 | + S: Subscriber + for<'a> LookupSpan<'a>, |
| 106 | + N: for<'a> FormatFields<'a> + 'static { |
| 107 | + fn format_event( |
| 108 | + &self, |
| 109 | + _ctx: &FmtContext<'_, S, N>, |
| 110 | + _writer: Writer<'_>, |
| 111 | + event: &Event<'_> |
| 112 | + ) -> core::fmt::Result { |
| 113 | + let mut visitor = LogVisitor { msg: None, once: false }; |
| 114 | + event.record(&mut visitor); |
| 115 | + |
| 116 | + fn fmt_msg(event: &Event<'_>, msg: &str, suffix: &str) -> String { |
| 117 | + let data = event.metadata(); |
| 118 | + let target = if data.target() == "ddtrace" { |
| 119 | + match *data.level() { |
| 120 | + Level::ERROR => "error", |
| 121 | + Level::WARN => "warning", |
| 122 | + Level::INFO => "info", |
| 123 | + Level::DEBUG => "debug", |
| 124 | + Level::TRACE => "trace", |
| 125 | + } |
| 126 | + } else { |
| 127 | + data.target() |
| 128 | + }; |
| 129 | + format!("[ddtrace] [{}] {}{}\0", target, msg, suffix) |
| 130 | + } |
| 131 | + |
| 132 | + if let Some(msg) = visitor.msg { |
| 133 | + if let Some(cb) = unsafe { ddog_log_callback } { |
| 134 | + let msg = if self.once && visitor.once { |
| 135 | + if let Some(formatted) = LOGGED_MSGS.with(|logged| { |
| 136 | + let mut logged = logged.borrow_mut(); |
| 137 | + if logged.contains(msg.as_str()) { |
| 138 | + return None; |
| 139 | + } |
| 140 | + let formatted = Some(fmt_msg(event, &msg, "; This message is only displayed once. Specify DD_TRACE_ONCE_LOGS=0 to show all messages.")); |
| 141 | + logged.insert(msg); |
| 142 | + formatted |
| 143 | + }) { |
| 144 | + formatted |
| 145 | + } else { |
| 146 | + return Ok(()); |
| 147 | + } |
| 148 | + } else { |
| 149 | + fmt_msg(event, &msg, "") |
| 150 | + }; |
| 151 | + cb(unsafe { CharSlice::new(msg.as_ptr() as *const c_char, msg.len() - 1) }); |
| 152 | + } |
| 153 | + } |
| 154 | + Ok(()) |
90 | 155 | } |
| 156 | +} |
91 | 157 |
|
92 | | - ddog_set_log_category(categories); |
| 158 | +#[no_mangle] |
| 159 | +pub unsafe extern "C" fn ddog_set_error_log_level(once: bool) { |
| 160 | + let subscriber = tracing_subscriber::fmt() |
| 161 | + .with_max_level(LevelFilter::ERROR) |
| 162 | + .event_format(LogFormatter { once }); |
| 163 | + set_log_subscriber(subscriber) |
93 | 164 | } |
94 | 165 |
|
95 | 166 | #[no_mangle] |
96 | | -pub extern "C" fn ddog_log(category: Log, msg: CharSlice) { |
97 | | - if let Some(cb) = unsafe { ddog_log_callback } { |
98 | | - if category.contains(Log::Once) && !unsafe { LOG_CATEGORY }.contains(Log::Once) { |
99 | | - LOGGED_MSGS.with(|logged| { |
100 | | - let mut logged = logged.borrow_mut(); |
101 | | - let msgstr = unsafe { msg.to_utf8_lossy() }; |
102 | | - if !logged.contains(msgstr.as_ref()) { |
103 | | - let msg = msgstr.to_string(); |
104 | | - let once_msg = format!("{}; This message is only displayed once. Specify DD_TRACE_ONCE_LOGS=0 to show all messages.\0", msg); |
105 | | - cb(category, unsafe { CharSlice::new(once_msg.as_ptr() as *const c_char, once_msg.len() - 1) }); |
106 | | - logged.insert(msg); |
107 | | - } |
108 | | - }); |
109 | | - } else { |
110 | | - cb(category, msg); |
111 | | - } |
| 167 | +pub unsafe extern "C" fn ddog_set_log_level(level: CharSlice, once: bool) { |
| 168 | + let subscriber = tracing_subscriber::fmt() |
| 169 | + .with_env_filter(EnvFilter::builder().parse_lossy(level.to_utf8_lossy())) |
| 170 | + .event_format(LogFormatter { once }); |
| 171 | + set_log_subscriber(subscriber) |
| 172 | +} |
| 173 | + |
| 174 | +fn set_log_subscriber<S>(subscriber: S) where S: SubscriberInitExt { |
| 175 | + TRACING_GUARDS.replace(None); // drop first to avoid a prior guard to reset the thread local subscriber it upon replace() |
| 176 | + TRACING_GUARDS.replace(Some(subscriber.set_default())); |
| 177 | +} |
| 178 | + |
| 179 | +#[no_mangle] |
| 180 | +pub unsafe extern "C" fn ddog_log(category: Log, msg: CharSlice) { |
| 181 | + let once = !(category & Log::Once).is_empty(); |
| 182 | + let category = category & !Log::Once; |
| 183 | + if once { |
| 184 | + with_target!(category, tracing::event!(once = true, "{}", msg.to_utf8_lossy())); |
| 185 | + } else { |
| 186 | + with_target!(category, tracing::event!("{}", msg.to_utf8_lossy())); |
112 | 187 | } |
113 | 188 | } |
114 | 189 |
|
|
0 commit comments