SnapshotWriteException: Expected snapshot chunk with equal snapshot total count 51, but got chunk with total count 23

[lenaschoenburg]

Describe the bug
A follower rejects an install request because SnapshotWriteException: Expected snapshot chunk with equal snapshot total count 51, but got chunk with total count 23 happened. Before and after this exception, the leader complains that it is not able to send install requests because chunks are out of order:

Failed to send InstallRequest to member 1, with RaftError{type=ILLEGAL_MEMBER_STATE, message=Request chunk is was received out of order}. Restart sending snapshot.

Impact
The follower immediately recovers: Leader retries sending a snapshot, follower successfully receives it and is able to restore state from it.

Details

• Error Group https://console.cloud.google.com/errors/CNnZibKZwZbA6gE?service=zeebe&time=P7D&refresh=off&project=camunda-cloud-240911
• Exported logs: https://drive.google.com/file/d/1-PeITwmQBBJxTZZjwWNIgW27ZWxuocTr/view?usp=sharing
• Stacktrace:

io.camunda.zeebe.snapshots.impl.SnapshotWriteException: Expected snapshot chunk with equal snapshot total count 51, but got chunk with total count 23.
	at io.camunda.zeebe.snapshots.impl.FileBasedReceivedSnapshot.checkTotalCountIsValid(FileBasedReceivedSnapshot.java:153) ~[zeebe-snapshots-1.2.4.jar:1.2.4]
	at io.camunda.zeebe.snapshots.impl.FileBasedReceivedSnapshot.applyInternal(FileBasedReceivedSnapshot.java:84) ~[zeebe-snapshots-1.2.4.jar:1.2.4]
	at io.camunda.zeebe.snapshots.impl.FileBasedReceivedSnapshot.lambda$apply$0(FileBasedReceivedSnapshot.java:64) ~[zeebe-snapshots-1.2.4.jar:1.2.4]
	at io.camunda.zeebe.util.sched.ActorJob.invoke(ActorJob.java:62) ~[zeebe-util-1.2.4.jar:1.2.4]
	at io.camunda.zeebe.util.sched.ActorJob.execute(ActorJob.java:39) [zeebe-util-1.2.4.jar:1.2.4]
	at io.camunda.zeebe.util.sched.ActorTask.execute(ActorTask.java:122) [zeebe-util-1.2.4.jar:1.2.4]
	at io.camunda.zeebe.util.sched.ActorThread.executeCurrentTask(ActorThread.java:95) [zeebe-util-1.2.4.jar:1.2.4]
	at io.camunda.zeebe.util.sched.ActorThread.doWork(ActorThread.java:78) [zeebe-util-1.2.4.jar:1.2.4]
	at io.camunda.zeebe.util.sched.ActorThread.run(ActorThread.java:192) [zeebe-util-1.2.4.jar:1.2.4]

[npepinpe]

It's possible that this is an expected case - we sometimes take consecutive snapshots with the same index. For example, if processing but not exporting, then the index will not change (even if the snapshot ID changes). The current replication logic expects snapshot indexes to be unique, which is not the case anymore, and there is no additional check on the other snapshot metadata properties after until we apply the chunk. So in this case, it could be the leader took a new snapshot for the same index, but that snapshot now has a different chunk count, checksum, etc.

If this is the case, then we should handle the case better by really checking if a new snapshot is sent to the follower, but the impact is very low. If that's not the case, we should try to figure out what went wrong since it's a bigger problem if we're sometimes sending the wrong snapshot metadata.

[lenaschoenburg]

we sometimes take consecutive snapshots with the same index

AFAICT this is not the case here. I think the problem starts before we see the SnapshotWriteException.

Here is a very condensed timeline:

• 2021-12-13 17:04:12.441 CET broker-2 receives a snapshot for partition-2, 418877-4-1301730-1289811-1
• 2021-12-13 17:04:19.844 CET broker-2 commits snapshot 418877-4-1301730-1289811

Roughly 5 minutes later:

• 2021-12-13 17:09:20.675 CET broker-2 receives a snapshot for partition-2, 636220-4-1904255-1870401-2
• broker-2 rejects all install requests: RaftError{type=ILLEGAL_MEMBER_STATE, message=Request chunk is was received out of order}
• 2021-12-13 17:14:14.168 CET broker-2 aborts the receive process for snapshot 636220-4-1904255-1870401-2

Another 5 minutes later:

• 2021-12-13 17:19:19.586 CET broker-2 receives a snapshot for partition-2, 955401-4-2759594-2723483-4
• broker-2 rejects all install requests: RaftError{type=ILLEGAL_MEMBER_STATE, message=Request chunk is was received out of order}
• 2021-12-13 17:24:12.544 CET broker-2 throws SnapshotWriteException and aborts the receive process for snapshot 955401-4-2759594-2723483-4

[lenaschoenburg]

During the ~5 minutes where the follower can't receive the snapshot, the leader continuously retries install requests. Maybe we can find a solution where either the follower always rolls back when it receives chunks out-of-order or we could even introduce a backoff when retrying install requests?

[korthout]

Also occurred on benchmark CW-34-mixed

[deepthidevaki]

Is this same as #10180 ?

[Zelldon]

Potentially fixed by #10183