(the idea of this is to show the community how some efforts/works go behind the scenes without necessarily being shown or valued in terms of posts. Well, I wanted to change a bit of that because I value these collaborative effort situations and I think it makes sense to show it off as an inspiration for the community)

Some of you might know I have been trying to help as a witness on Hive-Engine. You can find some of the posts I made in @atexoras account, but the witness (node) in active duty is being operated via @atexoras.witness.

Recently my main node has been struck with some problems, which I saw as an opportunity to find more information for myself to learn and if possible help in the continuous development of the side-chain. This is not something awkward on blockchain technology I think? 🤔 At least not on HIVE I might guess (maybe I am too naive) 🤷‍♂️

Either way... I like to help and learn...

There are actually a great number of people always trying to help behind the scenes that most people don't know about. I am just a little pee on this great salad! But, the point is, everyone, can help... bit by bit, in collaboration, I can tell you, we are huge!

So... trying to show you a bit of how that work goes... I would say (for me), 7 or 8 out of 10 in terms of technicality... and I am trying to include everyone on this blockchain (or attempting to), so don't get scared! There is worse in life... 🤣

Context

Recently, as I said above, I have been having some problems with my node that we don't know yet the reason for. These are not impacting anyone because I am usually a backup witness although I disable myself when doing these tests in case something goes wrong.

Eventually, I started working (these last few weeks) with @eonwarped (or rather him with me?) trying to figure this out. And the following lines are just an example of that collaboration. Thank you for all your time on this mate!

In the following steps, I am trying to find common denominators for the problem's reproducibility while "eon" (can I call you that?) is looking at that info, troubleshooting it, and attempting fixes or finding what is the problem, eventually resulting in merge requests that we all try to re-validate before they get into production.

All of it is a time-consuming effort indeed, but as I said... I learn a lot, therefore, it's a ✔check for me!

After this point it becomes technical...

All tests below were made using code from replayWithParallelDbCompare branch.

Using branch replayWithParallelDbCompare (but without enableHashVerification verification)

     "genesisHiveBlock": 41967000,
-    "enableHashVerification": true,
-    "defaultLogLevel": "warn"

This was an attempt to see if something different would be unveiled with this code in comparison with the production one.

Because I have a script (he_awn.sh) that auto stops if forked, this is where it stopped...

...
0|prod-hivengwit  | 2021-12-27 02:06:41 info: [P2P] currentRound 494123
0|prod-hivengwit  | currentWitness apiculture
0|prod-hivengwit  | lastBlockRound 13352950
0|prod-hivengwit  | lastProposedRound null
0|prod-hivengwit  | 2021-12-27 02:06:44 info: [P2P] currentRound 494123
0|prod-hivengwit  | currentWitness apiculture
0|prod-hivengwit  | lastBlockRound 13352950
0|prod-hivengwit  | lastProposedRound null
0|prod-hivengwit  | 2021-12-27 02:06:47 info: [P2P] currentRound 494123
0|prod-hivengwit  | currentWitness apiculture
0|prod-hivengwit  | lastBlockRound 13352950
0|prod-hivengwit  | lastProposedRound null
0|prod-hivengwit  | 2021-12-27 02:06:49 info: [Streamer] head_block_number 60390978 currentBlock 60340184 Hive blockchain is 50794 blocks ahead
0|prod-hivengwit  | Node block fetch average for https://rpc.ausbit.dev/,https://api.hivekings.com/,https://hived.privex.io/ is 3603.9393063583816 with 346 requests
0|prod-hivengwit  | 2021-12-27 02:06:49 info: [Streamer] Node block fetch average for https://rpc.ecency.com/,https://techcoderx.com/,https://hived.privex.io/ is 1189.5805243445693 with 801 requests
0|prod-hivengwit  | Node block fetch average for https://hived.hive-engine.com/,https://hived.emre.sh/,https://hived.privex.io/ is NaN with 0 requests
0|prod-hivengwit  | Node block fetch average for https://api.followbtcnews.com/,https://api.hive.blog/,https://hived.privex.io/ is 4421.732057416268 with 209 requests
0|prod-hivengwit  | Node block fetch average for https://api.openhive.network/,https://hive.roelandp.nl/,https://hived.privex.io/ is 7045.192660550459 with 109 requests
0|prod-hivengwit  | Node block fetch average for https://api.pharesim.me/,https://api.deathwing.me/,https://hived.privex.io/ is 5440.6328125 with 128 requests
0|prod-hivengwit  | 2021-12-27 02:06:50 info: [P2P] currentRound 494123
0|prod-hivengwit  | currentWitness lassecashwitness
0|prod-hivengwit  | lastBlockRound 13352950
0|prod-hivengwit  | lastProposedRound null
0|prod-hivengwit  | 2021-12-27 02:06:53 info: [P2P] currentRound 494123
0|prod-hivengwit  | currentWitness lassecashwitness
0|prod-hivengwit  | lastBlockRound 13352950
0|prod-hivengwit  | lastProposedRound null
0|prod-hivengwit  | 2021-12-27 02:06:56 info: [P2P] currentRound 494123
0|prod-hivengwit  | currentWitness lassecashwitness
0|prod-hivengwit  | lastBlockRound 13352950
0|prod-hivengwit  | lastProposedRound null
0|prod-hivengwit  | 2021-12-27 02:06:56 info: Stopping node...
...

The `find_divergent_block` (@eonwraped findDivergentBlock branch version)

I got stuck at 60339903

Transaction 35 mismatch: This: {"refHiveBlockNumber":60339903,"transactionId":"e4cfc69931450bc8eba30da2ed44b8104abb46b3-0","sender":"null","contract":"comments","action":"comment","payload":"
...
divergent block id at 13352938

This is interesting because on my previous test it got stuck at block 60375997, which is way ahead of this block.

Doing another restore and re-running with `enableHashVerification` and `warn` on debug messages.

I am using LVM snapshots to quickly do these experiments, which allow me to have a sweet spot for testing...

This time got stuck at 60338529 (sooner)

0|prod-hivengwit  | 2021-12-27 04:59:54 info: [Blockchain] Sidechain Block 13351564, Main db hash: 3b5e440cff1d9ccb449d938d13aabdef92d01daa7884dfe0cb4dfd88d172e597, Main block hash: 40466e16b6749241761081033d1d999b62f316a9ad89954e72af6138ae785d7f, This db hash: 3b5e440cff1d9ccb449d938d13aabdef92d01daa7884dfe0cb4dfd88d172e597, This block hash: fe0da97895491d5e219b91bc8d9fe6eeb42a39cfad4424fb986411306a3cb113
0|prod-hivengwit  | 2021-12-27 04:59:54 error: [Blockchain] Error: Block mismatch with api 
0|prod-hivengwit  | Main: {
0|prod-hivengwit  |   "_id": 13351564,
0|prod-hivengwit  |   "blockNumber": 13351564,
0|prod-hivengwit  |   "refHiveBlockNumber": 60338529,
0|prod-hivengwit  |   "refHiveBlockId": "0398b16180f3cb934983c38fd4cf392bd851475d",
0|prod-hivengwit  |   "prevRefHiveBlockId": "0398b160fdaa0baaa79c3cebae918a14dfca983b",
0|prod-hivengwit  |   "previousHash": "875c4062325a9e75d35e291352fc853df3e0c194ba09a38b68fe3dce2147f272",
0|prod-hivengwit  |   "previousDatabaseHash": "7749082e82b0c670a8b4329cb8730a25925f040e5aca0042f1a561cb94c473f1",
0|prod-hivengwit  |   "timestamp": "2021-12-25T06:17:33",

I tried reducing antiForkBufferMaxSize at plugins/Streamer.js, from 5 to 3, but as I learned that doesn't do any effect because the database is already at a specific state. find_divergent_block.js needs the chain to be forked before being able to tell the divergent block.

So I disabled the enableHashVerification and restarted the node, letting it process more than what I had defined at antiForkBufferMaxSize, to find the diverged block information.

...
low 13351564 high 13351576
low 13351564 high 13351570
low 13351564 high 13351567
low 13351564 high 13351565
### high block
Transaction 0 matches
Transaction 1 matches
Transaction 2 matches
Transaction 3 matches
Transaction 4 matches
Transaction 5 matches
Transaction 6 matches
Transaction 7 matches
Transaction 8 matches
Transaction 9 mismatch: This: {"refHiveBlockNumber":60338529,"transactionId":"c964efe97bd40a2630a4eba2a9c136b6abe4a7ff","sender":"null","contract":"comments","action":"comment","payload":"
...
divergent block id at 13351564

To see if I could confirm my theory (at this point I had already one yes...) I have decided to do a 3rd test... so got the state back to my LVM snapshot and began synchronizing again.

Then it got stuck again!

This time... on block 60338810 (later)

0|prod-hivengwit  | 2021-12-27 05:44:36 info: [Blockchain] Sidechain Block 13351845, Main db hash: f3968324871df7d39c646e40dd6902c8be0f1cffb7cfb2542fceeb4f45e0e647, Main block hash: 38b031ddbed9fe4d5f23d955f602d3c52614aa1610ee1822017fed1d58142032, This db hash: f3968324871df7d39c646e40dd6902c8be0f1cffb7cfb2542fceeb4f45e0e647, This block hash: 553c3b3f882021b9ed259eb7791f441838582c01d39a8fff15a12db95833738c
0|prod-hivengwit  | 2021-12-27 05:44:36 error: [Blockchain] Error: Block mismatch with api 
0|prod-hivengwit  | Main: {
0|prod-hivengwit  |   "_id": 13351845,
0|prod-hivengwit  |   "blockNumber": 13351845,
0|prod-hivengwit  |   "refHiveBlockNumber": 60338810,
0|prod-hivengwit  |   "refHiveBlockId": "0398b27a1e46b6e6aa3c3189e6acbc096c84b42b",
0|prod-hivengwit  |   "prevRefHiveBlockId": "0398b27941233d860a2ae725424d8ebdd068cf2f",
0|prod-hivengwit  |   "previousHash": "e4ce7a4d0fab9a00d54bbf7cb08405c98021633831ae4652045a2cba34002141",
0|prod-hivengwit  |   "previousDatabaseHash": "f1ad66748cd820ca9ee4ab1319b0e67be00f0b4396d4c428bdb9ffd0879fa622",
0|prod-hivengwit  |   "timestamp": "2021-12-25T06:31:39",

There it goes my theory... this is completely random. Hence something either from the mongo software or external is affecting the way it behaves.

Disabling `enableHashVerification` to fork and get info...

...
low 13351814 high 13351863
low 13351839 high 13351863
low 13351839 high 13351851
low 13351839 high 13351845
low 13351843 high 13351845
### high block
Transaction 0 matches
Transaction 1 matches
Transaction 2 matches
Transaction 3 matches
Transaction 4 matches
Transaction 5 matches
Transaction 6 matches
Transaction 7 matches
Transaction 8 matches
Transaction 9 matches
Transaction 10 matches
Transaction 11 mismatch: This: {"refHiveBlockNumber":60338810,"transactionId":"88e6734497f4b50a94cc67e6ea084b8e409948e0-0","sender":"null","contract":"comments","action":"comment","payload":"
...
divergent block id at 13351845

After this, and touching base with @eonwarped, which recommended me to re-arrange a configuration file used for synchronization, the thing looks like behaving and it might have just made the trick. We might still need to do more troubleshooting, but the "Achilles Foot" might just be it...

I am still running on catch-up for a few more hours or up to a day or two, to be really sure these fixes are working great for final review and then deployment.

This experience has been invaluable to me and I can only thank you for the dedication and time from @eonwarped. Totally deserving of my vote as a Hive-Engine witness.

See you soon on 🎆2022🎇

Technicality has stopped! Now it's just me, back again... 🤣

If I don't get another chance to wish everyone a Happy New Year, this is it and might be my last post of 2021. Hopefully, this will be inspirational for anyone out there that wants to grasp for more or try to dig into HIVE and/or Hive-Engine inner parts.

🍀 For a great 💪 cause check this quick post about #tourettes 🤯 call for ⚡ action!

It will not take more than a few seconds of your time and potentially make many lives happier. Thank you for even considering reading it.

🖐️HIVE5's!

Have fun, good luck on all the gaming, and lots of teaching "how to play" to new players.

🤝 Twitter - @forkyishere 😈 (@forykw dark side)

For #news about the #HIVE blockchain, and other stuff. I am following all users!

In addition, if you are looking for a nice place to either reach out, share or just have a great time, come along to @atexoras.pub gatherings. We welcome everyone on the HIVE blockchain.