vm: refactor fd_vm_log_appendf -> fd_vm_log_append_printf + add tests

src/flamenco/vm/fd_vm_private.h

@@ -382,26 +382,25 @@ fd_vm_log_append( fd_vm_t *    vm,
   return vm;
 }
 
-/* fd_vm_log_appendf is a convenience wrapper to fd_vm_log_append that
-   allows to format strings like printf.
-   Returns NULL on formatting error, vm on success. */
-
-#include <stdio.h>
-#include <stdarg.h>
-
-static inline fd_vm_t *
-fd_vm_log_appendf( fd_vm_t *    vm,
-                   const char * format,
-                   ... ) {
-  char msg[ FD_VM_LOG_TAIL+1 ];
-  va_list args;
-  va_start (args, format);
-  int msg_sz = vsnprintf( msg, FD_VM_LOG_TAIL, format, args );
-  if( FD_UNLIKELY( msg_sz<0 ) ) {
-    return NULL;
-  }
-  return fd_vm_log_append( vm, msg, (ulong)msg_sz );
-}
+/* fd_vm_log_append_printf is analogous to fd_vm_log_append and allows
+   to format arguments like printf.
+   It cancels any VM log message in preparation on vm and appends the message
+   resulting from formatting args to the VM's log.  The formatted message
+   includes a last byte set to 0.
+   Assumes vm is valid.
+   In case of formatting errors, no log is appended and the error is ignored
+   (internally, _vm->log[_vm->log_sz] is overwritten with 0).
+   Returns vm. */
+
+#define fd_vm_log_append_printf( vm, fmt, ... ) (__extension__({             \
+    fd_vm_t * _vm  = (vm);                                                   \
+    ulong     _sz  = _vm->log_sz; /* In [0,FD_VM_LOG_MAX] */                 \
+    ulong     _len;                                                          \
+    fd_cstr_printf_check( (char *)_vm->log + _sz, FD_VM_LOG_MAX + 1UL - _sz, \
+                          &_len, (fmt), __VA_ARGS__ );                       \
+    _vm->log_sz = _sz + _len;                                                \
+    (_vm);                                                                   \
+}))
 
 FD_PROTOTYPES_END
 

src/flamenco/vm/syscall/fd_vm_syscall_crypto.c

@@ -213,7 +213,7 @@ fd_vm_syscall_sol_poseidon( void *  _vm,
   /* https://github.com/anza-xyz/agave/blob/v1.18.12/programs/bpf_loader/src/syscalls/mod.rs#L1691-L1698 */
 
   if( FD_UNLIKELY( vals_len > FD_VM_SYSCALL_SOL_POSEIDON_MAX_VALS ) ) {
-    fd_vm_log_appendf( vm, "Poseidon hashing %lu sequences is not supported", vals_len );
+    fd_vm_log_append_printf( vm, "Poseidon hashing %lu sequences is not supported", vals_len );
     return FD_VM_ERR_INVAL; /* SyscallError::InvalidLength */
   }
 
@@ -231,7 +231,7 @@ fd_vm_syscall_sol_poseidon( void *  _vm,
 
   /* The following can never happen, left as comment for completeness.
      if( FD_UNLIKELY( cost == ULONG_MAX ) ) {
-       fd_vm_log_appendf( vm, "Overflow while calculating the compute cost" );
+       fd_vm_log_append_printf( vm, "Overflow while calculating the compute cost" );
        return FD_VM_ERR_INVAL; // SyscallError::ArithmeticOverflow
      }
   */

src/flamenco/vm/syscall/fd_vm_syscall_hash.c

@@ -36,7 +36,7 @@ fd_vm_syscall_sol_sha256( /**/            void *  _vm,
 
   /* https://github.com/anza-xyz/agave/blob/v1.18.12/programs/bpf_loader/src/syscalls/mod.rs#L1911-L1920 */
   if( FD_UNLIKELY( FD_VM_SHA256_MAX_SLICES < vals_len ) ) {
-    fd_vm_log_appendf( vm, "%s Hashing %d sequences in one syscall is over the limit %d", "Sha256", vals_len, FD_VM_SHA256_MAX_SLICES );
+    fd_vm_log_append_printf( vm, "%s Hashing %lu sequences in one syscall is over the limit %lu", "Sha256", vals_len, FD_VM_SHA256_MAX_SLICES );
     return FD_VM_ERR_INVAL; /* SyscallError::TooManySlices */
   }
 
@@ -89,7 +89,7 @@ fd_vm_syscall_sol_blake3( /**/            void *  _vm,
 
   /* https://github.com/anza-xyz/agave/blob/v1.18.12/programs/bpf_loader/src/syscalls/mod.rs#L1911-L1920 */
   if( FD_UNLIKELY( FD_VM_SHA256_MAX_SLICES < vals_len ) ) {
-    fd_vm_log_appendf( vm, "%s Hashing %d sequences in one syscall is over the limit %d", "Blake3", vals_len, FD_VM_SHA256_MAX_SLICES );
+    fd_vm_log_append_printf( vm, "%s Hashing %lu sequences in one syscall is over the limit %lu", "Blake3", vals_len, FD_VM_SHA256_MAX_SLICES );
     return FD_VM_ERR_INVAL; /* SyscallError::TooManySlices */
   }
 
@@ -142,7 +142,7 @@ fd_vm_syscall_sol_keccak256( /**/            void *  _vm,
 
   /* https://github.com/anza-xyz/agave/blob/v1.18.12/programs/bpf_loader/src/syscalls/mod.rs#L1911-L1920 */
   if( FD_UNLIKELY( FD_VM_SHA256_MAX_SLICES < vals_len ) ) {
-    fd_vm_log_appendf( vm, "%s Hashing %lu sequences in one syscall is over the limit %lu", "Keccak256", vals_len, FD_VM_SHA256_MAX_SLICES );
+    fd_vm_log_append_printf( vm, "%s Hashing %lu sequences in one syscall is over the limit %lu", "Keccak256", vals_len, FD_VM_SHA256_MAX_SLICES );
     return FD_VM_ERR_INVAL; /* SyscallError::TooManySlices */
   }
 

src/flamenco/vm/syscall/test_vm_syscalls.c

@@ -435,6 +435,27 @@ main( int     argc,
 
 # undef APPEND
 
+  /* tests for fd_vm_log_append_printf()
+     Note: we're simply testing that we don't overflow the memory region.
+     We're not testing behavior like how should multiple logs be appended,
+     should we add any custom messages when truncating, etc.
+
+     fd_vm_log_append_printf( vm, "test" ); // does NOT compile
+  */
+  FD_TEST( fd_vm_log_reset( vm )==vm );
+  FD_TEST( vm->log_sz == 0UL );
+  FD_TEST( fd_vm_log_append_printf( vm, "test %d", 10 ) == vm );
+  FD_TEST( vm->log_sz == 7UL );  /* "test 10" = 7 char */
+  FD_TEST( fd_vm_log_append_printf( vm, "test %s", "hello" ) == vm );
+  FD_TEST( vm->log_sz == 17UL ); /* "test hello" += 17 char */
+  vm->log_sz = FD_VM_LOG_MAX - 2;
+  FD_TEST( vm->log_sz == FD_VM_LOG_MAX - 2 );
+  FD_TEST( fd_vm_log_append_printf( vm, "test %d", 10 ) == vm );
+  FD_TEST( vm->log_sz == FD_VM_LOG_MAX ); /* no more than FD_VM_LOG_MAX */
+  FD_TEST( fd_vm_log_append_printf( vm, "test %s", "hello" ) == vm );
+  FD_TEST( vm->log_sz == FD_VM_LOG_MAX ); /* no more than FD_VM_LOG_MAX */
+  FD_LOG_NOTICE(( "Passed test program (%s)", "fd_vm_log_append_printf" ));
+
   fd_vm_delete    ( fd_vm_leave    ( vm  ) );
   fd_sha256_delete( fd_sha256_leave( sha ) );
   fd_rng_delete   ( fd_rng_leave   ( rng ) );