WASM ABI: implement console ABIs (#1664)

Author: Centril

crates/bindings-csharp/Runtime/bindings.c

@@ -36,11 +36,11 @@ OPAQUE_TYPEDEF(RowIter, uint32_t);
 #endif
 
 IMPORT(void, _console_log,
-       (LogLevel level, const uint8_t* target, uint32_t target_len,
-        const uint8_t* filename, uint32_t filename_len, uint32_t line_number,
-        const uint8_t* message, uint32_t message_len),
-       (level, target, target_len, filename, filename_len, line_number, message,
-        message_len));
+       (LogLevel level, const uint8_t* target_ptr, uint32_t target_len,
+        const uint8_t* filename_ptr, uint32_t filename_len, uint32_t line_number,
+        const uint8_t* message_ptr, uint32_t message_len),
+       (level, target_ptr, target_len, filename_ptr, filename_len, line_number,
+        message_ptr, message_len));
 
 IMPORT(Status, _table_id_from_name,
        (const uint8_t* name, uint32_t name_len, TableId* id),

crates/bindings-csharp/Runtime/build/SpacetimeDB.Runtime.targets

@@ -3,7 +3,6 @@
   <ItemGroup Condition="'$(EXPERIMENTAL_WASM_AOT)' == '1'">
     <NativeLibrary Include="$(MSBuildThisFileDirectory)..\bindings.c" />
     <UnmanagedEntryPointsAssembly Include="SpacetimeDB.Runtime" />
-    <WasmImport Include="$(SpacetimeNamespace)!_console_log" />
     <WasmImport Include="$(SpacetimeNamespace)!_iter_by_col_eq" />
     <WasmImport Include="$(SpacetimeNamespace)!_delete_by_col_eq" />
     <WasmImport Include="$(SpacetimeNamespace)!_iter_start_filtered" />
@@ -16,6 +15,7 @@
     <WasmImport Include="$(SpacetimeNamespace)!_datastore_delete_all_by_eq_bsatn" />
     <WasmImport Include="$(SpacetimeNamespace)!_bytes_source_read" />
     <WasmImport Include="$(SpacetimeNamespace)!_bytes_sink_write" />
+    <WasmImport Include="$(SpacetimeNamespace)!_console_log" />
 
     <PackageReference Include="Microsoft.DotNet.ILCompiler.LLVM" Version="8.0.0-*" />
     <PackageReference Include="runtime.win-x64.Microsoft.DotNet.ILCompiler.LLVM" Version="8.0.0-*" />

crates/bindings-sys/src/lib.rs

@@ -247,31 +247,6 @@ pub mod raw {
         /// - `SCHEDULE_AT_DELAY_TOO_LONG`, when the delay specified in the row was too long.
         pub fn _datastore_insert_bsatn(table_id: TableId, row_ptr: *mut u8, row_len_ptr: *mut usize) -> u16;
 
-        /// Log at `level` a `message` message occuring in `filename:line_number`
-        /// with [`target`] being the module path at the `log!` invocation site.
-        ///
-        /// These various pointers are interpreted lossily as UTF-8 strings with a corresponding `_len`.
-        ///
-        /// The `target` and `filename` pointers are ignored by passing `NULL`.
-        /// The line number is ignored if `line_number == u32::MAX`.
-        ///
-        /// No message is logged if
-        /// - `target != NULL && target + target_len > u64::MAX`
-        /// - `filename != NULL && filename + filename_len > u64::MAX`
-        /// - `message + message_len > u64::MAX`
-        ///
-        /// [`target`]: https://docs.rs/log/latest/log/struct.Record.html#method.target
-        pub fn _console_log(
-            level: u8,
-            target: *const u8,
-            target_len: usize,
-            filename: *const u8,
-            filename_len: usize,
-            line_number: u32,
-            message: *const u8,
-            message_len: usize,
-        );
-
         /// Schedules a reducer to be called asynchronously, nonatomically,
         /// and immediately on a best effort basis.
         ///
@@ -374,23 +349,66 @@ pub mod raw {
         /// ```
         pub fn _bytes_source_read(source: BytesSource, buffer_ptr: *mut u8, buffer_len_ptr: *mut usize) -> i16;
 
-        /// Begin a timing span.
+        /// Logs at `level` a `message` message occuring in `filename:line_number`
+        /// with [`target`](target) being the module path at the `log!` invocation site.
+        ///
+        /// These various pointers are interpreted lossily as UTF-8 strings with a corresponding `_len`.
         ///
-        /// When the returned `u32` span ID is passed to [`_span_end`],
+        /// The `target` and `filename` pointers are ignored by passing `NULL`.
+        /// The line number is ignored if `line_number == u32::MAX`.
+        ///
+        /// No message is logged if
+        /// - `target != NULL && target + target_len > u64::MAX`
+        /// - `filename != NULL && filename + filename_len > u64::MAX`
+        /// - `message + message_len > u64::MAX`
+        ///
+        /// # Traps
+        ///
+        /// Traps if:
+        /// - `target` is not NULL and `target_ptr[..target_len]` is not in bounds of WASM memory.
+        /// - `filename` is not NULL and `filename_ptr[..filename_len]` is not in bounds of WASM memory.
+        /// - `message` is not NULL and `message_ptr[..message_len]` is not in bounds of WASM memory.
+        ///
+        /// [target]: https://docs.rs/log/latest/log/struct.Record.html#method.target
+        pub fn _console_log(
+            level: u8,
+            target_ptr: *const u8,
+            target_len: usize,
+            filename_ptr: *const u8,
+            filename_len: usize,
+            line_number: u32,
+            message_ptr: *const u8,
+            message_len: usize,
+        );
+
+        /// Begins a timing span with `name = name_ptr[..name_len]`.
+        ///
+        /// When the returned `ConsoleTimerId` is passed to [`console_timer_end`],
         /// the duration between the calls will be printed to the module's logs.
         ///
-        /// The slice (`name`, `name_len`) must be valid UTF-8 bytes.
-        pub fn _span_start(name: *const u8, name_len: usize) -> u32;
+        /// The `name` is interpreted lossily as UTF-8.
+        ///
+        /// # Traps
+        ///
+        /// Traps if:
+        /// - `name_ptr` is NULL or `name` is not in bounds of WASM memory.
+        pub fn _console_timer_start(name_ptr: *const u8, name_len: usize) -> u32;
 
         /// End a timing span.
         ///
-        /// The `span_id` must be the result of a call to `_span_start`.
+        /// The `timer_id` must be the result of a call to `console_timer_start`.
         /// The duration between the two calls will be computed and printed to the module's logs.
+        /// Once `console_timer_end` is called on `id: ConsoleTimerId`, the `id` is invalid.
+        /// That is, `console_timer_end(id)` the second time will yield `NO_SUCH_CONSOLE_TIMER`.
         ///
-        /// Behavior is unspecified
-        /// if `_span_end` is called on a `span_id` which is not the result of a call to `_span_start`,
-        /// or if `_span_end` is called multiple times with the same `span_id`.
-        pub fn _span_end(span_id: u32);
+        /// Note that the host is free to reuse allocations in a pool,
+        /// destroying the handle logically does not entail that memory is necessarily reclaimed.
+        ///
+        /// # Errors
+        ///
+        /// Returns an error:
+        /// - `NO_SUCH_CONSOLE_TIMER`, when `timer_id` does not exist.
+        pub fn _console_timer_end(timer_id: u32) -> u16;
     }
 
     /// What strategy does the database index use?

crates/bindings/src/time_span.rs

@@ -5,7 +5,7 @@ pub struct Span {
 impl Span {
     pub fn start(name: &str) -> Self {
         let name = name.as_bytes();
-        let id = unsafe { spacetimedb_bindings_sys::raw::_span_start(name.as_ptr(), name.len()) };
+        let id = unsafe { spacetimedb_bindings_sys::raw::_console_timer_start(name.as_ptr(), name.len()) };
         Self { span_id: id }
     }
 
@@ -17,7 +17,7 @@ impl Span {
 impl std::ops::Drop for Span {
     fn drop(&mut self) {
         unsafe {
-            spacetimedb_bindings_sys::raw::_span_end(self.span_id);
+            spacetimedb_bindings_sys::raw::_console_timer_end(self.span_id);
         }
     }
 }

crates/cli/src/subcommands/generate/mod.rs

@@ -415,15 +415,15 @@ pub fn extract_descriptions(wasm_file: &Path) -> anyhow::Result<RawModuleDefV8>
         "_console_log",
         |mut caller: Caller<'_, WasmCtx>,
          _level: u32,
-         _target: u32,
+         _target_ptr: u32,
          _target_len: u32,
-         _filename: u32,
+         _filename_ptr: u32,
          _filename_len: u32,
          _line_number: u32,
-         message: u32,
+         message_ptr: u32,
          message_len: u32| {
             let (mem, _) = WasmCtx::mem_env(&mut caller);
-            let slice = mem.deref_slice(message, message_len).unwrap();
+            let slice = mem.deref_slice(message_ptr, message_len).unwrap();
             println!("from wasm: {}", String::from_utf8_lossy(slice));
         },
     )?;

crates/core/src/host/mod.rs

@@ -143,18 +143,20 @@ fn from_json_seed<'de, T: serde::de::DeserializeSeed<'de>>(s: &'de str, seed: T)
 pub enum AbiCall {
     TableIdFromName,
     DatastoreTableRowCount,
+    DatastoreTableScanBsatn,
     RowIterBsatnAdvance,
     RowIterBsatnClose,
+    DatastoreInsertBsatn,
+    DatastoreDeleteAllByEqBsatn,
     BytesSourceRead,
     BytesSinkWrite,
-
-    CancelReducer,
     ConsoleLog,
+    ConsoleTimerStart,
+    ConsoleTimerEnd,
+
     DeleteByColEq,
-    DeleteByRel,
-    DatastoreInsertBsatn,
     IterByColEq,
-    IterStart,
     IterStartFiltered,
-    ScheduleReducer,
+
+    VolatileNonatomicScheduleImmediate,
 }

crates/core/src/host/wasm_common.rs

@@ -302,11 +302,11 @@ pub(super) type RowIters = ResourceSlab<RowIterIdx>;
 
 pub(super) struct TimingSpan {
     pub start: Instant,
-    pub name: Vec<u8>,
+    pub name: String,
 }
 
 impl TimingSpan {
-    pub fn new(name: Vec<u8>) -> Self {
+    pub fn new(name: String) -> Self {
         Self {
             start: Instant::now(),
             name,
@@ -357,10 +357,9 @@ macro_rules! abi_funcs {
             "spacetime_10.0"::datastore_delete_all_by_eq_bsatn,
             "spacetime_10.0"::bytes_source_read,
             "spacetime_10.0"::bytes_sink_write,
-
             "spacetime_10.0"::console_log,
-            "spacetime_10.0"::span_end,
-            "spacetime_10.0"::span_start,
+            "spacetime_10.0"::console_timer_start,
+            "spacetime_10.0"::console_timer_end,
 
             "spacetime_10.0"::delete_by_col_eq,
             "spacetime_10.0"::iter_by_col_eq,