@@ -25,6 +25,7 @@ use crate::blocking_check::{BlockingCheckClient, BlockingCheckResult};
2525use crate :: config:: ProverConfig ;
2626use crate :: errors:: VirtualSnosProverError ;
2727use crate :: running:: runner:: { RpcRunnerFactory , RunnerOutput , VirtualSnosRunner } ;
28+ use crate :: server:: metrics:: { names as metric_names, outcomes} ;
2829
2930/// Result of a successful prove transaction operation.
3031///
@@ -149,7 +150,28 @@ impl<R: VirtualSnosRunner + 'static> VirtualSnosProver<R> {
149150 transaction : RpcTransaction ,
150151 ) -> Result < ProveTransactionResult , VirtualSnosProverError > {
151152 let start_time = Instant :: now ( ) ;
153+ let result = self . prove_transaction_inner ( block_id, transaction) . await ;
154+ let total = start_time. elapsed ( ) ;
155+ // One histogram observation per request. Latency is bucketed and is
156+ // recorded regardless of outcome so SLO calculations (e.g. p99 over
157+ // success-only) can be done in the query layer.
158+ metrics:: histogram!( metric_names:: PROVE_TRANSACTION_DURATION_SECONDS )
159+ . record ( total. as_secs_f64 ( ) ) ;
160+ let outcome = match & result {
161+ Ok ( _) => outcomes:: SUCCESS ,
162+ Err ( err) => err. metric_outcome ( ) ,
163+ } ;
164+ metrics:: counter!( metric_names:: PROVE_TRANSACTION_OUTCOME_TOTAL , "outcome" => outcome)
165+ . increment ( 1 ) ;
166+ info ! ( total_duration_ms = %total. as_millis( ) , outcome, "prove_transaction completed" ) ;
167+ result
168+ }
152169
170+ async fn prove_transaction_inner (
171+ & self ,
172+ block_id : BlockId ,
173+ transaction : RpcTransaction ,
174+ ) -> Result < ProveTransactionResult , VirtualSnosProverError > {
153175 // Validate block_id is not pending.
154176 if matches ! ( block_id, BlockId :: Pending ) {
155177 return Err ( VirtualSnosProverError :: ValidationError (
@@ -162,15 +184,12 @@ impl<R: VirtualSnosRunner + 'static> VirtualSnosProver<R> {
162184 validate_transaction_input ( & invoke_v3, self . validate_zero_fee_fields ) ?;
163185 let invoke_tx = InvokeTransaction :: V3 ( invoke_v3. into ( ) ) ;
164186
165- let result = match & self . blocking_check_client {
166- None => self . run_and_prove ( block_id, vec ! [ invoke_tx] ) . await ? ,
187+ match & self . blocking_check_client {
188+ None => self . run_and_prove ( block_id, vec ! [ invoke_tx] ) . await ,
167189 Some ( client) => {
168- self . prove_with_blocking_check ( client, block_id, transaction, invoke_tx) . await ?
190+ self . prove_with_blocking_check ( client, block_id, transaction, invoke_tx) . await
169191 }
170- } ;
171-
172- info ! ( total_duration_ms = %start_time. elapsed( ) . as_millis( ) , "prove_transaction completed" ) ;
173- Ok ( result)
192+ }
174193 }
175194
176195 /// Runs the OS and generates a proof. This is the core proving pipeline.
@@ -186,18 +205,18 @@ impl<R: VirtualSnosRunner + 'static> VirtualSnosProver<R> {
186205 . await
187206 . map_err ( |err| VirtualSnosProverError :: RunnerError ( Box :: new ( err) ) ) ?;
188207
189- info ! (
190- os_duration_ms = %os_start . elapsed ( ) . as_millis ( ) ,
191- "OS execution completed"
192- ) ;
208+ let os_duration = os_start . elapsed ( ) ;
209+ metrics :: histogram! ( metric_names :: OS_RUN_DURATION_SECONDS )
210+ . record ( os_duration . as_secs_f64 ( ) ) ;
211+ info ! ( os_duration_ms = %os_duration . as_millis ( ) , "OS execution completed" ) ;
193212
194213 let prove_start = Instant :: now ( ) ;
195214 let result = self . prove_virtual_snos_run ( runner_output) . await ?;
196215
197- info ! (
198- prove_duration_ms = %prove_start . elapsed ( ) . as_millis ( ) ,
199- "Proving completed"
200- ) ;
216+ let prove_duration = prove_start . elapsed ( ) ;
217+ metrics :: histogram! ( metric_names :: STWO_PROVE_DURATION_SECONDS )
218+ . record ( prove_duration . as_secs_f64 ( ) ) ;
219+ info ! ( prove_duration_ms = %prove_duration . as_millis ( ) , "Proving completed" ) ;
201220
202221 Ok ( result)
203222 }
0 commit comments