Add tracing feature to enable tracing_chrome support
This commit is contained in:
parent
7f0dbba263
commit
28900b0ee2
9 changed files with 799 additions and 73 deletions
|
|
@ -158,6 +158,15 @@ compiler that has `debug=true` set in `bootstrap.toml`.
|
|||
You can set `MIRI_BACKTRACE=1` to get a backtrace of where an
|
||||
evaluation error was originally raised.
|
||||
|
||||
#### Tracing
|
||||
|
||||
You can generate a Chrome trace file from a Miri execution by passing `--features=tracing` during the
|
||||
build and then setting `MIRI_TRACING=1` when running Miri. This will generate a `.json` file that
|
||||
you can visualize in [Perfetto](https://ui.perfetto.dev/). For example:
|
||||
|
||||
```sh
|
||||
MIRI_TRACING=1 ./miri run --features=tracing tests/pass/hello.rs
|
||||
```
|
||||
|
||||
### UI testing
|
||||
|
||||
|
|
|
|||
|
|
@ -627,6 +627,7 @@ dependencies = [
|
|||
"regex",
|
||||
"rustc_version",
|
||||
"serde",
|
||||
"serde_json",
|
||||
"smallvec",
|
||||
"tempfile",
|
||||
"tikv-jemalloc-sys",
|
||||
|
|
|
|||
|
|
@ -27,6 +27,7 @@ chrono = { version = "0.4.38", default-features = false }
|
|||
chrono-tz = "0.10"
|
||||
directories = "6"
|
||||
bitflags = "2.6"
|
||||
serde_json = { version = "1.0", optional = true }
|
||||
|
||||
# Copied from `compiler/rustc/Cargo.toml`.
|
||||
# But only for some targets, it fails for others. Rustc configures this in its CI, but we can't
|
||||
|
|
@ -67,6 +68,7 @@ default = ["stack-cache"]
|
|||
genmc = []
|
||||
stack-cache = []
|
||||
stack-cache-consistency-check = ["stack-cache"]
|
||||
tracing = ["serde_json"]
|
||||
|
||||
[lints.rust.unexpected_cfgs]
|
||||
level = "warn"
|
||||
|
|
|
|||
|
|
@ -8,3 +8,8 @@ imports_granularity = "Module"
|
|||
force_multiline_blocks = true
|
||||
match_arm_blocks = false
|
||||
match_arm_leading_pipes = "Preserve"
|
||||
|
||||
ignore = [
|
||||
# This file is copy-pasted from the tracing_chrome crate and should remain like the original.
|
||||
"src/bin/log/tracing_chrome.rs"
|
||||
]
|
||||
|
|
|
|||
2
src/tools/miri/src/bin/log/mod.rs
Normal file
2
src/tools/miri/src/bin/log/mod.rs
Normal file
|
|
@ -0,0 +1,2 @@
|
|||
pub mod setup;
|
||||
mod tracing_chrome;
|
||||
126
src/tools/miri/src/bin/log/setup.rs
Normal file
126
src/tools/miri/src/bin/log/setup.rs
Normal file
|
|
@ -0,0 +1,126 @@
|
|||
use std::env::{self, VarError};
|
||||
use std::str::FromStr;
|
||||
use std::sync::{Mutex, OnceLock};
|
||||
|
||||
use rustc_middle::ty::TyCtxt;
|
||||
use rustc_session::{CtfeBacktrace, EarlyDiagCtxt};
|
||||
|
||||
/// The tracing layer from `tracing-chrome` starts a thread in the background that saves data to
|
||||
/// file and closes the file when stopped. If the thread is not stopped properly, the file will be
|
||||
/// missing end terminators (`]` for JSON arrays) and other data may also not be flushed. Therefore
|
||||
/// we need to keep a guard that, when [Drop]ped, will send a signal to stop the thread. Make sure
|
||||
/// to manually drop this guard using [deinit_loggers], if you are exiting the program with
|
||||
/// [std::process::exit]!
|
||||
#[must_use]
|
||||
struct TracingGuard {
|
||||
#[cfg(feature = "tracing")]
|
||||
_chrome: super::tracing_chrome::FlushGuard,
|
||||
_no_construct: (),
|
||||
}
|
||||
|
||||
// This ensures TracingGuard is always a drop-type, even when the `_chrome` field is disabled.
|
||||
impl Drop for TracingGuard {
|
||||
fn drop(&mut self) {}
|
||||
}
|
||||
|
||||
fn rustc_logger_config() -> rustc_log::LoggerConfig {
|
||||
// Start with the usual env vars.
|
||||
let mut cfg = rustc_log::LoggerConfig::from_env("RUSTC_LOG");
|
||||
|
||||
// Overwrite if MIRI_LOG is set.
|
||||
if let Ok(var) = env::var("MIRI_LOG") {
|
||||
// MIRI_LOG serves as default for RUSTC_LOG, if that is not set.
|
||||
if matches!(cfg.filter, Err(VarError::NotPresent)) {
|
||||
// We try to be a bit clever here: if `MIRI_LOG` is just a single level
|
||||
// used for everything, we only apply it to the parts of rustc that are
|
||||
// CTFE-related. Otherwise, we use it verbatim for `RUSTC_LOG`.
|
||||
// This way, if you set `MIRI_LOG=trace`, you get only the right parts of
|
||||
// rustc traced, but you can also do `MIRI_LOG=miri=trace,rustc_const_eval::interpret=debug`.
|
||||
if tracing::Level::from_str(&var).is_ok() {
|
||||
cfg.filter = Ok(format!(
|
||||
"rustc_middle::mir::interpret={var},rustc_const_eval::interpret={var},miri={var}"
|
||||
));
|
||||
} else {
|
||||
cfg.filter = Ok(var);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
cfg
|
||||
}
|
||||
|
||||
/// The global logger can only be set once per process, so track whether that already happened and
|
||||
/// keep a [TracingGuard] so it can be [Drop]ped later using [deinit_loggers].
|
||||
static LOGGER_INITED: OnceLock<Mutex<Option<TracingGuard>>> = OnceLock::new();
|
||||
|
||||
fn init_logger_once(early_dcx: &EarlyDiagCtxt) {
|
||||
// If the logger is not yet initialized, initialize it.
|
||||
LOGGER_INITED.get_or_init(|| {
|
||||
let guard = if env::var_os("MIRI_TRACING").is_some() {
|
||||
#[cfg(not(feature = "tracing"))]
|
||||
{
|
||||
crate::show_error!(
|
||||
"fatal error: cannot enable MIRI_TRACING since Miri was not built with the \"tracing\" feature"
|
||||
);
|
||||
}
|
||||
|
||||
#[cfg(feature = "tracing")]
|
||||
{
|
||||
let (chrome_layer, chrome_guard) =
|
||||
super::tracing_chrome::ChromeLayerBuilder::new().include_args(true).build();
|
||||
rustc_driver::init_logger_with_additional_layer(
|
||||
early_dcx,
|
||||
rustc_logger_config(),
|
||||
|| {
|
||||
tracing_subscriber::layer::SubscriberExt::with(
|
||||
tracing_subscriber::Registry::default(),
|
||||
chrome_layer,
|
||||
)
|
||||
},
|
||||
);
|
||||
|
||||
Some(TracingGuard { _chrome: chrome_guard, _no_construct: () })
|
||||
}
|
||||
} else {
|
||||
// initialize the logger without any tracing enabled
|
||||
rustc_driver::init_logger(early_dcx, rustc_logger_config());
|
||||
None
|
||||
};
|
||||
Mutex::new(guard)
|
||||
});
|
||||
}
|
||||
|
||||
pub fn init_early_loggers(early_dcx: &EarlyDiagCtxt) {
|
||||
// We only initialize `rustc` if the env var is set (so the user asked for it).
|
||||
// If it is not set, we avoid initializing now so that we can initialize later with our custom
|
||||
// settings, and *not* log anything for what happens before `miri` starts interpreting.
|
||||
if env::var_os("RUSTC_LOG").is_some() {
|
||||
init_logger_once(early_dcx);
|
||||
}
|
||||
}
|
||||
|
||||
pub fn init_late_loggers(early_dcx: &EarlyDiagCtxt, tcx: TyCtxt<'_>) {
|
||||
// If the logger is not yet initialized, initialize it.
|
||||
init_logger_once(early_dcx);
|
||||
|
||||
// If `MIRI_BACKTRACE` is set and `RUSTC_CTFE_BACKTRACE` is not, set `RUSTC_CTFE_BACKTRACE`.
|
||||
// Do this late, so we ideally only apply this to Miri's errors.
|
||||
if let Some(val) = env::var_os("MIRI_BACKTRACE") {
|
||||
let ctfe_backtrace = match &*val.to_string_lossy() {
|
||||
"immediate" => CtfeBacktrace::Immediate,
|
||||
"0" => CtfeBacktrace::Disabled,
|
||||
_ => CtfeBacktrace::Capture,
|
||||
};
|
||||
*tcx.sess.ctfe_backtrace.borrow_mut() = ctfe_backtrace;
|
||||
}
|
||||
}
|
||||
|
||||
/// Must be called before the program terminates to ensure the trace file is closed correctly. Not
|
||||
/// doing so will result in invalid trace files. Also see [TracingGuard].
|
||||
pub fn deinit_loggers() {
|
||||
if let Some(guard) = LOGGER_INITED.get()
|
||||
&& let Ok(mut guard) = guard.lock()
|
||||
{
|
||||
std::mem::drop(guard.take());
|
||||
}
|
||||
}
|
||||
625
src/tools/miri/src/bin/log/tracing_chrome.rs
Normal file
625
src/tools/miri/src/bin/log/tracing_chrome.rs
Normal file
|
|
@ -0,0 +1,625 @@
|
|||
// SPDX-License-Identifier: MIT
|
||||
// SPDX-FileCopyrightText: Copyright (c) 2020 Thoren Paulson
|
||||
//! This file is taken unmodified from the following link, except for file attributes and
|
||||
//! `extern crate` 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
|
||||
//! rustc_private's `tracing_core` version).
|
||||
#![allow(warnings)]
|
||||
#![cfg(feature = "tracing")]
|
||||
|
||||
// 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;
|
||||
|
||||
use tracing_core::{field::Field, span, Event, Subscriber};
|
||||
use tracing_subscriber::{
|
||||
layer::Context,
|
||||
registry::{LookupSpan, SpanRef},
|
||||
Layer,
|
||||
};
|
||||
|
||||
use serde_json::{json, Value as JsonValue};
|
||||
use std::{
|
||||
marker::PhantomData,
|
||||
path::Path,
|
||||
sync::{
|
||||
atomic::{AtomicUsize, Ordering},
|
||||
Arc, Mutex,
|
||||
},
|
||||
};
|
||||
|
||||
use std::io::{BufWriter, Write};
|
||||
use std::sync::mpsc;
|
||||
use std::sync::mpsc::Sender;
|
||||
use std::{
|
||||
cell::{Cell, RefCell},
|
||||
thread::JoinHandle,
|
||||
};
|
||||
|
||||
thread_local! {
|
||||
static OUT: RefCell<Option<Sender<Message>>> = const { RefCell::new(None) };
|
||||
static TID: RefCell<Option<usize>> = const { RefCell::new(None) };
|
||||
}
|
||||
|
||||
type NameFn<S> = Box<dyn Fn(&EventOrSpan<'_, '_, S>) -> String + Send + Sync>;
|
||||
type Object = serde_json::Map<String, JsonValue>;
|
||||
|
||||
/// A [`Layer`](tracing_subscriber::Layer) that writes a Chrome trace file.
|
||||
pub struct ChromeLayer<S>
|
||||
where
|
||||
S: Subscriber + for<'span> LookupSpan<'span> + Send + Sync,
|
||||
{
|
||||
out: Arc<Mutex<Sender<Message>>>,
|
||||
start: std::time::Instant,
|
||||
max_tid: AtomicUsize,
|
||||
include_args: bool,
|
||||
include_locations: bool,
|
||||
trace_style: TraceStyle,
|
||||
name_fn: Option<NameFn<S>>,
|
||||
cat_fn: Option<NameFn<S>>,
|
||||
_inner: PhantomData<S>,
|
||||
}
|
||||
|
||||
/// A builder for [`ChromeLayer`](crate::ChromeLayer).
|
||||
#[derive(Default)]
|
||||
pub struct ChromeLayerBuilder<S>
|
||||
where
|
||||
S: Subscriber + for<'span> LookupSpan<'span> + Send + Sync,
|
||||
{
|
||||
out_writer: Option<Box<dyn Write + Send>>,
|
||||
name_fn: Option<NameFn<S>>,
|
||||
cat_fn: Option<NameFn<S>>,
|
||||
include_args: bool,
|
||||
include_locations: bool,
|
||||
trace_style: TraceStyle,
|
||||
_inner: PhantomData<S>,
|
||||
}
|
||||
|
||||
/// Decides how traces will be recorded.
|
||||
#[derive(Default)]
|
||||
pub enum TraceStyle {
|
||||
/// Traces will be recorded as a group of threads.
|
||||
/// In this style, spans should be entered and exited on the same thread.
|
||||
#[default]
|
||||
Threaded,
|
||||
|
||||
/// Traces will recorded as a group of asynchronous operations.
|
||||
Async,
|
||||
}
|
||||
|
||||
impl<S> ChromeLayerBuilder<S>
|
||||
where
|
||||
S: Subscriber + for<'span> LookupSpan<'span> + Send + Sync,
|
||||
{
|
||||
pub fn new() -> Self {
|
||||
ChromeLayerBuilder {
|
||||
out_writer: None,
|
||||
name_fn: None,
|
||||
cat_fn: None,
|
||||
include_args: false,
|
||||
include_locations: true,
|
||||
trace_style: TraceStyle::Threaded,
|
||||
_inner: PhantomData,
|
||||
}
|
||||
}
|
||||
|
||||
/// Set the file to which to output the trace.
|
||||
///
|
||||
/// Defaults to `./trace-{unix epoch in micros}.json`.
|
||||
///
|
||||
/// # Panics
|
||||
///
|
||||
/// If `file` could not be opened/created. To handle errors,
|
||||
/// open a file and pass it to [`writer`](crate::ChromeLayerBuilder::writer) instead.
|
||||
pub fn file<P: AsRef<Path>>(self, file: P) -> Self {
|
||||
self.writer(std::fs::File::create(file).expect("Failed to create trace file."))
|
||||
}
|
||||
|
||||
/// Supply an arbitrary writer to which to write trace contents.
|
||||
///
|
||||
/// # Examples
|
||||
///
|
||||
/// ```rust
|
||||
/// # use tracing_chrome::ChromeLayerBuilder;
|
||||
/// # use tracing_subscriber::prelude::*;
|
||||
/// let (layer, guard) = ChromeLayerBuilder::new().writer(std::io::sink()).build();
|
||||
/// # tracing_subscriber::registry().with(layer).init();
|
||||
/// ```
|
||||
pub fn writer<W: Write + Send + 'static>(mut self, writer: W) -> Self {
|
||||
self.out_writer = Some(Box::new(writer));
|
||||
self
|
||||
}
|
||||
|
||||
/// Include arguments in each trace entry.
|
||||
///
|
||||
/// Defaults to `false`.
|
||||
///
|
||||
/// Includes the arguments used when creating a span/event
|
||||
/// in the "args" section of the trace entry.
|
||||
pub fn include_args(mut self, include: bool) -> Self {
|
||||
self.include_args = include;
|
||||
self
|
||||
}
|
||||
|
||||
/// Include file+line with each trace entry.
|
||||
///
|
||||
/// Defaults to `true`.
|
||||
///
|
||||
/// This can add quite a bit of data to the output so turning
|
||||
/// it off might be helpful when collecting larger traces.
|
||||
pub fn include_locations(mut self, include: bool) -> Self {
|
||||
self.include_locations = include;
|
||||
self
|
||||
}
|
||||
|
||||
/// Sets the style used when recording trace events.
|
||||
///
|
||||
/// See [`TraceStyle`](crate::TraceStyle) for details.
|
||||
pub fn trace_style(mut self, style: TraceStyle) -> Self {
|
||||
self.trace_style = style;
|
||||
self
|
||||
}
|
||||
|
||||
/// Allows supplying a function that derives a name from
|
||||
/// an Event or Span. The result is used as the "name" field
|
||||
/// on trace entries.
|
||||
///
|
||||
/// # Example
|
||||
/// ```
|
||||
/// use tracing_chrome::{ChromeLayerBuilder, EventOrSpan};
|
||||
/// use tracing_subscriber::{registry::Registry, prelude::*};
|
||||
///
|
||||
/// let (chrome_layer, _guard) = ChromeLayerBuilder::new().name_fn(Box::new(|event_or_span| {
|
||||
/// match event_or_span {
|
||||
/// EventOrSpan::Event(ev) => { ev.metadata().name().into() },
|
||||
/// EventOrSpan::Span(_s) => { "span".into() },
|
||||
/// }
|
||||
/// })).build();
|
||||
/// tracing_subscriber::registry().with(chrome_layer).init()
|
||||
/// ```
|
||||
pub fn name_fn(mut self, name_fn: NameFn<S>) -> Self {
|
||||
self.name_fn = Some(name_fn);
|
||||
self
|
||||
}
|
||||
|
||||
/// Allows supplying a function that derives a category from
|
||||
/// an Event or Span. The result is used as the "cat" field on
|
||||
/// trace entries.
|
||||
///
|
||||
/// # Example
|
||||
/// ```
|
||||
/// use tracing_chrome::{ChromeLayerBuilder, EventOrSpan};
|
||||
/// use tracing_subscriber::{registry::Registry, prelude::*};
|
||||
///
|
||||
/// let (chrome_layer, _guard) = ChromeLayerBuilder::new().category_fn(Box::new(|_| {
|
||||
/// "my_module".into()
|
||||
/// })).build();
|
||||
/// tracing_subscriber::registry().with(chrome_layer).init()
|
||||
/// ```
|
||||
pub fn category_fn(mut self, cat_fn: NameFn<S>) -> Self {
|
||||
self.cat_fn = Some(cat_fn);
|
||||
self
|
||||
}
|
||||
|
||||
/// Creates a [`ChromeLayer`](crate::ChromeLayer) and associated [`FlushGuard`](crate::FlushGuard).
|
||||
///
|
||||
/// # Panics
|
||||
///
|
||||
/// If no file or writer was specified and the default trace file could not be opened/created.
|
||||
pub fn build(self) -> (ChromeLayer<S>, FlushGuard) {
|
||||
ChromeLayer::new(self)
|
||||
}
|
||||
}
|
||||
|
||||
/// This guard will signal the thread writing the trace file to stop and join it when dropped.
|
||||
pub struct FlushGuard {
|
||||
sender: Sender<Message>,
|
||||
handle: Cell<Option<JoinHandle<()>>>,
|
||||
}
|
||||
|
||||
impl FlushGuard {
|
||||
/// Signals the trace writing thread to flush to disk.
|
||||
pub fn flush(&self) {
|
||||
if let Some(handle) = self.handle.take() {
|
||||
let _ignored = self.sender.send(Message::Flush);
|
||||
self.handle.set(Some(handle));
|
||||
}
|
||||
}
|
||||
|
||||
/// Finishes the current trace and starts a new one.
|
||||
///
|
||||
/// If a [`Write`](std::io::Write) implementation is supplied,
|
||||
/// the new trace is written to it. Otherwise, the new trace
|
||||
/// goes to `./trace-{unix epoc in micros}.json`.
|
||||
pub fn start_new(&self, writer: Option<Box<dyn Write + Send>>) {
|
||||
if let Some(handle) = self.handle.take() {
|
||||
let _ignored = self.sender.send(Message::StartNew(writer));
|
||||
self.handle.set(Some(handle));
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
impl Drop for FlushGuard {
|
||||
fn drop(&mut self) {
|
||||
if let Some(handle) = self.handle.take() {
|
||||
let _ignored = self.sender.send(Message::Drop);
|
||||
if handle.join().is_err() {
|
||||
eprintln!("tracing_chrome: Trace writing thread panicked.");
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
struct Callsite {
|
||||
tid: usize,
|
||||
name: String,
|
||||
target: String,
|
||||
file: Option<&'static str>,
|
||||
line: Option<u32>,
|
||||
args: Option<Arc<Object>>,
|
||||
}
|
||||
|
||||
enum Message {
|
||||
Enter(f64, Callsite, Option<u64>),
|
||||
Event(f64, Callsite),
|
||||
Exit(f64, Callsite, Option<u64>),
|
||||
NewThread(usize, String),
|
||||
Flush,
|
||||
Drop,
|
||||
StartNew(Option<Box<dyn Write + Send>>),
|
||||
}
|
||||
|
||||
/// Represents either an [`Event`](tracing_core::Event) or [`SpanRef`](tracing_subscriber::registry::SpanRef).
|
||||
pub enum EventOrSpan<'a, 'b, S>
|
||||
where
|
||||
S: Subscriber + for<'span> LookupSpan<'span> + Send + Sync,
|
||||
{
|
||||
Event(&'a Event<'b>),
|
||||
Span(&'a SpanRef<'b, S>),
|
||||
}
|
||||
|
||||
fn create_default_writer() -> Box<dyn Write + Send> {
|
||||
Box::new(
|
||||
std::fs::File::create(format!(
|
||||
"./trace-{}.json",
|
||||
std::time::SystemTime::UNIX_EPOCH
|
||||
.elapsed()
|
||||
.unwrap()
|
||||
.as_micros()
|
||||
))
|
||||
.expect("Failed to create trace file."),
|
||||
)
|
||||
}
|
||||
|
||||
impl<S> ChromeLayer<S>
|
||||
where
|
||||
S: Subscriber + for<'span> LookupSpan<'span> + Send + Sync,
|
||||
{
|
||||
fn new(mut builder: ChromeLayerBuilder<S>) -> (ChromeLayer<S>, FlushGuard) {
|
||||
let (tx, rx) = mpsc::channel();
|
||||
OUT.with(|val| val.replace(Some(tx.clone())));
|
||||
|
||||
let out_writer = builder
|
||||
.out_writer
|
||||
.unwrap_or_else(|| create_default_writer());
|
||||
|
||||
let handle = std::thread::spawn(move || {
|
||||
let mut write = BufWriter::new(out_writer);
|
||||
write.write_all(b"[\n").unwrap();
|
||||
|
||||
let mut has_started = false;
|
||||
let mut thread_names: Vec<(usize, String)> = Vec::new();
|
||||
for msg in rx {
|
||||
if let Message::Flush = &msg {
|
||||
write.flush().unwrap();
|
||||
continue;
|
||||
} else if let Message::Drop = &msg {
|
||||
break;
|
||||
} else if let Message::StartNew(writer) = msg {
|
||||
// Finish off current file
|
||||
write.write_all(b"\n]").unwrap();
|
||||
write.flush().unwrap();
|
||||
|
||||
// Get or create new writer
|
||||
let out_writer = writer.unwrap_or_else(|| create_default_writer());
|
||||
write = BufWriter::new(out_writer);
|
||||
write.write_all(b"[\n").unwrap();
|
||||
has_started = false;
|
||||
|
||||
// Write saved thread names
|
||||
for (tid, name) in thread_names.iter() {
|
||||
let entry = json!({
|
||||
"ph": "M",
|
||||
"pid": 1,
|
||||
"name": "thread_name",
|
||||
"tid": *tid,
|
||||
"args": {
|
||||
"name": name,
|
||||
},
|
||||
});
|
||||
|
||||
if has_started {
|
||||
write.write_all(b",\n").unwrap();
|
||||
}
|
||||
serde_json::to_writer(&mut write, &entry).unwrap();
|
||||
has_started = true;
|
||||
}
|
||||
continue;
|
||||
}
|
||||
|
||||
let (ph, ts, callsite, id) = match &msg {
|
||||
Message::Enter(ts, callsite, None) => ("B", Some(ts), Some(callsite), None),
|
||||
Message::Enter(ts, callsite, Some(root_id)) => {
|
||||
("b", Some(ts), Some(callsite), Some(root_id))
|
||||
}
|
||||
Message::Event(ts, callsite) => ("i", Some(ts), Some(callsite), None),
|
||||
Message::Exit(ts, callsite, None) => ("E", Some(ts), Some(callsite), None),
|
||||
Message::Exit(ts, callsite, Some(root_id)) => {
|
||||
("e", Some(ts), Some(callsite), Some(root_id))
|
||||
}
|
||||
Message::NewThread(_tid, _name) => ("M", None, None, None),
|
||||
Message::Flush | Message::Drop | Message::StartNew(_) => {
|
||||
panic!("Was supposed to break by now.")
|
||||
}
|
||||
};
|
||||
let mut entry = json!({
|
||||
"ph": ph,
|
||||
"pid": 1,
|
||||
});
|
||||
|
||||
if let Message::NewThread(tid, name) = msg {
|
||||
thread_names.push((tid, name.clone()));
|
||||
entry["name"] = "thread_name".into();
|
||||
entry["tid"] = tid.into();
|
||||
entry["args"] = json!({ "name": name });
|
||||
} else {
|
||||
let ts = ts.unwrap();
|
||||
let callsite = callsite.unwrap();
|
||||
entry["ts"] = (*ts).into();
|
||||
entry["name"] = callsite.name.clone().into();
|
||||
entry["cat"] = callsite.target.clone().into();
|
||||
entry["tid"] = callsite.tid.into();
|
||||
|
||||
if let Some(&id) = id {
|
||||
entry["id"] = id.into();
|
||||
}
|
||||
|
||||
if ph == "i" {
|
||||
entry["s"] = "t".into();
|
||||
}
|
||||
|
||||
if let (Some(file), Some(line)) = (callsite.file, callsite.line) {
|
||||
entry[".file"] = file.into();
|
||||
entry[".line"] = line.into();
|
||||
}
|
||||
|
||||
if let Some(call_args) = &callsite.args {
|
||||
if !call_args.is_empty() {
|
||||
entry["args"] = (**call_args).clone().into();
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
if has_started {
|
||||
write.write_all(b",\n").unwrap();
|
||||
}
|
||||
serde_json::to_writer(&mut write, &entry).unwrap();
|
||||
has_started = true;
|
||||
}
|
||||
|
||||
write.write_all(b"\n]").unwrap();
|
||||
write.flush().unwrap();
|
||||
});
|
||||
|
||||
let guard = FlushGuard {
|
||||
sender: tx.clone(),
|
||||
handle: Cell::new(Some(handle)),
|
||||
};
|
||||
let layer = ChromeLayer {
|
||||
out: Arc::new(Mutex::new(tx)),
|
||||
start: std::time::Instant::now(),
|
||||
max_tid: AtomicUsize::new(0),
|
||||
name_fn: builder.name_fn.take(),
|
||||
cat_fn: builder.cat_fn.take(),
|
||||
include_args: builder.include_args,
|
||||
include_locations: builder.include_locations,
|
||||
trace_style: builder.trace_style,
|
||||
_inner: PhantomData,
|
||||
};
|
||||
|
||||
(layer, guard)
|
||||
}
|
||||
|
||||
fn get_tid(&self) -> (usize, bool) {
|
||||
TID.with(|value| {
|
||||
let tid = *value.borrow();
|
||||
match tid {
|
||||
Some(tid) => (tid, false),
|
||||
None => {
|
||||
let tid = self.max_tid.fetch_add(1, Ordering::SeqCst);
|
||||
value.replace(Some(tid));
|
||||
(tid, true)
|
||||
}
|
||||
}
|
||||
})
|
||||
}
|
||||
|
||||
fn get_callsite(&self, data: EventOrSpan<S>) -> Callsite {
|
||||
let (tid, new_thread) = self.get_tid();
|
||||
let name = self.name_fn.as_ref().map(|name_fn| name_fn(&data));
|
||||
let target = self.cat_fn.as_ref().map(|cat_fn| cat_fn(&data));
|
||||
let meta = match data {
|
||||
EventOrSpan::Event(e) => e.metadata(),
|
||||
EventOrSpan::Span(s) => s.metadata(),
|
||||
};
|
||||
let args = match data {
|
||||
EventOrSpan::Event(e) => {
|
||||
if self.include_args {
|
||||
let mut args = Object::new();
|
||||
e.record(&mut JsonVisitor { object: &mut args });
|
||||
Some(Arc::new(args))
|
||||
} else {
|
||||
None
|
||||
}
|
||||
}
|
||||
EventOrSpan::Span(s) => s
|
||||
.extensions()
|
||||
.get::<ArgsWrapper>()
|
||||
.map(|e| &e.args)
|
||||
.cloned(),
|
||||
};
|
||||
let name = name.unwrap_or_else(|| meta.name().into());
|
||||
let target = target.unwrap_or_else(|| meta.target().into());
|
||||
let (file, line) = if self.include_locations {
|
||||
(meta.file(), meta.line())
|
||||
} else {
|
||||
(None, None)
|
||||
};
|
||||
|
||||
if new_thread {
|
||||
let name = match std::thread::current().name() {
|
||||
Some(name) => name.to_owned(),
|
||||
None => tid.to_string(),
|
||||
};
|
||||
self.send_message(Message::NewThread(tid, name));
|
||||
}
|
||||
|
||||
Callsite {
|
||||
tid,
|
||||
name,
|
||||
target,
|
||||
file,
|
||||
line,
|
||||
args,
|
||||
}
|
||||
}
|
||||
|
||||
fn get_root_id(span: SpanRef<S>) -> u64 {
|
||||
span.scope()
|
||||
.from_root()
|
||||
.take(1)
|
||||
.next()
|
||||
.unwrap_or(span)
|
||||
.id()
|
||||
.into_u64()
|
||||
}
|
||||
|
||||
fn enter_span(&self, span: SpanRef<S>, ts: f64) {
|
||||
let callsite = self.get_callsite(EventOrSpan::Span(&span));
|
||||
let root_id = match self.trace_style {
|
||||
TraceStyle::Async => Some(ChromeLayer::get_root_id(span)),
|
||||
_ => None,
|
||||
};
|
||||
self.send_message(Message::Enter(ts, callsite, root_id));
|
||||
}
|
||||
|
||||
fn exit_span(&self, span: SpanRef<S>, ts: f64) {
|
||||
let callsite = self.get_callsite(EventOrSpan::Span(&span));
|
||||
let root_id = match self.trace_style {
|
||||
TraceStyle::Async => Some(ChromeLayer::get_root_id(span)),
|
||||
_ => None,
|
||||
};
|
||||
self.send_message(Message::Exit(ts, callsite, root_id));
|
||||
}
|
||||
|
||||
fn get_ts(&self) -> f64 {
|
||||
self.start.elapsed().as_nanos() as f64 / 1000.0
|
||||
}
|
||||
|
||||
fn send_message(&self, message: Message) {
|
||||
OUT.with(move |val| {
|
||||
if val.borrow().is_some() {
|
||||
let _ignored = val.borrow().as_ref().unwrap().send(message);
|
||||
} else {
|
||||
let out = self.out.lock().unwrap().clone();
|
||||
let _ignored = out.send(message);
|
||||
val.replace(Some(out));
|
||||
}
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
impl<S> Layer<S> for ChromeLayer<S>
|
||||
where
|
||||
S: Subscriber + for<'span> LookupSpan<'span> + Send + Sync,
|
||||
{
|
||||
fn on_enter(&self, id: &span::Id, ctx: Context<'_, S>) {
|
||||
if let TraceStyle::Async = self.trace_style {
|
||||
return;
|
||||
}
|
||||
|
||||
let ts = self.get_ts();
|
||||
self.enter_span(ctx.span(id).expect("Span not found."), ts);
|
||||
}
|
||||
|
||||
fn on_record(&self, id: &span::Id, values: &span::Record<'_>, ctx: Context<'_, S>) {
|
||||
if self.include_args {
|
||||
let span = ctx.span(id).unwrap();
|
||||
let mut exts = span.extensions_mut();
|
||||
|
||||
let args = exts.get_mut::<ArgsWrapper>();
|
||||
|
||||
if let Some(args) = args {
|
||||
let args = Arc::make_mut(&mut args.args);
|
||||
values.record(&mut JsonVisitor { object: args });
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
|
||||
let ts = self.get_ts();
|
||||
let callsite = self.get_callsite(EventOrSpan::Event(event));
|
||||
self.send_message(Message::Event(ts, callsite));
|
||||
}
|
||||
|
||||
fn on_exit(&self, id: &span::Id, ctx: Context<'_, S>) {
|
||||
if let TraceStyle::Async = self.trace_style {
|
||||
return;
|
||||
}
|
||||
let ts = self.get_ts();
|
||||
self.exit_span(ctx.span(id).expect("Span not found."), ts);
|
||||
}
|
||||
|
||||
fn on_new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, ctx: Context<'_, S>) {
|
||||
if self.include_args {
|
||||
let mut args = Object::new();
|
||||
attrs.record(&mut JsonVisitor { object: &mut args });
|
||||
ctx.span(id).unwrap().extensions_mut().insert(ArgsWrapper {
|
||||
args: Arc::new(args),
|
||||
});
|
||||
}
|
||||
if let TraceStyle::Threaded = self.trace_style {
|
||||
return;
|
||||
}
|
||||
|
||||
let ts = self.get_ts();
|
||||
self.enter_span(ctx.span(id).expect("Span not found."), ts);
|
||||
}
|
||||
|
||||
fn on_close(&self, id: span::Id, ctx: Context<'_, S>) {
|
||||
if let TraceStyle::Threaded = self.trace_style {
|
||||
return;
|
||||
}
|
||||
|
||||
let ts = self.get_ts();
|
||||
self.exit_span(ctx.span(&id).expect("Span not found."), ts);
|
||||
}
|
||||
}
|
||||
|
||||
struct JsonVisitor<'a> {
|
||||
object: &'a mut Object,
|
||||
}
|
||||
|
||||
impl<'a> tracing_subscriber::field::Visit for JsonVisitor<'a> {
|
||||
fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
|
||||
self.object
|
||||
.insert(field.name().to_owned(), format!("{value:?}").into());
|
||||
}
|
||||
}
|
||||
|
||||
struct ArgsWrapper {
|
||||
args: Arc<Object>,
|
||||
}
|
||||
|
|
@ -10,6 +10,8 @@
|
|||
|
||||
// Some "regular" crates we want to share with rustc
|
||||
extern crate tracing;
|
||||
#[cfg(feature = "tracing")]
|
||||
extern crate tracing_subscriber;
|
||||
|
||||
// The rustc crates we need
|
||||
extern crate rustc_abi;
|
||||
|
|
@ -24,14 +26,16 @@ extern crate rustc_middle;
|
|||
extern crate rustc_session;
|
||||
extern crate rustc_span;
|
||||
|
||||
use std::env::{self, VarError};
|
||||
mod log;
|
||||
|
||||
use std::env;
|
||||
use std::num::NonZero;
|
||||
use std::ops::Range;
|
||||
use std::path::PathBuf;
|
||||
use std::rc::Rc;
|
||||
use std::str::FromStr;
|
||||
use std::sync::Arc;
|
||||
use std::sync::atomic::{AtomicI32, AtomicU32, Ordering};
|
||||
use std::sync::{Arc, Once};
|
||||
|
||||
use miri::{
|
||||
BacktraceStyle, BorrowTrackerMethod, GenmcConfig, GenmcCtx, MiriConfig, MiriEntryFnType,
|
||||
|
|
@ -52,12 +56,14 @@ use rustc_middle::query::LocalCrate;
|
|||
use rustc_middle::traits::{ObligationCause, ObligationCauseCode};
|
||||
use rustc_middle::ty::{self, Ty, TyCtxt};
|
||||
use rustc_middle::util::Providers;
|
||||
use rustc_session::EarlyDiagCtxt;
|
||||
use rustc_session::config::{CrateType, ErrorOutputType, OptLevel};
|
||||
use rustc_session::search_paths::PathKind;
|
||||
use rustc_session::{CtfeBacktrace, EarlyDiagCtxt};
|
||||
use rustc_span::def_id::DefId;
|
||||
use tracing::debug;
|
||||
|
||||
use crate::log::setup::{deinit_loggers, init_early_loggers, init_late_loggers};
|
||||
|
||||
struct MiriCompilerCalls {
|
||||
miri_config: Option<MiriConfig>,
|
||||
many_seeds: Option<ManySeedsConfig>,
|
||||
|
|
@ -154,13 +160,13 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
|
|||
if tcx.sess.dcx().has_errors_or_delayed_bugs().is_some() {
|
||||
tcx.dcx().fatal("miri cannot be run on programs that fail compilation");
|
||||
}
|
||||
|
||||
let early_dcx = EarlyDiagCtxt::new(tcx.sess.opts.error_format);
|
||||
init_late_loggers(&early_dcx, tcx);
|
||||
if !tcx.crate_types().contains(&CrateType::Executable) {
|
||||
tcx.dcx().fatal("miri only makes sense on bin crates");
|
||||
}
|
||||
|
||||
let early_dcx = EarlyDiagCtxt::new(tcx.sess.opts.error_format);
|
||||
init_late_loggers(&early_dcx, tcx);
|
||||
|
||||
let (entry_def_id, entry_type) = entry_fn(tcx);
|
||||
let mut config = self.miri_config.take().expect("after_analysis must only be called once");
|
||||
|
||||
|
|
@ -213,7 +219,7 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
|
|||
if !many_seeds.keep_going {
|
||||
// `abort_if_errors` would actually not stop, since `par_for_each` waits for the
|
||||
// rest of the to finish, so we just exit immediately.
|
||||
std::process::exit(return_code);
|
||||
exit(return_code);
|
||||
}
|
||||
exit_code.store(return_code, Ordering::Relaxed);
|
||||
num_failed.fetch_add(1, Ordering::Relaxed);
|
||||
|
|
@ -223,7 +229,7 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
|
|||
if num_failed > 0 {
|
||||
eprintln!("{num_failed}/{total} SEEDS FAILED", total = many_seeds.seeds.count());
|
||||
}
|
||||
std::process::exit(exit_code.0.into_inner());
|
||||
exit(exit_code.0.into_inner());
|
||||
} else {
|
||||
let return_code = miri::eval_entry(tcx, entry_def_id, entry_type, &config, None)
|
||||
.unwrap_or_else(|| {
|
||||
|
|
@ -232,7 +238,7 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
|
|||
tcx.dcx().abort_if_errors();
|
||||
rustc_driver::EXIT_FAILURE
|
||||
});
|
||||
std::process::exit(return_code);
|
||||
exit(return_code);
|
||||
}
|
||||
|
||||
// Unreachable.
|
||||
|
|
@ -327,83 +333,31 @@ impl rustc_driver::Callbacks for MiriBeRustCompilerCalls {
|
|||
}
|
||||
}
|
||||
|
||||
fn show_error(msg: &impl std::fmt::Display) -> ! {
|
||||
fn exit(exit_code: i32) -> ! {
|
||||
// Drop the tracing guard before exiting, so tracing calls are flushed correctly.
|
||||
deinit_loggers();
|
||||
std::process::exit(exit_code);
|
||||
}
|
||||
|
||||
fn show_error_(msg: &impl std::fmt::Display) -> ! {
|
||||
eprintln!("fatal error: {msg}");
|
||||
std::process::exit(1)
|
||||
exit(1)
|
||||
}
|
||||
|
||||
macro_rules! show_error {
|
||||
($($tt:tt)*) => { show_error(&format_args!($($tt)*)) };
|
||||
}
|
||||
|
||||
fn rustc_logger_config() -> rustc_log::LoggerConfig {
|
||||
// Start with the usual env vars.
|
||||
let mut cfg = rustc_log::LoggerConfig::from_env("RUSTC_LOG");
|
||||
|
||||
// Overwrite if MIRI_LOG is set.
|
||||
if let Ok(var) = env::var("MIRI_LOG") {
|
||||
// MIRI_LOG serves as default for RUSTC_LOG, if that is not set.
|
||||
if matches!(cfg.filter, Err(VarError::NotPresent)) {
|
||||
// We try to be a bit clever here: if `MIRI_LOG` is just a single level
|
||||
// used for everything, we only apply it to the parts of rustc that are
|
||||
// CTFE-related. Otherwise, we use it verbatim for `RUSTC_LOG`.
|
||||
// This way, if you set `MIRI_LOG=trace`, you get only the right parts of
|
||||
// rustc traced, but you can also do `MIRI_LOG=miri=trace,rustc_const_eval::interpret=debug`.
|
||||
if tracing::Level::from_str(&var).is_ok() {
|
||||
cfg.filter = Ok(format!(
|
||||
"rustc_middle::mir::interpret={var},rustc_const_eval::interpret={var},miri={var}"
|
||||
));
|
||||
} else {
|
||||
cfg.filter = Ok(var);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
cfg
|
||||
}
|
||||
|
||||
/// The global logger can only be set once per process, so track
|
||||
/// whether that already happened.
|
||||
static LOGGER_INITED: Once = Once::new();
|
||||
|
||||
fn init_early_loggers(early_dcx: &EarlyDiagCtxt) {
|
||||
// We only initialize `rustc` if the env var is set (so the user asked for it).
|
||||
// If it is not set, we avoid initializing now so that we can initialize later with our custom
|
||||
// settings, and *not* log anything for what happens before `miri` starts interpreting.
|
||||
if env::var_os("RUSTC_LOG").is_some() {
|
||||
LOGGER_INITED.call_once(|| {
|
||||
rustc_driver::init_logger(early_dcx, rustc_logger_config());
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
fn init_late_loggers(early_dcx: &EarlyDiagCtxt, tcx: TyCtxt<'_>) {
|
||||
// If the logger is not yet initialized, initialize it.
|
||||
LOGGER_INITED.call_once(|| {
|
||||
rustc_driver::init_logger(early_dcx, rustc_logger_config());
|
||||
});
|
||||
|
||||
// If `MIRI_BACKTRACE` is set and `RUSTC_CTFE_BACKTRACE` is not, set `RUSTC_CTFE_BACKTRACE`.
|
||||
// Do this late, so we ideally only apply this to Miri's errors.
|
||||
if let Some(val) = env::var_os("MIRI_BACKTRACE") {
|
||||
let ctfe_backtrace = match &*val.to_string_lossy() {
|
||||
"immediate" => CtfeBacktrace::Immediate,
|
||||
"0" => CtfeBacktrace::Disabled,
|
||||
_ => CtfeBacktrace::Capture,
|
||||
};
|
||||
*tcx.sess.ctfe_backtrace.borrow_mut() = ctfe_backtrace;
|
||||
}
|
||||
($($tt:tt)*) => { $crate::show_error_(&format_args!($($tt)*)) };
|
||||
}
|
||||
use show_error;
|
||||
|
||||
/// Execute a compiler with the given CLI arguments and callbacks.
|
||||
fn run_compiler_and_exit(
|
||||
args: &[String],
|
||||
callbacks: &mut (dyn rustc_driver::Callbacks + Send),
|
||||
) -> ! {
|
||||
// Invoke compiler, and handle return code.
|
||||
// Invoke compiler, catch any unwinding panics and handle return code.
|
||||
let exit_code =
|
||||
rustc_driver::catch_with_exit_code(move || rustc_driver::run_compiler(args, callbacks));
|
||||
std::process::exit(exit_code)
|
||||
exit(exit_code)
|
||||
}
|
||||
|
||||
/// Parses a comma separated list of `T` from the given string:
|
||||
|
|
|
|||
|
|
@ -1019,6 +1019,8 @@ impl<'tcx> Machine<'tcx> for MiriMachine<'tcx> {
|
|||
|
||||
const PANIC_ON_ALLOC_FAIL: bool = false;
|
||||
|
||||
const TRACING_ENABLED: bool = cfg!(feature = "tracing");
|
||||
|
||||
#[inline(always)]
|
||||
fn enforce_alignment(ecx: &MiriInterpCx<'tcx>) -> bool {
|
||||
ecx.machine.check_alignment != AlignmentCheck::None
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue