Jormungandr: Question: initial bootstrap failed, error: BlockMissingParent... referring to block0, but wrong parent.

[rinor]

Describe the bug

Blocks already in storage:

• Block0 - 8c9bc5e8e244f5e902e25307e2b3d7f6eb6bd2827b73be42493dbd58e3028e28
• NextBlock - 60aa2fc89aff3da69835eef91e72169ea5802b7f0ec33c7d19a453dd3bb7c800
• .....
• _OtherBlocks_

---

- Block0 parent of NextBlock

At some point after the node is done retrieving/checking the blocks from storage:

Dec 10 13:43:29.544 DEBG retrieving block0 from storage with hash 8c9bc5e8e244f5e902e25307e2b3d7f6eb6bd2827b73be42493dbd58e3028e28, task: init

It connects to bootstrap peer, and decides the starting point block to retieve, in this case
starting from 305a69a7fc9b67c107c8e722ff531e3a5c4d8e1e3a6ad8c48640796f322717bb.
For some reasons (assumtions made later) it fails reporting BlockMissingParent(Hash(Blake2b256(0x8c9bc5e8e244f5e902e25307e2b3d7f6eb6bd2827b73be42493dbd58e3028e28))).

But that is the Block0 and for sure is not supposed to be missing...

Dec 10 13:49:56.544 INFO connecting to bootstrap peer 139.99.221.149:4006, peer_addr: 139.99.221.149:4006, task: bootstrap
Dec 10 13:49:56.824 DEBG pulling blocks starting from 305a69a7fc9b67c107c8e722ff531e3a5c4d8e1e3a6ad8c48640796f322717bb, peer_addr: 139.99.221.149:4006, task: bootstrap
Dec 10 13:49:57.108 WARN initial bootstrap failed, error: BlockMissingParent(Hash(Blake2b256(0x8c9bc5e8e244f5e902e25307e2b3d7f6eb6bd2827b73be42493dbd58e3028e28))), peer_addr: 139.99.221.149:4006, task: bootstrap

Mandatory Information

1. jormungandr 0.8.0-rc10 (master-73f68fc3, debug, linux [x86_64]) - [rustc 1.39.0 (4560ea788 2019-11-04)]

To Reproduce
Steps to reproduce the behavior:

1. Connect to a testnet (tested only on Cardano Private Testnet from telegram)
2. See error:

Dec 10 13:43:29.530 INFO Starting jormungandr 0.8.0-rc10 (master-73f68fc3, debug, linux [x86_64]) - [rustc 1.39.0 (4560ea788 2019-11-04)], task: init
Dec 10 13:43:29.530 DEBG system settings are: limit for open files (RLIMIT_NOFILE): 1024; limit for CPU usage (RLIMIT_CPU): 18446744073709551615, task: init
Dec 10 13:43:29.531 WARN Node started without path to the stored secret keys (not a stake pool or a BFT leader), task: init
Dec 10 13:43:29.537 INFO storing blockchain in '"jnode_storage/blocks.sqlite"', task: init
Dec 10 13:43:29.544 DEBG retrieving block0 from storage with hash 8c9bc5e8e244f5e902e25307e2b3d7f6eb6bd2827b73be42493dbd58e3028e28, task: init
Dec 10 13:49:56.544 INFO connecting to bootstrap peer 139.99.221.149:4006, peer_addr: 139.99.221.149:4006, task: bootstrap
Dec 10 13:49:56.824 DEBG pulling blocks starting from 305a69a7fc9b67c107c8e722ff531e3a5c4d8e1e3a6ad8c48640796f322717bb, peer_addr: 139.99.221.149:4006, task: bootstrap
Dec 10 13:49:57.108 WARN initial bootstrap failed, error: BlockMissingParent(Hash(Blake2b256(0x8c9bc5e8e244f5e902e25307e2b3d7f6eb6bd2827b73be42493dbd58e3028e28))), peer_addr: 139.99.221.149:4006, task: bootstrap
Dec 10 13:49:57.132 INFO start listening and accepting gRPC connections on 127.0.0.11:9001, task: network
Dec 10 13:49:57.132 INFO connecting to peer, node_id: e869d9bf130315f6c1ee630d850aea45158688ce635deb3e, peer_addr: 139.99.221.149:4006, task: network
Dec 10 13:49:57.133 DEBG scheduling events, nb_slots: 139, slot_start: 221, current_slot: 220, current_epoch: 192, epoch_tip: 192, task: leadership
Dec 10 13:49:57.134 DEBG no item scheduled, waiting for next epoch, task: leadership
Dec 10 13:49:59.583 INFO received block announcement, hash: d0ed48172e21cd9d19527583ea9c8ec909c61b1b1feed796b95bcafd1a5b0145, direction: in, stream: block_events, node_id: e869d9bf130315f6c1ee630d850aea45158688ce635deb3e, peer_addr: 139.99.221.149:4006, task: network
Dec 10 13:49:59.587 INFO receiving block announcement from network, from_node_id: e869d9bf130315f6c1ee630d850aea45158688ce635deb3e, date: 192.221, parent: 807819edf7a8011daaec70f4c5342780cf9491b6f495c3bcf1ed31509de4529e, hash: d0ed48172e21cd9d19527583ea9c8ec909c61b1b1feed796b95bcafd1a5b0145, task: block
Dec 10 13:49:59.588 DEBG block is missing a locally stored parent, from_node_id: e869d9bf130315f6c1ee630d850aea45158688ce635deb3e, date: 192.221, parent: 807819edf7a8011daaec70f4c5342780cf9491b6f495c3bcf1ed31509de4529e, hash: d0ed48172e21cd9d19527583ea9c8ec909c61b1b1feed796b95bcafd1a5b0145, task: block
Dec 10 13:49:59.588 DEBG pulling headers, to: d0ed48172e21cd9d19527583ea9c8ec909c61b1b1feed796b95bcafd1a5b0145, from: [305a69a7fc9b67c107c8e722ff531e3a5c4d8e1e3a6ad8c48640796f322717bb, 8622ed3290778dc294a98e82c398d28c8663a64546be79bda6fd48d173808869, 2edb7b44964c51373b8d9561acabb38bddf4aa1105aee2b10d2d8702495c6dcb, 16a5dbca2aa2176ce0681fe67981f660a6b4ed0263cfe05bd2ff504846997cd9, 8422372e294d9d2d9dde52704bbb3d603f23dfd15542972c795297056c55a382, 1a1b80e79aa586e901ae244e681b77f1652b2ded2ed281fc7a258b64e33caf58, a127f0f4a6d75ec5c0e94debedde4416e356b777e21e86070da73de2a4ddc796, 1230a95d6326c549f1bdc552e722ed7998e97c78d4b5493b13b87fdc0092a05e, e8453f9868e7f90fdc8c1437813c8ca85b86c19df35e8c53bfba64a26d544feb, 50053a6ef436247a41dc933d4c7ea0fff1ef869c5da001dd0af308720e3f24bb, 4c4aa3219b28e8373a7947b12dd5abd1e3c76f5ce940306c8d73c09e5fde073e, aae1a57403afba2c4d3b16fd704a31cca197e0af6a4772a985efacee042b7373, f2f1d26e1633c038db67129b1d8326cd724fc16acfc104443e201c173f7b4a3d, 8a28800cbee20b4f3a12c68908f0a6e97a1c9d157cecb349142a49da70dd1cd7, aa5a7f90eeccedc6fe31a0b74fed9450621c24c8d2e15da87d941740506edac6, 2a6ae46efb0bc5da1aa020934324d3ed47a3feb36942420daa7e6360bb763759, 1b6acb88e77ad3bed9ac05c63de9990623d4014188ea126e550fe05bdac857fb, d5717d0503d5c2e9be3ddbbb84bd47eea14426db131d1f6c98889bc2e4366693, a705de3b0329d04ff787bcdaeea967d2dcbdd1e3c1a398a786990c53ba9c5d13, 7f614a8c1412667d677df6d2ee0d4650f7e42f894de6ce6019567a2062560771, 3daf01aadae8e33ef28929ef6f60b59d29da5423c5eab10dec879abd0b9b9d63, 4d5abceb1c511d763ea3942156abc9a64aee2cf8880f18d761466ca1cb631225], node_id: e869d9bf130315f6c1ee630d850aea45158688ce635deb3e, task: network
Dec 10 13:49:59.590 INFO receiving header stream from network, task: block

Expected behavior
Not much else, just want to verify in what case scenarios this may happen, and most important how to check/prevent the harm it may cause, since I suspect it may be causing some other issues (to be reported on separate bur reports)

Additional context
I would like some help to check the causes and verify if this is a bug or not...

Could it be because of the presence of some nodes, residing in previous somewhat compatible version(s) of jörmungander, having the same genesis and still valid pools secrets. Since iirc that testnet did not invalidate block0 or pool secrets in a few versions now (compatible ones of course). Let me know if more information is required.

[bobdobs]

I got BlockMissingParent(Hash(Blake2b256(...)) for Block0 yesterday on nightly running on v0.8.0-rc10. Then I rc11 was released and I upgraded and started over after deleting storage.

Since upgrading to rc11 I have experienced similar issues to what rinor described in this and other issues.

The node gets stuck for me after running for 10-20 minutes. Blocks are received, lastBlockTime is current, and blockRecvCnt is increasing. But lastBlockHeight remains stuck.

When I restart jormungandr it will pick up where it left off and work for another 10-20 minutes. Then it gets stuck again.

I have not dug as deep as rinor has, and I don't currently have DEBG enabled. However I found this "panic"-entry in my log:

Dec 11 20:14:12 minr jormungandr[5498]: incoming connection closed, peer_addr: 82.217.191.196:39408, task: network
Dec 11 20:14:12 minr jormungandr[5498]: failed to connect to peer, node_id: 9342cea38d5135b9f9c17afdbb4d9e94f0eaffea43c48606, peer_addr: 178.188.86.3:8082, task: network, reason: No route to host (os error 113)
Dec 11 20:14:13 minr jormungandr[5498]: connecting to peer, node_id: a0c01b4fb045930d6e8c365c9da402d7f8925da26928df33, peer_addr: 85.218.89.33:28888, task: network
...skipping...
Dec 11 20:56:09 minr jormungandr[5498]: Task panicked, reason: invalid key, task: block
Dec 11 20:56:09 minr jormungandr[5498]: incoming connection closed, peer_addr: 85.235.66.63:54180, task: network
Dec 11 20:56:09 minr jormungandr[5498]: incoming connection on 192.168.130.2:3033, peer_addr: 3.124.132.123:57662, task: network

...it may be related but I have no idea :-)

[rinor]

Task panicked, reason: invalid key, task: block is a new one and probably (awaiting confirmation) related to some latest changes related to a new additional garbage collector. Check this https://github.com/input-output-hk/jormungandr/issues/1327#issuecomment-564495516. I have some additional information about this and probably will file a new issue a bit later. Thank you for reporting it.

[rinor]

BlockMissingParent - Maybe fixed in https://github.com/input-output-hk/jormungandr/pull/1385

[NicolasDP]

it will big fixed in #1385 @mzabaluev fixed the server side of thing, I have added the client side fix too.