From cd1f22243911dc0dbf2e8941de578352c558c52d Mon Sep 17 00:00:00 2001 From: Phoebe Goldman Date: Thu, 5 Mar 2026 14:38:36 -0500 Subject: [PATCH 1/5] Add a mode to the Rust SDK with additional logging to a file In the Rust client SDK, with this PR, doing `.with_debug_to_file("path.txt")` on the connection builder will result in the SDK logging additional verbose info to `path.txt`. --- crates/codegen/src/rust.rs | 3 +- sdks/rust/src/db_connection.rs | 136 +++++++++++++++++- sdks/rust/src/spacetime_module.rs | 6 +- sdks/rust/src/websocket.rs | 24 +++- .../src/module_bindings/mod.rs | 5 +- .../src/module_bindings/mod.rs | 5 +- .../test-client/src/module_bindings/mod.rs | 5 +- .../view-client/src/module_bindings/mod.rs | 5 +- .../src/module_bindings/mod.rs | 5 +- 9 files changed, 169 insertions(+), 25 deletions(-) diff --git a/crates/codegen/src/rust.rs b/crates/codegen/src/rust.rs index 086d467af97..7c80c47ba18 100644 --- a/crates/codegen/src/rust.rs +++ b/crates/codegen/src/rust.rs @@ -1308,7 +1308,7 @@ impl __sdk::InModule for Reducer {{ } fn print_db_update_defn(module: &ModuleDef, visibility: CodegenVisibility, out: &mut Indenter) { - writeln!(out, "#[derive(Default)]"); + writeln!(out, "#[derive(Default, Debug)]"); writeln!(out, "#[allow(non_snake_case)]"); writeln!(out, "#[doc(hidden)]"); out.delimited_block( @@ -1606,6 +1606,7 @@ fn print_const_db_context_types(out: &mut Indenter) { out, " #[doc(hidden)] +#[derive(Debug)] pub struct RemoteModule; impl __sdk::InModule for RemoteModule {{ diff --git a/sdks/rust/src/db_connection.rs b/sdks/rust/src/db_connection.rs index b5e74383adf..7c66fe4815e 100644 --- a/sdks/rust/src/db_connection.rs +++ b/sdks/rust/src/db_connection.rs @@ -37,7 +37,12 @@ use http::Uri; use spacetimedb_client_api_messages::websocket::{self as ws, common::QuerySetId}; use spacetimedb_lib::{bsatn, ser::Serialize, ConnectionId, Identity, Timestamp}; use spacetimedb_sats::Deserialize; -use std::sync::{atomic::AtomicU32, Arc, Mutex as StdMutex, OnceLock}; +use std::{ + fs::{File, OpenOptions}, + io::Write, + path::PathBuf, + sync::{atomic::AtomicU32, Arc, Mutex as StdMutex, OnceLock}, +}; use tokio::{ runtime::{self, Runtime}, sync::Mutex as TokioMutex, @@ -86,6 +91,8 @@ pub struct DbContextImpl { /// /// This may be none if we have not yet received the [`ws::v2::InitialConnection`] message. connection_id: SharedCell>, + + pub(crate) extra_logging: Option>, } impl Clone for DbContextImpl { @@ -103,14 +110,20 @@ impl Clone for DbContextImpl { pending_mutations_recv: Arc::clone(&self.pending_mutations_recv), identity: Arc::clone(&self.identity), connection_id: Arc::clone(&self.connection_id), + extra_logging: Option::>::clone(&self.extra_logging), } } } impl DbContextImpl { + pub(crate) fn debug_log(&self, body: impl FnOnce(&mut File) -> std::result::Result<(), std::io::Error>) { + debug_log(&self.extra_logging, body); + } + /// Process a parsed WebSocket message, /// applying its mutations to the client cache and invoking callbacks. fn process_message(&self, msg: ParsedMessage) -> crate::Result<()> { + self.debug_log(|out| writeln!(out, "`process_message`: {msg:?}")); match msg { // Error: treat this as an erroneous disconnect. ParsedMessage::Error(e) => { @@ -315,6 +328,7 @@ impl DbContextImpl { /// Apply an individual [`PendingMutation`]. fn apply_mutation(&self, mutation: PendingMutation) -> crate::Result<()> { + self.debug_log(|out| writeln!(out, "`apply_mutation`: {mutation:?}")); match mutation { // Subscribe: register the subscription in the [`SubscriptionManager`] // and send the `Subscribe` WS message. @@ -763,6 +777,8 @@ pub struct DbConnectionBuilder { on_connect_error: Option>, on_disconnect: Option>, + additional_logging_path: Option, + params: WsParams, } @@ -798,6 +814,15 @@ pub fn set_connection_id(id: ConnectionId) -> crate::Result<()> { Ok(()) } +pub(crate) fn debug_log( + extra_logging: &Option>, + body: impl FnOnce(&mut File) -> std::result::Result<(), std::io::Error>, +) { + if let Some(file) = extra_logging { + body(&mut *file.lock().expect("`extra_logging` file Mutex is poisoned")).expect("Writing debug log failed") + } +} + impl DbConnectionBuilder { /// Implementation of the generated `DbConnection::builder` method. /// Call that method instead. @@ -810,6 +835,7 @@ impl DbConnectionBuilder { on_connect: None, on_connect_error: None, on_disconnect: None, + additional_logging_path: None, params: <_>::default(), } } @@ -847,6 +873,16 @@ but you must call one of them, or else the connection will never progress. /// Open a WebSocket connection, build an empty client cache, &c, /// to construct a [`DbContextImpl`]. fn build_impl(self) -> crate::Result> { + let extra_logging = self + .additional_logging_path + .map(|path| { + OpenOptions::new().append(true).create(true).open(&path).map_err(|e| { + InternalError::new(format!("Failed to open file '{path:?}' for additional logging")).with_cause(e) + }) + }) + .transpose()? + .map(|file| Arc::new(StdMutex::new(file))); + let (runtime, handle) = enter_or_create_runtime()?; let db_callbacks = DbCallbacks::default(); let reducer_callbacks = ReducerCallbacks::default(); @@ -866,8 +902,10 @@ but you must call one of them, or else the connection will never progress. source: InternalError::new("Failed to initiate WebSocket connection").with_cause(source), })?; - let (_websocket_loop_handle, raw_msg_recv, raw_msg_send) = ws_connection.spawn_message_loop(&handle); - let (_parse_loop_handle, parsed_recv_chan) = spawn_parse_loop::(raw_msg_recv, &handle); + let (_websocket_loop_handle, raw_msg_recv, raw_msg_send) = + ws_connection.spawn_message_loop(&handle, extra_logging.clone()); + let (_parse_loop_handle, parsed_recv_chan) = + spawn_parse_loop::(raw_msg_recv, &handle, extra_logging.clone()); let inner = Arc::new(StdMutex::new(DbContextImplInner { runtime, @@ -898,6 +936,7 @@ but you must call one of them, or else the connection will never progress. pending_mutations_recv: Arc::new(TokioMutex::new(pending_mutations_recv)), identity: Arc::new(StdMutex::new(None)), connection_id: Arc::new(StdMutex::new(connection_id_override)), + extra_logging, }; Ok(ctx_imp) @@ -963,6 +1002,23 @@ but you must call one of them, or else the connection will never progress. self } + /// Set `path` as a path for additional debug logging related to SDK internals. + /// + /// When enabled, the SDK will create or open `path` for write-append and write logs to it. + /// This is useful for diagnosing bugs in the SDK, + /// but will generate a large volume of text logs and may have performance overhead, + /// so it should not be used in production. + /// + /// When running multiple connections in parallel, + /// either within the same process or from separate processes, + /// prefer giving each its own unique path here; + /// multiple `DbConnection`s writing to the same debug file concurrently + /// may interleave or corrupt the output. + pub fn with_debug_to_file(mut self, path: impl Into) -> Self { + self.additional_logging_path = Some(path.into()); + self + } + /// Register a callback to run when the connection is successfully initiated. /// /// The callback will receive three arguments: @@ -1043,6 +1099,7 @@ fn enter_or_create_runtime() -> crate::Result<(Option, runtime::Handle) } } +#[derive(Debug)] enum ParsedMessage { TransactionUpdate(M::DbUpdate), IdentityToken(Identity, Box, ConnectionId), @@ -1073,9 +1130,10 @@ enum ParsedMessage { fn spawn_parse_loop( raw_message_recv: mpsc::UnboundedReceiver, handle: &runtime::Handle, + extra_logging: Option>, ) -> (tokio::task::JoinHandle<()>, mpsc::UnboundedReceiver>) { let (parsed_message_send, parsed_message_recv) = mpsc::unbounded(); - let handle = handle.spawn(parse_loop(raw_message_recv, parsed_message_send)); + let handle = handle.spawn(parse_loop(raw_message_recv, parsed_message_send, extra_logging)); (handle, parsed_message_recv) } @@ -1084,9 +1142,13 @@ fn spawn_parse_loop( async fn parse_loop( mut recv: mpsc::UnboundedReceiver, send: mpsc::UnboundedSender>, + extra_logging: Option>, ) { while let Some(msg) = recv.next().await { - send.unbounded_send(match msg { + debug_log(&extra_logging, |file| { + writeln!(file, "`parse_loop`: Got raw message: {msg:?}") + }); + let parsed = match msg { ws::v2::ServerMessage::TransactionUpdate(transaction_update) => { match M::DbUpdate::parse_update(transaction_update) { Err(e) => ParsedMessage::Error( @@ -1210,8 +1272,12 @@ async fn parse_loop( ws::v2::ProcedureStatus::Returned(val) => Ok(val), }, }, - }) - .expect("Failed to send ParsedMessage to main thread"); + }; + debug_log(&extra_logging, |file| { + writeln!(file, "`parse_loop`: Parsed as: {parsed:?}") + }); + send.unbounded_send(parsed) + .expect("Failed to send ParsedMessage to main thread"); } } @@ -1263,6 +1329,62 @@ pub(crate) enum PendingMutation { }, } +// Hand-written `Debug` impl, 'cause `SubscriptionHandleImpl` and callbacks aren't printable. +impl std::fmt::Debug for PendingMutation { + fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result { + match self { + PendingMutation::Unsubscribe { query_set_id } => f + .debug_struct("PendingMutation::Unsubscribe") + .field("query_set_id", query_set_id) + .finish(), + PendingMutation::Subscribe { query_set_id, .. } => f + .debug_struct("PendingMutation::Subscribe") + .field("query_set_id", query_set_id) + .finish_non_exhaustive(), + PendingMutation::AddInsertCallback { table, callback_id, .. } => f + .debug_struct("PendingMutation::AddInsertCallback") + .field("table", table) + .field("callback_id", callback_id) + .finish_non_exhaustive(), + PendingMutation::RemoveInsertCallback { table, callback_id } => f + .debug_struct("PendingMutation::RemoveInsertCallback") + .field("table", table) + .field("callback_id", callback_id) + .finish(), + PendingMutation::AddDeleteCallback { table, callback_id, .. } => f + .debug_struct("PendingMutation::AddDeleteCallback") + .field("table", table) + .field("callback_id", callback_id) + .finish_non_exhaustive(), + PendingMutation::RemoveDeleteCallback { table, callback_id } => f + .debug_struct("PendingMutation::RemoveDeleteCallback") + .field("table", table) + .field("callback_id", callback_id) + .finish(), + PendingMutation::AddUpdateCallback { table, callback_id, .. } => f + .debug_struct("PendingMutation::AddUpdateCallback") + .field("table", table) + .field("callback_id", callback_id) + .finish_non_exhaustive(), + PendingMutation::RemoveUpdateCallback { table, callback_id } => f + .debug_struct("PendingMutation::RemoveUpdateCallback") + .field("table", table) + .field("callback_id", callback_id) + .finish(), + PendingMutation::Disconnect => write!(f, "PendingMutation::Disconnect"), + PendingMutation::InvokeReducerWithCallback { reducer, .. } => f + .debug_struct("PendingMutation::InvokeReducerWithCallback") + .field("reducer", reducer) + .finish_non_exhaustive(), + PendingMutation::InvokeProcedureWithCallback { procedure, args, .. } => f + .debug_struct("PendingMutation::InvokeProcedureWithCallback") + .field("procedure", procedure) + .field("args", args) + .finish_non_exhaustive(), + } + } +} + enum Message { Ws(Option>), Local(PendingMutation), diff --git a/sdks/rust/src/spacetime_module.rs b/sdks/rust/src/spacetime_module.rs index e50a3a90dfd..dfec381e56d 100644 --- a/sdks/rust/src/spacetime_module.rs +++ b/sdks/rust/src/spacetime_module.rs @@ -32,7 +32,7 @@ pub struct QueryTableAccessor; /// Each module's codegen will define a unit struct which implements this trait, /// with associated type links to various other generated types. -pub trait SpacetimeModule: Send + Sync + 'static { +pub trait SpacetimeModule: Debug + Send + Sync + 'static { /// [`crate::DbContext`] implementor which exists in the global scope. type DbConnection: DbConnection; @@ -83,7 +83,7 @@ pub trait SpacetimeModule: Send + Sync + 'static { /// Implemented by the autogenerated `DbUpdate` type, /// which is a parsed and typed analogue of [`crate::ws::v2::TransactionUpdate`]. pub trait DbUpdate: - TryFrom + Default + InModule + Send + 'static + TryFrom + Default + Debug + InModule + Send + 'static where Self::Module: SpacetimeModule, { @@ -217,11 +217,13 @@ where fn unsubscribe(self) -> crate::Result<()>; } +#[derive(Debug)] pub struct WithBsatn { pub bsatn: Bytes, pub row: Row, } +#[derive(Debug)] pub struct TableUpdate { pub inserts: Vec>, pub deletes: Vec>, diff --git a/sdks/rust/src/websocket.rs b/sdks/rust/src/websocket.rs index 5668ecb3aed..2b15b85a2d8 100644 --- a/sdks/rust/src/websocket.rs +++ b/sdks/rust/src/websocket.rs @@ -2,8 +2,10 @@ //! //! This module is internal, and may incompatibly change without warning. +use std::fs::File; +use std::io::Write; use std::mem; -use std::sync::Arc; +use std::sync::{Arc, Mutex}; use std::time::Duration; use bytes::Bytes; @@ -24,6 +26,7 @@ use tokio_tungstenite::{ }; use crate::compression::decompress_server_message; +use crate::db_connection::debug_log; use crate::metrics::CLIENT_METRICS; #[derive(Error, Debug, Clone)] @@ -207,9 +210,11 @@ fn request_insert_auth_header(req: &mut http::Request<()>, token: Option<&str>) /// /// Could be trivially written as a function, but macro-ifying it preserves the source location of the log. macro_rules! maybe_log_error { - ($cause:expr, $res:expr) => { + ($extra_logging:expr, $cause:expr, $res:expr) => { if let Err(e) = $res { - log::warn!("{}: {:?}", $cause, e); + let cause = $cause; + debug_log($extra_logging, |file| writeln!(file, "{}: {:?}", cause, e)); + log::warn!("{}: {:?}", cause, e); } }; } @@ -259,6 +264,7 @@ impl WsConnection { mut self, incoming_messages: mpsc::UnboundedSender, outgoing_messages: mpsc::UnboundedReceiver, + extra_logging: Option>>, ) { let websocket_received = CLIENT_METRICS.websocket_received.with_label_values(&self.db_name); let websocket_received_msg_size = CLIENT_METRICS @@ -312,6 +318,7 @@ impl WsConnection { Err(e) => { maybe_log_error!( + &extra_logging, "Error reading message from read WebSocket stream", Result::<(), _>::Err(e) ); @@ -323,10 +330,12 @@ impl WsConnection { record_metrics(bytes.len()); match Self::parse_response(&bytes) { Err(e) => maybe_log_error!( + &extra_logging, "Error decoding WebSocketMessage::Binary payload", Result::<(), _>::Err(e) ), Ok(msg) => maybe_log_error!( + &extra_logging, "Error sending decoded message to incoming_messages queue", incoming_messages.unbounded_send(msg) ), @@ -350,6 +359,7 @@ impl WsConnection { }, Ok(Some(other)) => { + debug_log(&extra_logging, |file| writeln!(file, "Unexpeccted WebSocket message {other:?}")); log::warn!("Unexpected WebSocket message {other:?}"); idle = false; record_metrics(other.len()); @@ -360,6 +370,7 @@ impl WsConnection { if mem::replace(&mut idle, true) { if want_pong { // Nothing received while we were waiting for a pong. + debug_log(&extra_logging, |file| writeln!(file, "Connection timed out")); log::warn!("Connection timed out"); break; } @@ -367,6 +378,7 @@ impl WsConnection { log::trace!("sending client ping"); let ping = WebSocketMessage::Ping(Bytes::new()); if let Err(e) = self.sock.send(ping).await { + debug_log(&extra_logging, |file| writeln!(file, "Error sending ping: {e:?}")); log::warn!("Error sending ping: {e:?}"); break; } @@ -379,12 +391,13 @@ impl WsConnection { Some(outgoing) => { let msg = Self::encode_message(outgoing); if let Err(e) = self.sock.send(msg).await { + debug_log(&extra_logging, |file| writeln!(file, "Error sending outgoing message: {e:?}")); log::warn!("Error sending outgoing message: {e:?}"); break; } } None => { - maybe_log_error!("Error sending close frame", SinkExt::close(&mut self.sock).await); + maybe_log_error!(&extra_logging, "Error sending close frame", SinkExt::close(&mut self.sock).await); outgoing_messages = None; } }, @@ -395,6 +408,7 @@ impl WsConnection { pub(crate) fn spawn_message_loop( self, runtime: &runtime::Handle, + extra_logging: Option>>, ) -> ( JoinHandle<()>, mpsc::UnboundedReceiver, @@ -402,7 +416,7 @@ impl WsConnection { ) { let (outgoing_send, outgoing_recv) = mpsc::unbounded(); let (incoming_send, incoming_recv) = mpsc::unbounded(); - let handle = runtime.spawn(self.message_loop(incoming_send, outgoing_recv)); + let handle = runtime.spawn(self.message_loop(incoming_send, outgoing_recv, extra_logging)); (handle, incoming_recv, outgoing_send) } } diff --git a/sdks/rust/tests/connect_disconnect_client/src/module_bindings/mod.rs b/sdks/rust/tests/connect_disconnect_client/src/module_bindings/mod.rs index fcd85e7f5d0..0bd7b8bd1a2 100644 --- a/sdks/rust/tests/connect_disconnect_client/src/module_bindings/mod.rs +++ b/sdks/rust/tests/connect_disconnect_client/src/module_bindings/mod.rs @@ -1,7 +1,7 @@ // THIS FILE IS AUTOMATICALLY GENERATED BY SPACETIMEDB. EDITS TO THIS FILE // WILL NOT BE SAVED. MODIFY TABLES IN YOUR MODULE SOURCE CODE INSTEAD. -// This was generated using spacetimedb cli version 2.0.0 (commit 85095cfa85e3addc29ce58bfe670b6003271b288). +// This was generated using spacetimedb cli version 2.0.3 (commit c5743cfc8d2fe70b31f43f275313332524a56476). #![allow(unused, clippy::all)] use spacetimedb_sdk::__codegen::{self as __sdk, __lib, __sats, __ws}; @@ -56,7 +56,7 @@ impl __sdk::Reducer for Reducer { } } -#[derive(Default)] +#[derive(Default, Debug)] #[allow(non_snake_case)] #[doc(hidden)] pub struct DbUpdate { @@ -156,6 +156,7 @@ impl<'r> __sdk::AppliedDiff<'r> for AppliedDiff<'r> { } #[doc(hidden)] +#[derive(Debug)] pub struct RemoteModule; impl __sdk::InModule for RemoteModule { diff --git a/sdks/rust/tests/procedure-client/src/module_bindings/mod.rs b/sdks/rust/tests/procedure-client/src/module_bindings/mod.rs index e4e34268510..062b329d4d0 100644 --- a/sdks/rust/tests/procedure-client/src/module_bindings/mod.rs +++ b/sdks/rust/tests/procedure-client/src/module_bindings/mod.rs @@ -1,7 +1,7 @@ // THIS FILE IS AUTOMATICALLY GENERATED BY SPACETIMEDB. EDITS TO THIS FILE // WILL NOT BE SAVED. MODIFY TABLES IN YOUR MODULE SOURCE CODE INSTEAD. -// This was generated using spacetimedb cli version 2.0.0 (commit 85095cfa85e3addc29ce58bfe670b6003271b288). +// This was generated using spacetimedb cli version 2.0.3 (commit c5743cfc8d2fe70b31f43f275313332524a56476). #![allow(unused, clippy::all)] use spacetimedb_sdk::__codegen::{self as __sdk, __lib, __sats, __ws}; @@ -83,7 +83,7 @@ impl __sdk::Reducer for Reducer { } } -#[derive(Default)] +#[derive(Default, Debug)] #[allow(non_snake_case)] #[doc(hidden)] pub struct DbUpdate { @@ -216,6 +216,7 @@ impl<'r> __sdk::AppliedDiff<'r> for AppliedDiff<'r> { } #[doc(hidden)] +#[derive(Debug)] pub struct RemoteModule; impl __sdk::InModule for RemoteModule { diff --git a/sdks/rust/tests/test-client/src/module_bindings/mod.rs b/sdks/rust/tests/test-client/src/module_bindings/mod.rs index de9afc6155f..73a30d1e6c0 100644 --- a/sdks/rust/tests/test-client/src/module_bindings/mod.rs +++ b/sdks/rust/tests/test-client/src/module_bindings/mod.rs @@ -1,7 +1,7 @@ // THIS FILE IS AUTOMATICALLY GENERATED BY SPACETIMEDB. EDITS TO THIS FILE // WILL NOT BE SAVED. MODIFY TABLES IN YOUR MODULE SOURCE CODE INSTEAD. -// This was generated using spacetimedb cli version 2.0.0 (commit e528393902d8cc982769e3b1a0f250d7d53edfa1). +// This was generated using spacetimedb cli version 2.0.3 (commit c5743cfc8d2fe70b31f43f275313332524a56476). #![allow(unused, clippy::all)] use spacetimedb_sdk::__codegen::{self as __sdk, __lib, __sats, __ws}; @@ -2648,7 +2648,7 @@ impl __sdk::Reducer for Reducer { } } -#[derive(Default)] +#[derive(Default, Debug)] #[allow(non_snake_case)] #[doc(hidden)] pub struct DbUpdate { @@ -4259,6 +4259,7 @@ impl<'r> __sdk::AppliedDiff<'r> for AppliedDiff<'r> { } #[doc(hidden)] +#[derive(Debug)] pub struct RemoteModule; impl __sdk::InModule for RemoteModule { diff --git a/sdks/rust/tests/view-client/src/module_bindings/mod.rs b/sdks/rust/tests/view-client/src/module_bindings/mod.rs index 525e09f98b9..55b5bf9c5d2 100644 --- a/sdks/rust/tests/view-client/src/module_bindings/mod.rs +++ b/sdks/rust/tests/view-client/src/module_bindings/mod.rs @@ -1,7 +1,7 @@ // THIS FILE IS AUTOMATICALLY GENERATED BY SPACETIMEDB. EDITS TO THIS FILE // WILL NOT BE SAVED. MODIFY TABLES IN YOUR MODULE SOURCE CODE INSTEAD. -// This was generated using spacetimedb cli version 2.0.0 (commit 85095cfa85e3addc29ce58bfe670b6003271b288). +// This was generated using spacetimedb cli version 2.0.3 (commit c5743cfc8d2fe70b31f43f275313332524a56476). #![allow(unused, clippy::all)] use spacetimedb_sdk::__codegen::{self as __sdk, __lib, __sats, __ws}; @@ -83,7 +83,7 @@ impl __sdk::Reducer for Reducer { } } -#[derive(Default)] +#[derive(Default, Debug)] #[allow(non_snake_case)] #[doc(hidden)] pub struct DbUpdate { @@ -249,6 +249,7 @@ impl<'r> __sdk::AppliedDiff<'r> for AppliedDiff<'r> { } #[doc(hidden)] +#[derive(Debug)] pub struct RemoteModule; impl __sdk::InModule for RemoteModule { diff --git a/templates/chat-console-rs/src/module_bindings/mod.rs b/templates/chat-console-rs/src/module_bindings/mod.rs index 5503526e0a5..c219899fe0e 100644 --- a/templates/chat-console-rs/src/module_bindings/mod.rs +++ b/templates/chat-console-rs/src/module_bindings/mod.rs @@ -1,7 +1,7 @@ // THIS FILE IS AUTOMATICALLY GENERATED BY SPACETIMEDB. EDITS TO THIS FILE // WILL NOT BE SAVED. MODIFY TABLES IN YOUR MODULE SOURCE CODE INSTEAD. -// This was generated using spacetimedb cli version 2.0.0 (commit 9e0e81a6aaec6bf3619cfb9f7916743d86ab7ffc). +// This was generated using spacetimedb cli version 2.0.3 (commit c5743cfc8d2fe70b31f43f275313332524a56476-dirty). #![allow(unused, clippy::all)] use spacetimedb_sdk::__codegen::{self as __sdk, __lib, __sats, __ws}; @@ -56,7 +56,7 @@ impl __sdk::Reducer for Reducer { } } -#[derive(Default)] +#[derive(Default, Debug)] #[allow(non_snake_case)] #[doc(hidden)] pub struct DbUpdate { @@ -156,6 +156,7 @@ impl<'r> __sdk::AppliedDiff<'r> for AppliedDiff<'r> { } #[doc(hidden)] +#[derive(Debug)] pub struct RemoteModule; impl __sdk::InModule for RemoteModule { From c0d87a95f91926d7b38c96532b3d2a66c83b4cc6 Mon Sep 17 00:00:00 2001 From: Phoebe Goldman Date: Thu, 5 Mar 2026 14:53:13 -0500 Subject: [PATCH 2/5] Also debug log when hitting delete for non-existent row And dump the whole contents of the table, for good measure. --- sdks/rust/src/client_cache.rs | 47 +++++++++++++++++++++++++--------- sdks/rust/src/db_connection.rs | 2 +- 2 files changed, 36 insertions(+), 13 deletions(-) diff --git a/sdks/rust/src/client_cache.rs b/sdks/rust/src/client_cache.rs index 7c4b511c72a..d9c4c97c7f6 100644 --- a/sdks/rust/src/client_cache.rs +++ b/sdks/rust/src/client_cache.rs @@ -3,7 +3,7 @@ //! This module is internal, and may incompatibly change without warning. use crate::callbacks::CallbackId; -use crate::db_connection::{PendingMutation, SharedCell}; +use crate::db_connection::{debug_log, PendingMutation, SharedCell}; use crate::spacetime_module::{InModule, SpacetimeModule, TableUpdate, WithBsatn}; use anymap::{any::Any, Map}; use bytes::Bytes; @@ -11,6 +11,9 @@ use core::any::type_name; use core::hash::Hash; use futures_channel::mpsc; use spacetimedb_data_structures::map::{hash_map::Entry, HashCollectionExt, HashMap}; +use std::fmt::Debug; +use std::fs::File; +use std::io::Write; use std::marker::PhantomData; use std::sync::Arc; @@ -35,6 +38,9 @@ pub struct TableCache { /// Entries are added to this map during [`crate::DbConnectionBuilder::build`], /// via a `register_table` function autogenerated for each table. pub(crate) unique_indices: HashMap<&'static str, Box>>, + + /// Clone of the [`crate::db_connection::DbContextImpl::extra_logging`]. + extra_logging: Option>, } /// Stores an entry of the typed row value together with its ref count in the table cache. @@ -59,11 +65,12 @@ pub(crate) struct RowEntry { } // Can't derive this because the `Row` generic messes us up. -impl Default for TableCache { - fn default() -> Self { +impl TableCache { + fn new(extra_logging: Option>) -> Self { Self { entries: Default::default(), unique_indices: Default::default(), + extra_logging, } } } @@ -185,7 +192,13 @@ impl<'r, Row> TableAppliedDiff<'r, Row> { } } -impl TableCache { +impl TableCache { + fn debug_log(&self, body: impl FnOnce(&mut File) -> std::result::Result<(), std::io::Error>) { + debug_log(&self.extra_logging, body); + } +} + +impl TableCache { fn handle_delete<'r>( &mut self, inserts: &mut RowEventMap<'_, Row>, @@ -195,8 +208,16 @@ impl TableCache { // Extract the entry and decrement the `ref_count`. // Only create a delete event if `ref_count = 0`. let Entry::Occupied(mut entry) = self.entries.entry(delete.bsatn.clone()) else { + self.debug_log(|file| { + writeln!(file, "`handle_delete` for table with row type {}: a delete update should correspond to an existing row in the table cache, but the row {delete:?} was not present", std::any::type_name::())?; + writeln!(file, "table contents:")?; + for (bsatn, RowEntry { row, ref_count }) in self.entries.iter() { + writeln!(file, "\t{bsatn:?}\n\t\t{row:?}\n\t\tref_count {ref_count}")?; + } + Ok(()) + }); // We're guaranteed to never hit this as long as we apply inserts before deletes. - unreachable!("a delete update should correspond to an existing row in the table cache"); + unreachable!("a delete update should correspond to an existing row in the table cache, but the row {delete:?} was not present"); }; let ref_count = &mut entry.get_mut().ref_count; *ref_count -= 1; @@ -320,19 +341,21 @@ pub struct ClientCache { /// The strings are table names, since we may have multiple tables with the same row type. tables: Map, + /// Clone of the [`crate::db_connection::DbContextImpl::extra_logging`]. + extra_logging: Option>, + _module: PhantomData, } -impl Default for ClientCache { - fn default() -> Self { +impl ClientCache { + pub(crate) fn new(extra_logging: Option>) -> Self { Self { tables: Map::new(), + extra_logging, _module: PhantomData, } } -} -impl ClientCache { /// Get a handle on the [`TableCache`] which stores rows of type `Row` for the table `table_name`. pub(crate) fn get_table + Send + Sync + 'static>( &self, @@ -353,12 +376,12 @@ impl ClientCache { .entry::>>() .or_insert_with(Default::default) .entry(table_name) - .or_default() + .or_insert_with(|| TableCache::new(self.extra_logging.clone())) } /// Apply all the mutations in `diff` /// to the [`TableCache`] which stores rows of type `Row` for the table `table_name`. - pub fn apply_diff_to_table<'r, Row: InModule + Clone + Send + Sync + 'static>( + pub fn apply_diff_to_table<'r, Row: InModule + Clone + Debug + Send + Sync + 'static>( &mut self, table_name: &'static str, diff: &'r TableUpdate, @@ -530,7 +553,7 @@ pub struct UniqueConstraintHandle { } impl< - Row: Clone + InModule + Send + Sync + 'static, + Row: Clone + Debug + InModule + Send + Sync + 'static, Col: std::any::Any + Eq + std::hash::Hash + Clone + Send + Sync + std::fmt::Debug + 'static, > UniqueConstraintHandle { diff --git a/sdks/rust/src/db_connection.rs b/sdks/rust/src/db_connection.rs index 7c66fe4815e..cb40053453e 100644 --- a/sdks/rust/src/db_connection.rs +++ b/sdks/rust/src/db_connection.rs @@ -920,7 +920,7 @@ but you must call one of them, or else the connection will never progress. procedure_callbacks, })); - let mut cache = ClientCache::default(); + let mut cache = ClientCache::new(extra_logging.clone()); M::register_tables(&mut cache); let cache = Arc::new(StdMutex::new(cache)); let send_chan = Arc::new(StdMutex::new(Some(raw_msg_send))); From 58fb0f56319240d9e30ddc240fd0f976317acebb Mon Sep 17 00:00:00 2001 From: Phoebe Goldman Date: Thu, 5 Mar 2026 14:58:34 -0500 Subject: [PATCH 3/5] Clippy --- sdks/rust/src/db_connection.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sdks/rust/src/db_connection.rs b/sdks/rust/src/db_connection.rs index cb40053453e..60351f4d9fe 100644 --- a/sdks/rust/src/db_connection.rs +++ b/sdks/rust/src/db_connection.rs @@ -819,7 +819,7 @@ pub(crate) fn debug_log( body: impl FnOnce(&mut File) -> std::result::Result<(), std::io::Error>, ) { if let Some(file) = extra_logging { - body(&mut *file.lock().expect("`extra_logging` file Mutex is poisoned")).expect("Writing debug log failed") + body(&mut file.lock().expect("`extra_logging` file Mutex is poisoned")).expect("Writing debug log failed") } } From 47ec22a29b8892c212454c6ded996db60ad9e4b8 Mon Sep 17 00:00:00 2001 From: Phoebe Goldman Date: Tue, 10 Mar 2026 11:29:38 -0400 Subject: [PATCH 4/5] Event table test client bindings --- .../rust/tests/event-table-client/src/module_bindings/mod.rs | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/sdks/rust/tests/event-table-client/src/module_bindings/mod.rs b/sdks/rust/tests/event-table-client/src/module_bindings/mod.rs index 76f5f7db170..d8693aa3a79 100644 --- a/sdks/rust/tests/event-table-client/src/module_bindings/mod.rs +++ b/sdks/rust/tests/event-table-client/src/module_bindings/mod.rs @@ -1,7 +1,7 @@ // THIS FILE IS AUTOMATICALLY GENERATED BY SPACETIMEDB. EDITS TO THIS FILE // WILL NOT BE SAVED. MODIFY TABLES IN YOUR MODULE SOURCE CODE INSTEAD. -// This was generated using spacetimedb cli version 2.0.0 (commit 85095cfa85e3addc29ce58bfe670b6003271b288). +// This was generated using spacetimedb cli version 2.0.3 (commit c5743cfc8d2fe70b31f43f275313332524a56476). #![allow(unused, clippy::all)] use spacetimedb_sdk::__codegen::{self as __sdk, __lib, __sats, __ws}; @@ -62,7 +62,7 @@ impl __sdk::Reducer for Reducer { } } -#[derive(Default)] +#[derive(Default, Debug)] #[allow(non_snake_case)] #[doc(hidden)] pub struct DbUpdate { @@ -149,6 +149,7 @@ impl<'r> __sdk::AppliedDiff<'r> for AppliedDiff<'r> { } #[doc(hidden)] +#[derive(Debug)] pub struct RemoteModule; impl __sdk::InModule for RemoteModule { From 1760efd4d8ad25b4030f318cc1e477ce88250112 Mon Sep 17 00:00:00 2001 From: Phoebe Goldman Date: Tue, 10 Mar 2026 11:53:26 -0400 Subject: [PATCH 5/5] insta approve --- crates/codegen/tests/snapshots/codegen__codegen_rust.snap | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/crates/codegen/tests/snapshots/codegen__codegen_rust.snap b/crates/codegen/tests/snapshots/codegen__codegen_rust.snap index 53ea2c7b113..96c5ce8afd6 100644 --- a/crates/codegen/tests/snapshots/codegen__codegen_rust.snap +++ b/crates/codegen/tests/snapshots/codegen__codegen_rust.snap @@ -1230,7 +1230,7 @@ _ => unreachable!(), } } -#[derive(Default)] +#[derive(Default, Debug)] #[allow(non_snake_case)] #[doc(hidden)] pub struct DbUpdate { @@ -1346,6 +1346,7 @@ impl<'r> __sdk::AppliedDiff<'r> for AppliedDiff<'r> { #[doc(hidden)] +#[derive(Debug)] pub struct RemoteModule; impl __sdk::InModule for RemoteModule {