|
| 1 | +use rust_tracing::{Event, Subscriber}; |
| 2 | +use tracing_subscriber::{ |
| 3 | + fmt::{ |
| 4 | + format::{self, FormatEvent, FormatFields, Writer}, |
| 5 | + time::{FormatTime, SystemTime}, |
| 6 | + FmtContext, FormattedFields, |
| 7 | + }, |
| 8 | + registry::LookupSpan, |
| 9 | +}; |
| 10 | + |
1 | 11 | use tracing::log::LevelFilter; |
2 | 12 | use tracing_subscriber::{fmt, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter}; |
3 | 13 |
|
4 | 14 | // Initializes tracing with the specified log level. |
5 | 15 | // Allows fine-grained filtering with `EnvFilter` directives. |
6 | 16 | // The directives are read from `DEFGUARD_PROXY_LOG_FILTER` env variable. |
7 | | -// For more info check: <https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html> |
| 17 | +// For more info read: <https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html> |
8 | 18 | pub fn init_tracing(level: &LevelFilter) { |
9 | 19 | tracing_subscriber::registry() |
10 | 20 | .with( |
11 | 21 | EnvFilter::try_from_env("DEFGUARD_PROXY_LOG_FILTER") |
12 | 22 | .unwrap_or_else(|_| level.to_string().into()), |
13 | 23 | ) |
14 | | - .with(fmt::layer()) |
| 24 | + .with(fmt::layer().event_format(HttpFormatter::default())) |
15 | 25 | .init(); |
16 | 26 | info!("Tracing initialized"); |
17 | 27 | } |
| 28 | + |
| 29 | +/// Implements fail2ban-friendly log format using `tracing_subscriber::fmt::format::FormatEvent` trait. |
| 30 | +/// HTTP info (if available) is extracted from the specified tracing span. The format is as follows: |
| 31 | +/// TIMESTAMP LEVEL CLIENT_ADDR METHOD URI LOG_MESSAGE || TRACING_DATA |
| 32 | +pub(crate) struct HttpFormatter<'a> { |
| 33 | + span: &'a str, |
| 34 | + timer: SystemTime, |
| 35 | +} |
| 36 | + |
| 37 | +impl<'a> Default for HttpFormatter<'a> { |
| 38 | + fn default() -> Self { |
| 39 | + Self { |
| 40 | + span: "http_request", |
| 41 | + timer: SystemTime, |
| 42 | + } |
| 43 | + } |
| 44 | +} |
| 45 | + |
| 46 | +impl HttpFormatter<'_> { |
| 47 | + fn format_timestamp(&self, writer: &mut Writer<'_>) -> std::fmt::Result { |
| 48 | + if self.timer.format_time(writer).is_err() { |
| 49 | + writer.write_str("<unknown time>")?; |
| 50 | + } |
| 51 | + writer.write_char(' ') |
| 52 | + } |
| 53 | +} |
| 54 | + |
| 55 | +impl<S, N> FormatEvent<S, N> for HttpFormatter<'_> |
| 56 | +where |
| 57 | + S: Subscriber + for<'a> LookupSpan<'a>, |
| 58 | + N: for<'a> FormatFields<'a> + 'static, |
| 59 | +{ |
| 60 | + fn format_event( |
| 61 | + &self, |
| 62 | + ctx: &FmtContext<'_, S, N>, |
| 63 | + mut writer: format::Writer<'_>, |
| 64 | + event: &Event<'_>, |
| 65 | + ) -> std::fmt::Result { |
| 66 | + let meta = event.metadata(); |
| 67 | + |
| 68 | + // timestamp & level |
| 69 | + self.format_timestamp(&mut writer)?; |
| 70 | + write!(writer, "{} ", meta.level())?; |
| 71 | + |
| 72 | + // iterate and accumulate spans storing our special span in separate variable if encountered |
| 73 | + let mut context_logs: Vec<String> = Vec::new(); |
| 74 | + let mut http_log: Option<String> = None; |
| 75 | + if let Some(scope) = ctx.event_scope() { |
| 76 | + let mut seen = false; |
| 77 | + for span in scope.from_root() { |
| 78 | + let span_name = span.metadata().name(); |
| 79 | + context_logs.push(span_name.to_string()); |
| 80 | + seen = true; |
| 81 | + |
| 82 | + if let Some(fields) = span.extensions().get::<FormattedFields<N>>() { |
| 83 | + if !fields.is_empty() { |
| 84 | + match span_name { |
| 85 | + x if x == self.span => http_log = Some(format!("{fields}")), |
| 86 | + _ => context_logs.push(format!("{{{fields}}}")), |
| 87 | + } |
| 88 | + } |
| 89 | + } |
| 90 | + context_logs.push(":".into()); |
| 91 | + } |
| 92 | + if seen { |
| 93 | + context_logs.push(' '.into()); |
| 94 | + } |
| 95 | + }; |
| 96 | + |
| 97 | + // write http context log (ip, method, path) |
| 98 | + if let Some(log) = http_log { |
| 99 | + let split: Vec<&str> = log.split(['=', ' ']).collect(); |
| 100 | + let method = split.get(1).unwrap_or(&"unknown"); |
| 101 | + let path = split.get(3).unwrap_or(&"unknown"); |
| 102 | + |
| 103 | + let addr = split.get(5).and_then(|s| Some(s.replace('"', ""))); |
| 104 | + let ip = addr |
| 105 | + .and_then(|s| s.split(":").next().map(|s| s.to_string())) |
| 106 | + .unwrap_or("unknown".to_string()); |
| 107 | + write!(writer, "{ip} {method} {path} ")?; |
| 108 | + } |
| 109 | + |
| 110 | + // write actual log message |
| 111 | + ctx.format_fields(writer.by_ref(), event)?; |
| 112 | + |
| 113 | + // write span context |
| 114 | + if !context_logs.is_empty() { |
| 115 | + write!(writer, " || Tracing data: ")?; |
| 116 | + for log in context_logs { |
| 117 | + write!(writer, "{log}")? |
| 118 | + } |
| 119 | + } |
| 120 | + writeln!(writer) |
| 121 | + } |
| 122 | +} |
0 commit comments