Skip to content

Conversation

NotEvenANeko
Copy link

@NotEvenANeko NotEvenANeko commented Sep 5, 2025

Refactor tracing to spdlog-rs for logging, which is behind the spdlog-rs feature flag, and tracing codes should be removed before this PR gets merged.

The original tracing logger is behind the tracing feature flag now.

Haven't written comments yet...

And blocked by SpriteOvO/spdlog-rs#93 .

This closes #486 .

cc @SpriteOvO

@eatradish
Copy link
Member

eatradish commented Sep 5, 2025

Initially it looks good, but what I'm wondering is whether we should just replace the tracing family directly with spdlog instead of optional?

@NotEvenANeko
Copy link
Author

Yeah we should replace tracing with spdlog, current codes is just convenient for debugging. I'll delete the tracing codes after spdlog parts are good to go.

Copy link

@SpriteOvO SpriteOvO left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just a brief look and most of it seems to be fine. I'll probably merge SpriteOvO/spdlog-rs#93 in the next couple days. In the meantime, you can try removing the use of tracing from oma entirely.

src/main.rs Outdated
Comment on lines 304 to 321
let rotating_sink = if let Ok(log_file) = &log_file {
Some(
AsyncPoolSink::builder()
.sink(Arc::new(
RotatingFileSink::builder()
.base_path(&log_file)
.formatter(formatter.clone())
.rotation_policy(RotationPolicy::Hourly)
.build()
.unwrap(),
))
.overflow_policy(spdlog::sink::OverflowPolicy::DropIncoming)
.build()
.unwrap(),
)
} else {
None
};

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The RotatingFileSink should not rotate hourly as oma did not do so. Could try RotationPolicy::FileSize(u64::MAX) and set max_files(config.save_log_count()).

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed, file size is set to 10MB.

src/main.rs Outdated
.join("oma")
};

let log_file = create_log_file(&log_dir);

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Creating variants for filenames has been done internally by spdlog-rs, so oma no longer needs to create names manually.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed

@SpriteOvO
Copy link

FYI, SpriteOvO/spdlog-rs#93 is merged.

@NotEvenANeko
Copy link
Author

I'll work on this PR tomorrow.

@NotEvenANeko
Copy link
Author

spdlog-rs is set to main-dev branch now.

Comment on lines 147 to 148
/// StdStreamSink::builder().formatter(Box::new(OmaLayer::default())).build().unwrap()
/// )).build().unwrap();

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is preferred that unwrap() not be used inside an example, and some of the error handling components be hidden if they make the example too difficult to follow.

Quote from https://doc.rust-lang.org/rustdoc/write-documentation/what-to-include.html?highlight=unwrap#examples

dest.write_str(&console::strip_ansi_codes(record.payload()))?;
}

dest.write_char('\n')?;

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also, we should write out the key-values of the record here.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Where we place the KV data? Just append it to the end of the log? 🤔

And it looks messy if we output the KV data in stdout.

Copy link

@SpriteOvO SpriteOvO Oct 2, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

let mut visitor = OmaRecorder(BTreeMap::new());
event.record(&mut visitor);
for (k, v) in visitor.0 {
if k == "message" {
if self.with_ansi {
self.writer.writeln(&prefix, &v).ok();
} else {
self.writer
.writeln(&prefix, &console::strip_ansi_codes(&v))
.ok();
}
}
}
}
}
/// OmaRecorder
/// `OmaRecorder` is used for recording oma-style logs.
///
/// # Example:
/// ```ignore
/// let mut visitor = OmaRecorder(BTreeMap::new());
/// event.record(&mut visitor);
/// for (k, v) in visitor.0 {
/// if k == "message" {
/// self.writer.writeln(&prefix, &v).ok();
/// }
/// }
/// ```
struct OmaRecorder<'a>(BTreeMap<&'a str, String>);
impl tracing::field::Visit for OmaRecorder<'_> {
fn record_f64(&mut self, field: &Field, value: f64) {
self.0.insert(field.name(), value.to_string());
}
fn record_i64(&mut self, field: &Field, value: i64) {
self.0.insert(field.name(), value.to_string());
}
fn record_u64(&mut self, field: &Field, value: u64) {
self.0.insert(field.name(), value.to_string());
}
fn record_bool(&mut self, field: &Field, value: bool) {
self.0.insert(field.name(), value.to_string());
}
fn record_str(&mut self, field: &Field, value: &str) {
self.0.insert(field.name(), value.to_string());
}
fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) {
self.0.insert(field.name(), format!("{value:#?}"));
}
fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
self.0.insert(field.name(), format!("{value:#?}"));
}
}

Since before this PR, oma is already used OmaRecorder to write KV to the end of a log record, I think keeping the behavior should be fine.

Some dep crates may completely use KV to recording variables instead of formatting into the payload.

Copy link

@SpriteOvO SpriteOvO Oct 2, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oops, seems I understand it incorrectly, oma only cares value with "message" as the key.

My bad, let's just keep the old behavior. You can use KeyValues::get method to get value with "message" as the key.

EDIT: NVM, tracing uses "message" KV to store payload, the current code works the same as before already, so looks good to me.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll leave the original implementation here, which is not to print KV

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The with_kv field is added to formatter but unused if we need to print KV later.

src/main.rs Outdated
Comment on lines 39 to 41
// FIXME: `spdlog::error` is conflict with `mod error`
use spdlog::{
Level, LevelFilter, Logger, debug, default_logger, error as error2, info, set_default_logger,

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, this is definitely a mistake in spdlog-rs, I haven't figure out the right way to fix it. For now, we can import the error! macro from spdlog::prelude::error.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

use spdlog:prelude:error has the same issue

Copy link

@SpriteOvO SpriteOvO Oct 2, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm, so it's not a conflict between spdlog::error mod and spdlog::error! macro? So, if not, then it's probably should not consider as a mistake from spdlog-rs.

Okay, let's just keep the alias here. I'll suggest another name error as err.

src/main.rs Outdated
Comment on lines 286 to 287
.to_string_lossy()
.to_string();

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm, since spdlog-rs accepts a path type instead of a string type, I think we should place the conversion to the end of the function.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed

let level_filter = LevelFilter::MoreSevereEqual(Level::Info);

if !debug && !dry_run {
let no_i18n_embd: EnvFilter = "i18n_embed=off,info".parse().unwrap();

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks like we have not setup the log crate proxy in this PR. The logs from log crate will only be available after we set it up via spdlog::init_log_crate_proxy().

And we really should migrate env filters, but spdlog-rs currently does not support filter logs from log crate, we will probably support this feature in the next minor release.

For now, is it acceptable for not migrate this at the moment? @eatradish

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks like we have not setup the log crate proxy in this PR. The logs from log crate will only be available after we set it up via spdlog::init_log_crate_proxy().

And we really should migrate env filters, but spdlog-rs currently does not support filter logs from log crate, we will probably support this feature in the next minor release.

For now, is it acceptable for not migrate this at the moment? @eatradish

Yes, but subsequent releases may include this feature as a breaking

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

init_log_crate_proxy() added.

@SpriteOvO
Copy link

FYI, we have just released spdlog-rs v0.5.0. You could target the dependency spdlog-rs in this PR to the crates.io registry now.

@NotEvenANeko
Copy link
Author

Updated to v0.5.0

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Replace the current logging system with spdlog-rs
3 participants