Skip to main content

pharos_plugins/
log_format.rs

1//! Compiled CoreDNS-style query log formats.
2
3use std::{fmt::Write, net::SocketAddr, time::Duration};
4
5use pharos_proto::{Message, NameRef, Opcode, Rcode, Rdata};
6use pharos_server::{Context, Outcome, Protocol, response_limit};
7
8/// CoreDNS's default query log format.
9pub const COMMON_LOG_FORMAT: &str = "{remote}:{port} - {>id} \"{type} {class} {name} {proto} {size} {>do} {>bufsize}\" {rcode} {>rflags} {rsize} {duration}";
10/// The common format with the numeric query opcode appended.
11pub const COMBINED_LOG_FORMAT: &str = "{remote}:{port} - {>id} \"{type} {class} {name} {proto} {size} {>do} {>bufsize}\" {rcode} {>rflags} {rsize} {duration} \"{>opcode}\"";
12
13#[derive(Clone, Debug)]
14enum Part {
15    Literal(String),
16    Metadata(String),
17    Type,
18    Name,
19    Class,
20    Proto,
21    Size,
22    Remote,
23    Port,
24    Local,
25    Id,
26    Opcode,
27    Do,
28    Bufsize,
29    Rcode,
30    Rsize,
31    Duration,
32    Rflags,
33}
34
35/// A parsed format, reusable across requests and safe to share between threads.
36#[derive(Clone, Debug)]
37pub struct Format {
38    parts: Vec<Part>,
39}
40
41impl Format {
42    /// Expand the log shortcuts and compile known labels. Unknown labels stay literal.
43    #[must_use]
44    pub fn compile(format: &str) -> Self {
45        let expanded = format
46            .replace("{common}", COMMON_LOG_FORMAT)
47            .replace("{combined}", COMBINED_LOG_FORMAT);
48        let mut remaining = expanded.as_str();
49        let mut parts = Vec::new();
50        while let Some(end) = remaining.find('}') {
51            let Some(start) = remaining[..end].rfind('{') else {
52                parts.push(Part::Literal(remaining[..=end].to_owned()));
53                remaining = &remaining[end + 1..];
54                continue;
55            };
56            let label = &remaining[start..=end];
57            let part = match label {
58                "{type}" => Some(Part::Type),
59                "{name}" => Some(Part::Name),
60                "{class}" => Some(Part::Class),
61                "{proto}" => Some(Part::Proto),
62                "{size}" => Some(Part::Size),
63                "{remote}" => Some(Part::Remote),
64                "{port}" => Some(Part::Port),
65                "{local}" => Some(Part::Local),
66                "{>id}" => Some(Part::Id),
67                "{>opcode}" => Some(Part::Opcode),
68                "{>do}" => Some(Part::Do),
69                "{>bufsize}" => Some(Part::Bufsize),
70                "{rcode}" => Some(Part::Rcode),
71                "{rsize}" => Some(Part::Rsize),
72                "{duration}" => Some(Part::Duration),
73                "{>rflags}" => Some(Part::Rflags),
74                _ if label.starts_with("{/") => {
75                    Some(Part::Metadata(label[2..label.len() - 1].to_owned()))
76                }
77                _ => None,
78            };
79            if let Some(part) = part {
80                if start != 0 {
81                    parts.push(Part::Literal(remaining[..start].to_owned()));
82                }
83                parts.push(part);
84            } else {
85                parts.push(Part::Literal(remaining[..=end].to_owned()));
86            }
87            remaining = &remaining[end + 1..];
88        }
89        if !remaining.is_empty() {
90            parts.push(Part::Literal(remaining.to_owned()));
91        }
92        Self { parts }
93    }
94
95    /// Append a formatted entry to `output`, without clearing it.
96    ///
97    /// Formatting allocates only if `output` needs to grow. Deferred server
98    /// errors are represented as the response the listener will synthesize.
99    /// `{local}` uses the Listener address in the context.
100    pub fn format(
101        &self,
102        output: &mut String,
103        cx: &Context<'_>,
104        outcome: Outcome,
105        elapsed: Duration,
106    ) {
107        let response = self
108            .parts
109            .iter()
110            .any(|part| matches!(part, Part::Rcode | Part::Rsize | Part::Rflags))
111            .then(|| response(cx, outcome));
112        for part in &self.parts {
113            match part {
114                Part::Literal(value) => output.push_str(value),
115                Part::Metadata(key) => output.push_str(cx.metadata.get(key).unwrap_or("-")),
116                Part::Type => {
117                    if let Some(question) = cx.query.questions().next() {
118                        let _ = write!(output, "{}", question.qtype);
119                    }
120                }
121                Part::Class => {
122                    if let Some(question) = cx.query.questions().next() {
123                        let _ = write!(output, "{}", question.qclass);
124                    }
125                }
126                Part::Name => {
127                    if let Some(question) = cx.query.questions().next() {
128                        let start = output.len();
129                        let _ = write!(output, "{}", question.name);
130                        output[start..].make_ascii_lowercase();
131                    } else {
132                        output.push('.');
133                    }
134                }
135                Part::Proto => output.push_str(match cx.protocol {
136                    Protocol::Udp => "udp",
137                    Protocol::Tcp => "tcp",
138                }),
139                Part::Size => {
140                    let _ = write!(output, "{}", message_len(cx.query));
141                }
142                Part::Remote => match cx.client {
143                    SocketAddr::V4(addr) => {
144                        let _ = write!(output, "{}", addr.ip());
145                    }
146                    SocketAddr::V6(addr) => {
147                        let _ = write!(output, "[{}", addr.ip());
148                        if addr.scope_id() != 0 {
149                            let _ = write!(output, "%{}", addr.scope_id());
150                        }
151                        output.push(']');
152                    }
153                },
154                Part::Port => {
155                    let _ = write!(output, "{}", cx.client.port());
156                }
157                // shortcut: wildcard addresses lack a destination IP, until Listener tracking is added.
158                Part::Local => match cx.local {
159                    SocketAddr::V4(addr) => {
160                        let _ = write!(output, "{}", addr.ip());
161                    }
162                    SocketAddr::V6(addr) => {
163                        let _ = write!(output, "[{}", addr.ip());
164                        if addr.scope_id() != 0 {
165                            let _ = write!(output, "%{}", addr.scope_id());
166                        }
167                        output.push(']');
168                    }
169                },
170                Part::Id => {
171                    let _ = write!(output, "{}", cx.query.id());
172                }
173                Part::Opcode => {
174                    let _ = write!(output, "{}", cx.query.opcode().0);
175                }
176                Part::Do => {
177                    let _ = write!(
178                        output,
179                        "{}",
180                        cx.query.opt().is_some_and(|opt| opt.dnssec_ok())
181                    );
182                }
183                Part::Bufsize => {
184                    let _ = write!(output, "{}", response_limit(cx.query, cx.protocol));
185                }
186                Part::Rcode => {
187                    if let Some(code) = response.and_then(|r| r.code) {
188                        let _ = write!(output, "{code}");
189                    } else {
190                        output.push('-');
191                    }
192                }
193                Part::Rsize => {
194                    let _ = write!(output, "{}", response.map_or(0, |r| r.size));
195                }
196                Part::Duration => {
197                    let _ = write!(output, "{}s", elapsed.as_secs_f64());
198                }
199                Part::Rflags => {
200                    if let Some(flags) = response.and_then(|r| r.flags) {
201                        append_flags(output, flags);
202                    } else {
203                        output.push('-');
204                    }
205                }
206            }
207        }
208    }
209}
210
211#[derive(Clone, Copy)]
212struct Response {
213    code: Option<Rcode>,
214    flags: Option<u16>,
215    size: usize,
216}
217
218fn response(cx: &Context<'_>, outcome: Outcome) -> Response {
219    let deferred = match outcome {
220        Outcome::Error(_) => Some(Rcode::SERVFAIL),
221        Outcome::Unanswered(code)
222            if matches!(
223                code,
224                Rcode::SERVFAIL | Rcode::REFUSED | Rcode::FORMERR | Rcode::NOTIMP
225            ) =>
226        {
227            Some(code)
228        }
229        _ => None,
230    };
231    if let Some(code) = deferred {
232        let flags = 0x8000
233            | (cx.query.flags() & 0x7800)
234            | if cx.query.opcode() == Opcode::QUERY {
235                cx.query.flags() & 0x0110
236            } else {
237                0
238            };
239        let size = 12
240            + cx.query
241                .questions()
242                .next()
243                .map_or(0, |q| name_len(q.name) + 4)
244            + usize::from(cx.query.opt().is_some()) * 11;
245        return Response {
246            code: Some(code),
247            flags: Some(flags),
248            size,
249        };
250    }
251    if outcome == Outcome::Response {
252        return match Message::parse(cx.response) {
253            Ok(message) => Response {
254                code: Some(message.rcode()),
255                flags: Some(message.flags()),
256                size: message_len(message),
257            },
258            Err(_) => Response {
259                code: None,
260                flags: None,
261                size: cx.response.len(),
262            },
263        };
264    }
265    Response {
266        code: None,
267        flags: None,
268        size: 0,
269    }
270}
271
272fn append_flags(output: &mut String, flags: u16) {
273    let mut separator = "";
274    for (mask, label) in [
275        (0x8000, "qr"),
276        (0x0400, "aa"),
277        (0x0200, "tc"),
278        (0x0100, "rd"),
279        (0x0080, "ra"),
280        (0x0040, "z"),
281        (0x0020, "ad"),
282        (0x0010, "cd"),
283    ] {
284        if flags & mask != 0 {
285            output.push_str(separator);
286            output.push_str(label);
287            separator = ",";
288        }
289    }
290}
291
292fn name_len(name: NameRef<'_>) -> usize {
293    1 + name.labels().map(|label| label.len() + 1).sum::<usize>()
294}
295
296fn message_len(message: Message<'_>) -> usize {
297    let questions = message
298        .questions()
299        .map(|q| name_len(q.name) + 4)
300        .sum::<usize>();
301    let records = message
302        .answers()
303        .chain(message.authorities())
304        .chain(message.additionals())
305        .map(|record| {
306            let mut size = record.rdata.len();
307            let mut expand = |name: NameRef<'_>| {
308                size = size - name.wire_len() + name_len(name);
309            };
310            match record.data() {
311                Ok(Rdata::Ns(name) | Rdata::Cname(name) | Rdata::Ptr(name)) => expand(name),
312                Ok(Rdata::Mx { exchange, .. }) => expand(exchange),
313                Ok(Rdata::Soa { mname, rname, .. }) => {
314                    expand(mname);
315                    expand(rname);
316                }
317                Ok(
318                    Rdata::Srv { target, .. }
319                    | Rdata::Svcb { target, .. }
320                    | Rdata::Https { target, .. },
321                ) => expand(target),
322                Ok(Rdata::Naptr { replacement, .. }) => expand(replacement),
323                Ok(Rdata::Rrsig { signer, .. }) => expand(signer),
324                Ok(Rdata::Nsec { next, .. }) => expand(next),
325                Ok(Rdata::Tsig { algorithm, .. }) => expand(algorithm),
326                // shortcut: unsupported or malformed name-bearing RDATA stays encoded; extend pharos-proto to decode it.
327                _ => {}
328            }
329            name_len(record.name) + 10 + size
330        })
331        .sum::<usize>();
332    12 + questions + records
333}