From f9f5e5da36fb86629820d331f41101b0faf1756d Mon Sep 17 00:00:00 2001 From: Avi Cohen Date: Sun, 24 May 2026 19:39:18 +0300 Subject: [PATCH] starknet_transaction_prover: log errors at origin and keep transaction data out of failure logs --- .../starknet_transaction_prover/src/errors.rs | 15 +++++++ .../src/errors_test.rs | 32 ++++++++++++++ .../src/proving/virtual_snos_prover.rs | 43 +++++++++++++++---- .../src/server/rpc_impl.rs | 17 +++++++- 4 files changed, 97 insertions(+), 10 deletions(-) diff --git a/crates/starknet_transaction_prover/src/errors.rs b/crates/starknet_transaction_prover/src/errors.rs index ab15459a911..8e2310d4bed 100644 --- a/crates/starknet_transaction_prover/src/errors.rs +++ b/crates/starknet_transaction_prover/src/errors.rs @@ -155,6 +155,21 @@ impl VirtualSnosProverError { VirtualSnosProverError::ProvingError(_) => outcomes::FAILURE_PROVING, } } + + /// Whether this error's `Display` can embed data derived from the client's + /// transaction. These failures reach the operator's log aggregator, so `true` + /// means the caller must not render the message verbatim: + /// - `InvalidTransactionInput` quotes the client's fee inputs. `InvalidTransactionType` and + /// `ValidationError` carry a message payload, which defaults to sensitive. + /// - `TransactionReverted` carries the transaction hash and the revert reason. + /// - Runner, output-parse and proving errors can quote transaction-derived program output. + /// - A transport error renders the node URL, including any credentials in its path or query. + /// + /// Only variants that carry no payload at all are exempt, so a new variant + /// defaults to sensitive. + pub fn may_embed_transaction_data(&self) -> bool { + !matches!(self, VirtualSnosProverError::TransactionBlocked) + } } /// Errors that can occur during configuration. diff --git a/crates/starknet_transaction_prover/src/errors_test.rs b/crates/starknet_transaction_prover/src/errors_test.rs index b5c9b16cc02..0140730583a 100644 --- a/crates/starknet_transaction_prover/src/errors_test.rs +++ b/crates/starknet_transaction_prover/src/errors_test.rs @@ -1,7 +1,39 @@ use starknet_proof_verifier::ProgramOutputError; +use starknet_types_core::felt::Felt; use super::*; +/// The revert-reason variant carries the client's transaction hash and the +/// revert string, and these failures reach the operator's log aggregator. +#[test] +fn reverted_transaction_error_is_marked_as_carrying_transaction_data() { + let reverted = VirtualSnosProverError::RunnerError(Box::new( + RunnerError::VirtualBlockExecutor(VirtualBlockExecutorError::TransactionReverted( + TransactionHash(Felt::from_hex_unchecked("0x1234")), + "insufficient balance".to_string(), + )), + )); + + let rendered = reverted.to_string(); + assert!( + rendered.contains("0x1234") && rendered.contains("insufficient balance"), + "this test assumes Display embeds the hash and revert reason, got: {rendered}" + ); + assert!( + reverted.may_embed_transaction_data(), + "the revert reason and transaction hash must never be logged verbatim" + ); +} + +#[test] +fn only_payload_free_variants_may_be_logged_verbatim() { + assert!(!VirtualSnosProverError::TransactionBlocked.may_embed_transaction_data()); + assert!( + VirtualSnosProverError::ValidationError(String::new()).may_embed_transaction_data(), + "payload-carrying validation variants default to sensitive" + ); +} + #[test] fn metric_outcome_maps_each_variant_to_its_label() { let cases = [ diff --git a/crates/starknet_transaction_prover/src/proving/virtual_snos_prover.rs b/crates/starknet_transaction_prover/src/proving/virtual_snos_prover.rs index 1895bd39ae5..eb832978c22 100644 --- a/crates/starknet_transaction_prover/src/proving/virtual_snos_prover.rs +++ b/crates/starknet_transaction_prover/src/proving/virtual_snos_prover.rs @@ -19,7 +19,7 @@ use starknet_api::execution_resources::GasAmount; use starknet_api::rpc_transaction::{RpcInvokeTransaction, RpcInvokeTransactionV3, RpcTransaction}; use starknet_api::transaction::fields::{Proof, ProofFacts, Tip}; use starknet_api::transaction::{InvokeTransaction, MessageToL1}; -use tracing::{info, instrument}; +use tracing::{info, instrument, warn, Instrument, Span}; use url::Url; use crate::blocking_check::{BlockingCheckClient, BlockingCheckResult}; @@ -199,16 +199,28 @@ impl VirtualSnosProver { block_id: BlockId, transaction: RpcTransaction, ) -> Result { - // Validate block_id is not pending. if matches!(block_id, BlockId::Pending) { + warn!(event = "validation_error", reason = "pending_block_unsupported"); return Err(VirtualSnosProverError::ValidationError( "Pending blocks are not supported; only finalized blocks can be proven." .to_string(), )); } - let invoke_v3 = extract_rpc_invoke_tx(transaction.clone())?; - validate_transaction_input(&invoke_v3, self.validate_zero_fee_fields)?; + let invoke_v3 = extract_rpc_invoke_tx(transaction.clone()).inspect_err(|_err| { + // The log omits `error` because this variant carries a message payload, which + // defaults to sensitive under `may_embed_transaction_data`. The reason code + // carries all a reader needs. + warn!(event = "validation_error", reason = "non_invoke_transaction"); + })?; + validate_transaction_input(&invoke_v3, self.validate_zero_fee_fields).inspect_err( + |_err| { + // The log omits `error` because the invalid-input message quotes the client's + // fee inputs, and transaction data is private. The reason code carries all a + // reader needs. + warn!(event = "validation_error", reason = "invalid_transaction_input"); + }, + )?; let invoke_tx = InvokeTransaction::V3(invoke_v3.into()); match &self.blocking_check_client { @@ -230,14 +242,24 @@ impl VirtualSnosProver { .runner .run_virtual_os(block_id, txs) .await - .map_err(|err| VirtualSnosProverError::RunnerError(Box::new(err)))?; + .map_err(|err| VirtualSnosProverError::RunnerError(Box::new(err))) + .inspect_err(|_err| { + // The log omits `error` because a runner failure can quote the transaction hash + // and its revert reason. See + // `VirtualSnosProverError::may_embed_transaction_data`. + warn!(event = "os_run_error"); + })?; let os_duration = os_start.elapsed(); metrics::histogram!(names::OS_RUN_DURATION_SECONDS).record(os_duration.as_secs_f64()); info!(os_duration_ms = %os_duration.as_millis(), "OS execution completed"); let prove_start = Instant::now(); - let result = self.prove_virtual_snos_run(runner_output).await?; + let result = self.prove_virtual_snos_run(runner_output).await.inspect_err(|_err| { + // The log omits `error` because proving errors can quote transaction-derived + // program output. See `VirtualSnosProverError::may_embed_transaction_data`. + warn!(event = "proving_error"); + })?; let prove_duration = prove_start.elapsed(); metrics::histogram!(names::STWO_PROVE_DURATION_SECONDS) @@ -269,10 +291,13 @@ impl VirtualSnosProver { invoke_tx: InvokeTransaction, ) -> Result { // Kick off proving in parallel with the check. Clone is cheap: inner fields are - // Arcs or small configs. + // Arcs or small configs. `instrument` carries the ambient tracing span (request id and + // tx fields) into the spawned task, which starts without a span otherwise. let prover = self.clone(); - let prove_handle = - tokio::spawn(async move { prover.run_and_prove(block_id, vec![invoke_tx]).await }); + let prove_handle = tokio::spawn( + async move { prover.run_and_prove(block_id, vec![invoke_tx]).await } + .instrument(Span::current()), + ); let timeout_duration = std::time::Duration::from_millis(client.timeout_millis); let check_outcome = diff --git a/crates/starknet_transaction_prover/src/server/rpc_impl.rs b/crates/starknet_transaction_prover/src/server/rpc_impl.rs index 07e7e2134fe..2eb975ed90b 100644 --- a/crates/starknet_transaction_prover/src/server/rpc_impl.rs +++ b/crates/starknet_transaction_prover/src/server/rpc_impl.rs @@ -105,7 +105,22 @@ impl ProvingRpcServer for ProvingRpcServerImpl { let (_saturation_clear_guard, _permit) = self.acquire_worker_slot().await?; self.prover.prove_transaction(block_id, transaction).await.map_err(|err| { - warn!("prove_transaction failed: {:?}", err); + // This is not a duplicate of the origin-level breadcrumbs. Those name the step + // that failed. This is the single per-request record of the final outcome. + // `outcome` is the metric's bounded label set, so it is safe to log. The error + // message goes out only when it cannot carry client transaction data, because + // these logs leave the service. See `may_embed_transaction_data`. + let outcome = err.metric_outcome(); + if err.may_embed_transaction_data() { + warn!(event = "prove_transaction_failed", outcome, "prove_transaction failed"); + } else { + warn!( + event = "prove_transaction_failed", + outcome, + error = %err, + "prove_transaction failed", + ); + } ErrorObjectOwned::from(err) }) }