Integration test CallOrdering => ordering(boolean[], Client) fails with vqueues

[tillrohrmann]

Right now, the integration test CallOrdering => ordering(boolean[], Client) fails with vqueues. There are a couple of runs which show the failure:

https://github.com/restatedev/restate/actions/runs/23336632965/job/67881377470
https://github.com/restatedev/restate/actions/runs/23334465442/job/67873966839

[tillrohrmann]

Root Cause Analysis

Symptom

The test sends 3 calls to the same VirtualObject key (ListObject/{key}/append) with arguments "0", "1", "2" in that order. With vqueues enabled, the execution order comes back as ["0", "2", "1"] — items 1 and 2 are consistently swapped. Reproduced both in CI and locally.

The call pattern in the failing test cases involves a mix of Call and OneWayCall:

• CI run ([true, false, false]): OneWayCall, Call, Call → result ["0", "2", "1"]
• Local repro ([false, true, false]): Call, OneWayCall, Call → result ["0", "2", "1"]

"0" is always in the correct position because it runs immediately (the vqueue is empty). The misordering is between "1" and "2", which both land in the vqueue inbox while "0" is executing.

Root Cause: Millisecond-precision timestamp collision in vqueue inbox ordering

The ordering of items within a vqueue inbox is determined by the RocksDB key, which sorts by:

PRIORITY → VISIBLE_AT → CREATED_AT (UniqueTimestamp) → KIND → ENTRY_ID

The problem is that CREATED_AT uses a UniqueTimestamp that has only millisecond precision with logical clock always set to 0, causing same-millisecond entries to have identical ordering keys. Here's how it happens:

1. The Proxy handler produces 3 outbox messages (seq 0, 1, 2) in the correct order within a single state machine apply.

2. The shuffle service sends each outbox message to Bifrost as a separate record. Each record gets a NanosSinceEpoch::now() timestamp at the point of Arc<Envelope> → InputRecord conversion (bifrost/src/record.rs:255).

3. The partition processor converts the nanosecond timestamp to milliseconds (MillisSinceEpoch) when reading record.created_at() (worker/src/partition/mod.rs:590,973), losing sub-millisecond ordering information.

4. UniqueTimestamp::from_unix_millis_unchecked() (clock/src/unique_timestamp.rs:143-148) always creates a timestamp with logical clock = 0:

   Self::from_parts_unchecked(unix_millis.as_u64() - RESTATE_EPOCH.as_u64(), 0)

   Two messages arriving within the same millisecond get identical UniqueTimestamp values.

5. With identical PRIORITY, VISIBLE_AT, and CREATED_AT, the tiebreaker falls through to ENTRY_ID, which is derived from the random InvocationUuid bytes (storage-api/src/vqueue_table/entry.rs:82-87). This makes the ordering non-deterministic.

6. The DRR scheduler reads entries from the inbox in RocksDB key order, so it dequeues them in the random UUID-based order rather than the intended FIFO order.

Key Code Locations

Component	File	Line(s)
NanosSinceEpoch::now() per Bifrost record	bifrost/src/record.rs	252-260
Nanos→Millis for record_created_at	worker/src/partition/mod.rs	590, 973
UniqueTimestamp with logical clock=0	clock/src/unique_timestamp.rs	143-148
VQueue enqueue uses record_unique_ts	worker/src/partition/state_machine/mod.rs	905
Inbox key ordering (RocksDB)	partition-store/src/vqueue_table/inbox.rs	~20-33
EntryId from random InvocationUuid	storage-api/src/vqueue_table/entry.rs	82-87
Shuffle sends messages 1-by-1 to Bifrost	worker/src/partition/shuffle.rs	407
EntryCard derives Ord for lexicographic key	storage-api/src/vqueue_table/entry.rs	97-105

[tillrohrmann]

As a temporary solution, I plan to use the LSN as the logical part of the UniqueTimestamp. Given the monotonicity of the LSN, this should solve the observed re-ordering problem of the CallOrdering test case. The proper fix is probably to use a UniqueTimestamp instead of NanosSinceEpoch record_created_at field in the Record that is written to Bifrost.