[BUG] - MissingBlockError for block k from tip #359
Assignees
Labels
Comments
|
The only I know that might be related is this: We have one race condition related to copying stuff to the ImmutableDB: But I have no idea if that is actually the cause. |
|
Your block of interest is d2af962b11 in slot 103532636 at blockno 9308212. The Cardano CLI converts the 2023-09-19T17:03:49Z timestamp from your log to slot 103576738. fafcff9b8a0 in slot 103576729 at blockno 9310373 If your node had selected fafcff9b8a0, then d2af962b11 was exactly your immutable tip (because 9310373 - 9308212 = k+1). (edit 3: this is right for the wrong reasons) Which does seem suspicious. Edit: Actually, your first error message is 16 seconds earlier, ie slot 103576722. The youngest block as of that moment is ad1fb12337 in slot 103576716 at blockno 9310372 for which your d2af962b11 would be the successor of the immutable tip (edit 3: this is wrong). Edit 2: it's possible that fafcff9b8a0 had a better tiebreaker than another block with height 9310373 in a slot <= 103576722. In which case d2af962b11 might have been indeed the immutable tip. But this seems relatively unlikely. Perhaps the rest of your logs could clarify @karknu? Edit 3: My counting above was off by one. Suppose k were 1. Then d2af962b11 would be your immutable tip when your selected block no was 9308212+k, not 9308212+k+1. Since 9308212+2160 = 9310372, then ad1fb12337 was the imm tip when ad1fb12337 (from the first Edit) was your tip. |
|
Two theories:
That's as far as we've considered so far (triage). |
|
@nfrisby Here is the output during startup. To me it looks like the immutable tip was d2af962b11 . |
|
The is no trace of any forks ( |
|
Hmm. This log message indicates that
This suggests an hypothesis.
|
|
I was able to reproduce something similar to this error on my local setup. The setup is as follows:
Then the n2n-pg processes sometimes exits with: So the server is saying It seems it has to do with timing, as sometimes I have been able to spawn over 30 instances and it would still work. It also seems that the more processes I spawn, the more it takes for any of them to start streaming blocks. Perhaps there is some bound on the resources available in the server to attend all those requests? As I increase the number of processes it becomes more likely for the error to happen. |
|
I'm trying to see if this is to do with exhausting resources, by tracing the exceptions thrown by the node when attacked like this. I am being unable to reproduce it because it seems between the point at which I make the query and the moment the profiled (slow) node starts answering, enough time has passed for everything to work. |
|
I provided @johnalotoski a patched node (https://github.com/IntersectMBO/cardano-node/tree/js/clarify-missing-block) to try to shed some light by adding more data to the printed message. Will wait for results |
|
With the patch I provided, we can see the following information: Just a first eyeball over it already shows several things: |
|
Correction, it is probably not |
|
I do have a hypothesis. First of all, when we try to get the information for a slot, we call this function: This will first compute which offset should the block be in, then read that offset from the Index. To compute which offset the block would be in, we call Say we want the Now we try to read this offset from the index by calling This will consult the MVar of the cache, and then check if splitting the sequence at the desired point gives us two sequences which don't end and start with the same slot (which would indicate that it is a Now two other observations: when is this value updated and how did we end up looking in the immutable db. We ended up looking in the immutable DB because the desired point is no longer in the Before removing it from the chain, we have called which in turn will call So the values there will supposedly be updated. This is basically a race condition https://hackage.haskell.org/package/base-4.20.0.1/docs/Control-Concurrent-MVar.html#v:modifyMVar_
My suggestions are the following: |
As you are quoting this part of the documentation: What other producers are there for |
|
Right indeed. I was discussing this with Joris. There doesn't seem to be a single If things don't align correctly this might result in outdated information ending up in the MVar, no? |
|
This ticket is blocked on the results from the deployed relays by @johnalotoski, with the patch in https://github.com/IntersectMBO/ouroboros-consensus/tree/js/tvar-cache |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
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:
Data from dbsync:
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
kblocks 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
kfrom the tip.System info (please complete the following information):
The text was updated successfully, but these errors were encountered: