vincenzopalazzo
/
arti
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Merge branch 'report-bugs-v2' into 'main' 

Optional tracing support in tor-error for error reporting

See merge request tpo/core/arti!1379
This commit is contained in:
Nick Mathewson 2023-07-07 13:49:59 +00:00
parent 80f397fb0b 023d288ba2
commit 70f0fe634f
10 changed files with 231 additions and 44 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
Cargo.lock generated
View File

@ -4362,8 +4362,10 @@ dependencies = [
"derive_more",
"futures",
"once_cell",
"static_assertions",
"strum",
"thiserror",
"tracing",
]
[[package]]

2
crates/tor-circmgr/Cargo.toml
View File

@ -72,7 +72,7 @@ thiserror = "1"
tor-basic-utils = { path = "../tor-basic-utils", version = "0.7.1" }
tor-chanmgr = { path = "../tor-chanmgr", version = "0.9.1" }
tor-config = { path = "../tor-config", version = "0.9.2" }
tor-error = { path = "../tor-error", version = "0.5.2" }
tor-error = { path = "../tor-error", version = "0.5.2", features = ["tracing"] }
tor-guardmgr = { path = "../tor-guardmgr", version = "0.9.1" }
tor-hscrypto = { path = "../tor-hscrypto", version = "0.3.0", optional = true }
tor-linkspec = { path = "../tor-linkspec", version = "0.8.1" }

5
crates/tor-circmgr/src/build.rs
View File

@ -13,13 +13,12 @@ use std::sync::{
};
use std::time::{Duration, Instant};
use tor_chanmgr::{ChanMgr, ChanProvenance, ChannelUsage};
use tor_error::ErrorReport;
use tor_error::warn_report;
use tor_guardmgr::GuardStatus;
use tor_linkspec::{ChanTarget, IntoOwnedChanTarget, OwnedChanTarget, OwnedCircTarget};
use tor_netdir::params::NetParameters;
use tor_proto::circuit::{CircParameters, ClientCirc, PendingClientCirc};
use tor_rtcompat::{Runtime, SleepProviderExt};
use tracing::warn;
mod guardstatus;
@ -470,7 +469,7 @@ impl<R: Runtime> CircuitBuilder<R> {
pub fn circparameters_from_netparameters(inp: &NetParameters) -> CircParameters {
let mut p = CircParameters::default();
if let Err(e) = p.set_initial_send_window(inp.circuit_window.get() as u16) {
warn!("Invalid parameter in directory: {}", e.report());
warn_report!(e, "Invalid parameter in directory");
}
p.set_extend_by_ed25519_id(inp.extend_by_ed25519_id.into());
p

10
crates/tor-circmgr/src/hspool.rs
View File

@ -11,7 +11,8 @@ use std::{
use crate::{timeouts, CircMgr, Error, Result};
use futures::{task::SpawnExt, StreamExt, TryFutureExt};
use once_cell::sync::OnceCell;
use tor_error::{bad_api_usage, internal, ErrorReport};
use tor_error::debug_report;
use tor_error::{bad_api_usage, internal};
use tor_linkspec::{CircTarget, OwnedCircTarget};
use tor_netdir::{NetDir, NetDirProvider, Relay, SubnetConfig};
use tor_proto::circuit::{self, ClientCirc};
@ -19,7 +20,7 @@ use tor_rtcompat::{
scheduler::{TaskHandle, TaskSchedule},
Runtime, SleepProviderExt,
};
use tracing::{debug, warn};
use tracing::warn;
/// The (onion-service-related) purpose for which a given circuit is going to be
/// used.
@ -435,10 +436,7 @@ async fn launch_hs_circuits_as_needed<R: Runtime>(
n_to_launch -= 1;
}
Err(err) => {
debug!(
"Unable to build preemptive circuit for onion services: {}",
err.report()
);
debug_report!(err, "Unable to build preemptive circuit for onion services");
}
}
} else {

28
crates/tor-circmgr/src/lib.rs
View File

@ -41,7 +41,7 @@
use tor_basic_utils::retry::RetryDelay;
use tor_chanmgr::ChanMgr;
use tor_error::ErrorReport;
use tor_error::{error_report, warn_report};
use tor_linkspec::ChanTarget;
use tor_netdir::{DirEvent, NetDir, NetDirProvider, Timeliness};
use tor_proto::circuit::{CircParameters, ClientCirc, UniqId};
@ -54,7 +54,7 @@ use futures::task::SpawnExt;
use futures::StreamExt;
use std::sync::{Arc, Mutex, Weak};
use std::time::{Duration, Instant};
use tracing::{debug, error, info, trace, warn};
use tracing::{debug, info, trace, warn};
#[cfg(feature = "testing")]
pub use config::test_config::TestConfig;
@ -491,11 +491,7 @@ impl<R: Runtime> CircMgr<R> {
trace!("Circuit already existed created for {:?}", circs[i]);
}
Err(e) => {
warn!(
"Failed to build preemptive circuit {:?}: {}",
sv(&circs[i]),
e.report(),
);
warn_report!(e, "Failed to build preemptive circuit {:?}", sv(&circs[i]));
n_errors += 1;
}
}
@ -664,10 +660,7 @@ impl<R: Runtime> CircMgr<R> {
if let (Some(cm), Some(dm)) = (Weak::upgrade(&circmgr), Weak::upgrade(&dirmgr)) {
if let Ok(netdir) = dm.netdir(Timeliness::Unchecked) {
if let Err(e) = cm.launch_timeout_testing_circuit_if_appropriate(&netdir) {
warn!(
"Problem launching a timeout testing circuit: {}",
e.report()
);
warn_report!(e, "Problem launching a timeout testing circuit");
}
let delay = netdir
.params()
@ -706,25 +699,25 @@ impl<R: Runtime> CircMgr<R> {
match statemgr.try_lock() {
Err(e) => {
error!("Problem with state lock file: {}", e.report());
error_report!(e, "Problem with state lock file");
break;
}
Ok(NewlyAcquired) => {
info!("We now own the lock on our state files.");
if let Err(e) = circmgr.upgrade_to_owned_persistent_state() {
error!("Unable to upgrade to owned state files: {}", e.report());
error_report!(e, "Unable to upgrade to owned state files");
break;
}
}
Ok(AlreadyHeld) => {
if let Err(e) = circmgr.store_persistent_state() {
error!("Unable to flush circmgr state: {}", e.report());
error_report!(e, "Unable to flush circmgr state");
break;
}
}
Ok(NoLock) => {
if let Err(e) = circmgr.reload_persistent_state() {
error!("Unable to reload circmgr state: {}", e.report());
error_report!(e, "Unable to reload circmgr state");
break;
}
}
@ -838,10 +831,7 @@ impl<R: Runtime> Drop for CircMgr<R> {
match self.store_persistent_state() {
Ok(true) => info!("Flushed persistent state at exit."),
Ok(false) => debug!("Lock not held; no state to flush."),
Err(e) => error!(
"Unable to flush state on circuit manager drop: {}",
e.report()
),
Err(e) => error_report!(e, "Unable to flush state on circuit manager drop"),
}
}
}

24
crates/tor-circmgr/src/mgr.rs
View File

@ -29,7 +29,7 @@ use retry_error::RetryError;
use tor_basic_utils::retry::RetryDelay;
use tor_chanmgr::ChannelUsage;
use tor_config::MutCfg;
use tor_error::{internal, AbsRetryTime, ErrorReport, HasRetryTime};
use tor_error::{debug_report, info_report, internal, warn_report, AbsRetryTime, HasRetryTime};
use tor_rtcompat::{Runtime, SleepProviderExt};
use async_trait::async_trait;
@ -43,7 +43,7 @@ use std::hash::Hash;
use std::panic::AssertUnwindSafe;
use std::sync::{self, Arc, Weak};
use std::time::{Duration, Instant};
use tracing::{debug, info, warn};
use tracing::{debug, warn};
use weak_table::PtrWeakHashSet;
mod streams;
@ -876,10 +876,10 @@ impl<B: AbstractCircBuilder + 'static, R: Runtime> AbstractCircMgr<B, R> {
}
Err(e) => {
// We couldn't pick the action!
debug!(
"Couldn't pick action for circuit attempt {}: {}",
debug_report!(
&e,
"Couldn't pick action for circuit attempt {}",
attempt_num,
e.report(),
);
e
}
@ -1146,18 +1146,18 @@ impl<B: AbstractCircBuilder + 'static, R: Runtime> AbstractCircMgr<B, R> {
x => x,
};
if src == streams::Source::Left {
info!(
"{} suggested we use {:?}, but restrictions failed: {}",
info_report!(
&e,
"{} suggested we use {:?}, but restrictions failed",
describe_source(building, src),
id,
e.report(),
);
} else {
debug!(
"{} suggested we use {:?}, but restrictions failed: {}",
debug_report!(
&e,
"{} suggested we use {:?}, but restrictions failed",
describe_source(building, src),
id,
e.report(),
);
}
record_error(&mut retry_error, src, building, e);
@ -1523,7 +1523,7 @@ fn spawn_expiration_task<B, R>(
};
cm.expire_circ(&circ_id, exp_inst);
}) {
warn!("Unable to launch expiration task: {}", e.report());
warn_report!(e, "Unable to launch expiration task");
}
}
}

4
crates/tor-circmgr/src/timeouts/estimator.rs
View File

@ -8,7 +8,7 @@ use crate::timeouts::{
use crate::TimeoutStateHandle;
use std::sync::Mutex;
use std::time::Duration;
use tor_error::ErrorReport;
use tor_error::warn_report;
use tor_netdir::params::NetParameters;
use tracing::{debug, warn};
@ -138,7 +138,7 @@ fn estimator_from_storage(
Ok(Some(v)) => v,
Ok(None) => ParetoTimeoutState::default(),
Err(e) => {
warn!("Unable to load timeout state: {}", e.report());
warn_report!(e, "Unable to load timeout state");
return (true, Box::new(ReadonlyTimeoutEstimator::new()));
}
};

6
crates/tor-error/Cargo.toml
View File

@ -13,13 +13,15 @@ categories = ["rust-patterns"]
[features]
default = ["backtrace"]
full = ["backtrace"]
full = ["backtrace", "tracing"]
experimental = ["experimental-api", "rpc"]
experimental-api = ["rpc", "__is_experimental"]
rpc = ["__is_experimental"]
tracing = ["dep:tracing", "static_assertions"]
__is_experimental = []
[dependencies]
@ -27,8 +29,10 @@ backtrace = { version = "0.3.39", optional = true }
derive_more = "0.99.3"
futures = "0.3"
once_cell = "1"
static_assertions = { version = "1", optional = true }
strum = { version = "0.25", features = ["derive"] }
thiserror = "1"
tracing = { version = "0.1.36", optional = true }
[dev-dependencies]
[package.metadata.docs.rs]

3
crates/tor-error/src/lib.rs
View File

@ -53,6 +53,9 @@ pub use retriable::*;
mod misc;
pub use misc::*;
#[cfg(feature = "tracing")]
pub mod tracing;
/// Classification of an error arising from Arti's Tor operations
///
/// This `ErrorKind` should suffice for programmatic handling by most applications embedding Arti:

191
crates/tor-error/src/tracing.rs Normal file
View File

@ -0,0 +1,191 @@
//! Support for using `tor-error` with the `tracing` crate.
use crate::ErrorKind;
#[doc(hidden)]
pub use static_assertions;
#[doc(hidden)]
pub use tracing::{event, Level};
impl ErrorKind {
/// Return true if this [`ErrorKind`] should always be logged as
/// a warning (or more severe).
pub fn is_always_a_warning(&self) -> bool {
matches!(self, ErrorKind::Internal | ErrorKind::BadApiUsage)
}
}
#[doc(hidden)]
/// Return true if a given string has an ending that makes sense for our
/// formats.
pub const fn fmt_ending_ok(s: &str) -> bool {
// This implementation is slightly roundabout because we need this function
// to be const.
!matches!(s.as_bytes().last(), Some(b' ' | b'.' | b':'))
}
/// Log a [`Report`](crate::Report) of a provided error at a given level, or a
/// higher level if appropriate.
///
/// (If [`ErrorKind::is_always_a_warning`] returns true for the error's kind, we
/// log it at WARN, unless this event is already at level WARN or ERROR.)
///
/// We require that the format string _not_ end with ' ', ',' or ':'; if it doesn't,
/// we produce a compile-time error.
///
/// # Examples
///
/// ```
/// # // this is what implements HasKind in this crate.
/// # fn demo(err: &futures::task::SpawnError) {
/// # let num = 7;
/// use tor_error::event_report;
/// use tracing::Level;
///
/// event_report!(Level::DEBUG, err, "Couldn't chew gum while walking");
///
/// event_report!(Level::TRACE, err, "Ephemeral error on attempt #{}", num);
/// # }
/// ```
///
/// # Limitations
///
/// This macro does not support the full range of syntaxes supported by
/// [`tracing::event`].
///
/// The compile-time error produced when the format string has a bad ending is
/// kind of confusing. This is a limitation of the `static_assertions` crate.
//
// NOTE: We need this fancy conditional here because tracing::event! insists on
// getting a const expression for its `Level`. So we can do
// `if cond {debug!(..)} else {warn!(..)}`,
// but we can't do
// `event!(if cond {DEBUG} else {WARN}, ..)`.
#[macro_export]
macro_rules! event_report {
($level:expr, $err:expr, $fmt:literal, $($arg:expr),* $(,)?) => {
{
use $crate::{tracing as tr, HasKind as _, };
let err = $err;
if err.kind().is_always_a_warning() && tr::Level::WARN < $level {
$crate::event_report!(@raw tr::Level::WARN, err, $fmt, $($arg),*);
} else {
$crate::event_report!(@raw $level, err, $fmt, $($arg),*);
}
}
};
($level:expr, $err:expr, $fmt:literal) => {
$crate::event_report!($level, $err, $fmt, )
};
(@raw $level:expr, $err:expr, $fmt:literal $(, $arg:expr)* $(,)?) => {
{
use $crate::{tracing as tr, ErrorReport as _};
tr::static_assertions::const_assert!(
tr::fmt_ending_ok($fmt)
);
tr::event!(
$level,
concat!($fmt, ": {}"),
$($arg ,)*
($err).report()
)
}
}
}
/// Log a report for `err` at level `TRACE` (or higher if it is a bug).
///
/// # Examples:
///
/// ```
/// # fn demo(err: &futures::task::SpawnError) {
/// # let msg = ();
/// use tor_error::trace_report;
/// trace_report!(err, "Cheese exhausted (ephemeral)");
/// trace_report!(err, "Unable to parse message {:?}", msg);
/// # }
/// ```
#[macro_export]
macro_rules! trace_report {
( $err:expr, $($rest:expr),+ $(,)? ) => {
$crate::event_report!($crate::tracing::Level::TRACE, $err, $($rest),+)
}
}
/// Log a report for `err` at level `DEBUG` (or higher if it is a bug).
///
/// # Examples
///
/// ```
/// # fn demo(err: &futures::task::SpawnError) {
/// # let peer = "";
/// use tor_error::debug_report;
/// debug_report!(err, "Existentialism overload; retrying");
/// debug_report!(err, "Recoverable error from {}; will try somebody else", peer);
/// # }
/// ```
#[macro_export]
macro_rules! debug_report {
( $err:expr, $($rest:expr),+ $(,)? ) => {
$crate::event_report!($crate::tracing::Level::DEBUG, $err, $($rest),+)
}
}
/// Log a report for `err` at level `INFO` (or higher if it is a bug).
///
/// # Examples
///
/// ```
/// # fn demo(err: &futures::task::SpawnError) {
/// # let first = ""; let second = "";
/// use tor_error::info_report;
/// info_report!(err, "Speculative load failed; proceeding anyway");
/// info_report!(err, "No {} available; will try {} instead", first, second);
/// # }
/// ```
#[macro_export]
macro_rules! info_report {
( $err:expr, $($rest:expr),+ $(,)? ) => {
$crate::event_report!($crate::tracing::Level::INFO, $err, $($rest),+)
}
}
/// Log a report for `err` at level `WARN`.
///
/// # Examples
///
/// ```
/// # fn demo(err: &futures::task::SpawnError) {
/// # let peer = "";
/// use tor_error::warn_report;
/// warn_report!(err, "Cannot contact remote server");
/// warn_report!(err, "No address found for {}", peer);
/// # }
/// ```
#[macro_export]
macro_rules! warn_report {
( $err:expr, $($rest:expr),+ $(,)? ) => {
// @raw, since we don't escalate warnings any higher,
// no matter what their kind might be.
$crate::event_report!(@raw $crate::tracing::Level::WARN, $err, $($rest),+)
}
}
/// Log a report for `err` at level `ERROR`.
///
/// # Examples
///
/// ```
/// # fn demo(err: &futures::task::SpawnError) {
/// # let action = "";
/// use tor_error::error_report;
/// error_report!(err, "Everything has crashed");
/// error_report!(err, "Everything has crashed while trying to {}", action);
/// # }
/// ```
#[macro_export]
macro_rules! error_report {
( $err:expr, $($rest:expr),+ $(,)? ) => {
// @raw, since we don't escalate warnings any higher,
// no matter what their kind might be.
$crate::event_report!(@raw $crate::tracing::Level::ERROR, $err, $($rest),+)
}
}