From d81497d021b8174117da7fb556b246f61ca7f2eb Mon Sep 17 00:00:00 2001 From: "iguerNL@Functori" Date: Thu, 6 Mar 2025 11:29:12 +0100 Subject: [PATCH 1/7] Libs/event_logging: add the ability to prefix events names with sections --- src/lib_event_logging/internal_event.ml | 57 +++++++++++++++++------- src/lib_event_logging/internal_event.mli | 14 ++++++ 2 files changed, 54 insertions(+), 17 deletions(-) diff --git a/src/lib_event_logging/internal_event.ml b/src/lib_event_logging/internal_event.ml index 5c89b53af46f..9fd6eaca4c52 100644 --- a/src/lib_event_logging/internal_event.ml +++ b/src/lib_event_logging/internal_event.ml @@ -802,8 +802,15 @@ module Simple = struct ~name (Data_encoding.With_version.first_version encoding) - let declare_0 ?alternative_color ?section ~name ~msg ?(level = Info) () = + let may_prefix_name ~prefix_name_with_section ~name ~section = + match (prefix_name_with_section, section) with + | true, Some sections -> Format.asprintf "%a.%s" Section.pp sections name + | false, _ | true, None -> name + + let declare_0 ?alternative_color ?section ?(prefix_name_with_section = false) + ~name ~msg ?(level = Info) () = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [] msg in let module Definition : EVENT_DEFINITION with type t = unit = struct type t = unit @@ -830,9 +837,11 @@ module Simple = struct emit_at_top_level = (fun () -> Event.emit_at_top_level ()); } - let declare_1 (type a) ?alternative_color ?section ~name ~msg ?(level = Info) - ?pp1 (f1_name, (f1_enc : a Data_encoding.t)) = + let declare_1 (type a) ?alternative_color ?section + ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) ?pp1 + (f1_name, (f1_enc : a Data_encoding.t)) = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [f1_name] msg in let module Definition : EVENT_DEFINITION with type t = a = struct type t = a @@ -864,10 +873,12 @@ module Simple = struct emit_at_top_level = (fun parameter -> Event.emit_at_top_level parameter); } - let declare_2 (type a b) ?alternative_color ?section ~name ~msg - ?(level = Info) ?pp1 (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 + let declare_2 (type a b) ?alternative_color ?section + ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) ?pp1 + (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 (f2_name, (f2_enc : b Data_encoding.t)) = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [f1_name; f2_name] msg in let module Definition : EVENT_DEFINITION with type t = a * b = struct type t = a * b @@ -906,11 +917,13 @@ module Simple = struct emit_at_top_level = (fun parameters -> Event.emit_at_top_level parameters); } - let declare_3 (type a b c) ?alternative_color ?section ~name ~msg - ?(level = Info) ?pp1 (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 + let declare_3 (type a b c) ?alternative_color ?section + ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) ?pp1 + (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 (f2_name, (f2_enc : b Data_encoding.t)) ?pp3 (f3_name, (f3_enc : c Data_encoding.t)) = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [f1_name; f2_name; f3_name] msg in let module Definition : EVENT_DEFINITION with type t = a * b * c = struct type t = a * b * c @@ -951,12 +964,14 @@ module Simple = struct emit_at_top_level = (fun parameters -> Event.emit_at_top_level parameters); } - let declare_4 (type a b c d) ?alternative_color ?section ~name ~msg - ?(level = Info) ?pp1 (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 + let declare_4 (type a b c d) ?alternative_color ?section + ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) ?pp1 + (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 (f2_name, (f2_enc : b Data_encoding.t)) ?pp3 (f3_name, (f3_enc : c Data_encoding.t)) ?pp4 (f4_name, (f4_enc : d Data_encoding.t)) = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [f1_name; f2_name; f3_name; f4_name] msg in let module Definition : EVENT_DEFINITION with type t = a * b * c * d = struct @@ -1000,13 +1015,15 @@ module Simple = struct emit_at_top_level = (fun parameters -> Event.emit_at_top_level parameters); } - let declare_5 (type a b c d e) ?alternative_color ?section ~name ~msg - ?(level = Info) ?pp1 (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 + let declare_5 (type a b c d e) ?alternative_color ?section + ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) ?pp1 + (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 (f2_name, (f2_enc : b Data_encoding.t)) ?pp3 (f3_name, (f3_enc : c Data_encoding.t)) ?pp4 (f4_name, (f4_enc : d Data_encoding.t)) ?pp5 (f5_name, (f5_enc : e Data_encoding.t)) = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [f1_name; f2_name; f3_name; f4_name; f5_name] msg in @@ -1054,14 +1071,16 @@ module Simple = struct emit_at_top_level = (fun parameters -> Event.emit_at_top_level parameters); } - let declare_6 (type a b c d e f) ?alternative_color ?section ~name ~msg - ?(level = Info) ?pp1 (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 + let declare_6 (type a b c d e f) ?alternative_color ?section + ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) ?pp1 + (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 (f2_name, (f2_enc : b Data_encoding.t)) ?pp3 (f3_name, (f3_enc : c Data_encoding.t)) ?pp4 (f4_name, (f4_enc : d Data_encoding.t)) ?pp5 (f5_name, (f5_enc : e Data_encoding.t)) ?pp6 (f6_name, (f6_enc : f Data_encoding.t)) = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [f1_name; f2_name; f3_name; f4_name; f5_name; f6_name] msg in @@ -1111,8 +1130,9 @@ module Simple = struct emit_at_top_level = (fun parameters -> Event.emit_at_top_level parameters); } - let declare_7 (type a b c d e f g) ?alternative_color ?section ~name ~msg - ?(level = Info) ?pp1 (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 + let declare_7 (type a b c d e f g) ?alternative_color ?section + ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) ?pp1 + (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 (f2_name, (f2_enc : b Data_encoding.t)) ?pp3 (f3_name, (f3_enc : c Data_encoding.t)) ?pp4 (f4_name, (f4_enc : d Data_encoding.t)) ?pp5 @@ -1120,6 +1140,7 @@ module Simple = struct (f6_name, (f6_enc : f Data_encoding.t)) ?pp7 (f7_name, (f7_enc : g Data_encoding.t)) = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [f1_name; f2_name; f3_name; f4_name; f5_name; f6_name; f7_name] @@ -1173,8 +1194,9 @@ module Simple = struct emit_at_top_level = (fun parameters -> Event.emit_at_top_level parameters); } - let declare_8 (type a b c d e f g h) ?alternative_color ?section ~name ~msg - ?(level = Info) ?pp1 (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 + let declare_8 (type a b c d e f g h) ?alternative_color ?section + ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) ?pp1 + (f1_name, (f1_enc : a Data_encoding.t)) ?pp2 (f2_name, (f2_enc : b Data_encoding.t)) ?pp3 (f3_name, (f3_enc : c Data_encoding.t)) ?pp4 (f4_name, (f4_enc : d Data_encoding.t)) ?pp5 @@ -1183,6 +1205,7 @@ module Simple = struct (f7_name, (f7_enc : g Data_encoding.t)) ?pp8 (f8_name, (f8_enc : h Data_encoding.t)) = let section = make_section section in + let name = may_prefix_name ~prefix_name_with_section ~name ~section in let parsed_msg = parse_msg [f1_name; f2_name; f3_name; f4_name; f5_name; f6_name; f7_name; f8_name] diff --git a/src/lib_event_logging/internal_event.mli b/src/lib_event_logging/internal_event.mli index a4fb6a689d1e..47863f921053 100644 --- a/src/lib_event_logging/internal_event.mli +++ b/src/lib_event_logging/internal_event.mli @@ -214,6 +214,8 @@ module Simple : sig let inject = Internal_event.Simple.declare_2 ~name: "inject" + ~section:["foo"; "bar"] + ~prefix_name_with_sections:false ~msg: "injected block {hash}" ("level", int) ("hash", string) @@ -221,6 +223,9 @@ module Simple : sig You must declare events only once for a given name. Usually you should thus declare them as global variables. + A way to enforce name uniqueness is to set [prefix_name_with_sections] to [true]. + In the example above, this would compute a new event name of the form "foo.bar.inject". + There is one [declare_n] function for each number [n] of parameters. For instance, the above example uses [declare_2] because it has two parameters: [level] and [hash]. @@ -276,6 +281,7 @@ module Simple : sig val declare_0 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> @@ -286,6 +292,7 @@ module Simple : sig val declare_1 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> @@ -297,6 +304,7 @@ module Simple : sig val declare_2 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> @@ -310,6 +318,7 @@ module Simple : sig val declare_3 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> @@ -325,6 +334,7 @@ module Simple : sig val declare_4 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> @@ -342,6 +352,7 @@ module Simple : sig val declare_5 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> @@ -361,6 +372,7 @@ module Simple : sig val declare_6 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> @@ -382,6 +394,7 @@ module Simple : sig val declare_7 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> @@ -405,6 +418,7 @@ module Simple : sig val declare_8 : ?alternative_color:alternative_color -> ?section:string list -> + ?prefix_name_with_section:bool -> name:string -> msg:string -> ?level:level -> -- GitLab From 69f517ecf01b4e4d3e5468a1aafff55d986dba27 Mon Sep 17 00:00:00 2001 From: "iguerNL@Functori" Date: Fri, 7 Mar 2025 15:49:47 +0100 Subject: [PATCH 2/7] Lib_event_logging: use _ as seperator as . is not accepted in names --- src/lib_event_logging/internal_event.ml | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/lib_event_logging/internal_event.ml b/src/lib_event_logging/internal_event.ml index 9fd6eaca4c52..13901e3bd43b 100644 --- a/src/lib_event_logging/internal_event.ml +++ b/src/lib_event_logging/internal_event.ml @@ -804,8 +804,9 @@ module Simple = struct let may_prefix_name ~prefix_name_with_section ~name ~section = match (prefix_name_with_section, section) with - | true, Some sections -> Format.asprintf "%a.%s" Section.pp sections name | false, _ | true, None -> name + | true, Some sections -> + String.concat "_" (Section.to_string_list sections @ [name]) let declare_0 ?alternative_color ?section ?(prefix_name_with_section = false) ~name ~msg ?(level = Info) () = -- GitLab From cf3d1bc01cf58b660122028dbd2a22cec10d6add Mon Sep 17 00:00:00 2001 From: "iguerNL@Functori" Date: Tue, 18 Feb 2025 15:49:50 +0100 Subject: [PATCH 3/7] DAL/GS: better events logging --- src/lib_dal_node/gossipsub/gs_logging.ml | 51 +++++++++++-------- .../gossipsub/gs_transport_connection.ml | 21 ++++---- 2 files changed, 42 insertions(+), 30 deletions(-) diff --git a/src/lib_dal_node/gossipsub/gs_logging.ml b/src/lib_dal_node/gossipsub/gs_logging.ml index cb124451d5f9..190b1c8fe0e5 100644 --- a/src/lib_dal_node/gossipsub/gs_logging.ml +++ b/src/lib_dal_node/gossipsub/gs_logging.ml @@ -32,16 +32,13 @@ module Events = struct include Internal_event.Simple open Data_encoding - let section = ["gossipsub"; "worker"; "event"] - - let prefix = - let prefix = String.concat "_" section in - fun s -> prefix ^ "-" ^ s + let section = ["dal"; "gs"] let heartbeat = declare_0 ~section - ~name:(prefix "heartbeat") + ~prefix_name_with_section:true + ~name:"heartbeat" ~msg:"Process Heartbeat" ~level:Debug () @@ -49,7 +46,8 @@ module Events = struct let check_unknown_messages = declare_0 ~section - ~name:(prefix "check_unknown_messages") + ~prefix_name_with_section:true + ~name:"check_unknown_messages" ~msg:"Process unknown messages" ~level:Debug () @@ -57,7 +55,8 @@ module Events = struct let publish_message = declare_2 ~section - ~name:(prefix "publish_message") + ~prefix_name_with_section:true + ~name:"publish_message" ~msg:"Process Publish_message id {message_id} with topic {topic}" ~level:Debug ~pp1:GS.Topic.pp @@ -68,7 +67,8 @@ module Events = struct let join = declare_1 ~section - ~name:(prefix "join") + ~prefix_name_with_section:true + ~name:"join" ~msg:"Process Join {topic}" ~level:Info ~pp1:GS.Topic.pp @@ -77,7 +77,8 @@ module Events = struct let leave = declare_1 ~section - ~name:(prefix "leave") + ~prefix_name_with_section:true + ~name:"leave" ~msg:"Process Leave {topic}" ~level:Info ~pp1:GS.Topic.pp @@ -86,7 +87,8 @@ module Events = struct let new_connection = declare_4 ~section - ~name:(prefix "new_connection") + ~prefix_name_with_section:true + ~name:"new_connection" ~msg: "Process New_connection from/to {peer} (direct={direct}, \ trusted={trusted}, bootstrap={bootstrap})" @@ -100,7 +102,8 @@ module Events = struct let disconnection = declare_1 ~section - ~name:(prefix "disconnection") + ~prefix_name_with_section:true + ~name:"disconnection" ~msg:"Process Disconnection of {peer}" ~level:Notice ~pp1:Types.Peer.pp @@ -109,7 +112,8 @@ module Events = struct let message_with_header = declare_3 ~section - ~name:(prefix "message_with_header") + ~prefix_name_with_section:true + ~name:"message_with_header" ~msg: "Process Message_with_header from {peer} with id {message_id} and \ topic {topic}" @@ -124,7 +128,8 @@ module Events = struct let subscribe = declare_2 ~section - ~name:(prefix "subscribe") + ~prefix_name_with_section:true + ~name:"subscribe" ~msg:"Process Subscribe {peer} to {topic}" ~level:Info ~pp1:P2p_peer.Id.pp @@ -135,7 +140,8 @@ module Events = struct let ping = declare_1 ~section - ~name:(prefix "ping") + ~prefix_name_with_section:true + ~name:"ping" ~msg:"Process Ping from {peer}" ~level:Info ~pp1:P2p_peer.Id.pp @@ -144,7 +150,8 @@ module Events = struct let unsubscribe = declare_2 ~section - ~name:(prefix "unsubscribe") + ~prefix_name_with_section:true + ~name:"unsubscribe" ~msg:"Process Unsubscribe {peer} from {topic}" ~level:Info ~pp1:P2p_peer.Id.pp @@ -155,7 +162,8 @@ module Events = struct let graft = declare_2 ~section - ~name:(prefix "graft") + ~prefix_name_with_section:true + ~name:"graft" ~msg:"Process Graft {peer} for {topic}" ~level:Info ~pp1:P2p_peer.Id.pp @@ -166,7 +174,8 @@ module Events = struct let prune = declare_4 ~section - ~name:(prefix "prune") + ~prefix_name_with_section:true + ~name:"prune" ~msg:"Process Prune {peer} for {topic} with backoff {backoff} and px {px}" ~level:Info ~pp1:P2p_peer.Id.pp @@ -181,7 +190,8 @@ module Events = struct let ihave = declare_3 ~section - ~name:(prefix "ihave") + ~prefix_name_with_section:true + ~name:"ihave" ~msg: "Process IHave from {peer} for {topic} with message_ids {message_ids}" ~level:Info @@ -195,7 +205,8 @@ module Events = struct let iwant = declare_2 ~section - ~name:(prefix "iwant") + ~prefix_name_with_section:true + ~name:"iwant" ~msg:"Process IWant from {peer} with message_ids {message_ids}" ~level:Info ~pp1:P2p_peer.Id.pp diff --git a/src/lib_dal_node/gossipsub/gs_transport_connection.ml b/src/lib_dal_node/gossipsub/gs_transport_connection.ml index 8ba136b07cd8..2e0b20767676 100644 --- a/src/lib_dal_node/gossipsub/gs_transport_connection.ml +++ b/src/lib_dal_node/gossipsub/gs_transport_connection.ml @@ -30,16 +30,13 @@ open Gs_interface.Worker_instance module Events = struct include Internal_event.Simple - let section = ["gossipsub"; "transport"; "event"] - - let prefix = - let prefix = String.concat "_" section in - fun s -> prefix ^ "-" ^ s + let section = ["dal"; "gs"] let no_connection_for_peer = declare_1 ~section - ~name:(prefix "no_connection_for_peer") + ~prefix_name_with_section:true + ~name:"no_connection_for_peer" ~msg:"No running connection found for peer {peer}" ~level:Notice ~pp1:P2p_peer.Id.pp @@ -48,7 +45,8 @@ module Events = struct let message_notified_to_app = declare_1 ~section - ~name:(prefix "message_notified_to_app") + ~prefix_name_with_section:true + ~name:"message_notified_to_app" ~msg:"Successfully notified message id {message_id} to the application" ~level:Info ~pp1:Worker.GS.Message_id.pp @@ -57,7 +55,8 @@ module Events = struct let app_message_callback_failed = declare_2 ~section - ~name:(prefix "app_message_callback_failed") + ~prefix_name_with_section:true + ~name:"app_message_callback_failed" ~msg:"Callback failed for message id {message_id}. Failure is {failure}" ~level:Warning ~pp1:Worker.GS.Message_id.pp @@ -68,7 +67,8 @@ module Events = struct let send_p2p_message_failed = declare_2 ~section - ~name:(prefix "p2p_send_failed") + ~prefix_name_with_section:true + ~name:"p2p_send_failed" ~msg:"Sending P2P message to {peer} failed with error {failure}" ~level:Warning ~pp1:P2p_peer.Id.pp @@ -79,7 +79,8 @@ module Events = struct let send_p2p_message = declare_2 ~section - ~name:(prefix "p2p_send") + ~prefix_name_with_section:true + ~name:"p2p_send" ~msg:"Sending to {peer} P2P message {message}" ~level:Debug ~pp1:P2p_peer.Id.pp -- GitLab From 2127c85e85dc7e22e28c7990a6d3c9dbb045c3a4 Mon Sep 17 00:00:00 2001 From: "iguerNL@Functori" Date: Fri, 7 Mar 2025 12:31:04 +0100 Subject: [PATCH 4/7] Lib crawler: improve events names --- src/lib_crawler/layer1_event.ml | 45 +++++++++++++-------------------- 1 file changed, 18 insertions(+), 27 deletions(-) diff --git a/src/lib_crawler/layer1_event.ml b/src/lib_crawler/layer1_event.ml index 782572db9893..8c9342d8e3b2 100644 --- a/src/lib_crawler/layer1_event.ml +++ b/src/lib_crawler/layer1_event.ml @@ -27,11 +27,12 @@ module Simple = struct include Internal_event.Simple - let section = ["lib_crawler"; "layer_1"] + let section = ["l1_crawler"] let declare_0 ~name ~msg ?level () = declare_1 ~section + ~prefix_name_with_section:true ~name ~msg:("[{name}] " ^ msg) ?level @@ -41,6 +42,7 @@ module Simple = struct let declare_1 ~name ~msg ?level ?pp1 enc1 = declare_2 ~section + ~prefix_name_with_section:true ~name ~msg:("[{name}] " ^ msg) ?level @@ -52,6 +54,7 @@ module Simple = struct let declare_2 ~name ~msg ?level ?pp1 ?pp2 enc1 enc2 = declare_3 ~section + ~prefix_name_with_section:true ~name ~msg:("[{name}] " ^ msg) ?level @@ -63,29 +66,21 @@ module Simple = struct ?pp3:pp2 let starting = - declare_0 - ~name:"lib_crawler_layer_1_starting" - ~msg:"Starting layer 1 tracker" - ~level:Notice - () + declare_0 ~name:"starting" ~msg:"Starting layer 1 tracker" ~level:Notice () let stopping = - declare_0 - ~name:"lib_crawler_layer_1_stopping" - ~msg:"Stopping layer 1 tracker" - ~level:Notice - () + declare_0 ~name:"stopping" ~msg:"Stopping layer 1 tracker" ~level:Notice () let connection_lost = declare_0 - ~name:"lib_crawler_connection_lost" + ~name:"connection_lost" ~msg:"connection to the node has been lost" ~level:Warning () let connection_timeout = declare_1 - ~name:"lib_crawler_connection_timeout" + ~name:"connection_timeout" ~msg: "Connection to the node has timeout after {timeout}s waiting for a new \ head" @@ -94,7 +89,7 @@ module Simple = struct let cannot_connect = declare_2 - ~name:"lib_crawler_cannot_connect" + ~name:"cannot_connect" ~msg:"cannot connect to Tezos node ({count}) {error}" ~level:Warning ("count", Data_encoding.int31) @@ -103,57 +98,53 @@ module Simple = struct let wait_reconnect = declare_1 - ~name:"lib_crawler_wait_reconnect" + ~name:"wait_reconnect" ~msg:"Retrying to connect in {delay}s" ~level:Warning ("delay", Data_encoding.float) let switched_new_head = declare_2 - ~name:"lib_crawler_layer_1_new_head" - ~msg:"Layer 1 node has switched to head {hash} at level {level}" + ~name:"new_head" + ~msg:"L1 node switched to head {hash} at level {level}" ~level:Info ("hash", Block_hash.encoding) ("level", Data_encoding.int32) let connected = - declare_0 - ~name:"lib_crawler_connected" - ~msg:"Connected to L1 node" - ~level:Debug - () + declare_0 ~name:"connected" ~msg:"Connected to L1 node" ~level:Debug () let stopping_old_connection = declare_0 - ~name:"lib_crawler_stopping_old_connection" + ~name:"stopping_old_connection" ~msg:"Stopping previous L1 connection before reconnecting" ~level:Debug () let reconnect_connecting = declare_0 - ~name:"lib_crawler_reconnect_connecting" + ~name:"reconnect_connecting" ~msg:"Reconnect, already pending reconnection, wait" ~level:Debug () let reconnect_notified = declare_0 - ~name:"lib_crawler_reconnect_notified" + ~name:"reconnect_notified" ~msg:"Notified of reconnection" ~level:Debug () let reconnect_disconnected = declare_0 - ~name:"lib_crawler_reconnect_disconnected" + ~name:"reconnect_disconnected" ~msg:"Reconnect on disconnected, connect" ~level:Debug () let reconnect_connected = declare_0 - ~name:"lib_crawler_reconnect_connected" + ~name:"reconnect_connected" ~msg:"Reconnect on connected, force reconnection" ~level:Debug () -- GitLab From efbb2411d485f02e1283769df6b953f9e02969ed Mon Sep 17 00:00:00 2001 From: "iguerNL@Functori" Date: Fri, 7 Mar 2025 12:31:41 +0100 Subject: [PATCH 5/7] DAL/Node: better/shorter events names --- src/bin_dal_node/daemon.ml | 21 ++++-- src/bin_dal_node/event.ml | 142 +++++++++++++++++++++++++++++-------- 2 files changed, 130 insertions(+), 33 deletions(-) diff --git a/src/bin_dal_node/daemon.ml b/src/bin_dal_node/daemon.ml index c8f0960c53b7..f76d5cd75c50 100644 --- a/src/bin_dal_node/daemon.ml +++ b/src/bin_dal_node/daemon.ml @@ -615,7 +615,8 @@ module Handler = struct in return_unit - let process_block ctxt cctxt proto_parameters finalized_shell_header = + let process_block ctxt cctxt proto_parameters finalized_shell_header + finalized_block_hash = let open Lwt_result_syntax in let store = Node_context.get_store ctxt in let block_level = finalized_shell_header.Block_header.level in @@ -715,17 +716,25 @@ module Handler = struct Dal_metrics.layer1_block_finalized ~block_level ; Dal_metrics.layer1_block_finalized_round ~block_round ; let*! () = - Event.emit_layer1_node_final_block ~level:block_level ~round:block_round + Event.emit_layer1_node_final_block + ~hash:finalized_block_hash + ~level:block_level + ~round:block_round in (* This should be done at the end of the function. *) let last_processed_level_store = Store.last_processed_level store in Store.Last_processed_level.save last_processed_level_store block_level let rec try_process_block ~retries ctxt cctxt proto_parameters - finalized_shell_header = + finalized_shell_header finalized_block_hash = let open Lwt_syntax in let* res = - process_block ctxt cctxt proto_parameters finalized_shell_header + process_block + ctxt + cctxt + proto_parameters + finalized_shell_header + finalized_block_hash in match res with | Error e when Layer_1.is_connection_error e && retries > 0 -> @@ -736,6 +745,7 @@ module Handler = struct cctxt proto_parameters finalized_shell_header + finalized_block_hash | _ -> return res (* Monitor finalized heads and store *finalized* published slot headers @@ -752,7 +762,7 @@ module Handler = struct let*! next_final_head = Lwt_stream.get stream in match next_final_head with | None -> Lwt.fail_with "L1 crawler lib shut down" - | Some (_finalized_hash, finalized_shell_header) -> + | Some (finalized_block_hash, finalized_shell_header) -> let level = finalized_shell_header.level in let () = Node_context.set_last_finalized_level ctxt level in let* () = @@ -803,6 +813,7 @@ module Handler = struct cctxt proto_parameters finalized_shell_header + finalized_block_hash in loop () in diff --git a/src/bin_dal_node/event.ml b/src/bin_dal_node/event.ml index 55b01f57b98d..e82e218ade7e 100644 --- a/src/bin_dal_node/event.ml +++ b/src/bin_dal_node/event.ml @@ -35,12 +35,13 @@ let pp_int_list fmt l = (* DAL node event definitions *) open struct - let section = ["dal"; "node"] + let section = ["dal"] let starting_node = declare_0 ~section - ~name:"starting_dal_node" + ~prefix_name_with_section:true + ~name:"starting" ~msg:"starting the DAL node" ~level:Notice () @@ -48,7 +49,8 @@ open struct let waiting_l1_node_bootstrapped = declare_0 ~section - ~name:"waiting_l1_node_to_be_bootstrapped" + ~prefix_name_with_section:true + ~name:"waiting_l1_node_to_bootstrap" ~msg:"waiting for the L1 node to be bootstrapped" ~level:Notice () @@ -56,7 +58,8 @@ open struct let l1_node_bootstrapped = declare_0 ~section - ~name:"l1_node_is_bootstrapped" + ~prefix_name_with_section:true + ~name:"l1_node_bootstrapped" ~msg:"the L1 node is bootstrapped" ~level:Notice () @@ -64,6 +67,7 @@ open struct let waiting_known_plugin = declare_0 ~section + ~prefix_name_with_section:true ~name:"waiting_l1_node_known_plugin" ~msg:"waiting for a block with a known protocol plugin" ~level:Notice @@ -72,7 +76,8 @@ open struct let shutdown_node = declare_1 ~section - ~name:"stopping_dal_node" + ~prefix_name_with_section:true + ~name:"stopping" ~msg:"stopping DAL node" ~level:Notice ("exit_status", Data_encoding.int8) @@ -80,7 +85,8 @@ open struct let dal_node_sqlite3_store_init = declare_0 ~section - ~name:"dal_node_sqlite3_store_init" + ~prefix_name_with_section:true + ~name:"sqlite3_store_init" ~msg:"initializing the SQLite3 store" ~level:Info () @@ -88,7 +94,8 @@ open struct let store_is_ready = declare_0 ~section - ~name:"dal_node_store_is_ready" + ~prefix_name_with_section:true + ~name:"store_is_ready" ~msg:"the DAL node store is ready" ~level:Notice () @@ -96,7 +103,8 @@ open struct let node_is_ready = declare_0 ~section - ~name:"dal_node_is_ready" + ~prefix_name_with_section:true + ~name:"is_ready" ~msg:"the DAL node is ready" ~level:Notice () @@ -104,7 +112,8 @@ open struct let data_dir_not_found = declare_1 ~section - ~name:"dal_node_no_data_dir" + ~prefix_name_with_section:true + ~name:"no_data_dir" ~msg: "the DAL node configuration file does not exist in {path}, creating one" ~level:Warning @@ -113,6 +122,7 @@ open struct let retry_fetching_node_config level prefix = declare_2 ~section + ~prefix_name_with_section:true ~name:(prefix ^ "retry_fetching_config") ~msg: "cannot fetch config from l1 node at {endpoint}, retrying in {delay}s" @@ -129,6 +139,7 @@ open struct let config_error_no_bootstrap = declare_0 ~section + ~prefix_name_with_section:true ~name:"config_error_no_bootstrap" ~msg: "no bootstrap peers found in the configuration file or network settings" @@ -138,6 +149,7 @@ open struct let resolved_bootstrap_points = declare_2 ~section + ~prefix_name_with_section:true ~name:"resolved_bootstrap_points" ~msg: "DNS resolution of {domainname} returned {number} bootstrap IP \ @@ -149,6 +161,7 @@ open struct let resolved_bootstrap_no_points = declare_0 ~section + ~prefix_name_with_section:true ~name:"resolved_bootstrap_no_points" ~msg:"DNS resolution returned no bootstrap IP address" ~level:Error @@ -157,6 +170,7 @@ open struct let resolved_bootstrap_points_total = declare_1 ~section + ~prefix_name_with_section:true ~name:"resolved_bootstrap_points_total" ~msg:"DNS resolution returned a total of {number} bootstrap IP addresses" ~level:Notice @@ -165,6 +179,7 @@ open struct let fetched_config_success = declare_1 ~section + ~prefix_name_with_section:true ~name:"fetched_config_success" ~msg:"success fetching config from l1 node at {endpoint}" ~level:Notice @@ -173,6 +188,7 @@ open struct let failed_to_persist_profiles = declare_2 ~section + ~prefix_name_with_section:true ~name:"failed_to_persist_profiles" ~msg:"failed to persist the profiles to the config file" ~level:Error @@ -182,6 +198,7 @@ open struct let fetched_slot = declare_2 ~section + ~prefix_name_with_section:true ~name:"reconstructed_slot" ~msg:"reconstructed slot: size {size}, shards {shards}" ~level:Info @@ -191,28 +208,33 @@ open struct let layer1_node_new_head = declare_3 ~section - ~name:"dal_node_layer_1_new_head" - ~msg: - "head of Layer 1 node updated to {hash} at level {level}, fitness \ - {fitness}" + ~prefix_name_with_section:true + ~name:"new_L1_head_block" + ~msg:"L1 head updated to {hash} at level {level}, fitness {fitness}" ~level:Info + ~pp1:Block_hash.pp_short + ~pp3:Fitness.pp ("hash", Block_hash.encoding) ("level", Data_encoding.int32) ("fitness", Fitness.encoding) let layer1_node_final_block = - declare_2 + declare_3 ~section - ~name:"dal_node_layer_1_new_final_block" - ~msg:"layer 1 node's block at level {level}, round {round} is final" + ~prefix_name_with_section:true + ~name:"new_L1_final_block" + ~msg:"Finalized block {hash} at level {level}, round {round}" ~level:Notice + ~pp1:Block_hash.pp + ("hash", Block_hash.encoding) ("level", Data_encoding.int32) ("round", Data_encoding.int32) let layer1_node_tracking_started = declare_0 ~section - ~name:"dal_node_layer_1_start_tracking" + ~prefix_name_with_section:true + ~name:"start_tracking_L1" ~msg:"started tracking layer 1's node" ~level:Notice () @@ -220,7 +242,8 @@ open struct let protocol_plugin_resolved = declare_1 ~section - ~name:"dal_node_plugin_resolved" + ~prefix_name_with_section:true + ~name:"plugin_resolved" ~msg:"resolved plugin on protocol {proto_hash}" ~level:Notice ~pp1:Protocol_hash.pp_short @@ -229,7 +252,8 @@ open struct let no_protocol_plugin = declare_1 ~section - ~name:"dal_node_no_plugin" + ~prefix_name_with_section:true + ~name:"no_plugin" ~msg:"could not resolve plugin for protocol {proto_hash}" ~level:Error ~pp1:Protocol_hash.pp_short @@ -238,7 +262,8 @@ open struct let unexpected_protocol_plugin = declare_0 ~section - ~name:"dal_node_unexpected_plugin" + ~prefix_name_with_section:true + ~name:"unexpected_plugin" ~msg: "found plugin for the current protocol, expected one for the next \ protocol." @@ -248,7 +273,8 @@ open struct let daemon_error = declare_1 ~section - ~name:"dal_node_daemon_error" + ~prefix_name_with_section:true + ~name:"daemon_error" ~msg:"daemon thrown an error: {error}" ~level:Notice ~pp1:Error_monad.pp_print_trace @@ -257,7 +283,8 @@ open struct let failed_to_fetch_block = declare_4 ~section - ~name:"dal_node_crawler_failed_to_fetch_header" + ~prefix_name_with_section:true + ~name:"crawler_failed_to_fetch_header" ~msg: "the crawler failed to fetch the block {type} at level {level} (for \ last_notified_level {last_notified}): {error}\n\ @@ -274,7 +301,8 @@ open struct let history_mode_warning = declare_2 ~section - ~name:"dal_node_history_mode_warning" + ~prefix_name_with_section:true + ~name:"history_mode_warning" ~msg: "The node will only store data related to the last {stored_levels} \ levels, but it should store data for {storage_period} levels in order \ @@ -286,6 +314,7 @@ open struct let configuration_loaded = declare_0 ~section + ~prefix_name_with_section:true ~name:"configuration_loaded" ~msg:"configuration loaded successfully" ~level:Notice @@ -294,6 +323,7 @@ open struct let stored_slot_content = declare_2 ~section + ~prefix_name_with_section:true ~name:"stored_slot_content" ~msg:"stored slot for level {published_level} and index {slot_index}" ~level:Info @@ -303,6 +333,7 @@ open struct let stored_slot_shard = declare_3 ~section + ~prefix_name_with_section:true ~name:"stored_slot_shard" ~msg: "stored shard {shard_index} for level {published_level} and index \ @@ -315,6 +346,7 @@ open struct let stored_slot_status = declare_3 ~section + ~prefix_name_with_section:true ~name:"stored_slot_status" ~msg: "stored slot status for level {published_level} and index \ @@ -327,6 +359,7 @@ open struct let removed_slot_shards = declare_2 ~section + ~prefix_name_with_section:true ~name:"removed_slot_shards" ~msg:"removed shards for level {published_level} and index {slot_index}" ~level:Debug @@ -336,6 +369,7 @@ open struct let removed_slot = declare_2 ~section + ~prefix_name_with_section:true ~name:"removed_slot" ~msg:"removed slot for level {published_level} and index {slot_index}" ~level:Debug @@ -345,6 +379,7 @@ open struct let removed_status = declare_1 ~section + ~prefix_name_with_section:true ~name:"removed_status" ~msg:"removed statuses for level {level}" ~level:Debug @@ -353,6 +388,7 @@ open struct let slot_header_status_storage_error = declare_3 ~section + ~prefix_name_with_section:true ~name:"slot_header_status_storage_error" ~msg: "slot header status storage error for level {published_level}, slot \ @@ -365,6 +401,7 @@ open struct let unexpected_slot_header_status = declare_4 ~section + ~prefix_name_with_section:true ~name:"unexpected_slot_header_status" ~msg: "Internal error: unexpected slot header status {got_status}, expected \ @@ -381,6 +418,7 @@ open struct let removed_skip_list_cells = declare_1 ~section + ~prefix_name_with_section:true ~name:"removed_skip_list_cells" ~msg:"removed skip list cells for level {level}" ~level:Debug @@ -389,6 +427,7 @@ open struct let removing_shards_failed = declare_3 ~section + ~prefix_name_with_section:true ~name:"removing_shards_failed" ~level:Warning ~msg: @@ -401,6 +440,7 @@ open struct let removing_slot_failed = declare_3 ~section + ~prefix_name_with_section:true ~name:"removing_slot_failed" ~level:Warning ~msg: @@ -413,6 +453,7 @@ open struct let removing_status_failed = declare_2 ~section + ~prefix_name_with_section:true ~name:"removing_status_failed" ~level:Warning ~msg:"removing status file for level {level} failed: {error}" @@ -422,6 +463,7 @@ open struct let removing_skip_list_cells_failed = declare_2 ~section + ~prefix_name_with_section:true ~name:"removing_skip_list_cells_failed" ~level:Warning ~msg:"removing skip list cells for level {level} failed: {error}" @@ -431,6 +473,7 @@ open struct let decoding_data_failed = declare_1 ~section + ~prefix_name_with_section:true ~name:"decoding_failed" ~msg:"error while decoding a {data_kind} value" ~level:Warning @@ -439,6 +482,7 @@ open struct let message_validation_error = declare_2 ~section + ~prefix_name_with_section:true ~name:"message_validation_failed" ~msg: "validating message with id {message_id} failed with error \ @@ -451,7 +495,8 @@ open struct let p2p_server_is_ready = declare_1 ~section - ~name:"dal_node_p2p_server_is_ready" + ~prefix_name_with_section:true + ~name:"p2p_server_is_ready" ~msg:"P2P server is listening on {point}" ~level:Notice ("point", P2p_point.Id.encoding) @@ -459,7 +504,8 @@ open struct let rpc_server_is_ready = declare_1 ~section - ~name:"dal_node_rpc_server_is_ready" + ~prefix_name_with_section:true + ~name:"rpc_server_is_ready" ~msg:"RPC server is listening on {point}" ~level:Notice ("point", P2p_point.Id.encoding) @@ -467,6 +513,7 @@ open struct let metrics_server_starting = declare_1 ~section:(section @ ["metrics"]) + ~prefix_name_with_section:true ~name:"metrics_service_start" ~msg:"Starting metrics service at {endpoint}" ~level:Notice @@ -475,6 +522,7 @@ open struct let metrics_server_not_starting = declare_0 ~section:(section @ ["metrics"]) + ~prefix_name_with_section:true ~name:"metrics_service_no_start" ~msg:"metrics service not enabled" ~level:Notice @@ -484,6 +532,7 @@ open struct let open Internal_event.Simple in declare_2 ~section + ~prefix_name_with_section:true ~name:"starting_metrics_server" ~msg:"metrics server is listening on {host}:{port}" ~level:Notice @@ -493,6 +542,7 @@ open struct let loading_profiles_failed = declare_1 ~section + ~prefix_name_with_section:true ~name:"loading_profiles_failed" ~msg:"loading profiles failed: {error}" ~level:Info @@ -501,6 +551,7 @@ open struct let saving_profiles_failed = declare_1 ~section + ~prefix_name_with_section:true ~name:"saving_profiles_failed" ~msg:"saving profiles failed: {error}" ~level:Error @@ -509,6 +560,7 @@ open struct let reconstruct_starting_in = declare_3 ~section + ~prefix_name_with_section:true ~name:"reconstruct_starting_in" ~msg: "For the level {level} and slot index {slot_index}, enough shards have \ @@ -525,6 +577,7 @@ open struct let reconstruct_started = declare_4 ~section + ~prefix_name_with_section:true ~name:"reconstruct_started" ~msg: "For the level {level} and slot index {slot_index}, \ @@ -543,6 +596,7 @@ open struct let reconstruct_finished = declare_2 ~section + ~prefix_name_with_section:true ~name:"reconstruct_finished" ~msg: "For the level {level} and slot index {slot_index}, missing shards \ @@ -556,6 +610,7 @@ open struct let reconstruct_no_missing_shard = declare_2 ~section + ~prefix_name_with_section:true ~name:"reconstruct_no_missing_shard" ~msg: "For the level {level}, all shards for slot index {slot_index} were \ @@ -569,6 +624,7 @@ open struct let reconstruct_error = declare_3 ~section + ~prefix_name_with_section:true ~name:"reconstruct_error" ~msg: "For the level {level} and slot index {slot_index}, unexpected error \ @@ -583,6 +639,7 @@ open struct let store_upgrade_error_moving_directory = declare_3 ~section + ~prefix_name_with_section:true ~name:"store_upgrade_error_moving_directory" ~msg:"There was an error trying to move {src} to {dst}: {exn}" ~level:Warning @@ -593,6 +650,7 @@ open struct let store_upgrade_error_creating_directory = declare_2 ~section + ~prefix_name_with_section:true ~name:"store_upgrade_error_creating_directory" ~msg:"There was an error trying to create directory {path}: {exn}" ~level:Warning @@ -602,6 +660,7 @@ open struct let store_upgrade_start = declare_2 ~section + ~prefix_name_with_section:true ~name:"store_upgrading" ~msg: "starting to upgrade the store from version {old_version} to \ @@ -613,6 +672,7 @@ open struct let store_upgraded = declare_2 ~section + ~prefix_name_with_section:true ~name:"store_upgraded" ~msg: "the store has been upgraded from version {old_version} to \ @@ -624,6 +684,7 @@ open struct let store_upgrade_error = declare_0 ~section + ~prefix_name_with_section:true ~name:"store_upgrade_error" ~msg:"Failed to upgrade the store." ~level:Error @@ -632,6 +693,7 @@ open struct let crypto_process_started = declare_1 ~section:(section @ ["crypto"]) + ~prefix_name_with_section:true ~name:"crypto_process_started" ~msg:"cryptographic child process started (pid: {pid})" ~level:Notice @@ -640,6 +702,7 @@ open struct let amplificator_uninitialized = declare_0 ~section:(section @ ["crypto"]) + ~prefix_name_with_section:true ~name:"amplificator_uninitialized" ~msg:"the amplificator process worker is not initialized" ~level:Warning @@ -648,6 +711,7 @@ open struct let crypto_process_received_query = declare_1 ~section:(section @ ["crypto"]) + ~prefix_name_with_section:true ~name:"crypto_process_received_query" ~msg:"cryptographic child process: received query #{query_id}." ~level:Notice @@ -656,6 +720,7 @@ open struct let crypto_process_sending_reply = declare_1 ~section:(section @ ["crypto"]) + ~prefix_name_with_section:true ~name:"crypto_process_sending_reply" ~msg:"cryptographic child process: sending reply #{query_id}." ~level:Info @@ -664,6 +729,7 @@ open struct let main_process_sending_query = declare_1 ~section:(section @ ["crypto"]) + ~prefix_name_with_section:true ~name:"main_process_sending_query" ~msg: "main process: sending query #{query_id} to cryptographic child \ @@ -674,6 +740,7 @@ open struct let main_process_received_reply = declare_1 ~section:(section @ ["crypto"]) + ~prefix_name_with_section:true ~name:"main_process_received_reply" ~msg:"main process: received reply #{query_id}." ~level:Info @@ -682,6 +749,7 @@ open struct let main_process_enqueue_query = declare_1 ~section:(section @ ["crypto"]) + ~prefix_name_with_section:true ~name:"main_process_enqueue_query" ~msg:"main process: enqueue query #{query_id}." ~level:Info @@ -690,6 +758,7 @@ open struct let get_attestable_slots_ok_notice = declare_3 ~section + ~prefix_name_with_section:true ~name:"get_attestable_slots_ok_notice" ~msg: "For slots {slots_indices} published at level {published_level}, \ @@ -704,6 +773,7 @@ open struct let get_attestable_slots_not_ok_warning = declare_4 ~section + ~prefix_name_with_section:true ~name:"get_attestable_slots_missing_shards_warning" ~msg: "For slots {slots_indices} published at level {published_level}, \ @@ -731,6 +801,7 @@ open struct let get_attestable_slots_future_level_warning = declare_2 ~section + ~prefix_name_with_section:true ~name:"get_attestable_slots_future_level_warning" ~msg: "It looks like the DAL node is lagging (its current level is \ @@ -743,6 +814,7 @@ open struct let warn_no_attestation = declare_2 ~section + ~prefix_name_with_section:true ~name:"no_attestation" ~msg: "An attestation operation was not included for {attester} at attested \ @@ -755,6 +827,7 @@ open struct let attester_attested = declare_3 ~section + ~prefix_name_with_section:true ~name:"attester_attested" ~msg: "{attester} attested slot(s) {slot_indexes} at attested level \ @@ -769,6 +842,7 @@ open struct let warn_attester_not_dal_attesting = declare_2 ~section + ~prefix_name_with_section:true ~name:"attester_not_dal_attesting" ~msg: "No DAL content was included by {attester} for attested level \ @@ -781,6 +855,7 @@ open struct let warn_attester_did_not_attest = declare_3 ~section + ~prefix_name_with_section:true ~name:"attester_did_not_attest" ~msg: "At level {attested_level}, slot index(es) {slot_indexes} were \ @@ -796,6 +871,7 @@ open struct let attester_did_not_attest_because_of_traps = declare_3 ~section + ~prefix_name_with_section:true ~name:"attester_did_not_attest_traps" ~msg: "At level {attested_level}, slot index(es) {slot_indexes} were \ @@ -811,6 +887,7 @@ open struct let trap_injection = declare_5 ~section + ~prefix_name_with_section:true ~name:"trap_injection" ~msg: "Injecting entrapment evidence for delegate {delegate}, published \ @@ -826,6 +903,7 @@ open struct let trap_injection_failure = declare_6 ~section + ~prefix_name_with_section:true ~name:"trap_injection_failure" ~msg: "Failed to inject an entrapment evidence for delegate {delegate}, \ @@ -843,6 +921,7 @@ open struct let trap_check_failure = declare_3 ~section + ~prefix_name_with_section:true ~name:"trap_check_failure" ~msg: "An error occurred when checking the trap for published level \ @@ -855,6 +934,7 @@ open struct let trap_registration_fail = declare_3 ~section + ~prefix_name_with_section:true ~name:"trap_registration_fail" ~msg: "An error occurred when checking if the shard for delegate {delegate}, \ @@ -867,6 +947,7 @@ open struct let registered_pkh_not_a_delegate = declare_1 ~section + ~prefix_name_with_section:true ~name:"register_pkh_not_a_delegate" ~msg: "The public key hash {pkh} registered by PATCH /profiles is not a \ @@ -877,6 +958,7 @@ open struct let cannot_attest_slot_because_of_trap = declare_4 ~section + ~prefix_name_with_section:true ~name:"slot_contains_trap" ~msg: "{delegate} cannot attest slot {slot_index} at published level \ @@ -890,6 +972,7 @@ open struct let register_trap = declare_4 ~section + ~prefix_name_with_section:true ~name:"register_trap" ~msg: "The shard {shard_index} for slot {slot_index} and published level \ @@ -903,6 +986,7 @@ open struct let start_catchup = declare_3 ~section + ~prefix_name_with_section:true ~name:"start_catchup" ~msg: "catching up to level {end_level}, from last processed level \ @@ -915,6 +999,7 @@ open struct let catching_up = declare_1 ~section + ~prefix_name_with_section:true ~name:"catching_up" ~msg:"caught up the store up to level {current_level}" ~level:Notice @@ -923,8 +1008,9 @@ open struct let end_catchup = declare_0 ~section + ~prefix_name_with_section:true ~name:"end_catchup" - ~msg:"done catching up" + ~msg:"catching up done" ~level:Notice () end @@ -975,8 +1061,8 @@ let emit_fetched_slot ~size ~shards = emit fetched_slot (size, shards) let emit_layer1_node_new_head ~hash ~level ~fitness = emit layer1_node_new_head (hash, level, fitness) -let emit_layer1_node_final_block ~level ~round = - emit layer1_node_final_block (level, round) +let emit_layer1_node_final_block ~hash ~level ~round = + emit layer1_node_final_block (hash, level, round) let emit_layer1_node_tracking_started () = emit layer1_node_tracking_started () -- GitLab From 4424c4400c1be0f3551fb28c884bcde84bcca51b Mon Sep 17 00:00:00 2001 From: "iguerNL@Functori" Date: Fri, 7 Mar 2025 15:50:59 +0100 Subject: [PATCH 6/7] Tezt/DAL: remove redundant wait_for_gossipsub_worker_event function --- tezt/lib_tezos/dal_common.mli | 4 ++++ tezt/tests/dal.ml | 9 +++------ 2 files changed, 7 insertions(+), 6 deletions(-) diff --git a/tezt/lib_tezos/dal_common.mli b/tezt/lib_tezos/dal_common.mli index 32a2c5bf7dbe..96d9cab52e8d 100644 --- a/tezt/lib_tezos/dal_common.mli +++ b/tezt/lib_tezos/dal_common.mli @@ -164,6 +164,10 @@ module Helpers : sig | `Invalid_shard ] -> unit + (* A helper function to wait for an event emitted by gs_logging.ml *) + val wait_for_gossipsub_worker_event : + name:string -> Dal_node.t -> (JSON.t -> 'a option) -> 'a Lwt.t + (** Wait for a connection event between [main_node] and [other_node]. The optional argument [other_peer_id] can be used to ignore the connection events which are not between these two diff --git a/tezt/tests/dal.ml b/tezt/tests/dal.ml index cddd2ed32577..8cdbbfb1b071 100644 --- a/tezt/tests/dal.ml +++ b/tezt/tests/dal.ml @@ -3589,9 +3589,6 @@ let register_end_to_end_tests ~protocols = protocols) e2e_tests -let wait_for_gossipsub_worker_event ~name dal_node lambda = - Dal_node.wait_for dal_node (sf "gossipsub_worker_event-%s.v0" name) lambda - let check_expected expected found = if expected <> found then None else Some () let ( let*?? ) a b = Option.bind a b @@ -3657,7 +3654,7 @@ let check_events_with_topic ~event_with_topic dal_node ~num_slots in Some JSON.(topic |-> "slot_index" |> as_int) in - wait_for_gossipsub_worker_event + Dal_common.Helpers.wait_for_gossipsub_worker_event dal_node ~name:(event_with_topic_to_string event_with_topic) (fun event -> @@ -3720,7 +3717,7 @@ let check_events_with_message ~event_with_message dal_node ~number_of_shards seen |> Array.to_seqi |> Seq.for_all (fun (i, b) -> if List.mem i shard_indexes then b else true) in - wait_for_gossipsub_worker_event + Dal_common.Helpers.wait_for_gossipsub_worker_event dal_node ~name:(event_with_message_to_string event_with_message) (fun event -> @@ -3781,7 +3778,7 @@ let check_events_with_message_id ~event_with_message_id dal_node seen |> Array.to_seqi |> Seq.for_all (fun (i, b) -> if List.mem i shard_indexes then b else true) in - wait_for_gossipsub_worker_event + Dal_common.Helpers.wait_for_gossipsub_worker_event ~name:(event_with_message_id_to_string event_with_message_id) dal_node (fun event -> -- GitLab From fce80bab73d7c72c5ee19810e30572e2bef0a498 Mon Sep 17 00:00:00 2001 From: "iguerNL@Functori" Date: Fri, 7 Mar 2025 12:35:23 +0100 Subject: [PATCH 7/7] Tezt/tests: adapt events in tests --- tezt/lib_tezos/dal_common.ml | 2 +- tezt/lib_tezos/dal_node.ml | 4 ++-- tezt/tests/dal.ml | 38 +++++++++++++++++------------------- 3 files changed, 21 insertions(+), 23 deletions(-) diff --git a/tezt/lib_tezos/dal_common.ml b/tezt/lib_tezos/dal_common.ml index d0d18c83dc4b..a3924bebd240 100644 --- a/tezt/lib_tezos/dal_common.ml +++ b/tezt/lib_tezos/dal_common.ml @@ -778,7 +778,7 @@ module Helpers = struct return commitment_string let wait_for_gossipsub_worker_event ~name dal_node lambda = - Dal_node.wait_for dal_node (sf "gossipsub_worker_event-%s.v0" name) lambda + Dal_node.wait_for dal_node (sf "dal_gs_%s.v0" name) lambda let check_expected expected found = if expected <> found then None else Some () diff --git a/tezt/lib_tezos/dal_node.ml b/tezt/lib_tezos/dal_node.ml index 3f401126473c..918b90b05eff 100644 --- a/tezt/lib_tezos/dal_node.ml +++ b/tezt/lib_tezos/dal_node.ml @@ -258,7 +258,7 @@ let wait_for_ready dal_node = let promise, resolver = Lwt.task () in dal_node.persistent_state.pending_ready <- resolver :: dal_node.persistent_state.pending_ready ; - check_event dal_node "dal_node_is_ready.v0" promise + check_event dal_node "dal_is_ready.v0" promise let wait_for_connections node connections = let counter = ref 0 in @@ -277,7 +277,7 @@ let wait_for_disconnection node ~peer_id = if JSON.(event |-> "peer" |> as_string) = peer_id then Some () else None) let handle_event dal_node {name; value = _; timestamp = _} = - match name with "dal_node_is_ready.v0" -> set_ready dal_node | _ -> () + match name with "dal_is_ready.v0" -> set_ready dal_node | _ -> () let create_from_endpoint ?runner ?(path = Uses.path Constant.octez_dal_node) ?name ?color ?data_dir ?event_pipe ?(rpc_host = Constant.default_host) diff --git a/tezt/tests/dal.ml b/tezt/tests/dal.ml index 8cdbbfb1b071..a465f0095e94 100644 --- a/tezt/tests/dal.ml +++ b/tezt/tests/dal.ml @@ -143,13 +143,13 @@ let check_skip_list_store dal_node ~number_of_slots ~expected_levels = (* Wait for 'new_head' event. Note that the DAL node processes a new head with a delay of one level. Also, this event is emitted before block processing. *) let wait_for_layer1_head dal_node level = - Dal_node.wait_for dal_node "dal_node_layer_1_new_head.v0" (fun e -> + Dal_node.wait_for dal_node "dal_new_L1_head_block.v0" (fun e -> if JSON.(e |-> "level" |> as_int) = level then Some () else None) (* Wait for 'new_final_block' event. This event is emitted after processing a final block. *) let wait_for_layer1_final_block dal_node level = - Dal_node.wait_for dal_node "dal_node_layer_1_new_final_block.v0" (fun e -> + Dal_node.wait_for dal_node "dal_new_L1_final_block.v0" (fun e -> if JSON.(e |-> "level" |> as_int) = level then Some () else None) (* We use a custom [bake_for], which by default bakes with all delegates, unlike @@ -231,7 +231,7 @@ let wait_for_stored_slot ?shard_index dal_node ~published_level ~slot_index = | None -> true | Some shard_index -> JSON.(e |-> "shard_index" |> as_int) = shard_index in - Dal_node.wait_for dal_node "stored_slot_shard.v0" (fun e -> + Dal_node.wait_for dal_node "dal_stored_slot_shard.v0" (fun e -> if check_slot_id e && check_shard_index e then Some () else None) (* Wait until the given [dal_node] receives all the shards whose @@ -2279,8 +2279,7 @@ let test_dal_node_startup = let* () = Lwt.join [ - Dal_node.wait_for dal_node "dal_node_plugin_resolved.v0" (fun _ -> - Some ()); + Dal_node.wait_for dal_node "dal_plugin_resolved.v0" (fun _ -> Some ()); bake_for client; ] in @@ -3824,10 +3823,7 @@ let check_message_notified_to_app_event dal_node ~number_of_shards seen |> Array.to_seqi |> Seq.for_all (fun (i, b) -> if List.mem i shard_indexes then b else true) in - Dal_node.wait_for - dal_node - "gossipsub_transport_event-message_notified_to_app.v0" - (fun event -> + Dal_node.wait_for dal_node "dal_gs_message_notified_to_app.v0" (fun event -> let*?? shard_index = get_shard_index_opt event in Check.( (seen.(shard_index) = false) @@ -4558,7 +4554,7 @@ let test_migration_plugin ~migrate_from ~migrate_to = let blocks_till_migration = migration_level - current_level in let wait_for_plugin = - Dal_node.wait_for dal_node "dal_node_plugin_resolved.v0" (fun json -> + Dal_node.wait_for dal_node "dal_plugin_resolved.v0" (fun json -> let proto_hash = JSON.(json |> as_string) in if String.equal proto_hash (Protocol.hash migrate_to) then Some () else None) @@ -4702,7 +4698,7 @@ let test_producer_profile _protocol _dal_parameters _cryptobox _node _client let monitor_finalized_levels_events ~__LOC__ ~last_notified_level ~target_level dal_node = let next_finalized_level = ref (last_notified_level + 1) in - Dal_node.wait_for dal_node "dal_node_layer_1_new_final_block.v0" (fun e -> + Dal_node.wait_for dal_node "dal_new_L1_final_block.v0" (fun e -> let finalized_level = JSON.(e |-> "level" |> as_int) in Check.( (finalized_level = !next_finalized_level) @@ -6005,7 +6001,10 @@ module Amplification = struct let wait_slot ~published_level:_ ~slot_index:_ = Log.info "Waiting for first reconstruction event" ; let* () = - Dal_node.wait_for observer "reconstruct_starting_in.v0" (fun event -> + Dal_node.wait_for + observer + "dal_reconstruct_starting_in.v0" + (fun event -> if JSON.( event |-> "level" |> as_int = publication_level @@ -6019,7 +6018,7 @@ module Amplification = struct let promise_reconstruction_cancelled = Dal_node.wait_for observer - "reconstruct_no_missing_shard.v0" + "dal_reconstruct_no_missing_shard.v0" (fun event -> if JSON.( @@ -6029,7 +6028,7 @@ module Amplification = struct else None) in let promise_reconstruction_finished = - Dal_node.wait_for observer "reconstruct_finished.v0" (fun event -> + Dal_node.wait_for observer "dal_reconstruct_finished.v0" (fun event -> if JSON.( event |-> "level" |> as_int = publication_level @@ -6068,7 +6067,7 @@ module Garbage_collection = struct receiving the shards, each node deletes them from its storage. *) let wait_remove_shards ~published_level ~slot_index node = - Dal_node.wait_for node "removed_slot_shards.v0" (fun event -> + Dal_node.wait_for node "dal_removed_slot_shards.v0" (fun event -> if (published_level = JSON.(event |-> "published_level" |> as_int)) && slot_index = JSON.(event |-> "slot_index" |> as_int) @@ -6076,7 +6075,7 @@ module Garbage_collection = struct else None) let wait_for_first_shard ~published_level ~slot_index node = - Dal_node.wait_for node "stored_slot_shard.v0" (fun event -> + Dal_node.wait_for node "dal_stored_slot_shard.v0" (fun event -> let actual_published_level = JSON.(event |-> "published_level" |> as_int) in @@ -7572,8 +7571,7 @@ let scenario_tutorial_dal_baker = ~error_msg:"Expecting a empty list of topics") ; let wait_join_event_promise = - Dal_node.wait_for dal_node "gossipsub_worker_event-join.v0" (fun _ -> - Some ()) + Dal_node.wait_for dal_node "dal_gs_join.v0" (fun _ -> Some ()) in let all_delegates = @@ -8847,7 +8845,7 @@ let test_attester_did_not_attest (_protocol : Protocol.t) "We promise the attester_did_not_attest_slot will be emitted by the \ [attester node]" ; let not_attested_by_bootstrap2_promise = - Dal_node.wait_for attester_node "attester_did_not_attest.v0" (fun _ -> + Dal_node.wait_for attester_node "dal_attester_did_not_attest.v0" (fun _ -> Some ()) in log_step "The producer crafts a commitment and publish it" ; @@ -9413,7 +9411,7 @@ let test_e2e_trap_faulty_dal_node _protocol dal_parameters _cryptobox node ~__LOC__ ~error_msg:"Expected the faulty delegate to not be denounced" ; let wait_for_trap_injection = - Dal_node.wait_for dal_node "trap_injection.v0" (fun e -> + Dal_node.wait_for dal_node "dal_trap_injection.v0" (fun e -> let open JSON in let delegate = e |-> "delegate" |> as_string in let attested_level = e |-> "attested_level" |> as_int in -- GitLab