hbbft consensus message memorial (tracking)

[SurfingNerd]

Currently it is very hard to figure out, which node did send it's contribution shares to whom,
and which node did not send any.
it requires a lot of deep analysis of log files, what is very time consuming.

In the long term, it is required for identifying inactive consensus nodes, so the nodes can agree on a malice report for the specific node.

There are different options:

• provide the information via RPC call
• continuous output in the log files all few seconds
• write out as files

Development Branch: https://github.com/SurfingNerd/openethereum-3.x/tree/surfingnerd/hbbft-message-memorium

Settings

• Number of Blocks to store staging implementation for configurability of consensus memorial #91
• Configurable storage directory ( example /tmp/dmdmessages/ temp dir allows us to store it in memory ) (Configurable storage directory ( example /tmp/dmdmessages/ temp dir allows us to store it in memory #93)

Values to Track

• Consensus tracking of contributions, sealings and steps for each block and each Validator #94
• Delay of contribution for each block and each Validator (after finishing block)

Usage of Data

• provide Data by the Prometheus Interface. provide hbbft data by via Prometheus Interface. diamond-node#14

[SurfingNerd]

i can confirm that the system builds the block after receiving enough signatures, but it still receives all messages, what is exactly what we need.
example:

0x59ec…3f5f
2021-07-19 15:43:07  Worker Client1 TRACE consensus  Sending exclusive message to 0x8de7…4354
2021-07-19 15:43:07  Worker Client1 TRACE consensus  Sending exclusive message to 0xe362…4752
2021-07-19 15:43:07  Worker Client1 TRACE consensus  Sending exclusive message to 0xf9f7…a608
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Received message of idx 23558  Message { epoch: 436, content: Subset(Message { proposer_id: 0d..6b, content: Agreement(Message { epoch: 2, content: Term(false) }) }) } from NodeId(0x59ec…3f5f)
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Skipping honey_badger forward to epoch(block) 436, was at epoch(block) 437.
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Received message of idx 21461  Message { epoch: 436, content: Subset(Message { proposer_id: 0d..6b, content: Agreement(Message { epoch: 2, content: Term(false) }) }) } from NodeId(0x0ddc…956b)
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Skipping honey_badger forward to epoch(block) 436, was at epoch(block) 437.
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Received message of idx 21918  Message { epoch: 436, content: Subset(Message { proposer_id: 0d..6b, content: Agreement(Message { epoch: 2, content: Term(false) }) }) } from NodeId(0x11c7…6bc6)
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Skipping honey_badger forward to epoch(block) 436, was at epoch(block) 437.
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Received message of idx 17964  Message { epoch: 436, content: Subset(Message { proposer_id: 0d..6b, content: Agreement(Message { epoch: 2, content: Term(false) }) }) } from NodeId(0xf9f7…a608)
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Skipping honey_badger forward to epoch(block) 436, was at epoch(block) 437.
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Received message of idx 21269  Message { epoch: 436, content: Subset(Message { proposer_id: 0d..6b, content: Agreement(Message { epoch: 2, content: Term(false) }) }) } from NodeId(0xe362…4752)
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Skipping honey_badger forward to epoch(block) 436, was at epoch(block) 437.
2021-07-19 15:43:07  Worker Hbbft1 TRACE engine  replay_cached_messages: Could not query posdao epoch at parent block#436, re-trying later. Probably due to the block not being imported yet.
2021-07-19 15:43:07  Worker Hbbft1 TRACE consensus  Skipping honey_badger forward to epoch(block) 436, was at epoch(block) 437.
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Received sealing message  Message(SignatureShare(0d64..6c52)) from NodeId(0x8de7…4354)
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Skipping honey_badger forward to epoch(block) 436, was at epoch(block) 437.
2021-07-19 15:43:07  Worker Client2 TRACE consensus  Received signature share for block 436 from NodeId(0x8de7…4354)
2021-07-19 15:43:07  Worker Client0 TRACE consensus  Received sealing message  Message(SignatureShare(14a4..db38)) from NodeId(0xf9f7…a608)
2021-07-19 15:43:07  Worker Client0 TRACE consensus  Skipping honey_badger forward to epoch(block) 436, was at epoch(block) 437.
2021-07-19 15:43:07  Worker Client0 TRACE consensus  Received signature share for block 436 from NodeId(0xf9f7…a608)
2021-07-19 15:43:07  Worker Client0 TRACE consensus  Signature for block 436 is ready

[SurfingNerd]

it's better to use an own fork of HBBFT.
Since the messages are only public within the crate.
The only way to access detail information i have found so far is to workaround over serialisation, like json.
The problem with it: the messages contain the byte arrays as well, and JSON serializing/deserialisation of that information becomes very CPU/memory intensive.

[SurfingNerd]

state of message memorial should also be written out to the terminal, so we have more tools for error analysis.
this should also include the current state of the hbbft.

[SurfingNerd]

Here is an example of some tracked faulty messages

2023-04-21 22:17:47  Worker Client2 TRACE consensus  Received message of idx 2  Message { epoch: 252, content: Subset(Message { proposer_id: 66..60, content: Broadcast(Value(Proof { #1, root_hash: 858f..3003, value: 435b..f396, .. })) }) } from NodeId(0x66ca…ce60)
2023-04-21 22:17:47  Worker Client2 WARN consensus  Block 252 Node NodeId(0x66ca…ce60) reported fault: SubsetFault(BroadcastFault(MultipleValues))
2023-04-21 22:17:47  Worker Client0 TRACE consensus  Received message of idx 13  Message { epoch: 252, content: Subset(Message { proposer_id: 66..60, content: Broadcast(Echo(Proof { #9, root_hash: 858f..3003, value: 73a4..4b48, .. })) }) } from NodeId(0x66ca…ce60)
2023-04-21 22:17:47  Worker Client0 WARN consensus  Block 252 Node NodeId(0x66ca…ce60) reported fault: SubsetFault(BroadcastFault(MultipleEchos))
2023-04-21 22:17:47  MessageMemorial WARN hbbft_message_memorium  add_message_event_faulty: event.block_num 252 <= last_message_faulty 252
2023-04-21 22:17:47  MessageMemorial WARN hbbft_message_memorium  add_message_event_faulty: event.block_num 252 <= last_message_faulty 252
2023-04-21 22:17:47  Worker Client1 TRACE consensus  Received message of idx 20  Message { epoch: 252, content: Subset(Message { proposer_id: 66..60, content: Broadcast(Echo(Proof { #12, root_hash: 858f..3003, value: 7ddc..da2e, .. })) }) } from NodeId(0x743b…800f)
2023-04-21 22:17:47  Worker Client1 WARN consensus  Block 252 Node NodeId(0x743b…800f) reported fault: SubsetFault(BroadcastFault(MultipleEchos))
2023-04-21 22:17:47  MessageMemorial WARN hbbft_message_memorium  add_message_event_faulty: event.block_num 252 <= last_message_faulty 252
2023-04-21 22:17:48  Worker Client0 TRACE txqueue  [0x0eb1216c15a3e570dc7270b2ed7f2120e97f3903f7866193f4f9484379fc3f58] Rejecting recently rejected: NotAllowed

[SurfingNerd]

Malice Reports get a redesign with the Bonus Score System. We will address it there.