flexi_logger/
deferred_now.rs

1use chrono::{
2    format::{DelayedFormat, StrftimeItems},
3    DateTime, Local, SecondsFormat, Utc,
4};
5#[cfg(feature = "syslog_writer")]
6use chrono::{Datelike, Timelike};
7use std::sync::{Mutex, OnceLock};
8
9/// Deferred timestamp creation.
10///
11/// Is used to ensure that a log record that is sent to multiple outputs
12/// (in maybe different formats) always uses the same timestamp.
13#[derive(Debug, Default)]
14pub struct DeferredNow(Option<DateTime<Local>>);
15impl<'a> DeferredNow {
16    /// Constructs a new instance, but does not generate the timestamp.
17    #[must_use]
18    pub fn new() -> Self {
19        Self(None)
20    }
21
22    #[cfg(test)]
23    #[must_use]
24    fn new_from_datetime(dt: DateTime<Local>) -> Self {
25        Self(Some(dt))
26    }
27
28    /// Retrieve the timestamp for local time zone.
29    ///
30    /// Requires mutability because the first caller will generate the timestamp.
31    pub fn now(&'a mut self) -> &'a DateTime<Local> {
32        self.0.get_or_insert_with(Local::now)
33    }
34
35    /// Retrieve the UTC timestamp.
36    ///
37    /// Requires mutability because the first caller will generate the timestamp.
38    pub fn now_utc_owned(&'a mut self) -> DateTime<Utc> {
39        (*self.now()).into()
40    }
41
42    /// Produces a preformatted object suitable for printing.
43    ///
44    /// # Panics
45    ///
46    /// Panics if `fmt` has an inappropriate value.
47    pub fn format<'b>(&'a mut self, fmt: &'b str) -> DelayedFormat<StrftimeItems<'b>> {
48        if use_utc() {
49            self.now_utc_owned().format(fmt)
50        } else {
51            self.now().format(fmt)
52        }
53    }
54
55    /// Prints itself in a format compliant with RFC 3339.
56    ///
57    /// Example: 2021-04-29T13:14:15.678+01:00
58    ///
59    /// We do not use the Z variant of RFC 3339, because it is often misinterpreted.
60    pub fn format_rfc3339(&mut self) -> String {
61        if use_utc() {
62            self.now_utc_owned()
63                .to_rfc3339_opts(SecondsFormat::Millis, false)
64        } else {
65            self.now().to_rfc3339_opts(SecondsFormat::Millis, false)
66        }
67    }
68
69    // format_rfc3164: Mmm dd hh:mm:ss, where
70    // mmm = one of "Jan, Feb, Mar, Apr, May, Jun, Jul, Aug, Sep, Oct, Nov, Dec",
71    // dd = "xy" where x = " " or "1" or "2" or "3"
72    // hh = "00" ... "23"
73    // mm, ss= "00" ... "59"
74    #[cfg(feature = "syslog_writer")]
75    pub(crate) fn format_rfc3164(&mut self) -> String {
76        let (date, time) = if use_utc() {
77            let now = self.now_utc_owned();
78            (now.date_naive(), now.time())
79        } else {
80            let now = self.now();
81            (now.date_naive(), now.time())
82        };
83
84        format!(
85            "{mmm} {dd:>2} {hh:02}:{mm:02}:{ss:02}",
86            mmm = match date.month() {
87                1 => "Jan",
88                2 => "Feb",
89                3 => "Mar",
90                4 => "Apr",
91                5 => "May",
92                6 => "Jun",
93                7 => "Jul",
94                8 => "Aug",
95                9 => "Sep",
96                10 => "Oct",
97                11 => "Nov",
98                12 => "Dec",
99                _ => unreachable!(),
100            },
101            dd = date.day(),
102            hh = time.hour(),
103            mm = time.minute(),
104            ss = time.second()
105        )
106    }
107
108    /// Enforce the use of UTC rather than local time.
109    ///
110    /// By default, `flexi_logger` uses or tries to use local time.
111    /// By calling early in your program either `Logger::use_utc()` or directly this method,
112    /// you can override this to always use UTC.
113    ///
114    /// # Panics
115    ///
116    /// Panics if called too late, i.e., if [`DeferredNow::now`] was already called before on
117    /// any instance of `DeferredNow`.
118    pub fn force_utc() {
119        let mut cfg_force_utc = cfg_force_utc().lock().unwrap();
120        match *cfg_force_utc {
121            Some(false) => {
122                panic!("offset is already initialized not to enforce UTC");
123            }
124            Some(true) => {
125                // is already set, nothing to do
126            }
127            None => *cfg_force_utc = Some(true),
128        }
129    }
130}
131
132fn cfg_force_utc() -> &'static Mutex<Option<bool>> {
133    static CFG_FORCE_UTC: OnceLock<Mutex<Option<bool>>> = OnceLock::new();
134    CFG_FORCE_UTC.get_or_init(|| Mutex::new(None))
135}
136
137fn use_utc() -> bool {
138    let mut cfg_force_utc = cfg_force_utc().lock().unwrap();
139    if let Some(true) = *cfg_force_utc {
140        true
141    } else {
142        if cfg_force_utc.is_none() {
143            *cfg_force_utc = Some(false);
144        }
145        false
146    }
147}
148
149#[cfg(test)]
150pub(crate) fn set_force_utc(b: bool) {
151    let mut cfg_force_utc = cfg_force_utc().lock().unwrap();
152    *cfg_force_utc = Some(b);
153}
154
155#[cfg(test)]
156mod test {
157    use crate::DeferredNow;
158    use chrono::{
159        DateTime, FixedOffset, NaiveDate, NaiveDateTime, NaiveTime, SecondsFormat, TimeZone, Utc,
160    };
161
162    #[test]
163    fn test_timestamp_taken_only_once() {
164        let mut deferred_now = super::DeferredNow::new();
165        let once = *deferred_now.now();
166        std::thread::sleep(std::time::Duration::from_millis(30));
167        let again = *deferred_now.now();
168        assert_eq!(once, again);
169        println!("Now: {}", deferred_now.format("%Y-%m-%d %H:%M:%S%.6f %:z"));
170        println!("Now: {}", once.format("%Y-%m-%d %H:%M:%S%.6f %:z"));
171        println!("Now: {}", again.format("%Y-%m-%d %H:%M:%S%.6f %:z"));
172    }
173
174    fn utc_and_offset_timestamps() -> (DateTime<Utc>, DateTime<FixedOffset>) {
175        let naive_datetime = NaiveDateTime::new(
176            NaiveDate::from_ymd_opt(2021, 4, 29).unwrap(),
177            NaiveTime::from_hms_milli_opt(13, 14, 15, 678).unwrap(),
178        );
179        (
180            Utc.from_local_datetime(&naive_datetime).unwrap(),
181            FixedOffset::east_opt(3600)
182                .unwrap()
183                .from_local_datetime(&naive_datetime)
184                .unwrap(),
185        )
186    }
187    fn get_deferred_nows() -> (DeferredNow, DeferredNow) {
188        let (ts_utc, ts_plus1) = utc_and_offset_timestamps();
189        (
190            DeferredNow::new_from_datetime(ts_utc.into()),
191            DeferredNow::new_from_datetime(ts_plus1.into()),
192        )
193    }
194
195    #[test]
196    fn test_chrono_rfc3339() {
197        let (ts_utc, ts_plus1) = utc_and_offset_timestamps();
198
199        assert_eq!(
200            ts_utc.to_rfc3339_opts(SecondsFormat::Millis, true),
201            "2021-04-29T13:14:15.678Z",
202        );
203        assert_eq!(
204            ts_plus1.to_rfc3339_opts(SecondsFormat::Millis, true),
205            "2021-04-29T13:14:15.678+01:00",
206        );
207
208        assert_eq!(
209            ts_utc.to_rfc3339_opts(SecondsFormat::Millis, false),
210            "2021-04-29T13:14:15.678+00:00",
211        );
212        assert_eq!(
213            ts_plus1.to_rfc3339_opts(SecondsFormat::Millis, false),
214            "2021-04-29T13:14:15.678+01:00",
215        );
216    }
217
218    #[test]
219    fn test_formats() {
220        #[cfg(feature = "syslog_writer")]
221        {
222            log::info!("test rfc3164");
223            super::set_force_utc(true);
224            let (mut dn1, mut dn2) = get_deferred_nows();
225            assert_eq!("Apr 29 13:14:15", &dn1.format_rfc3164());
226            assert_eq!("Apr 29 12:14:15", &dn2.format_rfc3164());
227        }
228
229        log::info!("test rfc3339");
230        {
231            // with local timestamps, offsets ≠ 0 are printed (except in Greenwich time zone):
232            super::set_force_utc(false);
233            let (mut dn1, mut dn2) = get_deferred_nows();
234            log::info!("2021-04-29T15:14:15.678+02:00, {}", &dn1.format_rfc3339());
235            log::info!("2021-04-29T14:14:15.678+02:00, {}", &dn2.format_rfc3339());
236
237            // with utc, the timestamps are normalized to offset 0
238            super::set_force_utc(true);
239            let (mut dn1, mut dn2) = get_deferred_nows();
240            assert_eq!("2021-04-29T13:14:15.678+00:00", &dn1.format_rfc3339());
241            assert_eq!("2021-04-29T12:14:15.678+00:00", &dn2.format_rfc3339());
242        }
243    }
244}
flexi_logger/deferred_now.rs

flexi_logger/
deferred_now.rs
