From 0fd3c6218d94acedd3aa5376198af886cff75a2c Mon Sep 17 00:00:00 2001 From: Alain Mebsout Date: Fri, 4 Jul 2025 11:59:24 +0200 Subject: [PATCH 1/6] Rollup-node: Log Etherlink block numbers and evaluation time This commit introduces logging for the time it takes to evaluate an Etherlink block within the smart rollup node. A new event, `eval_etherlink_block`, is added to log the block number and the evaluation time. This is achieved by recording a timestamp before the PVM evaluation and calculating the elapsed time after the kernel has signaled that the block has been stored. This provides valuable performance metrics for the Etherlink kernel. --- src/lib_smart_rollup_node/interpreter.ml | 1 + .../interpreter_event.ml | 28 ++++++++++++++++ src/lib_smart_rollup_node/node_context.ml | 33 +++++++++++++++++++ src/lib_smart_rollup_node/node_context.mli | 10 ++++++ .../node_context_loader.ml | 7 ++-- 5 files changed, 77 insertions(+), 2 deletions(-) diff --git a/src/lib_smart_rollup_node/interpreter.ml b/src/lib_smart_rollup_node/interpreter.ml index 1cbdc2b0c69d..b91e7e06f523 100644 --- a/src/lib_smart_rollup_node/interpreter.ml +++ b/src/lib_smart_rollup_node/interpreter.ml @@ -137,6 +137,7 @@ let transition_pvm (module Plugin : Protocol_plugin_sig.PARTIAL) node_ctxt ctxt } = Octez_telemetry.Trace.with_tzresult ~service_name:"Pvm" "eval_block" @@ fun _ -> + Node_context.reset_kernel_tracing () ; Plugin.Pvm.Fueled.Free.eval_block_inbox ~fuel:(Fuel.Free.of_ticks 0L) node_ctxt diff --git a/src/lib_smart_rollup_node/interpreter_event.ml b/src/lib_smart_rollup_node/interpreter_event.ml index 244c1c915a91..3b8372e7ce63 100644 --- a/src/lib_smart_rollup_node/interpreter_event.ml +++ b/src/lib_smart_rollup_node/interpreter_event.ml @@ -94,6 +94,31 @@ module Simple = struct ~level:Error ("exception", Data_encoding.string) ~pp1:Format.pp_print_string + + let eval_etherlink_block = + let ns_in_a_day = Int64.(mul 1_000_000_000L (of_int (24 * 3600))) in + let ns_to_span ns = + let d = Int64.div ns ns_in_a_day in + let ns = Int64.sub ns (Int64.mul d ns_in_a_day) in + let ps = Int64.mul ns 1000L in + Ptime.Span.of_d_ps (Int64.to_int d, ps) + |> Option.value ~default:(Ptime.Span.of_int_s (-1)) + in + let span_to_ns span = + let d, ps = Ptime.Span.to_d_ps span in + Int64.mul (Int64.of_int d) ns_in_a_day |> Int64.add (Int64.div ps 1000L) + in + let time_encoding = + Data_encoding.conv ns_to_span span_to_ns Time.System.Span.encoding + in + declare_2 + ~section + ~name:"smart_rollup_node_interpreter_eval_etherlink_block" + ~msg:"Evaluated Etherlink block {block_number} in {time}" + ~level:Info + ("block_number", Data_encoding.int31) + ("time", time_encoding) + ~pp2:(fun fmt ns -> Time.System.Span.pp_hum fmt (ns_to_span ns)) end (** [transition_pvm inbox_level hash tick n] emits the event that a PVM @@ -120,3 +145,6 @@ let fetched_incorrect_pre_image ~expected_hash ~content_hash = let patching_genesis_state patch = Simple.(emit patching_genesis_state) patch let fast_exec_panic exn = Simple.(emit fast_exec_panic) (Printexc.to_string exn) + +let eval_etherlink_block block_number time_ns = + Simple.(emit eval_etherlink_block) (block_number, time_ns) diff --git a/src/lib_smart_rollup_node/node_context.ml b/src/lib_smart_rollup_node/node_context.ml index 5895c9810fe8..4c525873d6f6 100644 --- a/src/lib_smart_rollup_node/node_context.ml +++ b/src/lib_smart_rollup_node/node_context.ml @@ -1181,6 +1181,39 @@ let wait_synchronized node_ctxt = if is_synchronized node_ctxt then Lwt.return_unit else Lwt_condition.wait node_ctxt.sync.on_synchronized +(** {2 Kernel tracing} *) + +type kernel_tracer = {mutable start_time : int64} + +let kernel_tracer = {start_time = Opentelemetry.Timestamp_ns.now_unix_ns ()} + +let kernel_store_block_re = Re.Str.regexp ".*Storing block \\([0-9]+\\)" + +let reset_kernel_tracing () = + kernel_tracer.start_time <- Opentelemetry.Timestamp_ns.now_unix_ns () + +let kernel_tracing config = + let open Lwt_syntax in + if not config.Configuration.etherlink then Event.kernel_debug + else fun msg -> + let* () = Event.kernel_debug msg in + let block_number = + if Re.Str.string_match kernel_store_block_re msg 0 then + try Re.Str.matched_group 1 msg |> int_of_string_opt with _ -> None + else None + in + match block_number with + | None -> return_unit + | Some block_number -> + let start_time = kernel_tracer.start_time in + let end_time = Opentelemetry.Timestamp_ns.now_unix_ns () in + let* () = + Interpreter_event.eval_etherlink_block + block_number + (Int64.sub end_time start_time) + in + return_unit + (**/**) module Internal_for_tests = struct diff --git a/src/lib_smart_rollup_node/node_context.mli b/src/lib_smart_rollup_node/node_context.mli index aabc1c4904ca..4d61bc4aade7 100644 --- a/src/lib_smart_rollup_node/node_context.mli +++ b/src/lib_smart_rollup_node/node_context.mli @@ -656,6 +656,16 @@ val is_synchronized : _ t -> bool already synchronized, it resolves immediately. *) val wait_synchronized : _ t -> unit Lwt.t +(** {2 Kernel tracing} *) + +(** Reset the kernel tracing with the current time. Call this function before + executing the PVM/kernel. *) +val reset_kernel_tracing : unit -> unit + +(** Kernel logging function to be used instead of [Event.kernel_log], which + extracts information from kernel logs to produce Opentelemetry traces. *) +val kernel_tracing : Configuration.t -> string -> unit Lwt.t + module Internal_for_tests : sig val write_protocols_in_store : [> `Write] store -> Store.Protocols.proto_info list -> unit tzresult Lwt.t diff --git a/src/lib_smart_rollup_node/node_context_loader.ml b/src/lib_smart_rollup_node/node_context_loader.ml index f418bfe68c10..626ec4a021dd 100644 --- a/src/lib_smart_rollup_node/node_context_loader.ml +++ b/src/lib_smart_rollup_node/node_context_loader.ml @@ -114,8 +114,11 @@ let init (cctxt : #Client_context.full) ~data_dir ~irmin_cache_size let*! kernel_debug_logger, kernel_debug_finaliser = let open Lwt_syntax in if configuration.log_kernel_debug then - make_kernel_logger Event.kernel_debug ?log_kernel_debug_file data_dir - else return (Event.kernel_debug, fun () -> return_unit) + make_kernel_logger + (kernel_tracing configuration) + ?log_kernel_debug_file + data_dir + else return (kernel_tracing configuration, fun () -> return_unit) in let global_block_watcher = Lwt_watcher.create_input () in let private_info = -- GitLab From 092b81f5a205e8d6894a9d1c73e41a98775fdaf3 Mon Sep 17 00:00:00 2001 From: Alain Mebsout Date: Fri, 4 Jul 2025 17:00:05 +0200 Subject: [PATCH 2/6] Rollup-node: Emit OpenTelemetry traces for Etherlink blocks This commit enhances the Etherlink block evaluation logging to emit OpenTelemetry traces. The `kernel_tracing` function now creates a new span for each evaluated Etherlink block. This span includes the block number as an attribute and is linked to the parent "eval_block" span. This provides more detailed and structured telemetry data, allowing for better observability of the rollup nodes performance. --- src/lib_smart_rollup_node/interpreter.ml | 4 +-- src/lib_smart_rollup_node/node_context.ml | 36 +++++++++++++++++++--- src/lib_smart_rollup_node/node_context.mli | 6 ++-- 3 files changed, 36 insertions(+), 10 deletions(-) diff --git a/src/lib_smart_rollup_node/interpreter.ml b/src/lib_smart_rollup_node/interpreter.ml index b91e7e06f523..8cc0a391365c 100644 --- a/src/lib_smart_rollup_node/interpreter.ml +++ b/src/lib_smart_rollup_node/interpreter.ml @@ -136,8 +136,8 @@ let transition_pvm (module Plugin : Protocol_plugin_sig.PARTIAL) node_ctxt ctxt num_ticks; } = Octez_telemetry.Trace.with_tzresult ~service_name:"Pvm" "eval_block" - @@ fun _ -> - Node_context.reset_kernel_tracing () ; + @@ fun scope -> + Node_context.reset_kernel_tracing scope ; Plugin.Pvm.Fueled.Free.eval_block_inbox ~fuel:(Fuel.Free.of_ticks 0L) node_ctxt diff --git a/src/lib_smart_rollup_node/node_context.ml b/src/lib_smart_rollup_node/node_context.ml index 4c525873d6f6..367b09779218 100644 --- a/src/lib_smart_rollup_node/node_context.ml +++ b/src/lib_smart_rollup_node/node_context.ml @@ -1183,14 +1183,19 @@ let wait_synchronized node_ctxt = (** {2 Kernel tracing} *) -type kernel_tracer = {mutable start_time : int64} +type kernel_tracer = { + mutable start_time : int64; + mutable scope : Opentelemetry.Scope.t option; +} -let kernel_tracer = {start_time = Opentelemetry.Timestamp_ns.now_unix_ns ()} +let kernel_tracer = + {start_time = Opentelemetry.Timestamp_ns.now_unix_ns (); scope = None} let kernel_store_block_re = Re.Str.regexp ".*Storing block \\([0-9]+\\)" -let reset_kernel_tracing () = - kernel_tracer.start_time <- Opentelemetry.Timestamp_ns.now_unix_ns () +let reset_kernel_tracing scope = + kernel_tracer.start_time <- Opentelemetry.Timestamp_ns.now_unix_ns () ; + kernel_tracer.scope <- Some scope let kernel_tracing config = let open Lwt_syntax in @@ -1212,7 +1217,28 @@ let kernel_tracing config = block_number (Int64.sub end_time start_time) in - return_unit + if not (Opentelemetry.Collector.has_backend ()) then return_unit + else + let trace_id, parent = + match kernel_tracer.scope with + | None -> (Opentelemetry.Trace_id.create (), None) + | Some scope -> (scope.trace_id, Some scope.span_id) + in + let span_id = Opentelemetry.Span_id.create () in + let scope = Opentelemetry.Scope.make ~trace_id ~span_id () in + let span, _ = + Opentelemetry.Span.create + ~attrs:[("etherlink.block.number", `Int block_number)] + ?parent + ~id:scope.span_id + ~trace_id:scope.trace_id + ~start_time + ~end_time + "eval_etherlink_block" + in + Opentelemetry.Trace.emit ~service_name:"rollup_node" [span] ; + kernel_tracer.start_time <- end_time ; + return_unit (**/**) diff --git a/src/lib_smart_rollup_node/node_context.mli b/src/lib_smart_rollup_node/node_context.mli index 4d61bc4aade7..2e43abc5ec83 100644 --- a/src/lib_smart_rollup_node/node_context.mli +++ b/src/lib_smart_rollup_node/node_context.mli @@ -658,9 +658,9 @@ val wait_synchronized : _ t -> unit Lwt.t (** {2 Kernel tracing} *) -(** Reset the kernel tracing with the current time. Call this function before - executing the PVM/kernel. *) -val reset_kernel_tracing : unit -> unit +(** Reset the kernel tracing with the current time and provided scope. Call this + function before executing the PVM/kernel. *) +val reset_kernel_tracing : Opentelemetry.Scope.t -> unit (** Kernel logging function to be used instead of [Event.kernel_log], which extracts information from kernel logs to produce Opentelemetry traces. *) -- GitLab From 33706ef8d1f669603094d2227530aef32753a8a8 Mon Sep 17 00:00:00 2001 From: Alain Mebsout Date: Fri, 4 Jul 2025 17:04:31 +0200 Subject: [PATCH 3/6] Rollup-node/refatcor: Remove redundant Etherlink block events This commit removes the `etherlink_blocks_processed` event and its associated logic from the rollup node daemon. This event has been made redundant by the recently introduced logging and OpenTelemetry traces for evaluated Etherlink blocks, which provide more precise and structured data. Removing the old event simplifies the code and avoids duplicate reporting. --- src/lib_smart_rollup_node/daemon_event.ml | 28 --------------- src/lib_smart_rollup_node/daemon_event.mli | 8 ----- .../rollup_node_daemon.ml | 35 ------------------- 3 files changed, 71 deletions(-) diff --git a/src/lib_smart_rollup_node/daemon_event.ml b/src/lib_smart_rollup_node/daemon_event.ml index 79706f91aba8..4593e5f53a21 100644 --- a/src/lib_smart_rollup_node/daemon_event.ml +++ b/src/lib_smart_rollup_node/daemon_event.ml @@ -53,20 +53,6 @@ module Simple = struct ("process_time", Time.System.Span.encoding) ~pp3:Ptime.Span.pp - let etherlink_blocks_processed = - declare_4 - ~section - ~name:"smart_rollup_node_daemon_etherlink_blocks_processed" - ~msg: - "{nb_blocks} Etherlink blocks (from {first_block} to {last_block}) \ - processed in {process_time}" - ~level:Notice - ("nb_blocks", Data_encoding.int31) - ("first_block", Data_encoding.int31) - ("last_block", Data_encoding.int31) - ("process_time", Time.System.Span.encoding) - ~pp4:Ptime.Span.pp - let new_head_degraded = declare_2 ~section @@ -242,20 +228,6 @@ let head_processing hash level = Simple.(emit head_processing (hash, level)) let new_head_processed hash level process_time = Simple.(emit new_head_processed (hash, level, process_time)) -let etherlink_blocks_processed ~etherlink_start_block ~etherlink_end_block - process_time = - match (etherlink_start_block, etherlink_end_block) with - | None, _ | _, None -> Lwt.return_unit - | Some start_block, Some end_block -> - let nb = end_block - start_block in - if nb <= 0 then Lwt.return_unit - else - let first_block = start_block + 1 in - Simple.( - emit - etherlink_blocks_processed - (nb, first_block, end_block, process_time)) - let new_head_degraded hash level = Simple.(emit new_head_degraded (hash, level)) let new_heads_iteration event = function diff --git a/src/lib_smart_rollup_node/daemon_event.mli b/src/lib_smart_rollup_node/daemon_event.mli index db48c2205d5f..cef0e42a9b8b 100644 --- a/src/lib_smart_rollup_node/daemon_event.mli +++ b/src/lib_smart_rollup_node/daemon_event.mli @@ -38,14 +38,6 @@ val head_processing : Block_hash.t -> int32 -> unit Lwt.t [level] in [process_time] seconds. *) val new_head_processed : Block_hash.t -> int32 -> Ptime.Span.t -> unit Lwt.t -(** [etherlink_blocks_processed ~etherlink_start_block ~etherlink_end_block - process_time] emits an event for Etherlink processed block levels if any. *) -val etherlink_blocks_processed : - etherlink_start_block:int option -> - etherlink_end_block:int option -> - Ptime.span -> - unit Lwt.t - (** [new_head_degraded hash level] emits an error event that indicates the rollup node is running in degraded modes and sees an L1 block [hash] and at the given [level]. *) diff --git a/src/lib_smart_rollup_node/rollup_node_daemon.ml b/src/lib_smart_rollup_node/rollup_node_daemon.ml index 49e503404819..0d1b3296b90f 100644 --- a/src/lib_smart_rollup_node/rollup_node_daemon.ml +++ b/src/lib_smart_rollup_node/rollup_node_daemon.ml @@ -124,25 +124,6 @@ let register_outbox_messages (module Plugin : Protocol_plugin_sig.S) node_ctxt let indexes = List.map fst outbox_messages in Node_context.register_outbox_messages node_ctxt ~outbox_level:level ~indexes -let etherlink_current_block pvm_plugin node_ctxt ctxt = - let open Lwt_syntax in - if node_ctxt.Node_context.config.etherlink then - Etherlink_specific.current_level pvm_plugin ctxt - else return_none - -let emit_etherlink_telemetry_events scope start_block end_block = - match (start_block, end_block) with - | Some start_block, Some end_block when end_block > start_block -> - let first_block = start_block + 1 in - List.iter - (fun block -> - Opentelemetry.Scope.add_event scope @@ fun () -> - Opentelemetry_lwt.Event.make - ~attrs:[("etherlink.block.number", `Int block)] - "rollup_node.processed_etherlink_block") - (first_block -- end_block) - | _ -> () - (* Process a L1 that we have never seen and for which we have processed the predecessor. *) let process_unseen_head ({node_ctxt; _} as state) ~catching_up ~predecessor @@ -159,9 +140,6 @@ let process_unseen_head ({node_ctxt; _} as state) ~catching_up ~predecessor let* () = handle_protocol_migration ~catching_up state head in let* rollup_ctxt = previous_context node_ctxt ~predecessor in let module Plugin = (val state.plugin) in - let*! etherlink_start_block = - etherlink_current_block (module Plugin.Pvm) node_ctxt rollup_ctxt - in let start_timestamp = Time.System.now () in let* inbox_hash, inbox, inbox_witness, messages = Plugin.Inbox.process_head node_ctxt ~predecessor head @@ -190,13 +168,6 @@ let process_unseen_head ({node_ctxt; _} as state) ~catching_up ~predecessor (Layer1.head_of_header head) (inbox, messages) in - let*! etherlink_end_block = - etherlink_current_block (module Plugin.Pvm) node_ctxt ctxt - in - emit_etherlink_telemetry_events - scope - etherlink_start_block - etherlink_end_block ; let*! context_hash = Context.commit ctxt in let* commitment_hash = Publisher.process_head @@ -242,12 +213,6 @@ let process_unseen_head ({node_ctxt; _} as state) ~catching_up ~predecessor let end_timestamp = Time.System.now () in let total_time = Ptime.diff end_timestamp start_timestamp in let process_time = Ptime.diff end_timestamp fetch_timestamp in - let*! () = - Daemon_event.etherlink_blocks_processed - ~etherlink_start_block - ~etherlink_end_block - process_time - in Metrics.wrap (fun () -> Metrics.Inbox.set_process_time process_time ; Metrics.Inbox.set_total_time total_time) ; -- GitLab From 53c8bb27dedd88deff20aff89a7c3541c21e7160 Mon Sep 17 00:00:00 2001 From: Alain Mebsout Date: Wed, 9 Jul 2025 15:02:44 +0200 Subject: [PATCH 4/6] Rollup node: don't trace Etherlink blocks in simulation This can conflict with the main rollup node kernel. --- src/lib_smart_rollup_node/node_context.ml | 59 +++++++++++-------- src/lib_smart_rollup_node/node_context.mli | 29 +++++---- .../node_context_loader.ml | 13 ++-- src/lib_smart_rollup_node/simulation.ml | 6 +- 4 files changed, 57 insertions(+), 50 deletions(-) diff --git a/src/lib_smart_rollup_node/node_context.ml b/src/lib_smart_rollup_node/node_context.ml index 367b09779218..55018a35f87b 100644 --- a/src/lib_smart_rollup_node/node_context.ml +++ b/src/lib_smart_rollup_node/node_context.ml @@ -158,29 +158,6 @@ let processing_lockfile_path ~data_dir = let gc_lockfile_path ~data_dir = Filename.concat data_dir "gc_lock" -let make_kernel_logger event ?log_kernel_debug_file logs_dir = - let open Lwt_syntax in - let path = - match log_kernel_debug_file with - | None -> Filename.concat logs_dir "kernel.log" - | Some path -> path - in - let path_dir = Filename.dirname path in - let* () = Lwt_utils_unix.create_dir path_dir in - let* fd = - Lwt_unix.openfile path Lwt_unix.[O_WRONLY; O_CREAT; O_APPEND] 0o0644 - in - let chan = - Lwt_io.of_fd ~close:(fun () -> Lwt_unix.close fd) ~mode:Lwt_io.Output fd - in - let kernel_debug msg = - let* () = Lwt_io.write chan msg in - let* () = Lwt_io.flush chan in - let* () = event msg in - return_unit - in - return (kernel_debug, fun () -> Lwt_io.close chan) - let checkout_context node_ctxt block_hash = let open Lwt_result_syntax in let* context_hash = Store.L2_blocks.find_context node_ctxt.store block_hash in @@ -1197,11 +1174,11 @@ let reset_kernel_tracing scope = kernel_tracer.start_time <- Opentelemetry.Timestamp_ns.now_unix_ns () ; kernel_tracer.scope <- Some scope -let kernel_tracing config = +let kernel_tracing config event = let open Lwt_syntax in - if not config.Configuration.etherlink then Event.kernel_debug + if not config.Configuration.etherlink then event else fun msg -> - let* () = Event.kernel_debug msg in + let* () = event msg in let block_number = if Re.Str.string_match kernel_store_block_re msg 0 then try Re.Str.matched_group 1 msg |> int_of_string_opt with _ -> None @@ -1240,6 +1217,36 @@ let kernel_tracing config = kernel_tracer.start_time <- end_time ; return_unit +let make_kernel_logger ~enable_tracing ?log_kernel_debug_file ~logs_dir + (config : Configuration.t) event = + let open Lwt_syntax in + let on_kernel_log = + if enable_tracing then kernel_tracing config event else event + in + if not config.log_kernel_debug then + return (on_kernel_log, fun () -> return_unit) + else + let path = + match log_kernel_debug_file with + | None -> Filename.concat logs_dir "kernel.log" + | Some path -> path + in + let path_dir = Filename.dirname path in + let* () = Lwt_utils_unix.create_dir path_dir in + let* fd = + Lwt_unix.openfile path Lwt_unix.[O_WRONLY; O_CREAT; O_APPEND] 0o0644 + in + let chan = + Lwt_io.of_fd ~close:(fun () -> Lwt_unix.close fd) ~mode:Lwt_io.Output fd + in + let kernel_debug msg = + let* () = Lwt_io.write chan msg in + let* () = Lwt_io.flush chan in + let* () = on_kernel_log msg in + return_unit + in + return (kernel_debug, fun () -> Lwt_io.close chan) + (**/**) module Internal_for_tests = struct diff --git a/src/lib_smart_rollup_node/node_context.mli b/src/lib_smart_rollup_node/node_context.mli index 2e43abc5ec83..3b9189cb638c 100644 --- a/src/lib_smart_rollup_node/node_context.mli +++ b/src/lib_smart_rollup_node/node_context.mli @@ -633,18 +633,6 @@ val get_last_context_split_level : _ t -> int32 option tzresult Lwt.t val save_context_split_level : _ rw_store -> int32 -> unit tzresult Lwt.t -(** {2 Helpers} *) - -(** [make_kernel_logger event ?log_kernel_debug_file logs_dir] returns two - functions [kernel_debug_logger] and [finaliser], to be used in the node - context. [kernel_debug_logger] writes kernel logs to - [logs_dir/log_kernel_debug_file] and emits them with the [event]. *) -val make_kernel_logger : - (string -> unit Lwt.t) -> - ?log_kernel_debug_file:string -> - string -> - ((string -> unit Lwt.t) * (unit -> unit Lwt.t)) Lwt.t - (** {2 Synchronization tracking} *) (** [is_synchronized node_ctxt] returns [true] iff the rollup node has processed @@ -662,9 +650,20 @@ val wait_synchronized : _ t -> unit Lwt.t function before executing the PVM/kernel. *) val reset_kernel_tracing : Opentelemetry.Scope.t -> unit -(** Kernel logging function to be used instead of [Event.kernel_log], which - extracts information from kernel logs to produce Opentelemetry traces. *) -val kernel_tracing : Configuration.t -> string -> unit Lwt.t +(** [make_kernel_logger ~enable_tracing ?log_kernel_debug_file ~logs_dir config + event] returns two functions [kernel_debug_logger] and [finaliser], to be + used in the node context. [kernel_debug_logger] writes kernel logs to + [logs_dir/log_kernel_debug_file] and emits them with the [event] + function. In addition if [enable_tracing = true] then information is + extracted from the kernel logs to emit Opentelemetry traces for + Etherlink. *) +val make_kernel_logger : + enable_tracing:bool -> + ?log_kernel_debug_file:string -> + logs_dir:string -> + Configuration.t -> + (string -> unit Lwt.t) -> + ((string -> unit Lwt.t) * (unit -> unit Lwt.t)) Lwt.t module Internal_for_tests : sig val write_protocols_in_store : diff --git a/src/lib_smart_rollup_node/node_context_loader.ml b/src/lib_smart_rollup_node/node_context_loader.ml index 626ec4a021dd..d38b87b170ee 100644 --- a/src/lib_smart_rollup_node/node_context_loader.ml +++ b/src/lib_smart_rollup_node/node_context_loader.ml @@ -112,13 +112,12 @@ let init (cctxt : #Client_context.full) ~data_dir ~irmin_cache_size else Lwt.return_unit in let*! kernel_debug_logger, kernel_debug_finaliser = - let open Lwt_syntax in - if configuration.log_kernel_debug then - make_kernel_logger - (kernel_tracing configuration) - ?log_kernel_debug_file - data_dir - else return (kernel_tracing configuration, fun () -> return_unit) + make_kernel_logger + ~enable_tracing:true + ?log_kernel_debug_file + ~logs_dir:data_dir + configuration + Event.kernel_debug in let global_block_watcher = Lwt_watcher.create_input () in let private_info = diff --git a/src/lib_smart_rollup_node/simulation.ml b/src/lib_smart_rollup_node/simulation.ml index c3c404b03f15..1537ee6445a5 100644 --- a/src/lib_smart_rollup_node/simulation.ml +++ b/src/lib_smart_rollup_node/simulation.ml @@ -61,9 +61,11 @@ let set_simulation_kernel_log ?log_kernel_debug_file in let log_kernel_debug_file = Filename.concat logs_dir file in Node_context.make_kernel_logger - Event.simulation_kernel_debug + ~enable_tracing:false ~log_kernel_debug_file - logs_dir + ~logs_dir + node_ctxt.config + Event.simulation_kernel_debug | _ -> return (Event.simulation_kernel_debug, fun () -> return_unit) in return {node_ctxt with kernel_debug_logger; finaliser} -- GitLab From c8dfb2a2ab8cbe211c630f24f7f3feafc9a97b3f Mon Sep 17 00:00:00 2001 From: Alain Mebsout Date: Wed, 9 Jul 2025 15:18:01 +0200 Subject: [PATCH 5/6] Rollup node/Configuration: move log_kernel_debug_file in config --- .../main_smart_rollup_node.ml | 9 ++++-- src/lib_smart_rollup_node/configuration.ml | 31 +++++++++++++------ src/lib_smart_rollup_node/configuration.mli | 3 ++ .../node_context_loader.ml | 13 +++++--- .../node_context_loader.mli | 1 - .../rollup_node_daemon.ml | 6 ++-- 6 files changed, 43 insertions(+), 20 deletions(-) diff --git a/src/bin_smart_rollup_node/main_smart_rollup_node.ml b/src/bin_smart_rollup_node/main_smart_rollup_node.ml index 3cf4bf61a97c..77ee16e69e71 100644 --- a/src/bin_smart_rollup_node/main_smart_rollup_node.ml +++ b/src/bin_smart_rollup_node/main_smart_rollup_node.ml @@ -43,7 +43,7 @@ let config_init_command = ~group ~desc:"Configure the smart rollup node." (merge_options - (args23 + (args24 force_switch data_dir_arg config_file_arg @@ -63,6 +63,7 @@ let config_init_command = index_buffer_size_arg index_buffer_size_arg log_kernel_debug_arg + log_kernel_debug_file_arg boot_sector_file_arg no_degraded_arg gc_frequency_arg @@ -98,6 +99,7 @@ let config_init_command = index_buffer_size, irmin_cache_size, log_kernel_debug, + log_kernel_debug_file, boot_sector_file, no_degraded, gc_frequency, @@ -140,6 +142,7 @@ let config_init_command = ~index_buffer_size ~irmin_cache_size ~log_kernel_debug + ~log_kernel_debug_file ~unsafe_disable_wasm_kernel_checks ~no_degraded ~gc_frequency @@ -266,6 +269,7 @@ let legacy_run_command = ~index_buffer_size ~irmin_cache_size ~log_kernel_debug + ~log_kernel_debug_file ~unsafe_disable_wasm_kernel_checks ~no_degraded ~gc_frequency @@ -280,7 +284,6 @@ let legacy_run_command = Rollup_node_daemon.run ~data_dir ~irmin_cache_size:Configuration.default_irmin_cache_size - ?log_kernel_debug_file configuration cctxt) @@ -393,6 +396,7 @@ let run_command = ~index_buffer_size ~irmin_cache_size ~log_kernel_debug + ~log_kernel_debug_file ~unsafe_disable_wasm_kernel_checks ~boot_sector_file ~no_degraded @@ -408,7 +412,6 @@ let run_command = Rollup_node_daemon.run ~data_dir ~irmin_cache_size:Configuration.default_irmin_cache_size - ?log_kernel_debug_file configuration cctxt) diff --git a/src/lib_smart_rollup_node/configuration.ml b/src/lib_smart_rollup_node/configuration.ml index 2f3b8e26947f..eaf01d61825b 100644 --- a/src/lib_smart_rollup_node/configuration.ml +++ b/src/lib_smart_rollup_node/configuration.ml @@ -96,6 +96,7 @@ type t = { index_buffer_size : int option; irmin_cache_size : int option; log_kernel_debug : bool; + log_kernel_debug_file : string option; unsafe_disable_wasm_kernel_checks : bool; no_degraded : bool; gc_parameters : gc_parameters; @@ -536,6 +537,7 @@ let encoding default_display : t Data_encoding.t = index_buffer_size; irmin_cache_size; log_kernel_debug; + log_kernel_debug_file; unsafe_disable_wasm_kernel_checks; no_degraded; gc_parameters; @@ -572,6 +574,7 @@ let encoding default_display : t Data_encoding.t = index_buffer_size, irmin_cache_size, log_kernel_debug, + log_kernel_debug_file, unsafe_disable_wasm_kernel_checks ), ( no_degraded, gc_parameters, @@ -607,6 +610,7 @@ let encoding default_display : t Data_encoding.t = index_buffer_size, irmin_cache_size, log_kernel_debug, + log_kernel_debug_file, unsafe_disable_wasm_kernel_checks ), ( no_degraded, gc_parameters, @@ -646,6 +650,7 @@ let encoding default_display : t Data_encoding.t = index_buffer_size; irmin_cache_size; log_kernel_debug; + log_kernel_debug_file; unsafe_disable_wasm_kernel_checks; no_degraded; gc_parameters; @@ -741,7 +746,7 @@ let encoding default_display : t Data_encoding.t = (dft "l2_blocks_cache_size" int31 default_l2_blocks_cache_size) (opt "prefetch_blocks" int31)) (merge_objs - (obj6 + (obj7 (dft "l1_rpc_timeout" Data_encoding.float @@ -753,6 +758,7 @@ let encoding default_display : t Data_encoding.t = (opt "index_buffer_size" int31 ~description:"Deprecated") (opt "irmin_cache_size" int31) (dft "log-kernel-debug" Data_encoding.bool false) + (opt "log-kernel-debug-file" Data_encoding.string) (dft "unsafe-disable-wasm-kernel-checks" Data_encoding.bool @@ -884,8 +890,8 @@ module Cli = struct ~dal_node_endpoint ~pre_images_endpoint ~injector_retention_period ~injector_attempts ~injection_ttl ~mode ~sc_rollup_address ~boot_sector_file ~operators ~index_buffer_size ~irmin_cache_size - ~log_kernel_debug ~no_degraded ~gc_frequency ~history_mode - ~allowed_origins ~allowed_headers ~apply_unsafe_patches + ~log_kernel_debug ~log_kernel_debug_file ~no_degraded ~gc_frequency + ~history_mode ~allowed_origins ~allowed_headers ~apply_unsafe_patches ~unsafe_disable_wasm_kernel_checks ~bail_on_disagree ~profiling ~force_etherlink = let open Lwt_result_syntax in @@ -943,6 +949,7 @@ module Cli = struct index_buffer_size; irmin_cache_size; log_kernel_debug; + log_kernel_debug_file; unsafe_disable_wasm_kernel_checks; no_degraded; gc_parameters = @@ -969,10 +976,10 @@ module Cli = struct ~reconnection_delay ~dal_node_endpoint ~pre_images_endpoint ~injector_retention_period ~injector_attempts ~injection_ttl ~mode ~sc_rollup_address ~boot_sector_file ~operators ~index_buffer_size - ~irmin_cache_size ~log_kernel_debug ~no_degraded ~gc_frequency - ~history_mode ~allowed_origins ~allowed_headers ~apply_unsafe_patches - ~unsafe_disable_wasm_kernel_checks ~bail_on_disagree ~profiling - ~force_etherlink = + ~irmin_cache_size ~log_kernel_debug ~log_kernel_debug_file ~no_degraded + ~gc_frequency ~history_mode ~allowed_origins ~allowed_headers + ~apply_unsafe_patches ~unsafe_disable_wasm_kernel_checks ~bail_on_disagree + ~profiling ~force_etherlink = let open Lwt_result_syntax in let mode = Option.value ~default:configuration.mode mode in let*? () = check_custom_mode mode in @@ -1044,6 +1051,10 @@ module Cli = struct irmin_cache_size = Option.either irmin_cache_size configuration.irmin_cache_size; log_kernel_debug = log_kernel_debug || configuration.log_kernel_debug; + log_kernel_debug_file = + Option.either + log_kernel_debug_file + configuration.log_kernel_debug_file; unsafe_disable_wasm_kernel_checks = unsafe_disable_wasm_kernel_checks || configuration.unsafe_disable_wasm_kernel_checks; @@ -1082,8 +1093,8 @@ module Cli = struct ~dal_node_endpoint ~pre_images_endpoint ~injector_retention_period ~injector_attempts ~injection_ttl ~mode ~sc_rollup_address ~boot_sector_file ~operators ~index_buffer_size ~irmin_cache_size - ~log_kernel_debug ~no_degraded ~gc_frequency ~history_mode - ~allowed_origins ~allowed_headers ~apply_unsafe_patches + ~log_kernel_debug ~log_kernel_debug_file ~no_degraded ~gc_frequency + ~history_mode ~allowed_origins ~allowed_headers ~apply_unsafe_patches ~unsafe_disable_wasm_kernel_checks ~bail_on_disagree ~profiling ~force_etherlink = let open Lwt_result_syntax in @@ -1114,6 +1125,7 @@ module Cli = struct ~index_buffer_size ~irmin_cache_size ~log_kernel_debug + ~log_kernel_debug_file ~no_degraded ~gc_frequency ~history_mode @@ -1167,6 +1179,7 @@ module Cli = struct ~index_buffer_size ~irmin_cache_size ~log_kernel_debug + ~log_kernel_debug_file ~no_degraded ~gc_frequency ~history_mode diff --git a/src/lib_smart_rollup_node/configuration.mli b/src/lib_smart_rollup_node/configuration.mli index 035efb5647ff..19a19992dbc2 100644 --- a/src/lib_smart_rollup_node/configuration.mli +++ b/src/lib_smart_rollup_node/configuration.mli @@ -138,6 +138,7 @@ type t = { index_buffer_size : int option; irmin_cache_size : int option; log_kernel_debug : bool; + log_kernel_debug_file : string option; unsafe_disable_wasm_kernel_checks : bool; no_degraded : bool; gc_parameters : gc_parameters; @@ -312,6 +313,7 @@ module Cli : sig index_buffer_size:int option -> irmin_cache_size:int option -> log_kernel_debug:bool -> + log_kernel_debug_file:string option -> no_degraded:bool -> gc_frequency:int32 option -> history_mode:history_mode option -> @@ -348,6 +350,7 @@ module Cli : sig index_buffer_size:int option -> irmin_cache_size:int option -> log_kernel_debug:bool -> + log_kernel_debug_file:string option -> no_degraded:bool -> gc_frequency:int32 option -> history_mode:history_mode option -> diff --git a/src/lib_smart_rollup_node/node_context_loader.ml b/src/lib_smart_rollup_node/node_context_loader.ml index d38b87b170ee..0dd373486f1c 100644 --- a/src/lib_smart_rollup_node/node_context_loader.ml +++ b/src/lib_smart_rollup_node/node_context_loader.ml @@ -64,13 +64,16 @@ let create_sync_info () = } let init (cctxt : #Client_context.full) ~data_dir ~irmin_cache_size - ?log_kernel_debug_file ?last_whitelist_update - ~(store_access : 'store Access_mode.t) + ?last_whitelist_update ~(store_access : 'store Access_mode.t) ~(context_access : 'context Access_mode.t) l1_ctxt genesis_info ~(lcc : lcc) ~lpc kind current_protocol Configuration.( - {sc_rollup_address = rollup_address; dal_node_endpoint; _} as - configuration) = + { + sc_rollup_address = rollup_address; + dal_node_endpoint; + log_kernel_debug_file; + _; + } as configuration) = let open Lwt_result_syntax in let* lockfile = lock ~data_dir in let metadata = @@ -242,6 +245,7 @@ module For_snapshots = struct irmin_cache_size = Some irmin_cache_size; prefetch_blocks = None; log_kernel_debug = false; + log_kernel_debug_file = None; no_degraded = false; gc_parameters = Configuration.default_gc_parameters; history_mode = None; @@ -359,6 +363,7 @@ module Internal_for_tests = struct l1_rpc_timeout; loop_retry_delay = 10.; log_kernel_debug = false; + log_kernel_debug_file = None; no_degraded = false; gc_parameters = Configuration.default_gc_parameters; history_mode = None; diff --git a/src/lib_smart_rollup_node/node_context_loader.mli b/src/lib_smart_rollup_node/node_context_loader.mli index c16835d7d7ba..e114505cdabb 100644 --- a/src/lib_smart_rollup_node/node_context_loader.mli +++ b/src/lib_smart_rollup_node/node_context_loader.mli @@ -39,7 +39,6 @@ val init : #Client_context.full -> data_dir:string -> irmin_cache_size:int -> - ?log_kernel_debug_file:string -> ?last_whitelist_update:Z.t * Int32.t -> store_access:([< `Read | `Write > `Read] as 'store) Access_mode.t -> context_access:([< `Read | `Write > `Read] as 'context) Access_mode.t -> diff --git a/src/lib_smart_rollup_node/rollup_node_daemon.ml b/src/lib_smart_rollup_node/rollup_node_daemon.ml index 0d1b3296b90f..c4ec2ddfb8c6 100644 --- a/src/lib_smart_rollup_node/rollup_node_daemon.ml +++ b/src/lib_smart_rollup_node/rollup_node_daemon.ml @@ -832,8 +832,8 @@ let setup_opentelemetry ~data_dir config = ~service_name:"rollup_node" config.Configuration.opentelemetry -let run ~data_dir ~irmin_cache_size ?log_kernel_debug_file - (configuration : Configuration.t) (cctxt : Client_context.full) = +let run ~data_dir ~irmin_cache_size (configuration : Configuration.t) + (cctxt : Client_context.full) = let open Lwt_result_syntax in let* () = Tezos_base_unix.Internal_event_unix.enable_default_daily_logs_at @@ -921,7 +921,6 @@ let run ~data_dir ~irmin_cache_size ?log_kernel_debug_file cctxt ~data_dir ~irmin_cache_size - ?log_kernel_debug_file ~store_access:Read_write ~context_access:Read_write l1_ctxt @@ -1027,6 +1026,7 @@ module Replay = struct ~index_buffer_size:None ~irmin_cache_size:None ~log_kernel_debug:true + ~log_kernel_debug_file:None ~unsafe_disable_wasm_kernel_checks:false ~no_degraded:true ~gc_frequency:None -- GitLab From 5a4ef1b06d2bf2dd76cf327b61c1d3b64f48169d Mon Sep 17 00:00:00 2001 From: Alain Mebsout Date: Wed, 9 Jul 2025 15:25:57 +0200 Subject: [PATCH 6/6] Rollup node: disable etherlink block tracing in refutation Also use a different event for refutation kernel log events and write refutation kernel logs in a dedicated directory. --- src/lib_smart_rollup_node/event.ml | 11 +++++++++++ src/lib_smart_rollup_node/event.mli | 4 ++++ src/lib_smart_rollup_node/refutation_coordinator.ml | 8 ++++++++ 3 files changed, 23 insertions(+) diff --git a/src/lib_smart_rollup_node/event.ml b/src/lib_smart_rollup_node/event.ml index c45662189c54..fa551ef952a1 100644 --- a/src/lib_smart_rollup_node/event.ml +++ b/src/lib_smart_rollup_node/event.ml @@ -107,6 +107,15 @@ module Simple = struct ("log", Data_encoding.string) ~pp1:Format.pp_print_string + let refutation_kernel_debug = + declare_1 + ~section + ~name:"refutation_kernel_debug" + ~level:Info + ~msg:"[refutation] {log}" + ("log", Data_encoding.string) + ~pp1:Format.pp_print_string + let warn_dal_enabled_no_node = declare_0 ~section @@ -218,6 +227,8 @@ let kernel_debug msg = Simple.(emit kernel_debug) msg let simulation_kernel_debug msg = Simple.(emit simulation_kernel_debug) msg +let refutation_kernel_debug msg = Simple.(emit refutation_kernel_debug) msg + let kernel_debug_dont_wait msg = Simple.(emit__dont_wait__use_with_care kernel_debug) msg diff --git a/src/lib_smart_rollup_node/event.mli b/src/lib_smart_rollup_node/event.mli index 6773c72e077a..c23f4847bb18 100644 --- a/src/lib_smart_rollup_node/event.mli +++ b/src/lib_smart_rollup_node/event.mli @@ -63,6 +63,10 @@ val kernel_debug : string -> unit Lwt.t [str] during a simulation. *) val simulation_kernel_debug : string -> unit Lwt.t +(** [refutation_kernel_debug str] emits the event that the kernel has logged + [str] during a refutation. *) +val refutation_kernel_debug : string -> unit Lwt.t + (** [kernel_debug str] emits the event that the kernel has logged [str]. (Doesn't wait for event to be emitted) *) val kernel_debug_dont_wait : string -> unit diff --git a/src/lib_smart_rollup_node/refutation_coordinator.ml b/src/lib_smart_rollup_node/refutation_coordinator.ml index 0dd1d4271016..9dacf71a4baf 100644 --- a/src/lib_smart_rollup_node/refutation_coordinator.ml +++ b/src/lib_smart_rollup_node/refutation_coordinator.ml @@ -197,6 +197,14 @@ let worker_promise, worker_waker = Lwt.task () let start (node_ctxt : _ Node_context.t) = let open Lwt_result_syntax in let*! () = Refutation_game_event.Coordinator.starting () in + let*! kernel_debug_logger, finaliser = + Node_context.make_kernel_logger + ~enable_tracing:false + ~logs_dir:(Filename.concat node_ctxt.data_dir "refutation") + node_ctxt.config + Event.refutation_kernel_debug + in + let node_ctxt = {node_ctxt with kernel_debug_logger; finaliser} in let+ worker = Worker.launch table () node_ctxt (module Handlers) in Lwt.wakeup worker_waker worker -- GitLab