Skip to main content

featherbit/plugins/util/
log_entry.rs

1//! Shared access-log entry builder for the logger plugins.
2//!
3//! Every logger (http-logger, tcp-logger, elasticsearch-logger, ...) turns the
4//! request [`Context`] into the same JSON entry so their output is consistent.
5//! Two shapes, mirroring APISIX's `log-util`:
6//!
7//! - **default entry** — a structured object (`request`, `response`,
8//!   `client_ip`, `latency`, `consumer`, ...) when no `log_format` is set.
9//! - **custom entry** — a flat object built from a configured `log_format` map
10//!   of `name -> "$var template"`, resolved with [`crate::vars::interpolate`].
11//!
12//! Latency is derived from the reserved `__request_start_ms` message key the
13//! data-plane listener stamps at request start; it is omitted when absent
14//! (e.g. in unit tests that build a Context directly).
15
16use std::collections::HashMap;
17
18use serde_json::{json, Map, Value};
19
20use crate::context::Context;
21use crate::vars;
22
23/// Builds a log entry for `ctx`.
24///
25/// When `log_format` is `Some`, produces a flat object whose values are the
26/// `$var`-interpolated templates. When `None`, produces the default structured
27/// entry. `include_req_body` / `include_resp_body` add the (UTF-8 lossy)
28/// bodies.
29pub fn build_entry(
30    ctx: &Context,
31    log_format: Option<&HashMap<String, Value>>,
32    include_req_body: bool,
33    include_resp_body: bool,
34) -> Value {
35    match log_format {
36        Some(fmt) => build_custom(ctx, fmt),
37        None => build_default(ctx, include_req_body, include_resp_body),
38    }
39}
40
41/// Parses a `log_format` config value (an object of `name -> string`) into a
42/// map, or `None` when absent. Returns an error if it is present but not an
43/// object of scalar values.
44pub fn parse_log_format(
45    config: &HashMap<String, Value>,
46) -> Result<Option<HashMap<String, Value>>, String> {
47    match config.get("log_format") {
48        None | Some(Value::Null) => Ok(None),
49        Some(Value::Object(m)) => {
50            for (k, v) in m {
51                if !v.is_string() && !v.is_number() && !v.is_boolean() {
52                    return Err(format!("log_format['{}'] must be a scalar", k));
53                }
54            }
55            Ok(Some(m.clone().into_iter().collect()))
56        }
57        Some(_) => Err("log_format must be an object of name -> template".to_string()),
58    }
59}
60
61fn build_custom(ctx: &Context, fmt: &HashMap<String, Value>) -> Value {
62    let mut out = Map::new();
63    for (name, template) in fmt {
64        let rendered = match template {
65            Value::String(s) => Value::String(vars::interpolate(ctx, s)),
66            other => other.clone(),
67        };
68        out.insert(name.clone(), rendered);
69    }
70    Value::Object(out)
71}
72
73fn build_default(ctx: &Context, include_req_body: bool, include_resp_body: bool) -> Value {
74    let mut request = json!({
75        "method": ctx.request.method,
76        "uri": request_uri(ctx),
77        "host": ctx.request.host,
78        "scheme": ctx.request.scheme,
79        "headers": headers_to_json(&ctx.request.headers),
80        "size": ctx.request.body.len(),
81    });
82    if include_req_body {
83        request["body"] = json!(String::from_utf8_lossy(&ctx.request.body));
84    }
85
86    let mut response = json!({
87        "status": ctx.response.status_code,
88        "headers": headers_to_json(&ctx.response.headers),
89        "size": ctx.response.body.len(),
90    });
91    if include_resp_body {
92        response["body"] = json!(String::from_utf8_lossy(&ctx.response.body));
93    }
94
95    let mut entry = Map::new();
96    entry.insert("request".to_string(), request);
97    entry.insert("response".to_string(), response);
98    entry.insert(
99        "client_ip".to_string(),
100        json!(client_ip(&ctx.request.remote_addr)),
101    );
102    if let Some(latency) = latency_ms(ctx) {
103        entry.insert("latency".to_string(), json!(latency));
104    }
105    if let Some(start) = ctx
106        .message
107        .get("__request_start_ms")
108        .and_then(|v| v.as_u64())
109    {
110        entry.insert("start_time".to_string(), json!(start));
111    }
112    if let Some(consumer) = ctx.message.get("consumer.name") {
113        entry.insert("consumer".to_string(), consumer.clone());
114    }
115    if !ctx.errors.is_empty() {
116        entry.insert(
117            "errors".to_string(),
118            json!(ctx
119                .errors
120                .iter()
121                .map(|e| json!({ "node_id": e.node_id, "code": e.code, "message": e.message }))
122                .collect::<Vec<_>>()),
123        );
124    }
125    Value::Object(entry)
126}
127
128/// Milliseconds elapsed since the listener stamped `__request_start_ms`.
129fn latency_ms(ctx: &Context) -> Option<u64> {
130    let start = ctx.message.get("__request_start_ms")?.as_u64()?;
131    let now = std::time::SystemTime::now()
132        .duration_since(std::time::UNIX_EPOCH)
133        .ok()?
134        .as_millis() as u64;
135    Some(now.saturating_sub(start))
136}
137
138/// Header map → JSON object of `name -> [values]`.
139fn headers_to_json(headers: &HashMap<String, Vec<String>>) -> Value {
140    let mut m = Map::new();
141    for (k, v) in headers {
142        m.insert(k.clone(), json!(v));
143    }
144    Value::Object(m)
145}
146
147/// Path plus sorted query string.
148fn request_uri(ctx: &Context) -> String {
149    let mut pairs: Vec<String> = Vec::new();
150    for (k, values) in &ctx.request.query_params {
151        for v in values {
152            pairs.push(format!("{}={}", k, v));
153        }
154    }
155    pairs.sort();
156    if pairs.is_empty() {
157        ctx.request.path.clone()
158    } else {
159        format!("{}?{}", ctx.request.path, pairs.join("&"))
160    }
161}
162
163/// Client IP without the port.
164fn client_ip(remote_addr: &str) -> String {
165    match remote_addr.rsplit_once(':') {
166        Some((ip, _)) if !ip.contains(':') => ip.to_string(),
167        _ => remote_addr.to_string(),
168    }
169}
170
171#[cfg(test)]
172mod tests {
173    use super::*;
174    use crate::context::{GatewayRequest, GatewayResponse, Protocol};
175    use bytes::Bytes;
176
177    fn ctx() -> Context {
178        let mut headers = HashMap::new();
179        headers.insert("user-agent".to_string(), vec!["curl/8".to_string()]);
180        let mut query = HashMap::new();
181        query.insert("q".to_string(), vec!["x".to_string()]);
182        let mut message = HashMap::new();
183        message.insert("consumer.name".to_string(), json!("alice"));
184        Context {
185            request: GatewayRequest {
186                method: "GET".to_string(),
187                path: "/api/items".to_string(),
188                host: "example.com".to_string(),
189                scheme: "https".to_string(),
190                headers,
191                query_params: query,
192                body: Bytes::from_static(b"req"),
193                remote_addr: "10.0.0.5:44321".to_string(),
194                protocol: Protocol::Http1,
195            },
196            response: GatewayResponse {
197                status_code: 200,
198                headers: HashMap::new(),
199                body: Bytes::from_static(b"hello"),
200            },
201            message,
202            errors: Vec::new(),
203        }
204    }
205
206    #[test]
207    fn test_default_entry() {
208        let e = build_entry(&ctx(), None, false, false);
209        assert_eq!(e["request"]["method"], "GET");
210        assert_eq!(e["request"]["uri"], "/api/items?q=x");
211        assert_eq!(e["request"]["size"], 3);
212        assert_eq!(e["response"]["status"], 200);
213        assert_eq!(e["response"]["size"], 5);
214        assert_eq!(e["client_ip"], "10.0.0.5");
215        assert_eq!(e["consumer"], "alice");
216        assert!(e.get("body").is_none());
217    }
218
219    #[test]
220    fn test_default_entry_with_bodies() {
221        let e = build_entry(&ctx(), None, true, true);
222        assert_eq!(e["request"]["body"], "req");
223        assert_eq!(e["response"]["body"], "hello");
224    }
225
226    #[test]
227    fn test_custom_log_format() {
228        let mut fmt = HashMap::new();
229        fmt.insert("who".to_string(), json!("$consumer_name@$remote_addr"));
230        fmt.insert("path".to_string(), json!("$uri"));
231        fmt.insert("code".to_string(), json!("$status"));
232        fmt.insert("const".to_string(), json!(7));
233        let e = build_entry(&ctx(), Some(&fmt), false, false);
234        assert_eq!(e["who"], "alice@10.0.0.5");
235        assert_eq!(e["path"], "/api/items");
236        assert_eq!(e["code"], "200");
237        assert_eq!(e["const"], 7);
238    }
239
240    #[test]
241    fn test_parse_log_format() {
242        let mut config = HashMap::new();
243        assert!(parse_log_format(&config).unwrap().is_none());
244        config.insert("log_format".to_string(), json!({ "a": "$uri" }));
245        assert!(parse_log_format(&config).unwrap().is_some());
246        config.insert("log_format".to_string(), json!("not an object"));
247        assert!(parse_log_format(&config).is_err());
248        config.insert("log_format".to_string(), json!({ "a": { "nested": 1 } }));
249        assert!(parse_log_format(&config).is_err());
250    }
251}