Skip to content

Commit

Permalink
chore: tracing everywhere
Browse files Browse the repository at this point in the history
  • Loading branch information
nhtyy committed Nov 25, 2024
1 parent 87cab0f commit edbcc5f
Show file tree
Hide file tree
Showing 14 changed files with 33 additions and 41 deletions.
4 changes: 0 additions & 4 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

1 change: 0 additions & 1 deletion crates/core/executor/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,6 @@ thiserror = "1.0.63"
tracing = { workspace = true }
strum_macros = "0.26.4"
strum = { version = "0.26.3", features = ["derive"] }
log = "0.4.22"
hex = "0.4.3"
bytemuck = "1.16.3"
tiny-keccak = { version = "2.0.2", features = ["keccak"] }
Expand Down
6 changes: 3 additions & 3 deletions crates/core/executor/src/executor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1299,7 +1299,7 @@ impl<'a> Executor<'a> {
}

if !shape_match_found {
log::warn!(
tracing::warn!(
"stopping shard early due to no shapes fitting: \
nb_cycles={}, \
addsub_count={}, \
Expand Down Expand Up @@ -1341,7 +1341,7 @@ impl<'a> Executor<'a> {
|| self.state.pc.wrapping_sub(self.program.pc_base)
>= (self.program.instructions.len() * 4) as u32;
if done && self.unconstrained {
log::error!("program ended in unconstrained mode at clk {}", self.state.global_clk);
tracing::error!("program ended in unconstrained mode at clk {}", self.state.global_clk);
return Err(ExecutionError::EndInUnconstrained());
}
Ok(done)
Expand Down Expand Up @@ -1658,7 +1658,7 @@ impl<'a> Executor<'a> {
}

if !self.unconstrained && self.state.global_clk % 10_000_000 == 0 {
log::info!("clk = {} pc = 0x{:x?}", self.state.global_clk, self.state.pc);
tracing::info!("clk = {} pc = 0x{:x?}", self.state.global_clk, self.state.pc);
}
}
}
Expand Down
4 changes: 2 additions & 2 deletions crates/core/executor/src/syscalls/write.rs
Original file line number Diff line number Diff line change
Expand Up @@ -128,7 +128,7 @@ fn start_cycle_tracker(rt: &mut Executor, name: &str) {
let depth = rt.cycle_tracker.len() as u32;
rt.cycle_tracker.insert(name.to_string(), (rt.state.global_clk, depth));
let padding = "│ ".repeat(depth as usize);
log::info!("{}┌╴{}", padding, name);
tracing::info!("{}┌╴{}", padding, name);
}

/// End tracking cycles for the given name, print out the log, and return the total number of cycles
Expand All @@ -137,7 +137,7 @@ fn end_cycle_tracker(rt: &mut Executor, name: &str) -> Option<u64> {
if let Some((start, depth)) = rt.cycle_tracker.remove(name) {
let padding = "│ ".repeat(depth as usize);
let total_cycles = rt.state.global_clk - start;
log::info!("{}└╴{} cycles", padding, num_to_comma_separated(total_cycles));
tracing::info!("{}└╴{} cycles", padding, num_to_comma_separated(total_cycles));
return Some(total_cycles);
}
None
Expand Down
1 change: 0 additions & 1 deletion crates/core/machine/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,6 @@ categories = { workspace = true }
bincode = "1.3.3"
serde = { workspace = true, features = ["derive", "rc"] }
itertools = { workspace = true }
log = "0.4.22"
num = { version = "0.4.3" }
p3-air = { workspace = true }
p3-baby-bear = { workspace = true }
Expand Down
4 changes: 2 additions & 2 deletions crates/core/machine/src/runtime/utils.rs
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@ impl<'a> Runtime<'a> {
// If RUST_LOG is set to "trace", then log the current state of the runtime every cycle.
let width = 12;
let registers = self.registers();
log::trace!(
tracing::trace!(
"clk={} [pc=0x{:x?}] {:<width$?} | x0={:<width$} x1={:<width$} x2={:<width$} x3={:<width$} x4={:<width$} x5={:<width$} x6={:<width$} x7={:<width$} x8={:<width$} x9={:<width$} x10={:<width$} x11={:<width$} x12={:<width$} x13={:<width$} x14={:<width$} x15={:<width$} x16={:<width$} x17={:<width$} x18={:<width$}",
self.state.global_clk,
self.state.pc,
Expand All @@ -69,7 +69,7 @@ impl<'a> Runtime<'a> {
);

if !self.unconstrained && self.state.global_clk % 10_000_000 == 0 {
log::info!("clk = {} pc = 0x{:x?}", self.state.global_clk, self.state.pc);
tracing::info!("clk = {} pc = 0x{:x?}", self.state.global_clk, self.state.pc);
}
}
}
4 changes: 2 additions & 2 deletions crates/core/machine/src/utils/prove.rs
Original file line number Diff line number Diff line change
Expand Up @@ -481,7 +481,7 @@ where
shape_config,
)
});
log::debug!("generated {} records", records.len());
tracing::debug!("generated {} records", records.len());
*report_aggregate.lock().unwrap() += report;
reset_seek(&mut checkpoint);

Expand Down Expand Up @@ -511,7 +511,7 @@ where

// See if any deferred shards are ready to be committed to.
let mut deferred = deferred.split(done, opts.split_opts);
log::debug!("deferred {} records", deferred.len());
tracing::debug!("deferred {} records", deferred.len());

// Update the public values & prover state for the shards which do not
// contain "cpu events" before committing to them.
Expand Down
1 change: 0 additions & 1 deletion crates/recursion/gnark-ffi/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,6 @@ sp1-stark = { workspace = true }
serde = { workspace = true }
serde_json = { workspace = true }
tempfile = "3.10.1"
log = "0.4.22"
num-bigint = "0.4.6"
cfg-if = "1.0"
bincode = "1.3.3"
Expand Down
6 changes: 3 additions & 3 deletions crates/recursion/gnark-ffi/src/ffi/docker.rs
Original file line number Diff line number Diff line change
Expand Up @@ -39,7 +39,7 @@ fn get_docker_image() -> String {

/// Calls `docker run` with the given arguments and bind mounts.
fn call_docker(args: &[&str], mounts: &[(&str, &str)]) -> Result<()> {
log::info!("Running {} in docker", args[0]);
tracing::info!("Running {} in docker", args[0]);
let mut cmd = Command::new("docker");
cmd.args(["run", "--rm"]);
for (src, dest) in mounts {
Expand All @@ -49,8 +49,8 @@ fn call_docker(args: &[&str], mounts: &[(&str, &str)]) -> Result<()> {
cmd.args(args);
let result = cmd.status()?;
if !result.success() {
log::error!("Failed to run `docker run`: {:?}", cmd);
log::error!("Execution result: {:?}", result);
tracing::error!("Failed to run `docker run`: {:?}", cmd);
tracing::error!("Execution result: {:?}", result);
return Err(anyhow!("docker command failed"));
}
Ok(())
Expand Down
1 change: 0 additions & 1 deletion crates/sdk/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,6 @@ p3-fri = { workspace = true }
indicatif = "0.17.8"
tracing = { workspace = true }
hex = "0.4.3"
log = "0.4.22"
dirs = "5.0.1"
tempfile = "3.10.1"
cfg-if = "1.0"
Expand Down
2 changes: 1 addition & 1 deletion crates/sdk/src/network-v2/client.rs
Original file line number Diff line number Diff line change
Expand Up @@ -216,7 +216,7 @@ impl NetworkClient {
self.http.put(&presigned_url).body(bincode::serialize::<T>(item)?).send().await?;

if !response.status().is_success() {
log::debug!("Artifact upload failed with status: {}", response.status());
tracing::debug!("Artifact upload failed with status: {}", response.status());
}
assert!(response.status().is_success());

Expand Down
24 changes: 12 additions & 12 deletions crates/sdk/src/network-v2/prover.rs
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,7 @@ impl NetworkProver {
/// Creates a new [NetworkProver] with the given private key.
pub fn new(private_key: &str, rpc_url: Option<String>, skip_simulation: bool) -> Self {
let version = SP1_CIRCUIT_VERSION;
log::info!("Client circuit version: {}", version);
tracing::info!("Client circuit version: {}", version);
let local_prover = CpuProver::new();
let client = NetworkClient::new(private_key, rpc_url);
Self { client, local_prover, skip_simulation }
Expand All @@ -59,10 +59,10 @@ impl NetworkProver {
let (_, report) =
self.local_prover.sp1_prover().execute(elf, &stdin, Default::default())?;
let cycles = report.total_instruction_count();
log::info!("Simulation complete, cycles: {}", cycles);
tracing::info!("Simulation complete, cycles: {}", cycles);
cycles
} else {
log::info!("Skipping simulation");
tracing::info!("Skipping simulation");
DEFAULT_CYCLE_LIMIT
};

Expand All @@ -72,7 +72,7 @@ impl NetworkProver {
// Get the timeout.
let timeout_secs = timeout.map(|dur| dur.as_secs()).unwrap_or(TIMEOUT_SECS);

log::info!("Requesting proof with cycle limit: {}", cycle_limit);
tracing::info!("Requesting proof with cycle limit: {}", cycle_limit);

// Request the proof.
let response = self
Expand All @@ -89,11 +89,11 @@ impl NetworkProver {
)
.await?;

// Log the request ID and transaction hash.
// tracing the request ID and transaction hash.
let tx_hash_hex = "0x".to_string() + &hex::encode(response.tx_hash);
let request_id = response.body.unwrap().request_id;
let request_id_hex = "0x".to_string() + &hex::encode(request_id.clone());
log::info!("Created request {} in transaction {}", request_id_hex, tx_hash_hex);
tracing::info!("Created request {} in transaction {}", request_id_hex, tx_hash_hex);

Ok(request_id)
}
Expand Down Expand Up @@ -131,25 +131,25 @@ impl NetworkProver {
if let Some(status) = e.downcast_ref::<tonic::Status>() {
match status.code() {
Code::NotFound => {
log::error!("Proof request not found: {}", status.message());
tracing::error!("Proof request not found: {}", status.message());
Err(backoff::Error::permanent(e))
}
Code::Unavailable => {
log::warn!(
tracing::warn!(
"Network temporarily unavailable, retrying: {}",
status.message()
);
Err(backoff::Error::transient(e))
}
Code::DeadlineExceeded => {
log::warn!(
tracing::warn!(
"Request deadline exceeded, retrying: {}",
status.message()
);
Err(backoff::Error::transient(e))
}
_ => {
log::error!(
tracing::error!(
"Permanent error encountered: {} ({})",
status.message(),
status.code()
Expand All @@ -158,7 +158,7 @@ impl NetworkProver {
}
}
} else {
log::error!("Unexpected error type: {}", e);
tracing::error!("Unexpected error type: {}", e);
Err(backoff::Error::permanent(e))
}
}
Expand All @@ -173,7 +173,7 @@ impl NetworkProver {
}
ProofStatus::Assigned => {
if !is_assigned {
log::info!("Proof request assigned, proving...");
tracing::info!("Proof request assigned, proving...");
is_assigned = true;
}
}
Expand Down
2 changes: 1 addition & 1 deletion crates/sdk/src/network/client.rs
Original file line number Diff line number Diff line change
Expand Up @@ -105,7 +105,7 @@ impl NetworkClient {

let proof = match res.status() {
ProofStatus::ProofFulfilled => {
log::info!("Proof request fulfilled");
tracing::info!("Proof request fulfilled");
let proof_bytes = self
.http
.get(res.proof_url.as_ref().expect("no proof url"))
Expand Down
14 changes: 7 additions & 7 deletions crates/sdk/src/network/prover.rs
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ impl NetworkProver {
/// Creates a new [NetworkProver] with the given private key.
pub fn new(private_key: &str, rpc_url: Option<String>, skip_simulation: bool) -> Self {
let version = SP1_CIRCUIT_VERSION;
log::info!("Client circuit version: {}", version);
tracing::info!("Client circuit version: {}", version);

let local_prover = CpuProver::new();
Self { client: NetworkClient::new(private_key, rpc_url), local_prover, skip_simulation }
Expand All @@ -56,16 +56,16 @@ impl NetworkProver {
if !self.skip_simulation {
let (_, report) =
self.local_prover.sp1_prover().execute(elf, &stdin, Default::default())?;
log::info!("Simulation complete, cycles: {}", report.total_instruction_count());
tracing::info!("Simulation complete, cycles: {}", report.total_instruction_count());
} else {
log::info!("Skipping simulation");
tracing::info!("Skipping simulation");
}

let proof_id = client.create_proof(elf, &stdin, mode, SP1_CIRCUIT_VERSION).await?;
log::info!("Created {}", proof_id);
tracing::info!("Created {}", proof_id);

if self.client.is_using_prover_network {
log::info!("View in explorer: https://explorer.succinct.xyz/{}", proof_id);
tracing::info!("View in explorer: https://explorer.succinct.xyz/{}", proof_id);
}
Ok(proof_id)
}
Expand All @@ -92,7 +92,7 @@ impl NetworkProver {

if let Err(e) = result {
consecutive_errors += 1;
log::warn!(
tracing::warn!(
"Failed to get proof status ({}/{}): {:?}",
consecutive_errors,
MAX_CONSECUTIVE_ERRORS,
Expand All @@ -116,7 +116,7 @@ impl NetworkProver {
}
ProofStatus::ProofClaimed => {
if !is_claimed {
log::info!("Proof request claimed, proving...");
tracing::info!("Proof request claimed, proving...");
is_claimed = true;
}
}
Expand Down

0 comments on commit edbcc5f

Please sign in to comment.