Add tracing_chrome under "tracing" feature #4406

Stypox · 2025-06-18T15:39:24Z

Added a "tracing" feature that enables Chrome traces, and sets Machine::TRACING_ENABLED to true
I ended up adding the tracing_chrome crate by copy-pasting this ~600 line file.
- As discussed previously, depending on the tracing-chrome crate from crates.io is unfortunately not possible since it depends on tracing_core which conflicts with rustc_private's tracing_core (meaning it would not be possible to use the ChromeLayer in a context that expects a Layer from from rustc_private's tracing_core version).
- I tried to use cargo's [patch] and [replace] sections, but although they would work for normal libraries, they don't seem to behave as expected when the crate to replace comes from rustc_private, see this Zulip comment for a list of experiments
- Also see more dicussion in this Zulip thread
- I am open to trying other stuff to avoid copy-pasting foreign code into Miri, but I didn't want to waste more time on this right now, as it's blocking any work on tracing.
- Do I need to mention the author and license at the top of the copied file, or is a link (like I've done now) enough for attribution?
I moved the logger/tracing setup functions out of miri.rs so the file is less cluttered.
- Should I put those new files under trace/ (like done now) or should I rather move them under bin/, since only bin/miri.rs uses those functions?
The ChromeLayer internally starts a thread to write data to file, and thus relies on a guard to properly flush the file and terminate the thread when dropped. Since std::process::exit() was being called in a few places, I had to restructure the code a bit to avoid exiting directly (which wouldn't call drop() on the guard).
- As far as I understand rustc does not call exit(), but rather raises an unwinding panic which is then caught by rustc_driver::catch_fatal_errors(). After modifying run_compiler_then_exit to not exit directly, I could confirm that the tracing file was being flushed correctly in case of a compiler error by running RUSTC_LOG=1 ./miri run --features tracing FILE_WITH_SYNTAX_ERRORS.
- I moved the call to init_early_loggers() after argument parsing, is this ok? I did not see any log/trace call during argument parsing anyway. This avoids having to refactor show_error!() to not exit() directly

Stypox · 2025-06-19T11:56:27Z

I am not sure why tests fail, when I tried locally they failed even on the latest commit on master ( 2f4f9ac ). I did a git bisect and it told me that either ab135f0 or 42f66f4 are the first bad commit (the first one doesn't build, so I skipped it, while the second is the first where ./miri test failed). However this does not explain why the CI on 2f4f9ac passed.

tiif · 2025-06-19T12:27:01Z

I am on x86_64-unknown-linux-gnu, ./miri test for current master branch (2f4f9ac) passed locally for me.

May I know what os are you currently using? And is the failure the same as the one in the CI?

Stypox · 2025-06-19T14:15:52Z

@tiif On my PC the tests that fail run into errors like "error: unsupported operation: extern static __rust_no_alloc_shim_is_unstable is not supported by Miri". Even just running ./miri run tests/pass/hello.rs triggerrs the same error. But the CI exits with code 143 without printing any error (I'm looking at ubuntu-latest):

2025-06-19T10:55:01.6057618Z ##[error]The runner has received a shutdown signal. This can happen when the runner service is stopped, or a manually started runner is canceled.
2025-06-19T10:55:01.6062974Z ##[error]Process completed with exit code 143.
2025-06-19T10:55:01.6983400Z Cleaning up orphan processes

I am also on x86_64-unknown-linux-gnu, my OS is Manjaro Linux with kernel 5.15.182-1-MANJARO, I have a AMD Ryzen 7 5800H cpu, let me know if you need anything else.

tiif · 2025-06-19T15:06:56Z

I suspect the CI failure might be triggered by the change in this PR, as there were successful CI runs after this one in https://github.com/rust-lang/miri/actions. (I haven't read the code closely, so this is just a guess :)

About the unsupported error, I think maybe the toolchain is outdated. You can try to follow the steps here https://github.com/rust-lang/miri/blob/master/CONTRIBUTING.md#preparing-the-build-environment to update it if you haven't done so recently.

If the problem persists, feel free to ask for help in zulip.

The file was taken unmodified from the following link, except for file attributes at the top: https://github.com/thoren-d/tracing-chrome/blob/7e2625ab4aeeef2f0ef9bde9d6258dd181c04472/src/lib.rs Depending on the tracing-chrome crate from crates.io is unfortunately not possible since it depends on `tracing_core` which conflicts with rustc_private's `tracing_core` (meaning it would not be possible to use the [ChromeLayer] in a context that expects a [Layer] from from rustc_private's `tracing_core` version)

The tracing_chrome Layer has a connected Guard that needs to be dropped before exiting the process, or else data may not be flushed to the tracing file. This required making a few changes to main() to ensure std::process::exit() is not called without making sure to first drop the guard.

Stypox · 2025-06-25T10:15:23Z

The tests pass locally. I rebased on master and force pushed to make the CI rerun, but it still fails.

Both now and earlier, I think the cause for the CI failure was "memory allocation of 408 bytes failed" on windows-latest (see here and here). mac also fails due to "No space left on device (os error 28)" (see here). I don't understand why ubuntu fails with code 143 without printing any error.

I don't understand how changes in this PR can cause the tests to use more memory (assuming that's the culprit). The behavior of the code in this PR should be the same as before when no --tracing is passed.

Stypox

The build was failing because the ci/ci.sh script passed CARGO_EXTRA_FLAGS=--all-features and thus enabled the tracing feature, which caused every test to collect and save tracing information to file which filled up the worker filesystem leading to the errors above. Now I changed ci/ci.sh to only include the features relevant for tests, i.e. all but "tracing", i.e. genmc, stack-cache, stack-cache-consistency-check.

Stypox · 2025-06-25T14:57:47Z

ci/ci.sh


 # Determine configuration for installed build (used by test-cargo-miri and `./miri bench`).
 echo "Installing release version of Miri"
-time ./miri install
+time ./miri install "$FEATURES"


The change in this line changes the behavior of test-cargo-miri and ./miri bench down the line by enabling the genmc and stack-cache-consistency-check features which would otherwise be disabled by default. Since I couldn't find a comment explaining why those features are not being enabled here too, I made this change, but it's not really necessary. Is this ok or should I revert this change?

stack-cache-consistency-check makes things quite slow so it was deliberately not enabled here.

RalfJung · 2025-06-26T12:04:52Z

src/trace/tracing_chrome.rs

+//! Depending on the tracing-chrome crate from crates.io is unfortunately not possible, since it
+//! depends on `tracing_core` which conflicts with rustc_private's `tracing_core` (meaning it would
+//! not be possible to use the [ChromeLayer] in a context that expects a [Layer] from from
+//! rustc_private's `tracing_core` version).


Please explain the licensing situation to ensure we got that covered, too.

RalfJung · 2025-06-26T12:05:46Z

src/bin/miri.rs

@@ -63,6 +64,7 @@ struct MiriCompilerCalls {
    many_seeds: Option<ManySeedsConfig>,
    /// Settings for using GenMC with Miri.
    genmc_config: Option<GenmcConfig>,
+    tracing_guard: Option<TracingGuard>,


Why do we need a new field here and what does this do?

RalfJung · 2025-06-26T12:07:04Z

src/bin/miri.rs

@@ -211,6 +219,10 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
                if return_code != rustc_driver::EXIT_SUCCESS {
                    eprintln!("FAILING SEED: {seed}");
                    if !many_seeds.keep_going {
+                        // drop the tracing guard before exiting, so tracing calls are flushed correctly
+                        if let Ok(mut lock) = tracing_guard.try_lock() {
+                            let _guard_being_dropped = (*lock).take();


An explicit call to drop seems more clear here.

But it's not great tha we apparently have to remember to do this in multiple places...

RalfJung · 2025-06-26T12:07:13Z

src/bin/miri.rs

@@ -223,6 +235,9 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
            if num_failed > 0 {
                eprintln!("{num_failed}/{total} SEEDS FAILED", total = many_seeds.seeds.count());
            }
+            // drop the tracing guard before exiting, so tracing calls are flushed correctly
+            #[allow(clippy::drop_non_drop)]


You can probably avoid the lint by adding impl Drop for TracingGuard to make sure it is always a drop-type.

RalfJung · 2025-06-26T12:07:43Z

src/bin/miri.rs

+/// Does not call [std::process::exit] directly, but rather returns an [ExitCode],
+/// to allow the tracing guard to be dropped before exiting.


With those new semantics, the function name no longer makes sense.

RalfJung · 2025-06-26T12:13:45Z

src/trace/setup.rs

+        guard = Some(TracingGuard {
+            #[cfg(feature = "tracing")]
+            _chrome: chrome_guard,
+            _no_construct: (),
+        });


Why does this guard have toe be created here? This then causes all sorts of complexity since you can't know whether it gets created in early-init or late-init.

It seems better to just create the guard separately?

RalfJung · 2025-06-26T12:15:40Z

src/trace/setup.rs

I'm not convinced that this file should live here. That makes the responsibility sharing between the bin crate and the lib crate a lot more complicated.

Can this live as a separate file in the bin folder?

RalfJung · 2025-06-26T12:16:21Z

src/trace/setup.rs

+use tracing_subscriber::Registry;
+
+#[must_use]
+pub struct TracingGuard {


Please add a doc comment to this type.

RalfJung · 2025-06-26T12:16:54Z

src/trace/tracing_chrome.rs

@@ -0,0 +1,623 @@
+//! This file is taken unmodified from the following link, except for file attributes at the top:


And except for the extern crate I guess?

RalfJung · 2025-06-26T12:17:26Z

src/trace/tracing_chrome.rs

+// this is here and not in src/lib.rs since it is a direct dependency of tracing_chrome.rs and
+// should not be included if the "tracing" feature is disabled
+extern crate tracing_core;


Suggested change

// this is here and not in src/lib.rs since it is a direct dependency of tracing_chrome.rs and

// should not be included if the "tracing" feature is disabled

extern crate tracing_core;

// This is here and not in src/lib.rs since it is a direct dependency of tracing_chrome.rs and

// should not be included if the "tracing" feature is disabled.

extern crate tracing_core;

Stypox force-pushed the tracing branch 2 times, most recently from 16e2ce6 to d432b6b Compare June 19, 2025 10:31

Stypox marked this pull request as ready for review June 19, 2025 10:32

Stypox mentioned this pull request Jun 19, 2025

Add tracing in Miri for tcx.layout_of calls rust-lang/rust#142721

Draft

Stypox added 3 commits June 25, 2025 11:29

Add tracing feature

09752c7

Stypox force-pushed the tracing branch from d432b6b to 201c5c7 Compare June 25, 2025 09:30

Stypox force-pushed the tracing branch from 2f4d5f0 to 102bb96 Compare June 25, 2025 14:09

Only enable selected features when testing miri in CI

3b37e77

Stypox force-pushed the tracing branch from 102bb96 to 3b37e77 Compare June 25, 2025 14:26

Stypox commented Jun 25, 2025

View reviewed changes

Stypox mentioned this pull request Jun 26, 2025

Add tracing to validate_operand rust-lang/rust#143051

Draft

RalfJung reviewed Jun 26, 2025

View reviewed changes

		/// Does not call [std::process::exit] directly, but rather returns an [ExitCode],
		/// to allow the tracing guard to be dropped before exiting.

		@@ -0,0 +1,623 @@
		//! This file is taken unmodified from the following link, except for file attributes at the top:

Add tracing_chrome under "tracing" feature #4406

Are you sure you want to change the base?

Add tracing_chrome under "tracing" feature #4406

Uh oh!

Conversation

Stypox commented Jun 18, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Stypox commented Jun 19, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

tiif commented Jun 19, 2025

Uh oh!

Stypox commented Jun 19, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

tiif commented Jun 19, 2025

Uh oh!

Stypox commented Jun 25, 2025

Uh oh!

Stypox left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Stypox commented Jun 18, 2025 •

edited

Loading

Stypox commented Jun 19, 2025 •

edited

Loading

Stypox commented Jun 19, 2025 •

edited

Loading