soil_client/tracing/logging/
fast_local_time.rs

1// This file is part of Soil.
2
3// Copyright (C) Soil contributors.
4// Copyright (C) Parity Technologies (UK) Ltd.
5// SPDX-License-Identifier: GPL-3.0-or-later WITH Classpath-exception-2.0
6
7use chrono::{Datelike, Timelike};
8use std::{cell::RefCell, fmt::Write, time::SystemTime};
9use tracing_subscriber::fmt::{format, time::FormatTime};
10
11/// A structure which, when `Display`d, will print out the current local time.
12#[derive(Debug, Clone, Copy, Eq, PartialEq, Default)]
13pub struct FastLocalTime {
14	/// Decides whenever the fractional timestamp with be included in the output.
15	///
16	/// If `false` the output will match the following `chrono` format string:
17	///   `%Y-%m-%d %H:%M:%S`
18	///
19	/// If `true` the output will match the following `chrono` format string:
20	///   `%Y-%m-%d %H:%M:%S%.3f`
21	pub with_fractional: bool,
22}
23
24// This is deliberately slightly larger than we actually need, just in case.
25const TIMESTAMP_MAXIMUM_LENGTH: usize = 32;
26
27#[derive(Default)]
28struct InlineString {
29	buffer: [u8; TIMESTAMP_MAXIMUM_LENGTH],
30	length: usize,
31}
32
33impl Write for InlineString {
34	fn write_str(&mut self, s: &str) -> std::fmt::Result {
35		let new_length = self.length + s.len();
36		assert!(
37			new_length <= TIMESTAMP_MAXIMUM_LENGTH,
38			"buffer overflow when formatting the current timestamp"
39		);
40
41		self.buffer[self.length..new_length].copy_from_slice(s.as_bytes());
42		self.length = new_length;
43		Ok(())
44	}
45}
46
47impl InlineString {
48	fn as_str(&self) -> &str {
49		// SAFETY: this is safe since the only place we append to the buffer
50		//         is in `write_str` from an `&str`
51		unsafe { std::str::from_utf8_unchecked(&self.buffer[..self.length]) }
52	}
53}
54
55#[derive(Default)]
56struct CachedTimestamp {
57	buffer: InlineString,
58	last_regenerated_at: u64,
59	last_fractional: u32,
60}
61
62thread_local! {
63	static TIMESTAMP: RefCell<CachedTimestamp> = Default::default();
64}
65
66impl FormatTime for FastLocalTime {
67	fn format_time(&self, w: &mut format::Writer<'_>) -> std::fmt::Result {
68		const TIMESTAMP_PARTIAL_LENGTH: usize = "0000-00-00 00:00:00".len();
69
70		let elapsed = SystemTime::now()
71			.duration_since(SystemTime::UNIX_EPOCH)
72			.expect("system time is never before UNIX epoch; qed");
73		let unix_time = elapsed.as_secs();
74
75		TIMESTAMP.with(|cache| {
76			let mut cache = cache.borrow_mut();
77
78			// Regenerate the timestamp only at most once each second.
79			if cache.last_regenerated_at != unix_time {
80				let ts = chrono::Local::now();
81				let fractional = (ts.nanosecond() % 1_000_000_000) / 1_000_000;
82				cache.last_regenerated_at = unix_time;
83				cache.last_fractional = fractional;
84				cache.buffer.length = 0;
85
86				write!(
87					&mut cache.buffer,
88					"{:04}-{:02}-{:02} {:02}:{:02}:{:02}.{:03}",
89					ts.year(),
90					ts.month(),
91					ts.day(),
92					ts.hour(),
93					ts.minute(),
94					ts.second(),
95					fractional
96				)?;
97			} else if self.with_fractional {
98				let fractional = elapsed.subsec_millis();
99
100				// Regenerate the fractional part at most once each millisecond.
101				if cache.last_fractional != fractional {
102					cache.last_fractional = fractional;
103					cache.buffer.length = TIMESTAMP_PARTIAL_LENGTH + 1;
104					write!(&mut cache.buffer, "{:03}", fractional)?;
105				}
106			}
107
108			let mut slice = cache.buffer.as_str();
109			if !self.with_fractional {
110				slice = &slice[..TIMESTAMP_PARTIAL_LENGTH];
111			}
112
113			w.write_str(slice)
114		})
115	}
116}
117
118impl std::fmt::Display for FastLocalTime {
119	fn fmt(&self, mut w: &mut std::fmt::Formatter) -> std::fmt::Result {
120		self.format_time(&mut format::Writer::new(&mut w))
121	}
122}
123
124#[test]
125fn test_format_fast_local_time() {
126	assert_eq!(
127		chrono::Local::now().format("%Y-%m-%d %H:%M:%S").to_string().len(),
128		FastLocalTime { with_fractional: false }.to_string().len()
129	);
130	assert_eq!(
131		chrono::Local::now().format("%Y-%m-%d %H:%M:%S%.3f").to_string().len(),
132		FastLocalTime { with_fractional: true }.to_string().len()
133	);
134
135	// A simple trick to make sure this test won't randomly fail if we so happen
136	// to land on the exact moment when we tick over to the next second.
137	let now_1 = FastLocalTime { with_fractional: false }.to_string();
138	let expected = chrono::Local::now().format("%Y-%m-%d %H:%M:%S").to_string();
139	let now_2 = FastLocalTime { with_fractional: false }.to_string();
140
141	assert!(
142		now_1 == expected || now_2 == expected,
143		"'{}' or '{}' should have been equal to '{}'",
144		now_1,
145		now_2,
146		expected
147	);
148}
soil_client/tracing/logging/fast_local_time.rs

soil_client/tracing/logging/
fast_local_time.rs
