{"record":{"id":"66895befadb0477c","repo":"clockworklabs/SpacetimeDB","slug":"expected-reducer-transaction-update-request-id","errorCode":null,"errorMessage":"expected reducer transaction update {request_id}, got request id {:?}","messagePattern":"expected reducer transaction update (.+?), got request id (.+?)","errorType":"exception","errorClass":null,"httpStatus":null,"severity":"error","filePath":"crates/testing/src/modules.rs","lineNumber":145,"sourceCode":"\n    pub async fn recv_message(&mut self) -> Option<OutboundMessage> {\n        let mut buf = Vec::with_capacity(1);\n        (self.receiver.recv_many(&mut buf, 1).await != 0).then(|| buf.remove(0))\n    }\n\n    pub async fn recv_reducer_update(&mut self, request_id: RequestId) -> anyhow::Result<()> {\n        let message = self\n            .recv_message()\n            .await\n            .ok_or_else(|| anyhow::anyhow!(\"client receiver closed before reducer update {request_id}\"))?;\n        let OutboundMessage::V1(SerializableMessage::TxUpdate(update)) = message else {\n            anyhow::bail!(\"expected reducer transaction update {request_id}, got {message:?}\");\n        };\n        let Some(event) = update.event else {\n            anyhow::bail!(\"expected full reducer transaction update {request_id}, got light update\");\n        };\n        if event.request_id != Some(request_id) {\n            anyhow::bail!(\n                \"expected reducer transaction update {request_id}, got request id {:?}\",\n                event.request_id\n            );\n        }\n        match &event.status {\n            EventStatus::Committed(_) => Ok(()),\n            EventStatus::FailedUser(err) | EventStatus::FailedInternal(err) => {\n                anyhow::bail!(\"reducer transaction update {request_id} failed: {err}\")\n            }\n            EventStatus::OutOfEnergy => anyhow::bail!(\"reducer transaction update {request_id} ran out of energy\"),\n        }\n    }\n\n    pub async fn read_log(&self, size: Option<u32>) -> String {\n        let bytes = self\n            .client\n            .module()\n            .database_logger()","sourceCodeStart":127,"sourceCodeEnd":163,"githubUrl":"https://github.com/clockworklabs/SpacetimeDB/blob/fb7282411b0b73cc68d51e161f180cd409abd851/crates/testing/src/modules.rs#L127-L163","documentation":"Test-harness helper recv_reducer_update(request_id) in crates/testing/src/modules.rs:145 pops exactly one message from the client's outbound stream and requires it to be a full TxUpdate whose event.request_id equals the given RequestId. The outbound stream is FIFO across all traffic (other reducers, subscription updates, energy updates), so if the next message belongs to a different transaction, the helper bails with this mismatch error. It is a strict single-message assertion, not a search.","triggerScenarios":"Calling recv_reducer_update(rid_a) when an earlier transaction (another reducer call, a subscription initial load, a second client's write) produced an update that has not been consumed yet; passing a RequestId captured from a different call_reducer invocation; firing two reducers back-to-back and awaiting them in reverse order.","commonSituations":"Test modules that start subscriptions and then call reducers without draining the subscription's initial data first; helper functions that call reducers internally without awaiting their updates; copy-pasting request ids between tests.","solutions":["Call recv_reducer_update(request_id) immediately after the exact call_reducer* call that returned that request_id, before triggering any other transaction on the connection.","Consume preceding unrelated updates first with recv_message() in a loop until you reach the TxUpdate whose event.request_id matches.","Verify the RequestId comes from the same exec/call - the call_reducer_binary_result helper at crates/testing/src/modules.rs:104 returns it.","If tests genuinely interleave transactions, write a small dispatcher that routes each TxUpdate by request_id instead of assuming order."],"exampleFix":"// before: unrelated update arrives first, mismatch is fatal\nlet rid = module.call_reducer_binary_result(\"add\", &args).await?;\nmodule.recv_reducer_update(rid).await?; // bails if another TxUpdate is queued ahead\n// after: drain until the matching update\nwhile let Some(msg) = module.recv_message().await {\n    if let OutboundMessage::V1(SerializableMessage::TxUpdate(u)) = &msg {\n        if u.event.as_ref().and_then(|e| e.request_id) == Some(rid) {\n            break; // found ours; now assert on its status\n        }\n    }\n}","handlingStrategy":"try-catch","validationCode":null,"typeGuard":null,"tryCatchPattern":"// Rust test: route updates by request_id instead of assuming FIFO position.\nloop {\n    let Some(msg) = module.recv_message().await else { panic!(\"client closed\") };\n    let OutboundMessage::V1(SerializableMessage::TxUpdate(u)) = msg else { continue };\n    let Some(ev) = u.event else { continue };\n    if ev.request_id == Some(rid) {\n        assert!(matches!(ev.status, EventStatus::Committed(_)), \"status: {:?}\", ev.status);\n        break;\n    }\n}","preventionTips":["Await recv_reducer_update immediately after the exact call_reducer* that returned the request_id, before starting any other transaction.","Always bind the RequestId from the call's return value; never hand-copy ids between tests.","In helpers that call reducers, consume or return the update so callers cannot get out of sync with the message stream."],"tags":["spacetimedb","testing","test-harness","message-ordering","request-id"],"backgroundTag":"request-id-mismatch","analyzedSha":"fb7282411b0b73cc68d51e161f180cd409abd851","analyzedAt":"2026-08-20T06:08:37.179Z","contentChangedAt":"2026-08-20T06:08:37.179Z","schemaVersion":2},"datasetVersion":"2026-09-14T00:17:10.932Z"}