Skip to content

Commit d7376e3

Browse files
committed
refactor: reduce macro-generated lines by >70%, and drop tracing
Every `info!`, `warn!` and `error!` call expanded a complete `tracing::event!` to mirror its message into `tracing` (#6919), and that mirror made up most of core's macro output, now removed: it's down from 219k to 54k lines using RUSTC_BOOTSTRAP=1 cargo rustc -p deltachat --lib \ --profile check -- -Zmacro-stats A warm build and `touch src/lib.rs` with rustc 1.99.0, CARGO_INCREMENTAL=0 RUSTC_WRAPPER= /usr/bin/time -v \ cargo check -p deltachat takes about a third less time and 0.37 GiB less peak memory, `cargo build -p deltachat` about a tenth less time and 0.36 GiB less. The release binary from `nix build .#deltachat-rpc-server-x86_64-linux` gets 2.7% smaller. If we want to use tracing events to integrate better with iroh-debugging, for example when we move to iroh 1.X, we could introduce some iroh-relevant tracing events in core.
1 parent 6378533 commit d7376e3

5 files changed

Lines changed: 26 additions & 59 deletions

File tree

‎Cargo.lock‎

Lines changed: 0 additions & 1 deletion
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎Cargo.toml‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -104,7 +104,6 @@ astral-tokio-tar = { version = "0.7.0", default-features = false }
104104
tokio-util = { workspace = true }
105105
tokio = { workspace = true, features = ["fs", "rt-multi-thread", "macros"] }
106106
toml = "0.9"
107-
tracing = "0.1.41"
108107
url = "2"
109108
uuid = { version = "1", features = ["serde", "v4"] }
110109
walkdir = "2.5.0"

‎src/accounts.rs‎

Lines changed: 3 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -76,12 +76,8 @@ impl Accounts {
7676
Accounts::open(events, dir, writable).await
7777
}
7878

79-
/// Get the ID used to log events.
80-
///
81-
/// Account manager logs events with ID 0
82-
/// which is not used by any accounts.
83-
fn get_id(&self) -> u32 {
84-
0
79+
fn log_info(&self, file: &str, line: u32, msg: String) {
80+
self.emit_event(EventType::Info(format!("{file}:{line}: {msg}")));
8581
}
8682

8783
/// Ensures the accounts directory and config file exist.
@@ -395,11 +391,6 @@ impl Accounts {
395391
"Starting background fetch for {n_accounts} accounts."
396392
)),
397393
});
398-
::tracing::event!(
399-
::tracing::Level::INFO,
400-
account_id = 0,
401-
"Starting background fetch for {n_accounts} accounts."
402-
);
403394
let mut set = JoinSet::new();
404395
for account in accounts {
405396
set.spawn(async move {
@@ -415,11 +406,6 @@ impl Accounts {
415406
"Finished background fetch for {n_accounts} accounts."
416407
)),
417408
});
418-
::tracing::event!(
419-
::tracing::Level::INFO,
420-
account_id = 0,
421-
"Finished background fetch for {n_accounts} accounts."
422-
);
423409
}
424410

425411
/// Auxiliary function for [Accounts::background_fetch].
@@ -462,11 +448,6 @@ impl Accounts {
462448
id: 0,
463449
typ: EventType::Warning("Background fetch timed out.".to_string()),
464450
});
465-
::tracing::event!(
466-
::tracing::Level::WARN,
467-
account_id = 0,
468-
"Background fetch timed out."
469-
);
470451
}
471452
events.emit(Event {
472453
id: 0,
@@ -549,7 +530,7 @@ impl Accounts {
549530
}
550531
}
551532

552-
/// Emits a single event.
533+
/// Emits a single event with ID 0, which is not used by any accounts.
553534
pub fn emit_event(&self, event: EventType) {
554535
self.events.emit(Event { id: 0, typ: event })
555536
}

‎src/log.rs‎

Lines changed: 23 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
#![allow(missing_docs)]
44

55
use crate::context::Context;
6+
use crate::events::EventType;
67

78
mod stream;
89

@@ -12,15 +13,9 @@ macro_rules! info {
1213
($ctx:expr, $msg:expr) => {
1314
info!($ctx, $msg,)
1415
};
15-
($ctx:expr, $msg:expr, $($args:expr),* $(,)?) => {{
16-
let formatted = format!($msg, $($args),*);
17-
let full = format!("{file}:{line}: {msg}",
18-
file = file!(),
19-
line = line!(),
20-
msg = &formatted);
21-
::tracing::event!(::tracing::Level::INFO, account_id = $ctx.get_id(), "{}", &formatted);
22-
$ctx.emit_event($crate::EventType::Info(full));
23-
}};
16+
($ctx:expr, $msg:expr, $($args:expr),* $(,)?) => {
17+
$ctx.log_info(file!(), line!(), format!($msg, $($args),*))
18+
};
2419
}
2520

2621
// Workaround for <https://github.com/rust-lang/rust/issues/133708>.
@@ -30,15 +25,9 @@ mod warn_macro_mod {
3025
($ctx:expr, $msg:expr) => {
3126
warn_macro!($ctx, $msg,)
3227
};
33-
($ctx:expr, $msg:expr, $($args:expr),* $(,)?) => {{
34-
let formatted = format!($msg, $($args),*);
35-
let full = format!("{file}:{line}: {msg}",
36-
file = file!(),
37-
line = line!(),
38-
msg = &formatted);
39-
::tracing::event!(::tracing::Level::WARN, account_id = $ctx.get_id(), "{}", &formatted);
40-
$ctx.emit_event($crate::EventType::Warning(full));
41-
}};
28+
($ctx:expr, $msg:expr, $($args:expr),* $(,)?) => {
29+
$ctx.log_warn(file!(), line!(), format!($msg, $($args),*))
30+
};
4231
}
4332

4433
pub(crate) use warn_macro;
@@ -50,15 +39,25 @@ macro_rules! error {
5039
($ctx:expr, $msg:expr) => {
5140
error!($ctx, $msg,)
5241
};
53-
($ctx:expr, $msg:expr, $($args:expr),* $(,)?) => {{
54-
let formatted = format!($msg, $($args),*);
55-
::tracing::event!(::tracing::Level::ERROR, account_id = $ctx.get_id(), "{}", &formatted);
56-
$ctx.set_last_error(&formatted);
57-
$ctx.emit_event($crate::EventType::Error(formatted));
58-
}};
42+
($ctx:expr, $msg:expr, $($args:expr),* $(,)?) => {
43+
$ctx.log_error(format!($msg, $($args),*))
44+
};
5945
}
6046

6147
impl Context {
48+
pub(crate) fn log_info(&self, file: &str, line: u32, msg: String) {
49+
self.emit_event(EventType::Info(format!("{file}:{line}: {msg}")));
50+
}
51+
52+
pub(crate) fn log_warn(&self, file: &str, line: u32, msg: String) {
53+
self.emit_event(EventType::Warning(format!("{file}:{line}: {msg}")));
54+
}
55+
56+
pub(crate) fn log_error(&self, msg: String) {
57+
self.set_last_error(&msg);
58+
self.emit_event(EventType::Error(msg));
59+
}
60+
6261
/// Set last error string.
6362
/// Implemented as blocking as used from macros in different, not always async blocks.
6463
pub fn set_last_error(&self, error: &str) {
@@ -116,12 +115,6 @@ impl<T, E: std::fmt::Display> LogExt<T, E> for Result<T, E> {
116115
);
117116
// We can't use the warn!() macro here as the file!() and line!() macros
118117
// don't work with #[track_caller]
119-
tracing::event!(
120-
::tracing::Level::WARN,
121-
account_id = context.get_id(),
122-
"{}",
123-
&full
124-
);
125118
context.emit_event(crate::EventType::Warning(full));
126119
};
127120
self

‎src/log/stream.rs‎

Lines changed: 0 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -93,11 +93,6 @@ impl<S: SessionStream> AsyncRead for LoggingStream<S> {
9393
"Read error on stream {peer_addr:?} after reading {} and writing {} bytes: {err}.",
9494
this.metrics.total_read, this.metrics.total_written
9595
);
96-
tracing::event!(
97-
::tracing::Level::WARN,
98-
account_id = *this.account_id,
99-
log_message
100-
);
10196
this.events.emit(Event {
10297
id: *this.account_id,
10398
typ: EventType::Warning(log_message),

0 commit comments

Comments
 (0)