Our block at slot 306877 got orphaned. The block that took our place has slot number 306886. I would understand this if it was just 1, 2 or maybe even 3 seconds later, but shouldn’t 9 seconds be enough to propagate the block to most of the nodes? Most of my outgoing and incoming peers have a RTT of less than 50 ms. Also the block was visible in some block explorers first, but then was replaced.
I think the problem is that your node did not get the block at slot 306886 in time. I also had this issue, that is why I started to measure the network delay…
So when my node was scheduled to create the block, in the same time there where a significant delay receiving the validated blocks…
No, the other way around, because that block has a higher slot number than mine. They did not get my block in time (9 seconds later). I’ll give some more details below.
Did some digging (all times in UTC), on PoolTool:
Date | Slot | Pool | Block no. | Block hash | Status |
---|---|---|---|---|---|
10:59:28 | 306877 | NIMUE (me) | 5547977 | e6dfb148 … 47ef65cd | orphaned |
10:59:37 | 306886 | Binance 41 | 5547977 | 558241f6 … bd985a76 | adopted |
10:59:46 | 306895 | OCEA1 | 5547978 | 2dc43618 … d730f4d9 | orphaned |
10:59:40 | 306889 | ETO2 | 5547978 | 72449bcf … 963ecdcc | adopted |
You can see that the first two blocks have the same block no. and that the last two blocks also have the same block no. Also, the last two blocks are not listed chronologically, I guess this is the order in which PoolTool has received them.
In the logs of my relay node I can see that it saw all the blocks immediately after they were forged (except the one of OCEA1 which I saw only three seconds later). Also my own block was seen a minute before it was forged by my BPN, but that’ll be a minor clock mismatch I guess which should not be a problem.
What also is very strange, the message from my relay node that says “Chain extended, new tip” with my block hash only at 12:59:37, also 9-10 seconds after it has fetched it from my BPN. Why would that be the case?
I also see a lot of FetchDeclineChainNotPlausible messages in my log, also for my own forged block, but also on other blocks. Why is that and what does that mean? My block was given to other nodes, because for a moment it was listed in the minted blocks on some block explorers and on PoolTool you can see it as an orphaned block.
How can I check on what block the orphaned block of OCEA1 is based? I tried cncli validate, but it cannot find the block anymore (probably becuase it got removed from the DB because it was orphaned).
I understand that slot wars are possible, but that is not the case here, because all the slots are different. I also understand that height wars are possible, but it’s strange that this happens with two blocks nine second seperated in time…
I would be very happy if some other pool operators can check their relay node log (not BNP log!) for the order and exact time in which they received the four aformentioned blocks. I tried to contact OCEA1 because they also have an orphaned block, probably based on mine. But I cannot find contact information anywhere besides a Twitter where DM’s are turned off…
Thanks.
On PoolTool I also see high values of propgation delay of that block, 9000 and above. Is that how many ms after slot time the nodes received my block? Because that would explained what happened.
But it wouldn’t explain WHY it took so long for the block to get out. Also, is it a coincidence that the block with the same block number from Binance 41 also happened to be forged 9 seconds after mine?
The 9 seconds is also the time that my relay node said “Chain extended, new tip”. But why would it wait 9 seconds after fetching that block from my BPN? Does the FetchDeclineChainNotPlausible has someting to do with that? But if it does, you wouldn’t expect it to send it anyway after 9 seconds.
I really want to know if I can do something about this before forging my next block, that it doesn’t happen again. I’ve already turned off mempool tracing in the config of my relay node (after this happened), CPU is now a lot less (but it wasn’t so that the node was unresponsive before, just a higher load).
ok, understand for the first time I thought that your slot time was earlier…
yes.
that is interesting, why there is so much delay between your BP and relay… definitely could cause the situation…
My question is what was the highest slot in your BP node when the 306877 was produced - probably the parent of 306886.
There is no delay between BP node en relay node. The relay node was immediately aware of the block produced by the BP (if you look at the timestamp in the log even before it was forged :p, that’ll be a slight difference in clock of less than a second). But for some reason it decided FetchDeclineChainNotPlausible, and yet nine seconds later it the chain was extended with it, but too late. I really want to know if indeed other nodes only received it nine seconds after forging…
can you please send the related log statement for this event in relay?
What is also curious at 12:59:37 there first is a log entry that the block forged by Binance 41 is seen and after it with the same time that the chain was extened with my block. This isn’t a coincidence I think.
Here the log from my relay:
RELAY FETCHING MY BLOCK FROM MY CORE NODE (FetchDeclineChainNotPlausible): Apr 04 12:59:27 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:27.99 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Right [At (Block {blockPointSlot = SlotNo 25967677, blockPointHash = e6dfb148ab2d8bd607985d4c32465ad0a0fae4b833ffb76f013c5d6447ef65cd})]),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
Apr 04 12:59:30 nimue-relay1 bash[1332]: [nimue-re:cardano.node:Info:18780] [2021-04-04 10:59:30.50 UTC] fromList [("time(ps)",Number 6.6131797628408e16),("kind",String "MeasureTxsTimeStart"),("mempoolNumBytes",Number 1202.0),("mempoolNumTxs",Number 3.0)]
Apr 04 12:59:30 nimue-relay1 bash[1332]: [nimue-re:cardano.node.Mempool:Info:18780] [2021-04-04 10:59:30.50 UTC] fromList [("tx",Object (fromList [("txid",String "txid: TxId {_unTxId = \"5c33265d0e587315ad40c862b62fbe4e69602f924dc9c7e1df6f9b7b8f30e58a\"}")])),("kind",String "TraceMempoolAddedTx"),("mempoolSize",Object (fromList [("numTxs",Number 3.0),("bytes",Number 1202.0)]))]
Apr 04 12:59:30 nimue-relay1 bash[1332]: [nimue-re:cardano.node.Mempool:Info:268] [2021-04-04 10:59:30.52 UTC] fromList [("tx",Object (fromList [("txid",String "txid: TxId {_unTxId = \"5c33265d0e587315ad40c862b62fbe4e69602f924dc9c7e1df6f9b7b8f30e58a\"}")])),("kind",String "TraceMempoolRejectedTx"),("mempoolSize",Object (fromList [("numTxs",Number 3.0),("bytes",Number 1202.0)])),("err",Object (fromList [("kind",String "BadInputsUTxO"),("error",String "The transaction contains inputs that do not exist in the UTxO set."),("consumed",Object (fromList [("lovelace",Number 0.0),("policies",Object (fromList []))])),("badInputs",Array [Array [String "3fa78413aba48f4a3a3749c64349366aa714300ba076689a56d16cb2a109d854",Number 0.0]]),("produced",Object (fromList [("lovelace",Number 1.054774257e9),("policies",Object (fromList []))]))]))]
Apr 04 12:59:30 nimue-relay1 bash[1332]: [nimue-re:cardano.node.Mempool:Info:14375] [2021-04-04 10:59:30.65 UTC] fromList [("tx",Object (fromList [("txid",String "txid: TxId {_unTxId = \"5c33265d0e587315ad40c862b62fbe4e69602f924dc9c7e1df6f9b7b8f30e58a\"}")])),("kind",String "TraceMempoolRejectedTx"),("mempoolSize",Object (fromList [("numTxs",Number 3.0),("bytes",Number 1202.0)])),("err",Object (fromList [("kind",String "BadInputsUTxO"),("error",String "The transaction contains inputs that do not exist in the UTxO set."),("consumed",Object (fromList [("lovelace",Number 0.0),("policies",Object (fromList []))])),("badInputs",Array [Array [String "3fa78413aba48f4a3a3749c64349366aa714300ba076689a56d16cb2a109d854",Number 0.0]]),("produced",Object (fromList [("lovelace",Number 1.054774257e9),("policies",Object (fromList []))]))]))]
Apr 04 12:59:30 nimue-relay1 bash[1332]: [nimue-re:cardano.node.Mempool:Info:10579] [2021-04-04 10:59:30.65 UTC] fromList [("tx",Object (fromList [("txid",String "txid: TxId {_unTxId = \"5c33265d0e587315ad40c862b62fbe4e69602f924dc9c7e1df6f9b7b8f30e58a\"}")])),("kind",String "TraceMempoolRejectedTx"),("mempoolSize",Object (fromList [("numTxs",Number 3.0),("bytes",Number 1202.0)])),("err",Object (fromList [("kind",String "BadInputsUTxO"),("error",String "The transaction contains inputs that do not exist in the UTxO set."),("consumed",Object (fromList [("lovelace",Number 0.0),("policies",Object (fromList []))])),("badInputs",Array [Array [String "3fa78413aba48f4a3a3749c64349366aa714300ba076689a56d16cb2a109d854",Number 0.0]]),("produced",Object (fromList [("lovelace",Number 1.054774257e9),("policies",Object (fromList []))]))]))]
RELAY SEES OTHER BLOCK FROM BINANCE WITH SAME BLOCK NO AS MINE: Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:37.24 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Right [At (Block {blockPointSlot = SlotNo 25967686, blockPointHash = 558241f6312c1ed94dcefad7ba2b2038cfae16fd1d3468a4a57f1303bd985a76})]),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineAlreadyFetched),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:37.29 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineAlreadyFetched),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left FetchDeclineInFlightThisPeer),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
RELAY EXTENDING CHAIN WITH MY BLOCK: Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.ChainDB:Notice:48] [2021-04-04 10:59:37.35 UTC] Chain extended, new tip: e6dfb148ab2d8bd607985d4c32465ad0a0fae4b833ffb76f013c5d6447ef65cd at slot 25967677
Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.ChainDB:Notice:48] [2021-04-04 10:59:37.35 UTC] before next, messages elided = 66138644376224
RELAY EXTENDING CHAIN WITH MY BLOCK (REPEAT): Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.ChainDB:Notice:48] [2021-04-04 10:59:37.35 UTC] Chain extended, new tip: e6dfb148ab2d8bd607985d4c32465ad0a0fae4b833ffb76f013c5d6447ef65cd at slot 25967677
FORK RECOGNIZED: Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.ChainDB:Info:48] [2021-04-04 10:59:37.35 UTC] Block fits onto some fork: 558241f6312c1ed94dcefad7ba2b2038cfae16fd1d3468a4a57f1303bd985a76 at slot 25967686
Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.Mempool:Info:56] [2021-04-04 10:59:37.35 UTC] fromList [("kind",String "TraceMempoolRemoveTxs"),("mempoolSize",Object (fromList [("numTxs",Number 1.0),("bytes",Number 413.0)])),("txs",Array [Object (fromList [("txid",String "txid: TxId {_unTxId = \"ffa76d7d32d25662036394e5ea754a547a3e6c28d2a38947121a9af16e04cd5d\"}")]),Object (fromList [("txid",String "txid: TxId {_unTxId = \"3b9e1ee405abead92b11d7e28b1edc81e7ff46447384b87838638a7958d8f021\"}")])])]
Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:37.35 UTC] before next, messages elided = 2
Apr 04 12:59:37 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:37.35 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineAlreadyFetched),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left FetchDeclineInFlightThisPeer),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible)]
RELAY SEES OTHER BLOCK MINTED BY OCEA1 THAT HAS BEEN ORPHANED: Apr 04 12:59:46 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:46.08 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Right [At (Block {blockPointSlot = SlotNo 25967695, blockPointHash = 2dc4361886ffc9e5de2e2d225ca4fffdcd7972cfcd5af2eb1219aaa3d730f4d9})]),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
Apr 04 12:59:46 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:46.08 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Left FetchDeclineInFlightThisPeer),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
Apr 04 12:59:46 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:46.15 UTC] before next, messages elided = 1
Apr 04 12:59:46 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:46.15 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Left FetchDeclineInFlightThisPeer),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
RELAY EXTENDS CHAIN WITH BLOCK FROM OCEA1: Apr 04 12:59:46 nimue-relay1 bash[1332]: [nimue-re:cardano.node.ChainDB:Notice:48] [2021-04-04 10:59:46.15 UTC] Chain extended, new tip: 2dc4361886ffc9e5de2e2d225ca4fffdcd7972cfcd5af2eb1219aaa3d730f4d9 at slot 25967695
Apr 04 12:59:46 nimue-relay1 bash[1332]: [nimue-re:cardano.node.Mempool:Info:56] [2021-04-04 10:59:46.16 UTC] fromList [("kind",String "TraceMempoolRemoveTxs"),("mempoolSize",Object (fromList [("numTxs",Number 0.0),("bytes",Number 0.0)])),("txs",Array [Object (fromList [("txid",String "txid: TxId {_unTxId = \"5c33265d0e587315ad40c862b62fbe4e69602f924dc9c7e1df6f9b7b8f30e58a\"}")])])]
RELAY SEES BLOCK FROM ETO2 THAT ORPHANED BLOCK FROM OCEA1: Apr 04 12:59:49 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:49.14 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Right [At (Block {blockPointSlot = SlotNo 25967689, blockPointHash = 72449bcf4014a42ffebd3cbe184c89a813c0f95666a41dbb60410e3b963ecdcc})]),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
Apr 04 12:59:49 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:49.15 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Left FetchDeclineInFlightThisPeer),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
FORK RECOGNIZED: Apr 04 12:59:49 nimue-relay1 bash[1332]: [nimue-re:cardano.node.ChainDB:Info:48] [2021-04-04 10:59:49.23 UTC] Block fits onto some fork: 72449bcf4014a42ffebd3cbe184c89a813c0f95666a41dbb60410e3b963ecdcc at slot 25967689
Apr 04 12:59:49 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:49.23 UTC] before next, messages elided = 4
Apr 04 12:59:49 nimue-relay1 bash[1332]: [nimue-re:cardano.node.BlockFetchDecision:Info:58] [2021-04-04 10:59:49.23 UTC] [TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35903, remoteAddress = 15.237.129.233:6000}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:37573, remoteAddress = 178.128.196.58:5001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:42321, remoteAddress = 18.159.65.241:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43209, remoteAddress = 209.151.148.76:3001}) (Left (FetchDeclineConcurrencyLimit FetchModeDeadline 1)),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33119, remoteAddress = 34.66.64.195:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:33843, remoteAddress = 75.32.204.221:6001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:34899, remoteAddress = 34.80.179.174:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35439, remoteAddress = 3.126.142.56:3001}) (Left FetchDeclineInFlightThisPeer),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:35611, remoteAddress = MY_CORE_LOCAL_IP:2770}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:36867, remoteAddress = 78.23.133.211:3022}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:39737, remoteAddress = 73.129.228.216:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40369, remoteAddress = 66.42.127.211:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:40743, remoteAddress = 178.128.187.12:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:41505, remoteAddress = 88.99.39.191:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43093, remoteAddress = 161.97.175.144:3004}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:43695, remoteAddress = 89.40.9.152:6000}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:44037, remoteAddress = 134.209.26.2:3001}) (Left FetchDeclineChainNotPlausible),TraceLabelPeer (ConnectionId {localAddress = MY_RELAY_LOCAL_IP:46189, remoteAddress = 157.90.151.159:6003}) (Left FetchDeclineChainNotPlausible)]
Apr 04 12:59:49 nimue-relay1 bash[1332]: [nimue-re:cardano.node.ChainDB:Info:48] [2021-04-04 10:59:49.24 UTC] Valid candidate 72449bcf4014a42ffebd3cbe184c89a813c0f95666a41dbb60410e3b963ecdcc at slot 25967689
RELAY SWITCHES TO THE CHAIN WITH BLOCKS FROM BINANCE AND ETO2: Apr 04 12:59:49 nimue-relay1 bash[1332]: [nimue-re:cardano.node.ChainDB:Notice:48] [2021-04-04 10:59:49.24 UTC] Switched to a fork, new tip: 72449bcf4014a42ffebd3cbe184c89a813c0f95666a41dbb60410e3b963ecdcc at slot 25967689
and have you received the parent block of binance?
Yes, waaaaaaaaaaaaaay (i.e. 16 seconds) before mine was forged, from the logs of my block producing node this time:
Apr 04 12:59:12 nimue-core bash[1250]: [nimue-co:cardano.node.ChainDB:Notice:49] [2021-04-04 10:59:12.32 UTC] Chain extended, new tip: d890fd5bc8ba7f0437c7f017b330eb9591205daa7c12b9d561f0a6454639a192 at slot 25967661
But that shouldn’t matter with the one curious thing: my relay node sees my minted block, nine seconds later it sees the block from Binance and only then it extends the chain with my block. I guess other nodes can only see it after the local version of the chain is extened and the propagatio delays
confirm this.
But I don’t know why the wait…
The timing difference is also strange, but such a small difference shouldn’t be a problem in a dsitributed system. BP node logs forge at ‘10:59:28.01 UTC’ according to BP’s time. Relay logs first seen at ‘10:59:27.99 UTC’ according to relay’s time.
did you have successful block creation before? when was the chain extension event with your block in relay at that time?
also consider using chrony to have better system time.
Yes and it was added to the chain and propagated immediately after it was first seen by the relay. Also no mention of FetchDeclineChainNotPlausible.
This morning, we’ve minted another block that wasn’t held hostage by our relay node and was propagated immediately. Things changed since the problem:
- Installed Chrony for better time synchronization on core node and relay node. Also,
our relay node uses our core node as primary time server (same LAN), so the time on the relay node shouldn’t run ahead of the time on the core node anymore.our core node uses our relay node as primary time server (same LAN). - Disabled TraceMemPool on relay node which lowered CPU load from 30-60% to about 1%.
I don’t think these measures should make a difference, but they do lead to a more robust setup.
I hope this was a one-time thing and from now on this problem doesn’t arise anymore.
Hello. How many relays do you have? And how many peers do you have in your topology?
For the time being only one relay node. About 20 peers. But the problem wasn’t getting the blocks fast to other nodes, the problem was inside of the relay node that it decided not to add the block to the chain immediately. Also, the peers in my topology don’t matter I think, only who has me as a peer in their topology, because from what I understand, blocks are pulled by incoming peers, not pushed to outgoing peers.
I am a newbie so I might misinterpret the metrics. On PoolTool, you can download the propagation delay and in tiptiming your orphan block has about 9s with all peers.
Yes, but that is the time between forging and the other nodes adding it to the chain db. Most of that delay was within my relay node, it waited 9 seconds to add it to its own chain db. Only then other nodes could fetch it (what happend with ‘normal’ delays). My problem had nothing to do with slow network connections.
I understand it makes sense. It should be a problem in the validation with your relay. Do you know if you got a high CPU usage or else?
As I said in the last comment before your first comment, my CPU load was indeed relatively high, but not to an extent that this should occur… I’ve disabled mempool tracing now to lower CPU load.