sylvia_iot_corelib/
logger.rs

1//! To configure the logger.
2
3use std::{
4    env,
5    net::SocketAddr,
6    task::{Context, Poll},
7};
8
9use anyhow::Result;
10use axum::{
11    extract::{ConnectInfo, Request},
12    response::Response,
13};
14use chrono::{SecondsFormat, Utc};
15use clap::{Arg, ArgMatches, Command};
16use futures::future::BoxFuture;
17use log::{info, Level, LevelFilter, Record};
18use log4rs::{
19    self,
20    append::console::ConsoleAppender,
21    config::{Appender, Root},
22    encode::{Encode, Write},
23};
24use serde::{Deserialize, Serialize};
25use tower::{Layer, Service};
26
27/// Logger configuration object.
28#[derive(Default, Deserialize)]
29pub struct Config {
30    /// Log level. Can be `off`, `error`, `warn`, `info`, `debug`.
31    ///
32    /// Default is `info`.
33    pub level: Option<String>,
34    /// Log style. Can be `json`, `log4j`.
35    ///
36    /// Default is `json`.
37    pub style: Option<String>,
38}
39
40#[derive(Clone)]
41pub struct LoggerLayer;
42
43#[derive(Clone)]
44pub struct LoggerMiddleware<S> {
45    service: S,
46}
47
48/// The log4rs encoder for JSON format.
49#[derive(Debug)]
50struct JsonEncoder {
51    _proj_name: String,
52}
53
54/// The log4rs encoder for log4j format.
55#[derive(Debug)]
56struct Log4jEncoder {
57    _proj_name: String,
58}
59
60/// Normal log information.
61#[derive(Debug, Serialize)]
62struct JsonEncoderMsg {
63    pub ts: String,
64    pub level: String,
65    pub module: String,
66    pub msg: String,
67}
68
69/// HTTP log information.
70#[derive(Debug, Serialize)]
71struct JsonEncoderHttpMsg {
72    pub ts: String,
73    pub level: String,
74    pub remote: String,
75    pub status: String,
76    pub method: String,
77    pub url: String,
78    #[serde(rename = "latencyMs")]
79    pub latency_ms: i64,
80}
81
82// remote address, status code, processing milliseconds, request URL, request line (method, resource, version)
83pub const ACTIX_LOGGER_FORMAT: &'static str = "%a %s %D %U %r";
84pub const ACTIX_LOGGER_NAME: &'static str = "actix_web::middleware::logger";
85pub const SYLVIA_IOT_LOGGER_NAME: &'static str = module_path!();
86
87pub const LEVEL_OFF: &'static str = "off";
88pub const LEVEL_ERROR: &'static str = "error";
89pub const LEVEL_WARN: &'static str = "warn";
90pub const LEVEL_INFO: &'static str = "info";
91pub const LEVEL_DEBUG: &'static str = "debug";
92
93pub const STYLE_JSON: &'static str = "json";
94pub const STYLE_LOG4J: &'static str = "log4j";
95
96pub const DEF_LEVEL: &'static str = LEVEL_INFO;
97pub const DEF_STYLE: &'static str = STYLE_JSON;
98
99pub const FILTER_ONLY: [&'static str; 2] = ["/auth/oauth2/", "/api/"];
100
101impl LoggerLayer {
102    pub fn new() -> Self {
103        LoggerLayer {}
104    }
105}
106
107impl<S> Layer<S> for LoggerLayer {
108    type Service = LoggerMiddleware<S>;
109
110    fn layer(&self, inner: S) -> Self::Service {
111        LoggerMiddleware { service: inner }
112    }
113}
114
115impl<S> Service<Request> for LoggerMiddleware<S>
116where
117    S: Service<Request, Response = Response> + Clone + Send + 'static,
118    S::Future: Send + 'static,
119{
120    type Response = S::Response;
121    type Error = S::Error;
122    type Future = BoxFuture<'static, Result<Self::Response, Self::Error>>;
123
124    fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll<Result<(), Self::Error>> {
125        self.service.poll_ready(cx)
126    }
127
128    fn call(&mut self, req: Request) -> Self::Future {
129        let mut svc = self.service.clone();
130
131        Box::pin(async move {
132            let start_time = Utc::now().timestamp_millis();
133            let remote = match req.extensions().get::<ConnectInfo<SocketAddr>>() {
134                None => "".to_string(),
135                Some(info) => info.0.to_string(),
136            };
137            let method = req.method().clone();
138            let uri = req.uri().clone();
139
140            let res = svc.call(req).await?;
141
142            let latency = Utc::now().timestamp_millis() - start_time;
143            let status = res.status().as_u16();
144
145            info!(
146                target: SYLVIA_IOT_LOGGER_NAME,
147                "{} {} {} {} {}", remote, status, latency, uri, method
148            );
149
150            Ok(res)
151        })
152    }
153}
154
155impl JsonEncoder {
156    pub fn new(proj_name: &str) -> Self {
157        JsonEncoder {
158            _proj_name: proj_name.to_string(),
159        }
160    }
161}
162
163impl Log4jEncoder {
164    pub fn new(proj_name: &str) -> Self {
165        Log4jEncoder {
166            _proj_name: proj_name.to_string(),
167        }
168    }
169}
170
171impl Encode for Log4jEncoder {
172    fn encode(&self, w: &mut dyn Write, record: &Record<'_>) -> Result<()> {
173        let module = match get_module_name(record) {
174            None => return Ok(()),
175            Some(module) => module,
176        };
177
178        let str = if module.eq(SYLVIA_IOT_LOGGER_NAME) || module.eq(ACTIX_LOGGER_NAME) {
179            let msg = match get_http_msg(record) {
180                None => return Ok(()),
181                Some(msg) => msg,
182            };
183            let mut found = false;
184            for filter in FILTER_ONLY {
185                if msg.url.contains(filter) {
186                    found = true;
187                    break;
188                }
189            }
190            if !found {
191                return Ok(());
192            }
193            format!(
194                "{} {} [{}] {} {} {} ({} ms)\n",
195                Utc::now().to_rfc3339_opts(SecondsFormat::Millis, true),
196                match &msg.status.chars().next() {
197                    Some('4') => Level::Warn.as_str(),
198                    Some('5') => Level::Error.as_str(),
199                    _ => Level::Info.as_str(),
200                },
201                msg.remote,
202                msg.status,
203                msg.method,
204                msg.url,
205                msg.latency_ms,
206            )
207        } else {
208            format!(
209                "{} {} [{}] {}\n",
210                Utc::now().to_rfc3339_opts(SecondsFormat::Millis, true),
211                record.level(),
212                module,
213                record.args().to_string().replace("\n", "\\n")
214            )
215        };
216        w.write_all(str.as_bytes())?;
217        Ok(())
218    }
219}
220
221impl Encode for JsonEncoder {
222    fn encode(&self, w: &mut dyn Write, record: &Record<'_>) -> Result<()> {
223        let module = match get_module_name(record) {
224            None => return Ok(()),
225            Some(module) => module,
226        };
227
228        let str = if module.eq(SYLVIA_IOT_LOGGER_NAME) || module.eq(ACTIX_LOGGER_NAME) {
229            let mut msg = match get_http_msg(record) {
230                None => return Ok(()),
231                Some(msg) => msg,
232            };
233            let mut found = false;
234            for filter in FILTER_ONLY {
235                if msg.url.contains(filter) {
236                    found = true;
237                    break;
238                }
239            }
240            if !found {
241                return Ok(());
242            }
243            msg.level = match &msg.status.chars().next() {
244                Some('4') => Level::Warn.as_str().to_lowercase(),
245                Some('5') => Level::Error.as_str().to_lowercase(),
246                _ => Level::Info.as_str().to_lowercase(),
247            };
248            serde_json::to_string(&msg)? + "\n"
249        } else {
250            let msg = JsonEncoderMsg {
251                ts: Utc::now().to_rfc3339_opts(SecondsFormat::Millis, true),
252                level: record.level().to_string().to_lowercase(),
253                module,
254                msg: record.args().to_string(),
255            };
256            serde_json::to_string(&msg)? + "\n"
257        };
258        w.write_all(str.as_bytes())?;
259        Ok(())
260    }
261}
262
263/// To initialize the logger with configurations.
264pub fn init(proj_name: &str, conf: &Config) {
265    let conf = apply_default(&conf);
266
267    let level = match conf.level.as_ref() {
268        None => DEF_LEVEL,
269        Some(v) => v.as_str(),
270    };
271    let level = match level {
272        LEVEL_OFF => LevelFilter::Off,
273        LEVEL_ERROR => LevelFilter::Error,
274        LEVEL_WARN => LevelFilter::Warn,
275        LEVEL_INFO => LevelFilter::Info,
276        LEVEL_DEBUG => LevelFilter::Debug,
277        _ => LevelFilter::Info,
278    };
279    let style = match conf.style.as_ref() {
280        None => DEF_STYLE,
281        Some(v) => v.as_str(),
282    };
283
284    let log4j_encoder = ConsoleAppender::builder()
285        .encoder(Box::new(Log4jEncoder::new(proj_name)))
286        .build();
287    let json_encoder = ConsoleAppender::builder()
288        .encoder(Box::new(JsonEncoder::new(proj_name)))
289        .build();
290    let _ = log4rs::init_config(
291        log4rs::Config::builder()
292            .appender(Appender::builder().build("log4j", Box::new(log4j_encoder)))
293            .appender(Appender::builder().build("json", Box::new(json_encoder)))
294            .build(Root::builder().appender(style).build(level))
295            .unwrap(),
296    )
297    .unwrap();
298}
299
300/// To register Clap arguments.
301pub fn reg_args(cmd: Command) -> Command {
302    cmd.arg(
303        Arg::new("log.level")
304            .long("log.level")
305            .help("log level")
306            .num_args(1)
307            .value_parser([LEVEL_OFF, LEVEL_ERROR, LEVEL_WARN, LEVEL_INFO, LEVEL_DEBUG]),
308    )
309    .arg(
310        Arg::new("log.style")
311            .long("log.style")
312            .help("log style")
313            .num_args(1)
314            .value_parser([STYLE_JSON, STYLE_LOG4J]),
315    )
316}
317
318/// To read input arguments from command-line arguments and environment variables.
319///
320/// This function will call [`apply_default()`] to fill missing values so you do not need call it
321/// again.
322pub fn read_args(args: &ArgMatches) -> Config {
323    apply_default(&Config {
324        level: match args.get_one::<String>("log.level") {
325            None => match env::var("LOG_LEVEL") {
326                Err(_) => None,
327                Ok(v) => match v.as_str() {
328                    "off" => Some("off".to_string()),
329                    "error" => Some("error".to_string()),
330                    "warn" => Some("warn".to_string()),
331                    "info" => Some("info".to_string()),
332                    "debug" => Some("debug".to_string()),
333                    _ => None,
334                },
335            },
336            Some(v) => match v.as_str() {
337                "off" => Some("off".to_string()),
338                "error" => Some("error".to_string()),
339                "warn" => Some("warn".to_string()),
340                "info" => Some("info".to_string()),
341                "debug" => Some("debug".to_string()),
342                _ => None,
343            },
344        },
345        style: match args.get_one::<String>("log.style") {
346            None => match env::var("LOG_STYLE") {
347                Err(_) => None,
348                Ok(v) => match v.as_str() {
349                    STYLE_JSON => Some(STYLE_JSON.to_string()),
350                    STYLE_LOG4J => Some(STYLE_LOG4J.to_string()),
351                    _ => None,
352                },
353            },
354            Some(v) => match v.as_str() {
355                STYLE_JSON => Some(STYLE_JSON.to_string()),
356                STYLE_LOG4J => Some(STYLE_LOG4J.to_string()),
357                _ => None,
358            },
359        },
360    })
361}
362
363/// Fill missing configuration with default values.
364pub fn apply_default(config: &Config) -> Config {
365    Config {
366        level: match config.level.as_ref() {
367            None => Some(DEF_LEVEL.to_string()),
368            Some(v) => match v.as_str() {
369                "off" => Some("off".to_string()),
370                "error" => Some("error".to_string()),
371                "warn" => Some("warn".to_string()),
372                "info" => Some("info".to_string()),
373                "debug" => Some("debug".to_string()),
374                _ => Some(DEF_LEVEL.to_string()),
375            },
376        },
377        style: match config.style.as_ref() {
378            None => Some(DEF_STYLE.to_string()),
379            Some(v) => match v.as_str() {
380                STYLE_LOG4J => Some(STYLE_LOG4J.to_string()),
381                _ => Some(STYLE_JSON.to_string()),
382            },
383        },
384    }
385}
386
387/// To filter framework module and try to get the module name for printing logs.
388fn get_module_name(record: &Record<'_>) -> Option<String> {
389    match record.module_path() {
390        None => None,
391        Some(module) => {
392            if module.eq(SYLVIA_IOT_LOGGER_NAME) || module.eq(ACTIX_LOGGER_NAME) {
393                return Some(module.to_string());
394            }
395            match record.file() {
396                None => Some(module.to_string()),
397                Some(file) => match file.contains("/.cargo/") {
398                    false => match record.line() {
399                        None => Some(file.to_string()),
400                        Some(line) => Some(format!("{}:{}", file, line)),
401                    },
402                    true => None,
403                },
404            }
405        }
406    }
407}
408
409/// Parse HTTP log for generating logs.
410fn get_http_msg(record: &Record<'_>) -> Option<JsonEncoderHttpMsg> {
411    let msg = record.args().to_string();
412    let mut split = msg.split(' ');
413    let remote = match split.next() {
414        None => return None,
415        Some(remote) => remote,
416    };
417    let status = match split.next() {
418        None => return None,
419        Some(status) => status,
420    };
421    let latency_ms = match split.next() {
422        None => return None,
423        Some(latency) => latency,
424    };
425    let url = match split.next() {
426        None => return None,
427        Some(url) => url,
428    };
429    let method = match split.next() {
430        None => return None,
431        Some(method) => method,
432    };
433    Some(JsonEncoderHttpMsg {
434        ts: Utc::now().to_rfc3339_opts(SecondsFormat::Millis, true),
435        level: record.level().to_string(),
436        remote: remote.to_string(),
437        status: status.to_string(),
438        method: method.to_string(),
439        url: url.to_string(),
440        latency_ms: match latency_ms.parse() {
441            Err(_) => -1,
442            Ok(latency) => latency,
443        },
444    })
445}