diff --git a/barretenberg/cpp/src/barretenberg/vm/avm/trace/execution.cpp b/barretenberg/cpp/src/barretenberg/vm/avm/trace/execution.cpp index 6d1978806a4..ce4ecf72b2f 100644 --- a/barretenberg/cpp/src/barretenberg/vm/avm/trace/execution.cpp +++ b/barretenberg/cpp/src/barretenberg/vm/avm/trace/execution.cpp @@ -288,9 +288,12 @@ std::vector Execution::gen_trace(std::vector const& calldata, // on opcode logic and therefore is not maintained here. However, the next opcode in the execution // is determined by this value which require read access to the code below. uint32_t pc = 0; - while ((pc = trace_builder.getPc()) < instructions.size()) { + uint32_t counter = 0; + while ((pc = trace_builder.get_pc()) < instructions.size()) { auto inst = instructions.at(pc); - debug("[@" + std::to_string(pc) + "] " + inst.to_string()); + + debug("[PC:" + std::to_string(pc) + "] [IC:" + std::to_string(counter++) + "] " + inst.to_string() + + " (gasLeft l2=" + std::to_string(trace_builder.get_l2_gas_left()) + ")"); switch (inst.op_code) { // Compute @@ -654,6 +657,7 @@ std::vector Execution::gen_trace(std::vector const& calldata, break; } case OpCode::REVERT_8: { + info("HIT REVERT_8 ", "[PC=" + std::to_string(pc) + "] " + inst.to_string()); auto ret = trace_builder.op_revert(std::get(inst.operands.at(0)), std::get(inst.operands.at(1)), std::get(inst.operands.at(2))); @@ -662,6 +666,7 @@ std::vector Execution::gen_trace(std::vector const& calldata, break; } case OpCode::REVERT_16: { + info("HIT REVERT_16 ", "[PC=" + std::to_string(pc) + "] " + inst.to_string()); auto ret = trace_builder.op_revert(std::get(inst.operands.at(0)), std::get(inst.operands.at(1)), std::get(inst.operands.at(2))); diff --git a/barretenberg/cpp/src/barretenberg/vm/avm/trace/gas_trace.cpp b/barretenberg/cpp/src/barretenberg/vm/avm/trace/gas_trace.cpp index 18058228274..0575537d0e4 100644 --- a/barretenberg/cpp/src/barretenberg/vm/avm/trace/gas_trace.cpp +++ b/barretenberg/cpp/src/barretenberg/vm/avm/trace/gas_trace.cpp @@ -26,6 +26,9 @@ void AvmGasTraceBuilder::set_initial_gas(uint32_t l2_gas, uint32_t da_gas) uint32_t AvmGasTraceBuilder::get_l2_gas_left() const { + if (gas_trace.size() == 0) { + return initial_l2_gas; + } return gas_trace.back().remaining_l2_gas; } diff --git a/barretenberg/cpp/src/barretenberg/vm/avm/trace/helper.cpp b/barretenberg/cpp/src/barretenberg/vm/avm/trace/helper.cpp index 4789191094b..6c44d1b01e1 100644 --- a/barretenberg/cpp/src/barretenberg/vm/avm/trace/helper.cpp +++ b/barretenberg/cpp/src/barretenberg/vm/avm/trace/helper.cpp @@ -1,4 +1,5 @@ #include "barretenberg/vm/avm/trace/helper.hpp" +#include "barretenberg/vm/avm/trace/common.hpp" #include "barretenberg/vm/avm/trace/mem_trace.hpp" #include #include @@ -75,6 +76,29 @@ std::string to_hex(bb::avm_trace::AvmMemoryTag tag) return to_hex(static_cast(tag)); } +std::string to_name(bb::avm_trace::AvmMemoryTag tag) +{ + switch (tag) { + case bb::avm_trace::AvmMemoryTag::FF: + return "Field"; + case bb::avm_trace::AvmMemoryTag::U1: + return "Uint1"; + case bb::avm_trace::AvmMemoryTag::U8: + return "Uint8"; + case bb::avm_trace::AvmMemoryTag::U16: + return "Uint16"; + case bb::avm_trace::AvmMemoryTag::U32: + return "Uint32"; + case bb::avm_trace::AvmMemoryTag::U64: + return "Uint64"; + case bb::avm_trace::AvmMemoryTag::U128: + return "Uint128"; + default: + throw std::runtime_error("Invalid memory tag"); + break; + } +} + /** * * ONLY FOR TESTS - Required by dsl module and therefore cannot be moved to test/helpers.test.cpp diff --git a/barretenberg/cpp/src/barretenberg/vm/avm/trace/helper.hpp b/barretenberg/cpp/src/barretenberg/vm/avm/trace/helper.hpp index ecd1fc65076..bd45a1b472c 100644 --- a/barretenberg/cpp/src/barretenberg/vm/avm/trace/helper.hpp +++ b/barretenberg/cpp/src/barretenberg/vm/avm/trace/helper.hpp @@ -230,6 +230,8 @@ std::string to_hex(T value) std::string to_hex(bb::avm_trace::AvmMemoryTag tag); +std::string to_name(bb::avm_trace::AvmMemoryTag tag); + // Mutate the inputs void inject_end_gas_values(VmPublicInputs& public_inputs, std::vector& trace); diff --git a/barretenberg/cpp/src/barretenberg/vm/avm/trace/mem_trace.cpp b/barretenberg/cpp/src/barretenberg/vm/avm/trace/mem_trace.cpp index 11c35c14343..4a2e599f488 100644 --- a/barretenberg/cpp/src/barretenberg/vm/avm/trace/mem_trace.cpp +++ b/barretenberg/cpp/src/barretenberg/vm/avm/trace/mem_trace.cpp @@ -1,5 +1,6 @@ #include "barretenberg/vm/avm/trace/mem_trace.hpp" #include "barretenberg/vm/avm/trace/common.hpp" +#include "barretenberg/vm/avm/trace/helper.hpp" #include "barretenberg/vm/avm/trace/trace.hpp" #include @@ -29,6 +30,19 @@ std::vector AvmMemTraceBuilder::finalize() return std::move(mem_trace); } +void AvmMemTraceBuilder::debug_mem_trace_entry(MemoryTraceEntry entry) +{ + std::string suffix; + if (entry.m_space_id == INTERNAL_CALL_SPACE_ID) { + suffix = " (INTERNAL CALL STACK OP)"; + } + if (entry.m_rw) { + debug("set(", entry.m_addr, ", ", to_name(entry.w_in_tag), "(", entry.m_val, "))", suffix); + } else { + debug("get(", entry.m_addr, ", ", to_name(entry.r_in_tag), "(", entry.m_val, "))", suffix); + } +} + /** * @brief A method to insert a row/entry in the memory trace. * @@ -73,6 +87,8 @@ void AvmMemTraceBuilder::insert_in_mem_trace(uint8_t space_id, mem_trace_entry.poseidon_mem_op = true; break; } + + debug_mem_trace_entry(mem_trace_entry); mem_trace.emplace_back(mem_trace_entry); } @@ -114,17 +130,19 @@ void AvmMemTraceBuilder::load_mismatch_tag_in_mem_trace(uint8_t space_id, // Lookup counter hint, used for #[INCL_MAIN_TAG_ERR] lookup (joined on clk) m_tag_err_lookup_counts[m_clk]++; - mem_trace.emplace_back(MemoryTraceEntry{ .m_space_id = space_id, - .m_clk = m_clk, - .m_sub_clk = m_sub_clk, - .m_addr = m_addr, - .m_val = m_val, - .m_tag = m_tag, - .r_in_tag = r_in_tag, - .w_in_tag = w_in_tag, - .m_tag_err = true, - .m_one_min_inv = one_min_inv, - .m_tag_err_count_relevant = tag_err_count_relevant }); + auto mem_trace_entry = MemoryTraceEntry({ .m_space_id = space_id, + .m_clk = m_clk, + .m_sub_clk = m_sub_clk, + .m_addr = m_addr, + .m_val = m_val, + .m_tag = m_tag, + .r_in_tag = r_in_tag, + .w_in_tag = w_in_tag, + .m_tag_err = true, + .m_one_min_inv = one_min_inv, + .m_tag_err_count_relevant = tag_err_count_relevant }); + debug_mem_trace_entry(mem_trace_entry); + mem_trace.emplace_back(mem_trace_entry); } /** @@ -224,7 +242,7 @@ AvmMemTraceBuilder::MemEntry AvmMemTraceBuilder::read_and_load_mov_opcode(uint8_ auto& mem_space = memory.at(space_id); MemEntry mem_entry = mem_space.contains(addr) ? mem_space.at(addr) : MemEntry{}; - mem_trace.emplace_back(MemoryTraceEntry{ + auto mem_trace_entry = MemoryTraceEntry({ .m_space_id = space_id, .m_clk = clk, .m_sub_clk = SUB_CLK_LOAD_A, @@ -235,6 +253,8 @@ AvmMemTraceBuilder::MemEntry AvmMemTraceBuilder::read_and_load_mov_opcode(uint8_ .w_in_tag = mem_entry.tag, .m_sel_mov_ia_to_ic = true, }); + debug_mem_trace_entry(mem_trace_entry); + mem_trace.emplace_back(mem_trace_entry); return mem_entry; } @@ -258,7 +278,7 @@ AvmMemTraceBuilder::MemEntry AvmMemTraceBuilder::read_and_load_jumpi_opcode(uint auto& mem_space = memory.at(space_id); MemEntry cond_mem_entry = mem_space.contains(cond_addr) ? mem_space.at(cond_addr) : MemEntry{}; - mem_trace.emplace_back(MemoryTraceEntry{ + auto mem_trace_entry = MemoryTraceEntry({ .m_space_id = space_id, .m_clk = clk, .m_sub_clk = SUB_CLK_LOAD_D, @@ -268,6 +288,8 @@ AvmMemTraceBuilder::MemEntry AvmMemTraceBuilder::read_and_load_jumpi_opcode(uint .r_in_tag = cond_mem_entry.tag, .w_in_tag = cond_mem_entry.tag, }); + debug_mem_trace_entry(mem_trace_entry); + mem_trace.emplace_back(mem_trace_entry); return cond_mem_entry; } @@ -295,7 +317,7 @@ AvmMemTraceBuilder::MemEntry AvmMemTraceBuilder::read_and_load_cast_opcode(uint8 auto& mem_space = memory.at(space_id); MemEntry mem_entry = mem_space.contains(addr) ? mem_space.at(addr) : MemEntry{}; - mem_trace.emplace_back(MemoryTraceEntry{ + auto mem_trace_entry = MemoryTraceEntry({ .m_space_id = space_id, .m_clk = clk, .m_sub_clk = SUB_CLK_LOAD_A, @@ -305,6 +327,8 @@ AvmMemTraceBuilder::MemEntry AvmMemTraceBuilder::read_and_load_cast_opcode(uint8 .r_in_tag = mem_entry.tag, .w_in_tag = w_in_tag, }); + debug_mem_trace_entry(mem_trace_entry); + mem_trace.emplace_back(mem_trace_entry); return mem_entry; } diff --git a/barretenberg/cpp/src/barretenberg/vm/avm/trace/mem_trace.hpp b/barretenberg/cpp/src/barretenberg/vm/avm/trace/mem_trace.hpp index 16424000a35..09f5fe63692 100644 --- a/barretenberg/cpp/src/barretenberg/vm/avm/trace/mem_trace.hpp +++ b/barretenberg/cpp/src/barretenberg/vm/avm/trace/mem_trace.hpp @@ -115,6 +115,8 @@ class AvmMemTraceBuilder { // Global Memory table (used for simulation): (space_id, (address, mem_entry)) std::array, NUM_MEM_SPACES> memory; + static void debug_mem_trace_entry(MemoryTraceEntry entry); + void insert_in_mem_trace(uint8_t space_id, uint32_t m_clk, uint32_t m_sub_clk, diff --git a/barretenberg/cpp/src/barretenberg/vm/avm/trace/trace.hpp b/barretenberg/cpp/src/barretenberg/vm/avm/trace/trace.hpp index c1095864326..715e5a22ead 100644 --- a/barretenberg/cpp/src/barretenberg/vm/avm/trace/trace.hpp +++ b/barretenberg/cpp/src/barretenberg/vm/avm/trace/trace.hpp @@ -35,7 +35,9 @@ class AvmTraceBuilder { uint32_t side_effect_counter = 0, std::vector calldata = {}); - uint32_t getPc() const { return pc; } + uint32_t get_pc() const { return pc; } + uint32_t get_l2_gas_left() const { return gas_trace_builder.get_l2_gas_left(); } + uint32_t get_da_gas_left() const { return gas_trace_builder.get_da_gas_left(); } // Compute - Arithmetic void op_add(uint8_t indirect, uint32_t a_offset, uint32_t b_offset, uint32_t dst_offset); diff --git a/yarn-project/simulator/src/avm/avm_simulator.ts b/yarn-project/simulator/src/avm/avm_simulator.ts index a6dd4c636a1..582912a91e6 100644 --- a/yarn-project/simulator/src/avm/avm_simulator.ts +++ b/yarn-project/simulator/src/avm/avm_simulator.ts @@ -85,6 +85,7 @@ export class AvmSimulator { try { // Execute instruction pointed to by the current program counter // continuing until the machine state signifies a halt + let instrCounter = 0; while (!machineState.getHalted()) { const instruction = instructions[machineState.pc]; assert( @@ -96,7 +97,9 @@ export class AvmSimulator { const instrPc = machineState.pc; // Save PC before executing instruction (for profiling) this.log.debug( - `@${machineState.pc} ${instruction.toString()} (l2=${machineState.l2GasLeft} da=${machineState.daGasLeft})`, + `[PC:${machineState.pc}] [IC:${instrCounter++}] ${instruction.toString()} (gasLeft l2=${ + machineState.l2GasLeft + } da=${machineState.daGasLeft})`, ); // Execute the instruction. // Normal returns and reverts will return normally here.