From 262a05f9502c3bf8dee2bf827eae3749b8450d3b Mon Sep 17 00:00:00 2001 From: Mathias Bourgoin Date: Mon, 3 Jun 2024 20:36:57 +0200 Subject: [PATCH 1/4] Paris/Baker: bakport event for monitoring reset --- .../lib_delegate/operation_worker.ml | 16 +++++++++++++--- .../lib_delegate/operation_worker.ml | 16 +++++++++++++--- 2 files changed, 26 insertions(+), 6 deletions(-) diff --git a/src/proto_019_PtParisB/lib_delegate/operation_worker.ml b/src/proto_019_PtParisB/lib_delegate/operation_worker.ml index 42d91d24e545..2f030fe43b63 100644 --- a/src/proto_019_PtParisB/lib_delegate/operation_worker.ml +++ b/src/proto_019_PtParisB/lib_delegate/operation_worker.ml @@ -119,6 +119,14 @@ module Events = struct ~msg:"starting new monitoring" () + let resetting_monitoring = + declare_0 + ~section + ~name:"resetting_monitoring" + ~level:Debug + ~msg:"resetting monitoring after a mempool flush" + () + let end_of_stream = declare_0 ~section @@ -300,19 +308,21 @@ let is_valid_consensus_content (candidate : candidate) consensus_content = let cancel_monitoring state = state.proposal_watched <- None let reset_monitoring state = + let open Lwt_syntax in Lwt_mutex.with_lock state.lock @@ fun () -> + let* () = Events.(emit resetting_monitoring ()) in match state.proposal_watched with - | None -> Lwt.return_unit + | None -> return_unit | Some (Pqc_watch pqc_watched) -> pqc_watched.current_voting_power <- 0 ; pqc_watched.preattestations_count <- 0 ; pqc_watched.preattestations_received <- Preattestation_set.empty ; - Lwt.return_unit + return_unit | Some (Qc_watch qc_watched) -> qc_watched.current_voting_power <- 0 ; qc_watched.attestations_count <- 0 ; qc_watched.attestations_received <- Attestation_set.empty ; - Lwt.return_unit + return_unit let update_monitoring ?(should_lock = true) state ops = let open Lwt_syntax in diff --git a/src/proto_020_PsParisC/lib_delegate/operation_worker.ml b/src/proto_020_PsParisC/lib_delegate/operation_worker.ml index 42d91d24e545..2f030fe43b63 100644 --- a/src/proto_020_PsParisC/lib_delegate/operation_worker.ml +++ b/src/proto_020_PsParisC/lib_delegate/operation_worker.ml @@ -119,6 +119,14 @@ module Events = struct ~msg:"starting new monitoring" () + let resetting_monitoring = + declare_0 + ~section + ~name:"resetting_monitoring" + ~level:Debug + ~msg:"resetting monitoring after a mempool flush" + () + let end_of_stream = declare_0 ~section @@ -300,19 +308,21 @@ let is_valid_consensus_content (candidate : candidate) consensus_content = let cancel_monitoring state = state.proposal_watched <- None let reset_monitoring state = + let open Lwt_syntax in Lwt_mutex.with_lock state.lock @@ fun () -> + let* () = Events.(emit resetting_monitoring ()) in match state.proposal_watched with - | None -> Lwt.return_unit + | None -> return_unit | Some (Pqc_watch pqc_watched) -> pqc_watched.current_voting_power <- 0 ; pqc_watched.preattestations_count <- 0 ; pqc_watched.preattestations_received <- Preattestation_set.empty ; - Lwt.return_unit + return_unit | Some (Qc_watch qc_watched) -> qc_watched.current_voting_power <- 0 ; qc_watched.attestations_count <- 0 ; qc_watched.attestations_received <- Attestation_set.empty ; - Lwt.return_unit + return_unit let update_monitoring ?(should_lock = true) state ops = let open Lwt_syntax in -- GitLab From 9728c900a620bfade74e6c10e5b460c55f951b2b Mon Sep 17 00:00:00 2001 From: Albin Coquereau Date: Mon, 17 Jun 2024 10:43:27 +0200 Subject: [PATCH 2/4] paris/baker: put quorum event in info level instead of debug --- src/proto_019_PtParisB/lib_delegate/operation_worker.ml | 4 ++-- src/proto_020_PsParisC/lib_delegate/operation_worker.ml | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/src/proto_019_PtParisB/lib_delegate/operation_worker.ml b/src/proto_019_PtParisB/lib_delegate/operation_worker.ml index 2f030fe43b63..345b3ce63d81 100644 --- a/src/proto_019_PtParisB/lib_delegate/operation_worker.ml +++ b/src/proto_019_PtParisB/lib_delegate/operation_worker.ml @@ -55,7 +55,7 @@ module Events = struct declare_2 ~section ~name:"pqc_reached" - ~level:Debug + ~level:Info ~msg: "prequorum reached (voting power: {voting_power}, {preattestations} \ preattestations)" @@ -85,7 +85,7 @@ module Events = struct declare_2 ~section ~name:"qc_reached" - ~level:Debug + ~level:Info ~msg: "quorum reached (voting power: {voting_power}, {attestations} \ attestations)" diff --git a/src/proto_020_PsParisC/lib_delegate/operation_worker.ml b/src/proto_020_PsParisC/lib_delegate/operation_worker.ml index 2f030fe43b63..345b3ce63d81 100644 --- a/src/proto_020_PsParisC/lib_delegate/operation_worker.ml +++ b/src/proto_020_PsParisC/lib_delegate/operation_worker.ml @@ -55,7 +55,7 @@ module Events = struct declare_2 ~section ~name:"pqc_reached" - ~level:Debug + ~level:Info ~msg: "prequorum reached (voting power: {voting_power}, {preattestations} \ preattestations)" @@ -85,7 +85,7 @@ module Events = struct declare_2 ~section ~name:"qc_reached" - ~level:Debug + ~level:Info ~msg: "quorum reached (voting power: {voting_power}, {attestations} \ attestations)" -- GitLab From a2aa4c02148e794e334e727b0f26401a007327a6 Mon Sep 17 00:00:00 2001 From: Albin Coquereau Date: Wed, 5 Jun 2024 16:54:04 +0200 Subject: [PATCH 3/4] lib_shell/prevalidator: improve branch on a too old block error message --- src/lib_shell/prevalidator.ml | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/src/lib_shell/prevalidator.ml b/src/lib_shell/prevalidator.ml index f2a717e2ed65..e2348168176b 100644 --- a/src/lib_shell/prevalidator.ml +++ b/src/lib_shell/prevalidator.ml @@ -725,11 +725,15 @@ module Make_s pv.shell.live_blocks) then failwith - "Operation %a is branched on a block %a which is too old" + "Operation %a is branched on either:\n\ + \ - a block %a which is too old (%d blocks in the past)\n\ + \ - a predecessor block from an alternative branch which is \ + now unknown" Operation_hash.pp oph Block_hash.pp op.Operation.shell.branch + (Block_hash.Set.cardinal pv.shell.live_blocks) else let notifier = mk_notifier pv.operation_stream in let*! validation_state, validated_operation, to_handle = -- GitLab From 15ce2d8aec15c77e7606b3736ab01700aef72ddc Mon Sep 17 00:00:00 2001 From: Albin Coquereau Date: Thu, 6 Jun 2024 09:31:22 +0200 Subject: [PATCH 4/4] tezt/tests: adapt match error for prevalidator test with injection of blocks branched on unknown branch --- tezt/lib_tezos/operation_core.ml | 15 +++++++++++++++ tezt/lib_tezos/operation_core.mli | 20 ++++++++++++++++++++ tezt/tests/operations_liveness.ml | 24 +++++++++--------------- tezt/tests/prevalidator.ml | 9 +-------- 4 files changed, 45 insertions(+), 23 deletions(-) diff --git a/tezt/lib_tezos/operation_core.ml b/tezt/lib_tezos/operation_core.ml index 7385662ad5c5..d3ee0f4b45dc 100644 --- a/tezt/lib_tezos/operation_core.ml +++ b/tezt/lib_tezos/operation_core.ml @@ -169,6 +169,18 @@ let inject ?(request = `Inject) ?force ?protocol ?signature ?error t client : let* () = Process.check_error ~msg process in hash t client +let inject_and_capture1_stderr ~rex ?force ?protocol ?signature t client = + let* runnable = spawn_inject ?force ?protocol ?signature t client in + let*? process = runnable in + let* stderr = Process.check_and_read_stderr ~expect_failure:true process in + match stderr =~* rex with + | None -> + Test.fail + "Injection was expected to fail with:\n%s\nbut instead failed with:\n%s" + (show_rex rex) + stderr + | Some groups -> return groups + let inject_and_capture2_stderr ~rex ?force ?protocol ?signature t client = let* runnable = spawn_inject ?force ?protocol ?signature t client in let*? process = runnable in @@ -892,3 +904,6 @@ let already_denounced = let outdated_denunciation = rex {|A double-([\w]+) denunciation is outdated \(last acceptable cycle: ([\d]+), given level: ([\d]+)\).|} + +let injection_error_unknown_branch = + rex {|Operation ([\w\d]+) is branched on either:|} diff --git a/tezt/lib_tezos/operation_core.mli b/tezt/lib_tezos/operation_core.mli index bd5d563e5398..36c17899db65 100644 --- a/tezt/lib_tezos/operation_core.mli +++ b/tezt/lib_tezos/operation_core.mli @@ -132,6 +132,9 @@ val byte_size : injection fails. If the injection succeeds, the hash of the operation is returned. + @param dont_wait If [true], the operation is injected without waiting + on some node event. Making [request] ignore. Default is [false]. + @param request If [`Inject], we do not wait the [prevalidator] to classify the operation. This can create some flakyness in the test but is needed to test corner cases. If [`Notify], the function @@ -171,6 +174,16 @@ val spawn_inject : Client.t -> JSON.t Runnable.process Lwt.t +(** Run [spawn_inject] then capture one group on stderr with [rex]. *) +val inject_and_capture1_stderr : + rex:rex -> + ?force:bool -> + ?protocol:Protocol.t -> + ?signature:Tezos_crypto.Signature.t -> + t -> + Client.t -> + string Lwt.t + (** Run [spawn_inject] then capture two groups on stderr with [rex]. *) val inject_and_capture2_stderr : rex:rex -> @@ -719,3 +732,10 @@ val already_denounced : rex Captures [kind], [last_cycle], [level]. *) val outdated_denunciation : rex + +(** Matches the message + [Operation %a is branched on either:] + from [src/lib_shell/prevalidator.ml]. + + Captures [hash]. *) +val injection_error_unknown_branch : rex diff --git a/tezt/tests/operations_liveness.ml b/tezt/tests/operations_liveness.ml index d3672f06cda4..9b9040e2b48f 100644 --- a/tezt/tests/operations_liveness.ml +++ b/tezt/tests/operations_liveness.ml @@ -123,11 +123,9 @@ let operation_liveness_reorg = client1 in Log.info "Injecting op targeting a non-liveblock (expected to fail)" ; - let* _, _ = - Operation.inject_and_capture2_stderr - ~rex: - (rex - {|Operation ([\w\d]+) is branched on a block ([\w\d]+) which is too old|}) + let* _ = + Operation.inject_and_capture1_stderr + ~rex:Operation_core.injection_error_unknown_branch non_live_op client1 in @@ -218,11 +216,9 @@ let operation_liveness_reorg = in Log.info "Injecting op targeting a non-liveblock" ; - let* _, _ = - Operation.inject_and_capture2_stderr - ~rex: - (rex - {|Operation ([\w\d]+) is branched on a block ([\w\d]+) which is too old|}) + let* _ = + Operation.inject_and_capture1_stderr + ~rex:Operation_core.injection_error_unknown_branch non_live_op client1 in @@ -278,11 +274,9 @@ let operation_liveness = client1 in Log.info "Injecting op targeting a non-liveblock (expected to fail)" ; - let* _, _ = - Operation.inject_and_capture2_stderr - ~rex: - (rex - {|Operation ([\w\d]+) is branched on a block ([\w\d]+) which is too old|}) + let* _ = + Operation.inject_and_capture1_stderr + ~rex:Operation_core.injection_error_unknown_branch non_live_op client1 in diff --git a/tezt/tests/prevalidator.ml b/tezt/tests/prevalidator.ml index ce5ff26c838d..7936955a409a 100644 --- a/tezt/tests/prevalidator.ml +++ b/tezt/tests/prevalidator.ml @@ -3766,14 +3766,7 @@ let injecting_old_operation_fails = Client.RPC.spawn client @@ RPC.post_injection_operation (Data (`String (op_str_hex ^ signature))) in - let injection_error_rex = - rex - ~opts:[`Dotall] - "Fatal error:\n\ - \ Command failed: Operation .* is branched on a block .* which is too \ - old" - in - Process.check_error ~msg:injection_error_rex process + Process.check_error ~msg:Operation_core.injection_error_unknown_branch process let test_request_operations_peer = let step1_msg = "Step 1: Connect and initialise two nodes " in -- GitLab