feat!: debug logs for all (#6392)

Unify and implement debug log Noir and oracles.

avm-transpiler/src/opcodes.rs

@@ -64,6 +64,8 @@ pub enum AvmOpcode {
     DELEGATECALL,
     RETURN,
     REVERT,
+    // Misc
+    DEBUGLOG,
     // Gadgets
     KECCAK,
     POSEIDON2,
@@ -152,6 +154,9 @@ impl AvmOpcode {
             AvmOpcode::RETURN => "RETURN",
             AvmOpcode::REVERT => "REVERT",
 
+            // Misc
+            AvmOpcode::DEBUGLOG => "DEBUGLOG",
+
             // Gadgets
             AvmOpcode::KECCAK => "KECCAK",
             AvmOpcode::POSEIDON2 => "POSEIDON2",

avm-transpiler/src/transpile.rs

@@ -359,6 +359,7 @@ fn handle_foreign_call(
         }
         "storageRead" => handle_storage_read(avm_instrs, destinations, inputs),
         "storageWrite" => handle_storage_write(avm_instrs, destinations, inputs),
+        "debugLog" => handle_debug_log(avm_instrs, destinations, inputs),
         // Getters.
         _ if inputs.is_empty() && destinations.len() == 1 => {
             handle_getter_instruction(avm_instrs, function, destinations, inputs)
@@ -431,12 +432,14 @@ fn handle_external_call(
         opcode: opcode,
         // (left to right)
         //   * selector direct
+        //   * success offset direct
+        //   * (n/a) ret size is an immeadiate
         //   * ret offset INDIRECT
         //   * arg size offset direct
         //   * args offset INDIRECT
         //   * address offset direct
         //   * gas offset INDIRECT
-        indirect: Some(0b010101),
+        indirect: Some(0b00010101),
         operands: vec![
             AvmOperand::U32 { value: gas_offset },
             AvmOperand::U32 {
@@ -1003,6 +1006,57 @@ fn handle_black_box_function(avm_instrs: &mut Vec<AvmInstruction>, operation: &B
         _ => panic!("Transpiler doesn't know how to process {:?}", operation),
     }
 }
+
+fn handle_debug_log(
+    avm_instrs: &mut Vec<AvmInstruction>,
+    destinations: &Vec<ValueOrArray>,
+    inputs: &Vec<ValueOrArray>,
+) {
+    if !destinations.is_empty() || inputs.len() != 3 {
+        panic!(
+            "Transpiler expects ForeignCall::DEBUGLOG to have 0 destinations and 3 inputs, got {} and {}",
+            destinations.len(),
+            inputs.len()
+        );
+    }
+    let (message_offset, message_size) = match &inputs[0] {
+        ValueOrArray::HeapArray(HeapArray { pointer, size }) => (pointer.0 as u32, *size as u32),
+        _ => panic!("Message for ForeignCall::DEBUGLOG should be a HeapArray."),
+    };
+    // The fields are a slice, and this is represented as a (length: Field, slice: HeapVector).
+    // The length field is redundant and we skipt it.
+    let (fields_offset_ptr, fields_size_ptr) = match &inputs[2] {
+        ValueOrArray::HeapVector(HeapVector { pointer, size }) => (pointer.0 as u32, size.0 as u32),
+        _ => panic!("List of fields for ForeignCall::DEBUGLOG should be a HeapVector (slice)."),
+    };
+    avm_instrs.push(AvmInstruction {
+        opcode: AvmOpcode::DEBUGLOG,
+        // (left to right)
+        //  * fields_size_ptr direct
+        //  * fields_offset_ptr INDIRECT
+        //  * (N/A) message_size is an immediate
+        //  * message_offset direct
+        indirect: Some(0b011),
+        operands: vec![
+            AvmOperand::U32 {
+                value: message_offset,
+            },
+            AvmOperand::U32 {
+                value: message_size,
+            },
+            // indirect
+            AvmOperand::U32 {
+                value: fields_offset_ptr,
+            },
+            // indirect
+            AvmOperand::U32 {
+                value: fields_size_ptr,
+            },
+        ],
+        ..Default::default()
+    });
+}
+
 /// Emit a storage write opcode
 /// The current implementation writes an array of values into storage ( contiguous slots in memory )
 fn handle_storage_write(

barretenberg/cpp/src/barretenberg/vm/avm_trace/avm_opcode.hpp

@@ -92,6 +92,9 @@ enum class OpCode : uint8_t {
     RETURN,
     REVERT,
 
+    // Misc
+    DEBUGLOG,
+
     // Gadgets
     KECCAK,
     POSEIDON2,

docs/docs/misc/migration_notes.md

@@ -6,6 +6,17 @@ keywords: [sandbox, cli, aztec, notes, migration, updating, upgrading]
 
 Aztec is in full-speed development. Literally every version breaks compatibility with the previous ones. This page attempts to target errors and difficulties you might encounter when upgrading, and how to resolve them.
 
+## TBD
+
+### [Aztec.nr] Debug logging
+
+The function `debug_log_array_with_prefix` has been removed. Use `debug_log_format` with `{}` instead. The special sequence `{}` will be replaced with the whole array. You can also use `{0}`, `{1}`, ... as usual with `debug_log_format`.
+
+```diff
+- debug_log_array_with_prefix("Prefix", my_array);
++ debug_log_format("Prefix {}", my_array);
+```
+
 ## 0.39.0
 
 ### [Aztec.nr] Mutable delays in `SharedMutable`

noir-projects/noir-contracts/contracts/avm_test_contract/src/main.nr

@@ -177,6 +177,14 @@ contract AvmTest {
         helper_with_failed_assertion()
     }
 
+    #[aztec(public-vm)]
+    fn debug_logging() {
+        dep::aztec::oracle::debug_log::debug_log("just text");
+        dep::aztec::oracle::debug_log::debug_log_format("second: {1}", [1, 2, 3, 4]);
+        dep::aztec::oracle::debug_log::debug_log_format("whole array: {}", [1, 2, 3, 4]);
+        dep::aztec::oracle::debug_log::debug_log("tabs and newlines\n\t- first\n\t- second");
+    }
+
     /************************************************************************
      * Hashing functions
      ************************************************************************/

noir-projects/noir-contracts/contracts/contract_class_registerer_contract/src/main.nr

@@ -43,8 +43,8 @@ contract ContractClassRegisterer {
         context.push_new_nullifier(contract_class_id.to_field(), 0);
 
         // Broadcast class info including public bytecode
-        dep::aztec::oracle::debug_log::debug_log_array_with_prefix(
-            "ContractClassRegistered",
+        dep::aztec::oracle::debug_log::debug_log_format(
+            "ContractClassRegistered: {}",
             [
             contract_class_id.to_field(),
             artifact_hash,
@@ -76,8 +76,8 @@ contract ContractClassRegisterer {
             artifact_function_tree_leaf_index,
             function: function_data
         };
-        dep::aztec::oracle::debug_log::debug_log_array_with_prefix(
-            "ClassPrivateFunctionBroadcasted",
+        dep::aztec::oracle::debug_log::debug_log_format(
+            "ClassPrivateFunctionBroadcasted: {}",
             [
             contract_class_id.to_field(),
             artifact_metadata_hash,
@@ -107,8 +107,8 @@ contract ContractClassRegisterer {
             artifact_function_tree_leaf_index,
             function: function_data
         };
-        dep::aztec::oracle::debug_log::debug_log_array_with_prefix(
-            "ClassUnconstrainedFunctionBroadcasted",
+        dep::aztec::oracle::debug_log::debug_log_format(
+            "ClassUnconstrainedFunctionBroadcasted: {}",
             [
             contract_class_id.to_field(),
             artifact_metadata_hash,

noir-projects/noir-contracts/contracts/contract_instance_deployer_contract/src/main.nr

@@ -35,7 +35,7 @@ contract ContractInstanceDeployer {
         // Broadcast the event
         let event = ContractInstanceDeployed { contract_class_id, address, public_keys_hash, initialization_hash, salt, deployer, version: 1 };
         let event_payload = event.serialize();
-        dep::aztec::oracle::debug_log::debug_log_array_with_prefix("ContractInstanceDeployed", event_payload);
+        dep::aztec::oracle::debug_log::debug_log_format("ContractInstanceDeployed: {}", event_payload);
         context.emit_unencrypted_log(event_payload);
     }
 }

noir-projects/noir-protocol-circuits/crates/types/src/debug_log.nr

@@ -2,47 +2,22 @@
 // WARNING: sometimes when using debug logs the ACVM errors with: `thrown: "solver opcode resolution error: cannot solve opcode: expression has too many unknowns x155"`
 
 #[oracle(debugLog)]
-fn debug_log_oracle<T, N>(_msg: T, _num_args: Field) {}
-#[oracle(debugLog)]
-fn debug_log_format_oracle<T, N>(_msg: T, _args: [Field; N], _num_args: Field) {}
-#[oracle(debugLog)]
-fn debug_log_field_oracle(_field: Field) {}
-#[oracle(debugLog)]
-fn debug_log_array_oracle<T, N>(_arbitrary_array: [T; N]) {}
-#[oracle(debugLogWithPrefix)]
-fn debug_log_array_with_prefix_oracle<S, T, N>(_prefix: S, _arbitrary_array: [T; N]) {}
-
-/// NOTE: call this with a str<N> msg of length > 1
-/// Example:
-/// `debug_log("blah blah this is a debug string");`
-unconstrained pub fn debug_log<T>(msg: T) {
-    debug_log_oracle(msg, 0);
-}
+fn debug_log_oracle<M, N>(_msg: str<M>, args: [Field]) {}
 
 /// NOTE: call this with a str<N> msg of form
 /// "some string with {0} and {1} ... {N}"
 /// and an array of N field which will be formatted
 /// into the string in the simulator.
 /// Example:
 /// debug_log_format("get_2(slot:{0}) =>\n\t0:{1}\n\t1:{2}", [storage_slot, note0_hash, note1_hash]);
-unconstrained pub fn debug_log_format<T, N>(msg: T, args: [Field; N]) {
-    debug_log_format_oracle(msg, args, args.len() as Field);
-}
-
-/// Example:
-/// `debug_log_field(my_field);`
-unconstrained pub fn debug_log_field(field: Field) {
-    debug_log_field_oracle(field);
-}
-
-/// Example:
-/// `debug_log_array(my_array);`
-unconstrained fn debug_log_array<T, N>(arbitrary_array: [T; N]) {
-    debug_log_array_oracle(arbitrary_array);
+/// debug_log_format("whole array: {}", [e1, e2, e3, e4]);
+unconstrained pub fn debug_log_format<M, N>(msg: str<M>, args: [Field; N]) {
+    debug_log_oracle(msg, args.as_slice());
 }
 
+/// NOTE: call this with a str<N> msg of length > 1
 /// Example:
-/// `debug_log_array_with_prefix("Prefix", my_array);`
-unconstrained pub fn debug_log_array_with_prefix<S, T, N>(prefix: S, arbitrary_array: [T; N]) {
-    debug_log_array_with_prefix_oracle(prefix, arbitrary_array);
+/// `debug_log("blah blah this is a debug string");`
+unconstrained pub fn debug_log<N>(msg: str<N>) {
+    debug_log_format(msg, []);
 }

yarn-project/circuits.js/src/index.ts

@@ -1,6 +1,5 @@
 export * from './constants.gen.js';
 export * from './contract/index.js';
-export * from './debug_log.js';
 export * from './hints/index.js';
 export * from './interfaces/index.js';
 export * from './keys/index.js';

yarn-project/foundation/src/log/debug.ts

@@ -81,3 +81,24 @@ export function enableLogs(str: string) {
 export function isLogEnabled(str: string) {
   return debug.enabled(str);
 }
+
+/**
+ * Format a debug string filling in `'{0}'` entries with their
+ * corresponding values from the args array, amd `'{}'` with the whole array.
+ *
+ * @param formatStr - str of form `'this is a string with some entries like {0} and {1}'`
+ * @param args - array of fields to fill in the string format entries with
+ * @returns formatted string
+ */
+interface Printable {
+  toString(): string;
+}
+export function applyStringFormatting(formatStr: string, args: Printable[]): string {
+  return formatStr
+    .replace(/{(\d+)}/g, (match, index) => {
+      return typeof args[index] === 'undefined' ? match : args[index].toString();
+    })
+    .replace(/{}/g, (_match, _index) => {
+      return args.toString();
+    });
+}