consensus failure due to incorrect crankhash synchronization #3720
Comments
|
The latest experiment, with two validators ("good" and "bad"). We bounced "bad" between block 92 and 93. Nothing happens until the next timer wakeup, which must do a The first such delivery reports a different |
|
I instrumented Simply removing the |
|
I'm fairly sure that increment is supposed to be there, but I think it should only be there for the initial startup (i.e., it probably should be happening but probably should be initiated from a slightly different location in the code). |
|
Oh, like do it in One quick solution would be to add |
|
Currently, we call
which means there will be a pending (not-yet-committed) DB write of I think the right solution is to call
That should remove the extra DB write during |
|
I don't remember for sure but I think there may be one or two other things that read the crank number during the crank, and these need a correct number to read. Incrementing the crank number at the start of the crank is the right thing to do, but we do need to take care that it can't happen twice. |
|
Oh, it's deeper than that. The crankbuffer includes the The fix is going to be to commit more often. In addition to the |
We observed a consensus failure on the chain that was triggered by a validator getting restarted. The root cause seems to be that device calls (specifically `poll()` on the timer device) cause state changes, which are accumulated in the crankhasher and linger in the crank buffer until something causes them to be committed. This commit doesn't happen until a delivery is successfully made to some vat, which occurs in a subset of the times that `kernel.run()` is invoked. On the chain, each block causes a `poll()` followed by a `kernel.run()`. If the `poll()` did not cause any timers to fire, the timer device will not enqueue any messages to the timer vat, the run-queue remains empty, and `run()` has no work to do. Therefore the crank buffer is not committed. Imagine a chain in which some delivery causes everything to be committed in block 1, then blocks 2-9 have a `poll()` but no actual deliveries, then something happens to make block 10 have a delivery (causing a commit). Now follow validator A (which is not restarted): when the block 10 delivery happens, the crank buffer (and crankhasher) has accumulated all the state changes from blocks 2-10, including all the timer device state udpates from the `poll()` calls. Suppose validator B is restarted after block 5. When it resumes, the crank buffer is empty, and the crankhasher is at the starting state. Blocks 6-10 add changes to both, and at block 10 the `commit()` causes the crankhasher to be finalized. The total data in the crankhasher is different (the input is smaller) on B than on A, and the crankhash thus diverges. This causes the activityhash to diverge, which causes a consensus failure. The invariant we must maintain is that the crank buffer and crankhasher must be empty at any time the host application might commit the block buffer. There must be no lingering changes in the crank buffer, because that buffer is ephemeral (it lives only in RAM). The simplest way to achieve this is to add a `commitCrank()` to the exit paths of `kernel.step()` and `kernel.run()`, so that the invariant is established before the host application regains control. We must also rearrange the way that `incrementCrankNumber` is called. Previously, it was called at the end of `start()`, leaving the "current" crank number in the crank buffer (but not committed to the block buffer yet). Then, at end-of-crank, the sequence was `commitCrank()` followed by `incrementCrankNumber()`. In this approach, the crank buffer was never empty: except for the brief moment between these two calls, it always had a pending update. In the new approach, we remove the call from `start()`, and we increment the crank number just *before* the end-of-crank commit. This way, the crank buffer remains empty between cranks. One additional piece remains: we should really commit the crank buffer after every device call. The concern is that an e.g. timer device `poll()` causes some state changes but no delivery, and then the next delivery fails (i.e. it causes the target vat to terminate). We don't want the unrelated device changes to be discarded along with the vat's half-completed activity. This would be a good job for the #720 kernel input queue. refs #3720
dckc
changed the title
|
I promoted the diagnosis to the title. This might be a bit premature, but it seems pretty likely. |
We observed a consensus failure on the chain that was triggered by a validator getting restarted. The root cause seems to be that device calls (specifically `poll()` on the timer device) cause state changes, which are accumulated in the crankhasher and linger in the crank buffer until something causes them to be committed. This commit doesn't happen until processQueueMessage() finishes, which only happens if the run-queue had some work to do. This occurs in a subset of the times that `kernel.run()` is invoked. On the chain, each block causes a `poll()` followed by a `kernel.run()`. If the `poll()` did not cause any timers to fire, the timer device will not enqueue any messages to the timer vat, the run-queue remains empty, and `run()` has no work to do. Therefore the crank buffer is not committed. Imagine a chain in which some delivery causes everything to be committed in block 1, then blocks 2-9 have a `poll()` but no actual deliveries, then something happens to make block 10 have a delivery (causing a commit). Now follow validator A (which is not restarted): when the block 10 delivery happens, the crank buffer (and crankhasher) has accumulated all the state changes from blocks 2-10, including all the timer device state udpates from the `poll()` calls. Suppose validator B is restarted after block 5. When it resumes, the crank buffer is empty, and the crankhasher is at the starting state. Blocks 6-10 add changes to both, and at block 10 the `commit()` causes the crankhasher to be finalized. The total data in the crankhasher is different (the input is smaller) on B than on A, and the crankhash thus diverges. This causes the activityhash to diverge, which causes a consensus failure. The invariant we must maintain is that the crank buffer and crankhasher must be empty at any time the host application might commit the block buffer. There must be no lingering changes in the crank buffer, because that buffer is ephemeral (it lives only in RAM). The simplest way to achieve this is to add a `commitCrank()` to the exit paths of `kernel.step()` and `kernel.run()`, so that the invariant is established before the host application regains control. We must also rearrange the way that `incrementCrankNumber` is called. Previously, it was called at the end of `start()`, leaving the "current" crank number in the crank buffer (but not committed to the block buffer yet). Then, at end-of-crank, the sequence was `commitCrank()` followed by `incrementCrankNumber()`. In this approach, the crank buffer was never empty: except for the brief moment between these two calls, it always had a pending update. In the new approach, we remove the call from `start()`, and we increment the crank number just *before* the end-of-crank commit. This way, the crank buffer remains empty between cranks. One additional piece remains: we should really commit the crank buffer after every device call. The concern is that an e.g. timer device `poll()` causes some state changes but no delivery, and then the next delivery fails (i.e. it causes the target vat to terminate). We don't want the unrelated device changes to be discarded along with the vat's half-completed activity. This would be a good job for the #720 kernel input queue. refs #3720
|
Ok, here's an attempt to explain the issue The current/old code looks like this: The empty/white boxes are actions which the host application takes: calling In this first diagram, we can survive the save/reload cycle because the mailbox deliveries both cause a push to the run-queue, which means the subsequent But here's what happens when one of those mailbox deliveries is replaced with a timer-device poll that doesn't cause a run-queue event:
Here, "timer poll 1" causes timer-device state changes but not a run-queue event. The subsequent |
|
The fixed version looks like this:
Now we always When this approach is presented with the timer-device events:
we commit the "timer poll 1" device state changes during the subsequent |
|
#3723 implements this fixed ordering |
We observed a consensus failure on the chain that was triggered by a validator getting restarted. The root cause seems to be that device calls (specifically `poll()` on the timer device) cause state changes, which are accumulated in the crankhasher and linger in the crank buffer until something causes them to be committed. This commit doesn't happen until processQueueMessage() finishes, which only happens if the run-queue had some work to do. This occurs in a subset of the times that `kernel.run()` is invoked. On the chain, each block causes a `poll()` followed by a `kernel.run()`. If the `poll()` did not cause any timers to fire, the timer device will not enqueue any messages to the timer vat, the run-queue remains empty, and `run()` has no work to do. Therefore the crank buffer is not committed. Imagine a chain in which some delivery causes everything to be committed in block 1, then blocks 2-9 have a `poll()` but no actual deliveries, then something happens to make block 10 have a delivery (causing a commit). Now follow validator A (which is not restarted): when the block 10 delivery happens, the crank buffer (and crankhasher) has accumulated all the state changes from blocks 2-10, including all the timer device state udpates from the `poll()` calls. Suppose validator B is restarted after block 5. When it resumes, the crank buffer is empty, and the crankhasher is at the starting state. Blocks 6-10 add changes to both, and at block 10 the `commit()` causes the crankhasher to be finalized. The total data in the crankhasher is different (the input is smaller) on B than on A, and the crankhash thus diverges. This causes the activityhash to diverge, which causes a consensus failure. The invariant we must maintain is that the crank buffer and crankhasher must be empty at any time the host application might commit the block buffer. There must be no lingering changes in the crank buffer, because that buffer is ephemeral (it lives only in RAM). The simplest way to achieve this is to add a `commitCrank()` to the exit paths of `kernel.step()` and `kernel.run()`, so that the invariant is established before the host application regains control. We must also rearrange the way that `incrementCrankNumber` is called. Previously, it was called at the end of `start()`, leaving the "current" crank number in the crank buffer (but not committed to the block buffer yet). Then, at end-of-crank, the sequence was `commitCrank()` followed by `incrementCrankNumber()`. In this approach, the crank buffer was never empty: except for the brief moment between these two calls, it always had a pending update. In the new approach, we remove the call from `start()`, and we increment the crank number just *before* the end-of-crank commit. This way, the crank buffer remains empty between cranks. One additional piece remains: we should really commit the crank buffer after every device call. The concern is that an e.g. timer device `poll()` causes some state changes but no delivery, and then the next delivery fails (i.e. it causes the target vat to terminate). We don't want the unrelated device changes to be discarded along with the vat's half-completed activity. This would be a good job for the #720 kernel input queue. refs #3720
Describe the bug
a bit vague, for now
@michaelfig restarted one validator at block=1265, and then got CONSENSUS FAILURE on it at block=1294.
To Reproduce
Steps to reproduce the behavior:
Expected behavior
A clear and concise description of what you expected to happen.
Platform Environment
git describe --tags --always)35cb64e I think. i.e.
@agoric/[email protected]Additional context
Add any other context about the problem here.
Screenshots
If applicable, add screenshots to help explain your problem, especially for UI interactions.
The text was updated successfully, but these errors were encountered: