[BUG] - MissingBlockError for block k from tip

[karknu]

External

Summary One of my nodes encountered a MissingBlockError error which caused the cardano-node to exit. The “missing” block was for a block that was about k blocks from the tip which leads me to suspect that there is a race condition when you move blocks from the volatile db to the immutable db. Log messages:

node-20230919170240.json:{"app":[],"at":"2023-09-19T17:03:33.04Z","data":{"connectionId":{"localAddress":{"address":"10.0.0.1","port":"3001"},"remoteAddress":{"address":"11.0.0.1","port":"35797"}},"kind":"MuxErrored","reason":"UnexpectedFailure (MissingBlockError (EmptySlot (RealPoint (SlotNo 103532636) d2af962b1139168ba979d74ecc32e96a566e7ce0e6c327bdfdd5665d9fa813d6)))"},"env":"8.1.2:53422","host":"miami1","loc":null,"msg":"","ns":["cardano.node.InboundGovernor"],"pid":"2365086","sev":"Info","thread":"251"}
node-20230919170240.json:{"app":[],"at":"2023-09-19T17:03:33.04Z","data":{"connectionHandler":{"command":"ShutdownNode","context":"InboundError","kind":"Error","reason":"UnexpectedFailure (MissingBlockError (EmptySlot (RealPoint (SlotNo 103532636) d2af962b1139168ba979d74ecc32e96a566e7ce0e6c327bdfdd5665d9fa813d6)))"},"connectionId":{"localAddress":{"address":"10.0.0.1","port":"3001"},"remoteAddress":{"address":"11.0.0.1","port":"35797"}},"kind":"ConnectionHandler"},"env":"8.1.2:53422","host":"miami1","loc":null,"msg":"","ns":["cardano.node.ConnectionManager"],"pid":"2365086","sev":"Critical","thread":"62940"}
node-20230919170240.json:{"app":[],"at":"2023-09-19T17:03:49.17Z","data":{"kind":"DiffusionErrored","path":"ExceptionInHandler 11.0.0.1:35797 UnexpectedFailure (MissingBlockError (EmptySlot (RealPoint (SlotNo 103532636) d2af962b1139168ba979d74ecc32e96a566e7ce0e6c327bdfdd5665d9fa813d6)))"},"env":"8.1.2:53422","host":"miami1","loc":null,"msg":"","ns":["cardano.node.DiffusionInitializationTracer"],"pid":"2365086","sev":"Critical","thread":"7"}

Data from dbsync:

select block_no,time,slot_no,hash from block where block_no=(select block_no+180*12 from block where hash='\xd2af962b1139168ba979d74ecc32e96a566e7ce0e6c327bdfdd5665d9fa813d6');
 block_no |        time         |  slot_no  |                                hash                                
----------+---------------------+-----------+--------------------------------------------------------------------
  9310372 | 2023-09-19 17:03:27 | 103576716 | \xad1fb1233729b1ba3ee93fa315b299805e0d381af039367edcb596f236fdc67f

The block k blocks ahead of the missing block was forged at 2023-09-19 17:03:27 , that is 6 seconds from the log entry .

Steps to reproduce Not known, I've verified that the node normally manages to serve blocks around k blocks from the tip. I suspect this is a race condition so it may be easier to trigger in a simulation.

Expected behavior I expect the cardano-node to reliably be able to server blocks from the chain even if the block happens to be k from the tip.

System info (please complete the following information):

• OS Name: Debian
• OS Version: 12
• Consensus version: cardano-node 8.1.2 .