Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

chore: tracing everywhere #1817

Open
wants to merge 3 commits into
base: dev
Choose a base branch
from
Open

chore: tracing everywhere #1817

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
bf84c19
chore: tracing everywhere
nhtyy Nov 25, 2024
e9a14f5
fix: fmt
nhtyy Nov 25, 2024
7deecd6
fix: missing dep
nhtyy Nov 25, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 1 addition & 4 deletions Cargo.lock
View file
Open in desktop

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
View file
Open in desktop
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
View file
Open in desktop
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
View file
Open in desktop
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
View file
Open in desktop
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
View file
Open in desktop
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
View file
Open in desktop
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
2 changes: 1 addition & 1 deletion crates/recursion/gnark-ffi/Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,13 +19,13 @@ 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"
anyhow = "1.0.86"
sha2 = "0.10.8"
hex = "0.4.3"
tracing.workspace = true

[build-dependencies]
bindgen = "0.70.1"
Expand Down
6 changes: 3 additions & 3 deletions crates/recursion/gnark-ffi/src/ffi/docker.rs
View file
Open in desktop
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
View file
Open in desktop
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
View file
Open in desktop
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
27 changes: 15 additions & 12 deletions crates/sdk/src/network-v2/prover.rs
View file
Open in desktop
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,28 @@ 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 +161,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 +176,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
View file
Open in desktop
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
View file
Open in desktop
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
Loading