Skip to content

Conversation

@SpriteOvO
Copy link
Owner

@SpriteOvO SpriteOvO commented Nov 29, 2025

Reasons

  1. Using Atomic<T> (from atomic crate) with types that contain uninitialized bytes is undefined behavior. Prior to atomic v0.6, that crate did not restrict this (Footgun: compare_exchange may fail if T contains unused bytes Amanieu/atomic-rs#23). In spdlog-rs, LevelFilter is an enum, for variants Off and All, they have uninitialized bytes.

  2. The new introduced AtomicLevelFilter, makes downstream users no longer need to add atomic crate to their Cargo.toml, and eliminates uninitialized bytes. Ensured the soundness of atomic level filter.

  3. We can now bump atomic to the latest version, this was the main obstacle that kept us locked to atomic v0.5.

  4. Miri currently reports this error, so once it's fixed we can enable Miri in CI (there may be other obstacles, some tests run very slowly even on my real machine).

test log_macros::tests::kv_types ... error: Undefined Behavior: reading memory at alloc855131[0x8c..0x90], but memory is uninitialized at [0x8e..0x90], and this operation requires initialized memory
   --> ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/atomic-0.5.3/src/ops.rs:118:30
    |
118 |         mem::transmute_copy(&(*(dst as *const A)).load(order)),
    |                              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Undefined Behavior occurred here
    |
    = help: this indicates a bug in the program: it performed an invalid operation, and caused Undefined Behavior
    = help: see https://doc.rust-lang.org/nightly/reference/behavior-considered-undefined.html for further information
    = note: BACKTRACE on thread `log_macros::tes`:
    = note: inside `atomic::ops::atomic_load::<level::LevelFilter>` at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/atomic-0.5.3/src/ops.rs:118:30: 118:62
    = note: inside `atomic::Atomic::<level::LevelFilter>::load` at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/atomic-0.5.3/src/lib.rs:145:18: 145:59
note: inside `logger::Logger::flush_level_filter`
   --> spdlog/src/logger.rs:261:9
    |
261 |         self.flush_level_filter.load(Ordering::Relaxed)
    |         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
note: inside `logger::Logger::should_flush`
   --> spdlog/src/logger.rs:526:9
    |
526 |         self.flush_level_filter().test(record.level())
    |         ^^^^^^^^^^^^^^^^^^^^^^^^^
note: inside `logger::Logger::sink_record`
   --> spdlog/src/logger.rs:493:12
    |
493 |         if self.should_flush(record) {
    |            ^^^^^^^^^^^^^^^^^^^^^^^^^
note: inside `logger::Logger::log`
   --> spdlog/src/logger.rs:241:9
    |
241 |         self.sink_record(record);
    |         ^^^^^^^^^^^^^^^^^^^^^^^^
note: inside `__log`
   --> spdlog/src/lib.rs:802:5
    |
802 |     logger.log(&record);
    |     ^^^^^^^^^^^^^^^^^^^
note: inside `log_macros::tests::kv_types`
   --> spdlog/src/log_macros.rs:35:13
    |
 35 |             $crate::__log(logger, $level, $crate::source_location_current!(), $crate::__kv!($kv), format_args!($($arg)+));
    |             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
...
425 |         info!(logger: asserter, "1", kv: { v = 1 });
    |         ------------------------------------------- in this macro invocation
note: inside closure
   --> spdlog/src/log_macros.rs:370:18
    |
369 |     #[test]
    |     ------- in this attribute macro expansion
370 |     fn kv_types() {
    |                  ^

Uninitialized memory occurred at alloc855131[0x8e..0x90], in this allocation:
alloc855131 (stack variable, size: 144, align: 8) {
    0x00 │ 01 00 00 00 00 00 00 00 ╾0x139ded8[a854901]<2511963> (8 ptr bytes)╼ │ ........╾──────╼
    0x10 │ 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 80 │ ................
    0x20 │ __ __ __ __ __ __ __ __ __ __ __ __ __ __ __ __ │ ░░░░░░░░░░░░░░░░
    0x30 │ 00 00 00 00 00 00 00 00 00 __ __ __ __ __ __ __ │ .........░░░░░░░
    0x40 │ ╾0x139ab58[a854353]<2510869> (8 ptr bytes)╼ ╾0x139af90[a854401]<2510872> (8 ptr bytes)╼ │ ╾──────╼╾──────╼
    0x50 │ 00 00 00 00 00 __ __ __ __ __ __ __ __ __ __ __ │ .....░░░░░░░░░░░
    0x60 │ 00 ca 9a 3b __ __ __ __ __ __ __ __ __ __ __ __ │ ...;░░░░░░░░░░░░
    0x70 │ __ __ __ __ __ __ __ __ __ __ __ __ __ __ __ __ │ ░░░░░░░░░░░░░░░░
    0x80 │ __ __ __ __ __ __ __ __ 04 00 03 00 00 00 __ __ │ ░░░░░░░░......░░
}
alloc854901 (Rust heap, size: 16, align: 8) {
    ╾0x139bb48[a854532]<2511155> (8 ptr bytes)╼ ╾0x139bfa8[a854580]<2511158> (8 ptr bytes)╼ │ ╾──────╼╾──────╼
}
alloc854353 (Rust heap, size: 16, align: 8) {
    01 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 │ ................
}
alloc854401 (vtable: impl std::ops::Fn(error::Error) + std::marker::Send + std::marker::Sync for {closure@/tmp/cargo-target/miri/x86_64-unknown-linux-gnu/debug/build/spdlog-rs-c502dd30f0c9c7f4/out/test_utils/common_for_unit_test.rs:201:30: 201:35})
alloc854532 (Rust heap, size: 80, align: 8) {
    0x00 │ 01 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 │ ................
    0x10 │ 00 00 00 00 00 00 00 00 00 __ __ __ __ __ __ __ │ .........░░░░░░░
    0x20 │ 00 00 00 00 00 00 00 00 __ __ __ __ __ __ __ __ │ ........░░░░░░░░
    0x30 │ 00 00 00 00 00 00 00 00 ╾0x139b1e9[a854436]<2511046> (8 ptr bytes)╼ │ ........╾──────╼
    0x40 │ ╾0x139b4f0[a854470]<2510976> (8 ptr bytes)╼ 07 00 __ __ __ __ __ __ │ ╾──────╼..░░░░░░
}
alloc854580 (vtable: impl sink::Sink for log_macros::tests::kv_types::Asserter)
alloc854436 (Rust heap, size: 1, align: 1) {
    01                                              │ .
}
alloc854470 (vtable: impl formatter::Formatter for formatter::full_formatter::FullFormatter)

note: some details are omitted, run with `MIRIFLAGS=-Zmiri-backtrace=full` for a verbose backtrace

error: aborting due to 1 previous error; 5 warnings emitted

error: test failed, to rerun pass `-p spdlog-rs --lib`

@Lancern Given that this PR relates to safety, would you be willing to take a look?

@SpriteOvO SpriteOvO force-pushed the atomic-level-filter branch 3 times, most recently from 0741cb5 to ca57e28 Compare December 4, 2025 09:13
@SpriteOvO
Copy link
Owner Author

I have changed to use mem::transmute(AtomicLevelFilterInner) -> LevelFilter, since they should have the same layout and struct Inner contains no uninitialized bytes, this should be safe. This way we can avoid an extra discriminant enum and multiple match branches.

I'll run Miri later to see if there are any issues.

@SpriteOvO SpriteOvO force-pushed the atomic-level-filter branch 4 times, most recently from 15811c1 to ceb39bd Compare December 5, 2025 05:07
@SpriteOvO
Copy link
Owner Author

SpriteOvO commented Dec 5, 2025

In this PR we adds a repr(u16) to LevelFilter, refer to The Cargo Book - SemVer Compatibility, this change may not be considered as a breaking change, so we could include it in v0.5.2.

@SpriteOvO SpriteOvO force-pushed the atomic-level-filter branch from ceb39bd to 07d4747 Compare December 5, 2025 05:14
Copy link

@github-actions github-actions bot left a comment

Choose a reason for hiding this comment

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

⚠️ Performance Alert ⚠️

Possible performance regression was detected for benchmark 'spdlog-rs on Linux'.
Benchmark result of this commit is worse than the previous benchmark result exceeding threshold 2.

Benchmark suite Current: 1896486 Previous: 7c107c2 Ratio
bench_2_full_pattern_ct 428.9 ns/iter (± 10.42) 196.64 ns/iter (± 25.57) 2.18

This comment was automatically generated by workflow using github-action-benchmark.

CC: @SpriteOvO

@SpriteOvO
Copy link
Owner Author

⚠️ Performance Alert ⚠️

Possible performance regression was detected for benchmark 'spdlog-rs on Linux'. Benchmark result of this commit is worse than the previous benchmark result exceeding threshold 2.
Benchmark suite Current: 1896486 Previous: 7c107c2 Ratio
bench_2_full_pattern_ct 428.9 ns/iter (± 10.42) 196.64 ns/iter (± 25.57) 2.18

This comment was automatically generated by workflow using github-action-benchmark.

CC: @SpriteOvO

Should be false positive due to unstable CI VM environment.

@SpriteOvO SpriteOvO force-pushed the atomic-level-filter branch from 07d4747 to afd4805 Compare December 6, 2025 02:28
@SpriteOvO
Copy link
Owner Author

Renamed AtomicLevelFilterInner to LevelFilterLayout.


// Atomic

// This struct must have the same memory layout as `LevelFilter`.
Copy link
Collaborator

Choose a reason for hiding this comment

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

Could you explain the reason behind this constraint?

Copy link
Owner Author

@SpriteOvO SpriteOvO Dec 8, 2025

Choose a reason for hiding this comment

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

Because we are doing mem::transmute(LevelFilterLayout) -> LevelFilter in impl From<LevelFilterLayout> for LevelFilter, they must have the same layout to avoid undefined behavior.

Copy link
Collaborator

Choose a reason for hiding this comment

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

I still don't get why we have to use transmute to convert LevelFilterLayout to LevelFilter. Could we just do the conversion field-by-field, without invoking transmute?

Copy link
Owner Author

@SpriteOvO SpriteOvO Dec 8, 2025

Choose a reason for hiding this comment

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

Sure, just that way I'd be a bit concerned about the performance cost. Since it introduces match blocks, I'm not sure if the compiler will optimize them away.

I'll run a benchmark later and inspect the generated ASM to see if the compiler is smart enough. XD

Copy link
Collaborator

@Lancern Lancern Dec 8, 2025

Choose a reason for hiding this comment

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

I have faith in compiler optimizations. They should be really good at this sort of optimizations. But let's see the benchmark results first.

Copy link
Owner Author

Choose a reason for hiding this comment

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

Benchmarking commit: 4421785

running 4 tests
test safe_from_layout   ... bench:           1.07 ns/iter (+/- 0.01)
test safe_into_layout   ... bench:           0.71 ns/iter (+/- 0.01)
test unsafe_from_layout ... bench:           0.71 ns/iter (+/- 0.01)
test unsafe_into_layout ... bench:           1.07 ns/iter (+/- 0.01)

test result: ok. 0 passed; 0 failed; 0 ignored; 4 measured; 0 filtered out; finished in 1.22s

I inspected the generated ASM, it's just a very minor difference, likely because the unsafe version transmutes UNDEFINED_FALLBACK directly into the uninitialized bytes part of LevelFilter, while the safe version handles it separately.

Looks acceptable, though we'll need to write more code. I'll refactor this PR tomorrow to avoid unsafe code.

Copy link
Owner Author

Choose a reason for hiding this comment

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

Refactored to avoid unsafe code~ please review it again, thanks!

@SpriteOvO SpriteOvO force-pushed the atomic-level-filter branch from 4421785 to c5ef04a Compare December 9, 2025 18:09
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.

3 participants