Replace all println/eprintln calls outside of arti CLI with trace.

This commit is contained in:
Nick Mathewson 2021-11-04 11:04:59 -04:00
parent dae8cdb463
commit 83d9f2299e
8 changed files with 40 additions and 30 deletions

1
Cargo.lock generated
View File

@ -2883,6 +2883,7 @@ dependencies = [
"rand 0.8.4",
"thiserror",
"tor-rtcompat",
"tracing",
]
[[package]]

View File

@ -431,6 +431,7 @@ mod test {
use std::sync::Mutex;
use tor_llcrypto::pk::ed25519::Ed25519Identity;
use tor_rtcompat::{test_with_all_runtimes, SleepProvider};
use tracing::trace;
/// Make a new nonfunctional `Arc<GuardStatusHandle>`
fn gs() -> Arc<GuardStatusHandle> {
@ -457,7 +458,7 @@ mod test {
assert!(x.is_ok());
assert_eq!(x.unwrap(), 3_u32);
eprintln!("acquiesce after test1");
trace!("acquiesce after test1");
#[allow(clippy::clone_on_copy)]
let rt = tor_rtmock::MockSleepRuntime::new(rto.clone());
@ -481,7 +482,7 @@ mod test {
assert!(x.is_ok());
assert_eq!(x.unwrap(), 4_u32);
eprintln!("acquiesce after test2");
trace!("acquiesce after test2");
#[allow(clippy::clone_on_copy)]
let rt = tor_rtmock::MockSleepRuntime::new(rto.clone());
@ -511,7 +512,7 @@ mod test {
let waited = rt.wait_for(rcv).await;
assert_eq!(waited, Ok(()));
eprintln!("acquiesce after test3");
trace!("acquiesce after test3");
#[allow(clippy::clone_on_copy)]
let rt = tor_rtmock::MockSleepRuntime::new(rto.clone());

View File

@ -1135,6 +1135,7 @@ mod test {
use std::sync::atomic::{self, AtomicUsize};
use tor_rtcompat::SleepProvider;
use tor_rtmock::MockSleepRuntime;
use tracing::trace;
#[derive(Debug, Clone, Eq, PartialEq, Hash, Copy)]
struct FakeId {
@ -1291,7 +1292,7 @@ mod test {
}
FakeOp::Timeout => unreachable!(), // should be converted to the below
FakeOp::TimeoutReleaseAdvance(reason) => {
eprintln!("releasing advance to fake a timeout");
trace!("releasing advance to fake a timeout");
self.runtime.release_advance(reason);
let () = futures::future::pending().await;
unreachable!()

View File

@ -415,7 +415,7 @@ pub(crate) mod test {
let ed_id = [6; 32].into();
let rsa_id = [10; 20].into();
let send1 = send1.sink_map_err(|e| {
eprintln!("got sink error: {}", e);
trace!("got sink error: {}", e);
tor_cell::Error::ChanProto("dummy message".into())
});
let (chan, reactor) = crate::channel::Channel::new(

View File

@ -1284,15 +1284,15 @@ mod test {
let target = example_target();
let params = CircParameters::default();
let ret = if fast {
eprintln!("doing fast create");
trace!("doing fast create");
pending.create_firsthop_fast(&mut rng, &params).await
} else {
eprintln!("doing ntor create");
trace!("doing ntor create");
pending
.create_firsthop_ntor(&mut rng, &target, &params)
.await
};
eprintln!("create done: result {:?}", ret);
trace!("create done: result {:?}", ret);
ret
};
// Future to run the reactor.

View File

@ -15,6 +15,7 @@ async-trait = "0.1.48"
futures = "0.3.13"
pin-project = "1.0.5"
thiserror = "1.0.24"
tracing = "0.1.26"
tor-rtcompat = { version = "0.0.1", path = "../tor-rtcompat" }

View File

@ -10,6 +10,7 @@ use pin_project::pin_project;
use std::io::Result as IoResult;
use std::net::SocketAddr;
use std::time::{Duration, Instant, SystemTime};
use tracing::trace;
/// A wrapper Runtime that overrides the SleepProvider trait for the
/// underlying runtime.
@ -152,20 +153,20 @@ impl<F: Future> Future for WaitFor<F> {
type Output = F::Output;
fn poll(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Self::Output> {
eprintln!("waitfor poll");
trace!("waitfor poll");
let mut this = self.project();
this.sleep.register_waitfor_waker(cx.waker().clone());
if let Poll::Ready(r) = this.fut.poll(cx) {
eprintln!("waitfor done!");
trace!("waitfor done!");
this.sleep.clear_waitfor_waker();
return Poll::Ready(r);
}
eprintln!("waitfor poll complete");
trace!("waitfor poll complete");
if this.sleep.should_advance() {
if let Some(duration) = this.sleep.time_until_next_timeout() {
eprintln!("Advancing by {:?}", duration);
trace!("Advancing by {:?}", duration);
this.sleep.advance_noyield(duration);
} else {
// If we get here, something's probably wedged and the test isn't going to complete
@ -175,7 +176,7 @@ impl<F: Future> Future for WaitFor<F> {
panic!("WaitFor told to advance, but didn't have any duration to advance by");
}
} else {
eprintln!("waiting for sleepers to advance");
trace!("waiting for sleepers to advance");
}
Poll::Pending
}

View File

@ -16,6 +16,7 @@ use std::{
};
use futures::Future;
use tracing::trace;
use std::collections::HashSet;
use tor_rtcompat::SleepProvider;
@ -164,7 +165,7 @@ impl MockSleepProvider {
if !state.blocked_advance.is_empty() && state.allowed_advance == Duration::from_nanos(0) {
// We've had advances blocked, and don't have any quota for doing allowances while
// blocked left.
eprintln!(
trace!(
"should_advance = false: blocked by {:?}",
state.blocked_advance
);
@ -172,7 +173,7 @@ impl MockSleepProvider {
}
if !state.should_advance {
// The advance flag wasn't set.
eprintln!("should_advance = false; bit not previously set");
trace!("should_advance = false; bit not previously set");
return false;
}
// Clear the advance flag; we'll either return true and cause an advance to happen,
@ -182,7 +183,7 @@ impl MockSleepProvider {
if state.sleepers_polled < state.sleepers_made {
// Something did set the advance flag before, but it's not valid any more now because
// more unpolled sleepers were created.
eprintln!("should_advance = false; advancing no longer valid");
trace!("should_advance = false; advancing no longer valid");
return false;
}
if !state.blocked_advance.is_empty() && state.allowed_advance > Duration::from_nanos(0) {
@ -200,7 +201,7 @@ impl MockSleepProvider {
Some(x) => x,
None => {
// There's no timeout set, so we really shouldn't be here anyway.
eprintln!("should_advance = false; allow_one set but no timeout yet");
trace!("should_advance = false; allow_one set but no timeout yet");
return false;
}
};
@ -208,15 +209,16 @@ impl MockSleepProvider {
// We can advance up to the next timeout, since it's in our quota.
// Subtract the amount we're going to advance by from said quota.
state.allowed_advance -= next_timeout;
eprintln!(
trace!(
"WARNING: allowing advance due to allow_one; new allowed is {:?}",
state.allowed_advance
);
} else {
// The next timeout is too far in the future.
eprintln!(
trace!(
"should_advance = false; allow_one set but only up to {:?}, next is {:?}",
state.allowed_advance, next_timeout
state.allowed_advance,
next_timeout
);
return false;
}
@ -273,11 +275,11 @@ impl SleepSchedule {
fn maybe_advance(&mut self) {
if self.sleepers_polled >= self.sleepers_made {
if let Some(ref waker) = self.waitfor_waker {
eprintln!("setting advance flag");
trace!("setting advance flag");
self.should_advance = true;
waker.wake_by_ref();
} else {
eprintln!("would advance, but no waker");
trace!("would advance, but no waker");
}
}
}
@ -285,9 +287,10 @@ impl SleepSchedule {
/// Register a sleeper as having been polled, and advance if necessary.
fn increment_poll_count(&mut self) {
self.sleepers_polled += 1;
eprintln!(
trace!(
"sleeper polled, {}/{}",
self.sleepers_polled, self.sleepers_made
self.sleepers_polled,
self.sleepers_made
);
self.maybe_advance();
}
@ -300,9 +303,11 @@ impl SleepProvider for MockSleepProvider {
let when = provider.instant + duration;
// We're making a new sleeper, so register this in the state.
provider.sleepers_made += 1;
eprintln!(
trace!(
"sleeper made for {:?}, {}/{}",
duration, provider.sleepers_polled, provider.sleepers_made
duration,
provider.sleepers_polled,
provider.sleepers_made
);
Sleeping {
@ -315,14 +320,14 @@ impl SleepProvider for MockSleepProvider {
fn block_advance<T: Into<String>>(&self, reason: T) {
let mut provider = self.state.lock().expect("Poisoned lock for state");
let reason = reason.into();
eprintln!("advancing blocked: {}", reason);
trace!("advancing blocked: {}", reason);
provider.blocked_advance.insert(reason);
}
fn release_advance<T: Into<String>>(&self, reason: T) {
let mut provider = self.state.lock().expect("Poisoned lock for state");
let reason = reason.into();
eprintln!("advancing released: {}", reason);
trace!("advancing released: {}", reason);
provider.blocked_advance.remove(&reason);
if provider.blocked_advance.is_empty() {
provider.maybe_advance();
@ -332,7 +337,7 @@ impl SleepProvider for MockSleepProvider {
fn allow_one_advance(&self, dur: Duration) {
let mut provider = self.state.lock().expect("Poisoned lock for state");
provider.allowed_advance = Duration::max(provider.allowed_advance, dur);
println!(
trace!(
"** allow_one_advance fired; may advance up to {:?} **",
provider.allowed_advance
);
@ -375,7 +380,7 @@ impl Drop for Sleeping {
if !self.inserted {
// A sleeper being dropped will never be polled, so there's no point waiting;
// act as if it's been polled in order to avoid waiting forever.
eprintln!("sleeper dropped, incrementing count");
trace!("sleeper dropped, incrementing count");
provider.increment_poll_count();
self.inserted = true;
}