gts-logger 0.1.6

Gts logger
Documentation 
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109

use arrayvec::ArrayString;
use gts_logger::logbackend::consolelogger::ConsoleThreadLogBacked;
use gts_logger::logclient::LogClient;
use log::info;
use serde::{Deserialize, Serialize};
use std::time::Duration;

#[derive(Debug, Serialize, Deserialize, Copy, Clone, PartialEq)]
pub struct LogOneStruct {
    some_num: u64,
    some_other_num: u64,
    some_string: ArrayString<16>,
}

#[derive(Debug, Serialize, Deserialize, Copy, Clone, PartialEq)]
pub struct LogTwoStruct {
    some_string: ArrayString<16>,
}

#[derive(Debug, Serialize, Deserialize, Copy, Clone, PartialEq)]
#[serde(tag = "t", content = "c")]
pub enum LogEvent {
    LogOneOne(LogOneStruct),
    LogTwo(LogTwoStruct),
}

fn main() {
    let anc = minstant::Anchor::new();
    env_logger::init();

    let event = LogEvent::LogOneOne(LogOneStruct {
        some_num: 5,
        some_other_num: 7,
        some_string: ArrayString::from("333").unwrap(),
    });
    let _copy_event = event;
    let core_ids = core_affinity::get_core_ids().unwrap();
    let logthread_core = core_ids.last().unwrap().id;
    let mainthread_core = core_ids.first().unwrap().id;

    println!(
        "main thread: {}, log thread: {}",
        mainthread_core, logthread_core
    );

    let log_client = LogClient::<_, LogEvent>::new(ConsoleThreadLogBacked::<50000, _>::new(Some(
        logthread_core,
    )));
    assert!(core_affinity::set_for_current(core_affinity::CoreId {
        id: mainthread_core
    }));

    info!(">> println with logger:");

    let ulog_iters = 20000;
    let gstart = minstant::Instant::now();
    for _ in 0..ulog_iters {
        log_client.log(event).unwrap();
    }
    let gend = minstant::Instant::now();
    let ulog_end_ts = gend.as_unix_nanos(&anc);
    let ulog_start_ts = gstart.as_unix_nanos(&anc);

    info!(">> println with logger(without timestamp):");

    let ulogs_iters = 20000;
    let gsstart = minstant::Instant::now();
    for _ in 0..ulogs_iters {
        log_client.log_same(event).unwrap();
    }
    let gsend = minstant::Instant::now();
    let ulogs_end_ts = gsend.as_unix_nanos(&anc);
    let ulogs_start_ts = gsstart.as_unix_nanos(&anc);

    info!(">> regular println");
    let gstart = minstant::Instant::now();
    let mut timestamp = gstart.as_unix_nanos(&anc);

    let iters = 20000;
    for _ in 0..iters {
        let nstart = minstant::Instant::now();
        let ntimestamp = nstart.as_unix_nanos(&anc);
        println!("{} {:?}", ntimestamp - timestamp, event);
        timestamp = ntimestamp;
    }
    let gend = minstant::Instant::now();
    let end_ts = gend.as_unix_nanos(&anc);
    let start_ts = gstart.as_unix_nanos(&anc);
    std::thread::sleep(Duration::from_millis(2200));

    info!(
        "CONSOLE total {} in {}ns, {} ps per iter",
        iters,
        end_ts - start_ts,
        (end_ts - start_ts) * 1000 / iters
    );
    info!(
        "ULOG total {} in {}ns, {} ps per iter",
        ulog_iters,
        ulog_end_ts - ulog_start_ts,
        (ulog_end_ts - ulog_start_ts) * 1000 / ulog_iters
    );
    info!(
        "ULOG_same total {} in {}ns, {} ps per iter",
        ulogs_iters,
        ulogs_end_ts - ulogs_start_ts,
        (ulogs_end_ts - ulogs_start_ts) * 1000 / ulogs_iters
    );
}