1
//! To configure the logger.
2

            
3
use std::{
4
    env,
5
    net::SocketAddr,
6
    task::{Context, Poll},
7
};
8

            
9
use anyhow::Result;
10
use axum::{
11
    extract::{ConnectInfo, Request},
12
    response::Response,
13
};
14
use chrono::{SecondsFormat, Utc};
15
use clap::{Arg, ArgMatches, Command};
16
use futures::future::BoxFuture;
17
use log::{info, Level, LevelFilter, Record};
18
use log4rs::{
19
    self,
20
    append::console::ConsoleAppender,
21
    config::{Appender, Root},
22
    encode::{Encode, Write},
23
};
24
use serde::{Deserialize, Serialize};
25
use tower::{Layer, Service};
26

            
27
/// Logger configuration object.
28
#[derive(Default, Deserialize)]
29
pub 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)]
41
pub struct LoggerLayer;
42

            
43
#[derive(Clone)]
44
pub struct LoggerMiddleware<S> {
45
    service: S,
46
}
47

            
48
/// The log4rs encoder for JSON format.
49
#[derive(Debug)]
50
struct JsonEncoder {
51
    _proj_name: String,
52
}
53

            
54
/// The log4rs encoder for log4j format.
55
#[derive(Debug)]
56
struct Log4jEncoder {
57
    _proj_name: String,
58
}
59

            
60
/// Normal log information.
61
#[derive(Debug, Serialize)]
62
struct 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)]
71
struct 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)
83
pub const ACTIX_LOGGER_FORMAT: &'static str = "%a %s %D %U %r";
84
pub const ACTIX_LOGGER_NAME: &'static str = "actix_web::middleware::logger";
85
pub const SYLVIA_IOT_LOGGER_NAME: &'static str = module_path!();
86

            
87
pub const LEVEL_OFF: &'static str = "off";
88
pub const LEVEL_ERROR: &'static str = "error";
89
pub const LEVEL_WARN: &'static str = "warn";
90
pub const LEVEL_INFO: &'static str = "info";
91
pub const LEVEL_DEBUG: &'static str = "debug";
92

            
93
pub const STYLE_JSON: &'static str = "json";
94
pub const STYLE_LOG4J: &'static str = "log4j";
95

            
96
pub const DEF_LEVEL: &'static str = LEVEL_INFO;
97
pub const DEF_STYLE: &'static str = STYLE_JSON;
98

            
99
pub const FILTER_ONLY: [&'static str; 2] = ["/auth/oauth2/", "/api/"];
100

            
101
impl LoggerLayer {
102
    pub fn new() -> Self {
103
        LoggerLayer {}
104
    }
105
}
106

            
107
impl<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

            
115
impl<S> Service<Request> for LoggerMiddleware<S>
116
where
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

            
155
impl JsonEncoder {
156
    pub fn new(proj_name: &str) -> Self {
157
        JsonEncoder {
158
            _proj_name: proj_name.to_string(),
159
        }
160
    }
161
}
162

            
163
impl Log4jEncoder {
164
    pub fn new(proj_name: &str) -> Self {
165
        Log4jEncoder {
166
            _proj_name: proj_name.to_string(),
167
        }
168
    }
169
}
170

            
171
impl 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

            
221
impl 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.
264
pub 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.
301
9
pub fn reg_args(cmd: Command) -> Command {
302
9
    cmd.arg(
303
9
        Arg::new("log.level")
304
9
            .long("log.level")
305
9
            .help("log level")
306
9
            .num_args(1)
307
9
            .value_parser([LEVEL_OFF, LEVEL_ERROR, LEVEL_WARN, LEVEL_INFO, LEVEL_DEBUG]),
308
9
    )
309
9
    .arg(
310
9
        Arg::new("log.style")
311
9
            .long("log.style")
312
9
            .help("log style")
313
9
            .num_args(1)
314
9
            .value_parser([STYLE_JSON, STYLE_LOG4J]),
315
9
    )
316
9
}
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.
322
13
pub fn read_args(args: &ArgMatches) -> Config {
323
13
    apply_default(&Config {
324
13
        level: match args.get_one::<String>("log.level") {
325
7
            None => match env::var("LOG_LEVEL") {
326
1
                Err(_) => None,
327
6
                Ok(v) => match v.as_str() {
328
6
                    "off" => Some("off".to_string()),
329
5
                    "error" => Some("error".to_string()),
330
4
                    "warn" => Some("warn".to_string()),
331
3
                    "info" => Some("info".to_string()),
332
2
                    "debug" => Some("debug".to_string()),
333
1
                    _ => None,
334
                },
335
            },
336
6
            Some(v) => match v.as_str() {
337
6
                "off" => Some("off".to_string()),
338
5
                "error" => Some("error".to_string()),
339
4
                "warn" => Some("warn".to_string()),
340
2
                "info" => Some("info".to_string()),
341
1
                "debug" => Some("debug".to_string()),
342
                _ => None,
343
            },
344
        },
345
13
        style: match args.get_one::<String>("log.style") {
346
10
            None => match env::var("LOG_STYLE") {
347
4
                Err(_) => None,
348
6
                Ok(v) => match v.as_str() {
349
6
                    STYLE_JSON => Some(STYLE_JSON.to_string()),
350
5
                    STYLE_LOG4J => Some(STYLE_LOG4J.to_string()),
351
1
                    _ => None,
352
                },
353
            },
354
3
            Some(v) => match v.as_str() {
355
3
                STYLE_JSON => Some(STYLE_JSON.to_string()),
356
2
                STYLE_LOG4J => Some(STYLE_LOG4J.to_string()),
357
                _ => None,
358
            },
359
        },
360
    })
361
13
}
362

            
363
/// Fill missing configuration with default values.
364
17
pub fn apply_default(config: &Config) -> Config {
365
17
    Config {
366
17
        level: match config.level.as_ref() {
367
3
            None => Some(DEF_LEVEL.to_string()),
368
14
            Some(v) => match v.as_str() {
369
14
                "off" => Some("off".to_string()),
370
11
                "error" => Some("error".to_string()),
371
9
                "warn" => Some("warn".to_string()),
372
6
                "info" => Some("info".to_string()),
373
3
                "debug" => Some("debug".to_string()),
374
1
                _ => Some(DEF_LEVEL.to_string()),
375
            },
376
        },
377
17
        style: match config.style.as_ref() {
378
6
            None => Some(DEF_STYLE.to_string()),
379
11
            Some(v) => match v.as_str() {
380
11
                STYLE_LOG4J => Some(STYLE_LOG4J.to_string()),
381
4
                _ => Some(STYLE_JSON.to_string()),
382
            },
383
        },
384
    }
385
17
}
386

            
387
/// To filter framework module and try to get the module name for printing logs.
388
fn 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.
410
fn 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
}