From 8b40b13ea86f391e8c25a06d28b73f18c32fad7c Mon Sep 17 00:00:00 2001 From: James Deikun Date: Fri, 15 Jun 2018 15:34:01 -0400 Subject: [PATCH 1/3] more logging for the client daemons - log seen blocks and heads when monitoring - more detailed logging for baked blocks - more detailed logging for endorsements - more detailed logging for denunciations - more detailed logging for nonce revelations --- .../lib_delegate/client_baking_blocks.ml | 21 ++++++++++++++++--- .../client_baking_denunciation.ml | 2 ++ .../lib_delegate/client_baking_endorsement.ml | 1 + .../lib_delegate/client_baking_forge.ml | 6 ++++++ .../lib_delegate/client_baking_revelation.ml | 11 +++++++++- src/proto_alpha/lib_delegate/dune | 3 +++ src/proto_alpha/lib_delegate/logging.ml | 7 +++++++ src/proto_alpha/lib_delegate/logging.mli | 8 ++++++- .../lib_delegate/tezos-baking-alpha.opam | 1 + 9 files changed, 55 insertions(+), 5 deletions(-) diff --git a/src/proto_alpha/lib_delegate/client_baking_blocks.ml b/src/proto_alpha/lib_delegate/client_baking_blocks.ml index d40cc2c55b2d..a5c94d0207aa 100644 --- a/src/proto_alpha/lib_delegate/client_baking_blocks.ml +++ b/src/proto_alpha/lib_delegate/client_baking_blocks.ml @@ -25,6 +25,9 @@ open Proto_alpha open Alpha_context +open Logging + +include Tezos_stdlib.Logging.Make_semantic(struct let name = "client.blocks" end) type block_info = { hash: Block_hash.t ; @@ -65,15 +68,27 @@ let monitor_valid_blocks cctxt ?chains ?protocols ~next_protocols () = Monitor_services.valid_blocks cctxt ?chains ?protocols ?next_protocols () >>=? fun (block_stream, _stop) -> return (Lwt_stream.map_s - (fun ((chain, block), { Tezos_base.Block_header.shell }) -> - raw_info cctxt ~chain:(`Hash chain) block shell) + (fun ((chain, block), data) -> + log_info Tag.DSL.(fun f -> + f "Saw block %a on chain %a" + -% t event "monitor_saw_valid_block" + -% a Block_hash.Logging.tag block + -% a Tezos_shell.State_logging.chain_id chain + -% t block_header_tag data) ; + raw_info cctxt ~chain:(`Hash chain) block data.Tezos_base.Block_header.shell) block_stream) let monitor_heads cctxt ~next_protocols chain = Monitor_services.heads cctxt ?next_protocols chain >>=? fun (block_stream, _stop) -> return (Lwt_stream.map_s - (fun (block, { Tezos_base.Block_header.shell }) -> raw_info cctxt ~chain block shell) + (fun (block, data) -> + log_info Tag.DSL.(fun f -> + f "Saw head %a" + -% t event "monitor_saw_head" + -% a Block_hash.Logging.tag block + -% t block_header_tag data) ; + raw_info cctxt ~chain block data.Tezos_base.Block_header.shell) block_stream) let blocks_from_current_cycle cctxt ?(chain = `Main) block ?(offset = 0l) () = diff --git a/src/proto_alpha/lib_delegate/client_baking_denunciation.ml b/src/proto_alpha/lib_delegate/client_baking_denunciation.ml index 6b00e84b9349..162cc49682ff 100644 --- a/src/proto_alpha/lib_delegate/client_baking_denunciation.ml +++ b/src/proto_alpha/lib_delegate/client_baking_denunciation.ml @@ -113,6 +113,7 @@ let process_endorsements (cctxt : #Proto_alpha.full) state ~chain lwt_log_notice Tag.DSL.(fun f -> f "Double endorsement evidence injected %a" -% t event "double_endorsement_denounced" + -% t signed_operation_tag bytes -% a Operation_hash.Logging.tag op_hash) >>= fun () -> return @@ HLevel.replace state.endorsements_table level (Delegate_Map.add delegate new_endorsement map) @@ -166,6 +167,7 @@ let process_block (cctxt : #Proto_alpha.full) state ~chain (header : Alpha_block lwt_log_notice Tag.DSL.(fun f -> f "Double baking evidence injected %a" -% t event "double_baking_denounced" + -% t signed_operation_tag bytes -% a Operation_hash.Logging.tag op_hash) >>= fun () -> return @@ HLevel.replace state.blocks_table level (Delegate_Map.add baker hash map) diff --git a/src/proto_alpha/lib_delegate/client_baking_endorsement.ml b/src/proto_alpha/lib_delegate/client_baking_endorsement.ml index 4759717a5b86..f899677da374 100644 --- a/src/proto_alpha/lib_delegate/client_baking_endorsement.ml +++ b/src/proto_alpha/lib_delegate/client_baking_endorsement.ml @@ -137,6 +137,7 @@ let endorse_for_delegate cctxt block delegate = -% a Block_hash.Logging.tag hash -% a level_tag level -% s Client_keys.Logging.tag name + -% t Signature.Public_key_hash.Logging.tag delegate -% a Operation_hash.Logging.tag oph) >>= fun () -> return_unit diff --git a/src/proto_alpha/lib_delegate/client_baking_forge.ml b/src/proto_alpha/lib_delegate/client_baking_forge.ml index 3f09c777f39a..372ca3a18fdd 100644 --- a/src/proto_alpha/lib_delegate/client_baking_forge.ml +++ b/src/proto_alpha/lib_delegate/client_baking_forge.ml @@ -135,6 +135,12 @@ let inject_block src_sk shell_header priority seed_nonce_hash >>=? fun signed_header -> Shell_services.Injection.block cctxt ?force ~chain signed_header operations >>=? fun block_hash -> + lwt_log_info Tag.DSL.(fun f -> + f "Client_baking_forge.inject_block: inject %a" + -% t event "inject_baked_block" + -% a Block_hash.Logging.tag block_hash + -% t signed_header_tag signed_header + -% t operations_tag operations) >>= fun () -> return block_hash type error += diff --git a/src/proto_alpha/lib_delegate/client_baking_revelation.ml b/src/proto_alpha/lib_delegate/client_baking_revelation.ml index 068d0010ad6c..f80421179f30 100644 --- a/src/proto_alpha/lib_delegate/client_baking_revelation.ml +++ b/src/proto_alpha/lib_delegate/client_baking_revelation.ml @@ -34,7 +34,16 @@ let inject_seed_nonce_revelation rpc_config ?(chain = `Main) block ?async nonces Alpha_services.Forge.seed_nonce_revelation rpc_config (chain, block) ~branch ~level ~nonce () >>=? fun bytes -> let bytes = Signature.concat bytes Signature.zero in - Shell_services.Injection.operation rpc_config ?async ~chain bytes) + Shell_services.Injection.operation rpc_config ?async ~chain bytes >>=? fun oph -> + lwt_debug Tag.DSL.(fun f -> + f "Revealing nonce %a from level %a at chain %a, block %a with operation %a" + -% t event "reveal_nonce" + -% a Logging.nonce_tag nonce + -% a Logging.level_tag level + -% a Logging.chain_tag chain + -% a Logging.block_tag block + -% a Operation_hash.Logging.tag oph) >>= fun () -> + return oph) nonces >>=? fun ophs -> return ophs diff --git a/src/proto_alpha/lib_delegate/dune b/src/proto_alpha/lib_delegate/dune index ed916b4a9a3c..430fcbe521be 100644 --- a/src/proto_alpha/lib_delegate/dune +++ b/src/proto_alpha/lib_delegate/dune @@ -4,6 +4,7 @@ (libraries tezos-base tezos-protocol-alpha tezos-protocol-environment + tezos-shell tezos-shell-services tezos-client-base tezos-client-alpha @@ -30,6 +31,7 @@ (libraries tezos-base tezos-protocol-alpha tezos-protocol-environment + tezos-shell tezos-shell-services tezos-client-base tezos-client-alpha @@ -53,6 +55,7 @@ (libraries tezos-base tezos-protocol-alpha tezos-protocol-environment + tezos-shell tezos-shell-services tezos-client-base tezos-client-alpha diff --git a/src/proto_alpha/lib_delegate/logging.ml b/src/proto_alpha/lib_delegate/logging.ml index 191f0fff2608..75c2459535af 100644 --- a/src/proto_alpha/lib_delegate/logging.ml +++ b/src/proto_alpha/lib_delegate/logging.ml @@ -35,6 +35,8 @@ let current_slots_tag = Tag.def ~doc:"Number of baking slots that can be baked a let future_slots_tag = Tag.def ~doc:"Number of baking slots in the foreseeable future but not yet bakeable" "future_slots" Format.pp_print_int let timespan_tag = Tag.def ~doc:"Time in seconds" "timespan" (fun fmt i -> Format.fprintf fmt "%Lds" i) +let signed_header_tag = Tag.def ~doc:"Signed header" "signed_header" MBytes.pp_hex +let signed_operation_tag = Tag.def ~doc:"Signed operation" "signed_operation" MBytes.pp_hex let operations_tag = Tag.def ~doc:"Block Operations" "operations" (Format.pp_print_list ~pp_sep:(fun ppf () -> Format.fprintf ppf "+") @@ -48,8 +50,13 @@ let denounced_endorsements_slots_tag = Tag.def ~doc:"Endorsement Slots" "denounc let denouncement_source_tag = Tag.def ~doc:"Denounce Source" "source" Format.pp_print_text let level_tag = Tag.def ~doc:"Level" "level" Raw_level.pp +let nonce_tag = Tag.def ~doc:"Nonce" "nonce" Data_encoding.Json.(fun ppf nonce -> pp ppf (construct Nonce.encoding nonce)) +let chain_tag = Tag.def ~doc:"Chain selector" "chain" Format.(fun ppf chain -> pp_print_string ppf @@ Block_services.chain_to_string chain) +let block_tag = Tag.def ~doc:"Block selector" "block" Format.(fun ppf block -> pp_print_string ppf @@ Block_services.to_string block) let worker_tag = Tag.def ~doc:"Worker in which event occurred" "worker" Format.pp_print_text +let block_header_tag = Tag.def ~doc:"Raw block header" "block_header" (fun ppf _ -> Format.fprintf ppf "[raw block header]") + let conflicting_endorsements_tag = Tag.def ~doc:"Two conflicting endorsements signed by the same key" "conflicting_endorsements" Format.( fun ppf (a,b) -> fprintf ppf "%a / %a" Operation_hash.pp (Operation.hash a) Operation_hash.pp (Operation.hash b)) diff --git a/src/proto_alpha/lib_delegate/logging.mli b/src/proto_alpha/lib_delegate/logging.mli index 868594ee9c55..9613eaea1fe3 100644 --- a/src/proto_alpha/lib_delegate/logging.mli +++ b/src/proto_alpha/lib_delegate/logging.mli @@ -32,14 +32,20 @@ val current_slots_tag : int Tag.def val future_slots_tag : int Tag.def val timespan_tag : int64 Tag.def -val operations_tag : Proto_alpha.Alpha_context.Operation.raw list list Tag.def +val signed_header_tag : MBytes.t Tag.def +val signed_operation_tag : MBytes.t Tag.def +val operations_tag : Tezos_base.Operation.t list list Tag.def val bake_op_count_tag : int Tag.def val endorsement_slot_tag : int Tag.def val endorsement_slots_tag : int list Tag.def val denounced_endorsements_slots_tag : int list Tag.def val denouncement_source_tag : string Tag.def val level_tag : Proto_alpha.Alpha_context.Raw_level.t Tag.def +val nonce_tag : Proto_alpha.Alpha_context.Nonce.t Tag.def +val chain_tag : Block_services.chain Tag.def +val block_tag : Block_services.block Tag.def val worker_tag : string Tag.def +val block_header_tag : Block_header.t Tag.def open Proto_alpha.Alpha_context val conflicting_endorsements_tag : (Kind.endorsement operation * Kind.endorsement operation) Tag.def diff --git a/src/proto_alpha/lib_delegate/tezos-baking-alpha.opam b/src/proto_alpha/lib_delegate/tezos-baking-alpha.opam index 87e71ee1c037..541e3eb666a2 100644 --- a/src/proto_alpha/lib_delegate/tezos-baking-alpha.opam +++ b/src/proto_alpha/lib_delegate/tezos-baking-alpha.opam @@ -12,6 +12,7 @@ depends: [ "tezos-base" "tezos-protocol-environment" "tezos-protocol-alpha" + "tezos-shell" "tezos-shell-services" "tezos-client-base" "tezos-client-commands" -- GitLab From 9664afdd277ef3bd3d38436e4654752451f5d0bf Mon Sep 17 00:00:00 2001 From: Sebastien Mondet Date: Tue, 20 Nov 2018 14:12:52 -0500 Subject: [PATCH 2/3] Move `State_logging` to `tezos-shell-services` Cf. MR !659. --- src/{lib_shell => lib_shell_services}/state_logging.ml | 0 src/{lib_shell => lib_shell_services}/state_logging.mli | 0 src/proto_alpha/lib_delegate/client_baking_blocks.ml | 2 +- src/proto_alpha/lib_delegate/dune | 3 --- 4 files changed, 1 insertion(+), 4 deletions(-) rename src/{lib_shell => lib_shell_services}/state_logging.ml (100%) rename src/{lib_shell => lib_shell_services}/state_logging.mli (100%) diff --git a/src/lib_shell/state_logging.ml b/src/lib_shell_services/state_logging.ml similarity index 100% rename from src/lib_shell/state_logging.ml rename to src/lib_shell_services/state_logging.ml diff --git a/src/lib_shell/state_logging.mli b/src/lib_shell_services/state_logging.mli similarity index 100% rename from src/lib_shell/state_logging.mli rename to src/lib_shell_services/state_logging.mli diff --git a/src/proto_alpha/lib_delegate/client_baking_blocks.ml b/src/proto_alpha/lib_delegate/client_baking_blocks.ml index a5c94d0207aa..1c201f7cdd09 100644 --- a/src/proto_alpha/lib_delegate/client_baking_blocks.ml +++ b/src/proto_alpha/lib_delegate/client_baking_blocks.ml @@ -73,7 +73,7 @@ let monitor_valid_blocks cctxt ?chains ?protocols ~next_protocols () = f "Saw block %a on chain %a" -% t event "monitor_saw_valid_block" -% a Block_hash.Logging.tag block - -% a Tezos_shell.State_logging.chain_id chain + -% a State_logging.chain_id chain -% t block_header_tag data) ; raw_info cctxt ~chain:(`Hash chain) block data.Tezos_base.Block_header.shell) block_stream) diff --git a/src/proto_alpha/lib_delegate/dune b/src/proto_alpha/lib_delegate/dune index 430fcbe521be..ed916b4a9a3c 100644 --- a/src/proto_alpha/lib_delegate/dune +++ b/src/proto_alpha/lib_delegate/dune @@ -4,7 +4,6 @@ (libraries tezos-base tezos-protocol-alpha tezos-protocol-environment - tezos-shell tezos-shell-services tezos-client-base tezos-client-alpha @@ -31,7 +30,6 @@ (libraries tezos-base tezos-protocol-alpha tezos-protocol-environment - tezos-shell tezos-shell-services tezos-client-base tezos-client-alpha @@ -55,7 +53,6 @@ (libraries tezos-base tezos-protocol-alpha tezos-protocol-environment - tezos-shell tezos-shell-services tezos-client-base tezos-client-alpha -- GitLab From 9cb6d799fae750d6460e494348ce0ac686f77040 Mon Sep 17 00:00:00 2001 From: Sebastien Mondet Date: Tue, 20 Nov 2018 14:17:00 -0500 Subject: [PATCH 3/3] Remove wrong dependency in tezos-baking-alpha.opam --- src/proto_alpha/lib_delegate/tezos-baking-alpha.opam | 1 - 1 file changed, 1 deletion(-) diff --git a/src/proto_alpha/lib_delegate/tezos-baking-alpha.opam b/src/proto_alpha/lib_delegate/tezos-baking-alpha.opam index 541e3eb666a2..87e71ee1c037 100644 --- a/src/proto_alpha/lib_delegate/tezos-baking-alpha.opam +++ b/src/proto_alpha/lib_delegate/tezos-baking-alpha.opam @@ -12,7 +12,6 @@ depends: [ "tezos-base" "tezos-protocol-environment" "tezos-protocol-alpha" - "tezos-shell" "tezos-shell-services" "tezos-client-base" "tezos-client-commands" -- GitLab