From a7282c18b8c597aac5cc416a809c28450bfd57c7 Mon Sep 17 00:00:00 2001 From: Moritz Date: Fri, 1 Mar 2024 11:59:09 +0100 Subject: [PATCH 1/9] Add `InstructionTracer.js` helper --- tests/zkasm/helpers/InstructionTracer.js | 41 ++++++++++++++++++++++++ 1 file changed, 41 insertions(+) create mode 100644 tests/zkasm/helpers/InstructionTracer.js diff --git a/tests/zkasm/helpers/InstructionTracer.js b/tests/zkasm/helpers/InstructionTracer.js new file mode 100644 index 000000000000..e41155b305a7 --- /dev/null +++ b/tests/zkasm/helpers/InstructionTracer.js @@ -0,0 +1,41 @@ +const fs = require("fs"); + +/** + * Handles the generation of traces of instructions executed at runtime. + */ +class InstructionTracer { + constructor() { + // Contains executed instructions in order of execution. + this.rawTrace = []; + } + + /** + * @param {Object} ctx - The context passed by `zkevm-proverjs` to helper calls + * @param {Object} tag - Helper call specific information passed by `zkevm-proverjs` + * @param {Object} tag.params[0] - expects the identifier as first parameter of + * `$${instrumentInst(...)}` + * + * @example + * // To trace the execution of an `AluRRR` instruction, call + * // $${instrumentInst(AluRRR)} + */ + eval_traceInstruction(ctx, tag) { + const instruction = tag.params[0].varName; + this.rawTrace.push(instruction); + } + + /** + * Writes the raw trace to `path`. + * + * @param {string} path + */ + writeRawTrace(path) { + if (typeof path !== "string") { + // Writing to a descriptor will append instead of replace content, + // which might result in invalid traces, see + // https://nodejs.org/api/fs.html#using-fswritefile-with-file-descriptors + throw new Error("provide a file name (not descriptor) to write to"); + } + fs.writeFileSync(path, this.rawTrace.join("\n")); + } +} From df1b4b1955754e0b2054a09389ed54e4c6a3fa74 Mon Sep 17 00:00:00 2001 From: Moritz Date: Fri, 1 Mar 2024 12:03:28 +0100 Subject: [PATCH 2/9] Add `Inst::print_name` --- cranelift/codegen/src/isa/zkasm/inst/mod.rs | 61 +++++++++++++++++++++ 1 file changed, 61 insertions(+) diff --git a/cranelift/codegen/src/isa/zkasm/inst/mod.rs b/cranelift/codegen/src/isa/zkasm/inst/mod.rs index 6a2e4e8ce82e..920c5bb9a5b0 100644 --- a/cranelift/codegen/src/isa/zkasm/inst/mod.rs +++ b/cranelift/codegen/src/isa/zkasm/inst/mod.rs @@ -752,6 +752,8 @@ pub fn reg_name(reg: Reg) -> String { } impl Inst { + // TODO(#218): remove Risc-V info from `print_with_state` + // TODO(#217): print consistent names by reusing `print_name` fn print_with_state( &self, _state: &mut EmitState, @@ -1258,6 +1260,65 @@ impl Inst { &Inst::ECall {} => String::from("ecall"), } } + + /// Prints the enum variant identifier. + fn print_name(&self) -> String { + let name = match self { + &Inst::Nop => "Nop", + &Inst::Label { .. } => "Label", + &Inst::LoadConst32 { .. } => "LoadConst32", + &Inst::LoadConst64 { .. } => "LoadConst64", + &Inst::AluRRR { .. } => "AluRRR", + &Inst::MulArith { .. } => "MulArith", + &Inst::Shl64 { .. } => "Shl64", + &Inst::Shru64 { .. } => "Shru64", + &Inst::DivArith { .. } => "DivArith", + &Inst::UDivArith { .. } => "UDivArith", + &Inst::RemArith { .. } => "RemArith", + &Inst::URemArith { .. } => "URemArith", + &Inst::Ineg { .. } => "Ineg", + &Inst::Bnot { .. } => "Bnot", + &Inst::Load { .. } => "Load", + &Inst::Store { .. } => "Store", + &Inst::Args { .. } => "Args", + &Inst::Ret { .. } => "Ret", + &Inst::Extend { .. } => "Extend", + &Inst::ReserveSp { .. } => "ReserveSp", + &Inst::ReleaseSp { .. } => "ReleaseSp", + &Inst::Call { .. } => "Call", + &Inst::CallInd { .. } => "CallInd", + &Inst::ReturnCall { .. } => "ReturnCall", + &Inst::ReturnCallInd { .. } => "ReturnCallInd", + &Inst::TrapIf { .. } => "TrapIf", + &Inst::TrapIfC { .. } => "TrapIfC", + &Inst::Jal { .. } => "Jal", + &Inst::CondBr { .. } => "CondBr", + &Inst::LoadExtName { .. } => "LoadExtName", + &Inst::LoadAddr { .. } => "LoadAddr", + &Inst::VirtualSPOffsetAdj { .. } => "VirtualSPOffsetAdj", + &Inst::Mov { .. } => "Mov", + &Inst::MovFromPReg { .. } => "MovFromPReg", + &Inst::ECall => "ECall", + &Inst::EBreak => "EBreak", + &Inst::Udf { .. } => "Udf", + &Inst::Jalr { .. } => "Jalr", + &Inst::Select { .. } => "Select", + &Inst::BrTable { .. } => "BrTable", + &Inst::IntSelect { .. } => "IntSelect", + &Inst::Icmp { .. } => "Icmp", + &Inst::SelectReg { .. } => "SelectReg", + &Inst::RawData { .. } => "RawData", + &Inst::Unwind { .. } => "Unwind", + &Inst::DummyUse { .. } => "DummyUse", + &Inst::Popcnt { .. } => "Popcnt", + &Inst::Cltz { .. } => "Cltz", + &Inst::Rev8 { .. } => "Rev8", + &Inst::Brev8 { .. } => "Brev8", + &Inst::StackProbeLoop { .. } => "StackProbeLoop", + &Inst::AddImm32 { .. } => "AddImm32", + }; + String::from(name) + } } /// Different forms of label references for different instruction formats. From b8edf591d59c8cba96bad2fddc229790c402e5b4 Mon Sep 17 00:00:00 2001 From: Moritz Date: Fri, 1 Mar 2024 12:13:14 +0100 Subject: [PATCH 3/9] Emit call to `InstructionTracer.js` from zkASM --- cranelift/codegen/src/isa/zkasm/inst/emit.rs | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/cranelift/codegen/src/isa/zkasm/inst/emit.rs b/cranelift/codegen/src/isa/zkasm/inst/emit.rs index 156bcd6d4b73..97257511e1ea 100644 --- a/cranelift/codegen/src/isa/zkasm/inst/emit.rs +++ b/cranelift/codegen/src/isa/zkasm/inst/emit.rs @@ -369,13 +369,16 @@ impl Inst { } /// Emits zkASM to trace executed instructions. + /// + /// Calls a method implemented by the `InstructionTracer.js` helper. An instance of this helper + /// must be provided to `zkevm-proverjs` for the successful execution of the generated zkASM. fn emit_inst_instrumentation(&self, sink: &mut MachBuffer) { match self { // Labels are handled separately since benchmarking will provide a separate command to // analyze labels. &MInst::Label { .. } => {} _ => put_string( - ";; TODO(mooori) call the helper to trace `MInst` execution\n", + &format!("$${{traceInstruction({})}}\n", self.print_name()), sink, ), } From eb48eada02496418fabe4cbc373eee82dac8afc3 Mon Sep 17 00:00:00 2001 From: Moritz Date: Fri, 1 Mar 2024 12:16:23 +0100 Subject: [PATCH 4/9] Update expected `simple_instrumented.zkasm` --- .../testfiles/simple_instrumented.zkasm | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/cranelift/zkasm_data/analyze-zkasm/testfiles/simple_instrumented.zkasm b/cranelift/zkasm_data/analyze-zkasm/testfiles/simple_instrumented.zkasm index c014ca1d4e86..ff3a82ec1f5e 100644 --- a/cranelift/zkasm_data/analyze-zkasm/testfiles/simple_instrumented.zkasm +++ b/cranelift/zkasm_data/analyze-zkasm/testfiles/simple_instrumented.zkasm @@ -4,16 +4,16 @@ start: :JMP(function_0) :JMP(finalizeExecution) function_0: - ;; TODO(mooori) call the helper to trace `MInst` execution + $${traceInstruction(ReserveSp)} SP - 1 => SP - ;; TODO(mooori) call the helper to trace `MInst` execution + $${traceInstruction(Store)} RR :MSTORE(SP) - ;; TODO(mooori) call the helper to trace `MInst` execution - ;; TODO(mooori) call the helper to trace `MInst` execution + $${traceInstruction(Jal)} + $${traceInstruction(Load)} $ => RR :MLOAD(SP) - ;; TODO(mooori) call the helper to trace `MInst` execution + $${traceInstruction(ReleaseSp)} SP + 1 => SP - ;; TODO(mooori) call the helper to trace `MInst` execution + $${traceInstruction(Ret)} :JMP(RR) finalizeExecution: ${beforeLast()} :JMPN(finalizeExecution) From 7ecf5664198014e4d4b6bb5b4d1e9f4ca1368ae0 Mon Sep 17 00:00:00 2001 From: Moritz Date: Tue, 5 Mar 2024 12:46:20 +0100 Subject: [PATCH 5/9] Add `profile-instructions` command to JS runner --- tests/zkasm/run-tests-zkasm.js | 43 ++++++++++++++++++++++++---------- 1 file changed, 30 insertions(+), 13 deletions(-) diff --git a/tests/zkasm/run-tests-zkasm.js b/tests/zkasm/run-tests-zkasm.js index ebbc49cbb3a2..ebe86b283261 100644 --- a/tests/zkasm/run-tests-zkasm.js +++ b/tests/zkasm/run-tests-zkasm.js @@ -35,21 +35,38 @@ function value_to_json(key, value) { * Run this script with `--help` to print docs. */ async function main() { - const argv = require("yargs/yargs")(process.argv.slice(2)) - .command("$0 [outfile]", "the default command runs zkASM tests", (yargs) => { - yargs.positional("path", { - describe: "The zkASM file to run or a directory to search for zkASM files.", - type: "string" - }) - yargs.positional("outfile", { - describe: "If provided, results are written to this file. Otherwise they are printed to stdout.", - type: "string" - }) + require("yargs/yargs")(process.argv.slice(2)) + .command({ + command: "$0 [outfile]", + desc: "the default command runs zkASM tests", + builder: (yargs) => { + yargs.positional("path", { + describe: "The zkASM file to run or a directory to search for zkASM files.", + type: "string" + }) + yargs.positional("outfile", { + describe: "If provided, results are written to this file. Otherwise they are printed to stdout.", + type: "string" + }) + }, + handler: (argv) => runTestsCmd(argv.path, argv.outfile) + }) + .command({ + command: "profile-instructions [outfile]", + desc: "profiles instructions executed at runtime, assuming zkASM was instrumented", + builder: (yargs) => { + yargs.positional("path", { + describe: "The instrumented zkASM file to execute.", + type: "string" + }) + yargs.positional("outfile", { + describe: "If provided, results are written to this file. Otherwise they are printed to stdout.", + type: "string" + }) + }, + handler: (argv) => console.log(`running profile-instructions with ${argv.path} ${argv.outfile}`) }) .parse(); - - // Run the default command. - runTestsCmd(argv.path, argv.outfile); } /** From d9b9530b579a913d72b75b2f13e0fd808a633e8c Mon Sep 17 00:00:00 2001 From: Moritz Date: Wed, 6 Mar 2024 12:07:03 +0100 Subject: [PATCH 6/9] Add missing export and `setup()` to `InstructionTracer.js` --- tests/zkasm/helpers/InstructionTracer.js | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/tests/zkasm/helpers/InstructionTracer.js b/tests/zkasm/helpers/InstructionTracer.js index e41155b305a7..a302030baad5 100644 --- a/tests/zkasm/helpers/InstructionTracer.js +++ b/tests/zkasm/helpers/InstructionTracer.js @@ -9,6 +9,10 @@ class InstructionTracer { this.rawTrace = []; } + setup() { + // `zkevm-proverjs` requires a `setup` function on helper objects. + } + /** * @param {Object} ctx - The context passed by `zkevm-proverjs` to helper calls * @param {Object} tag - Helper call specific information passed by `zkevm-proverjs` @@ -39,3 +43,5 @@ class InstructionTracer { fs.writeFileSync(path, this.rawTrace.join("\n")); } } + +module.exports = InstructionTracer; From bbb6383015fb43f3cf928d1700b6c7a2747b4441 Mon Sep 17 00:00:00 2001 From: Moritz Date: Wed, 6 Mar 2024 12:25:19 +0100 Subject: [PATCH 7/9] Add function exec zkASM and generate trace --- tests/zkasm/run-tests-zkasm.js | 50 +++++++++++++++++++++++++++++++++- 1 file changed, 49 insertions(+), 1 deletion(-) diff --git a/tests/zkasm/run-tests-zkasm.js b/tests/zkasm/run-tests-zkasm.js index ebe86b283261..c3898b48243e 100644 --- a/tests/zkasm/run-tests-zkasm.js +++ b/tests/zkasm/run-tests-zkasm.js @@ -11,6 +11,7 @@ const { } = require('pilcom'); const buildPoseidon = require('@0xpolygonhermez/zkevm-commonjs').getPoseidon; const AssertHelper = require('./assert_helper'); +const InstructionTracer = require('./helpers/InstructionTracer'); const emptyInput = require('@0xpolygonhermez/zkevm-proverjs/test/inputs/empty_input.json'); @@ -64,7 +65,7 @@ async function main() { type: "string" }) }, - handler: (argv) => console.log(`running profile-instructions with ${argv.path} ${argv.outfile}`) + handler: (argv) => profileInstructions(argv.path, argv.outfile) }) .parse(); } @@ -193,4 +194,51 @@ async function runTest(pathTest, cmPols) { } } +/** + * Executes a zkASM file instrumented for instruction tracing and produces the + * trace of executed instructions. + * + * @param {string} zkasmFile - Path to the zkASM file. + * @param {string} [outfile] - Path to a file where output is written. If not + * given, the trace is written to `stdout`. + */ +async function profileInstructions(zkasmFile, outfile) { + const configZkasm = { + defines: [], + allowUndefinedLabels: true, + allowOverwriteLabels: true, + }; + + // Construct helper classes. + const instructionTracer = new InstructionTracer(); + + // Compile rom. + const config = { + debug: true, + stepsN: 8388608, + assertOutputs: false, + helpers: [ + instructionTracer + ] + }; + const cmPols = await compilePil(); + const rom = await zkasm.compile(zkasmFile, null, configZkasm); + + const result = await smMain.execute(cmPols.Main, emptyInput, rom, config); + + console.log("Execution finished"); + if (result.output) { + console.log(`Output: ${result.output}`) + } + if (result.logs && Object.keys(result.logs).length > 0) { + console.log(result.logs); + } + + if (outfile) { + instructionTracer.writeRawTrace(outfile); + } else { + console.log(instructionTracer.rawTrace); + } +} + main(); From 6ed99c1fbc1d2b062be6f38a0c902dc8ad27fbe2 Mon Sep 17 00:00:00 2001 From: Moritz Date: Thu, 7 Mar 2024 18:29:19 +0100 Subject: [PATCH 8/9] Write raw trace in batches --- tests/zkasm/helpers/InstructionTracer.js | 6 +++++- tests/zkasm/helpers/data-dump.js | 25 ++++++++++++++++++++++++ 2 files changed, 30 insertions(+), 1 deletion(-) create mode 100644 tests/zkasm/helpers/data-dump.js diff --git a/tests/zkasm/helpers/InstructionTracer.js b/tests/zkasm/helpers/InstructionTracer.js index a302030baad5..79f926e7abab 100644 --- a/tests/zkasm/helpers/InstructionTracer.js +++ b/tests/zkasm/helpers/InstructionTracer.js @@ -1,5 +1,7 @@ const fs = require("fs"); +const dataDump = require("./data-dump"); + /** * Handles the generation of traces of instructions executed at runtime. */ @@ -40,7 +42,9 @@ class InstructionTracer { // https://nodejs.org/api/fs.html#using-fswritefile-with-file-descriptors throw new Error("provide a file name (not descriptor) to write to"); } - fs.writeFileSync(path, this.rawTrace.join("\n")); + // Writing in batches of 1000 instructions to limit memory usage, + // as raw traces might grow big. + dataDump.writeToFileInBatches(this.rawTrace, path, 1000); } } diff --git a/tests/zkasm/helpers/data-dump.js b/tests/zkasm/helpers/data-dump.js new file mode 100644 index 000000000000..3600c4f1d9fd --- /dev/null +++ b/tests/zkasm/helpers/data-dump.js @@ -0,0 +1,25 @@ +const fs = require('fs'); + +/** + * Writes `lines` to a file in batches to limit memory usage. + * + * @param {string[]} lines - each string in the array is written on its own line + * @param {string} filePath + * @param {number} batchSize + */ +function writeToFileInBatches(lines, filePath, batchSize) { + // If the file already exists, clear it by writing empty string. + if (fs.existsSync(filePath)) { + fs.writeFileSync(filePath, "", "utf-8"); + } + + // Append batches to the file (will be created if it doesn't exist). + for (let i = 0; i < lines.length; i += batchSize) { + let batchedLines = lines.slice(i, i + batchSize).join("\n") + "\n"; + fs.appendFileSync(filePath, batchedLines, "utf-8"); + } +} + +module.exports = { + writeToFileInBatches +} From af25607dbbde078c1279b2d134beed5028016a7b Mon Sep 17 00:00:00 2001 From: Moritz Date: Thu, 7 Mar 2024 18:42:04 +0100 Subject: [PATCH 9/9] Rename `batch -> chunk` --- tests/zkasm/helpers/InstructionTracer.js | 4 ++-- tests/zkasm/helpers/data-dump.js | 16 ++++++++-------- 2 files changed, 10 insertions(+), 10 deletions(-) diff --git a/tests/zkasm/helpers/InstructionTracer.js b/tests/zkasm/helpers/InstructionTracer.js index 79f926e7abab..22d8a3fde5e0 100644 --- a/tests/zkasm/helpers/InstructionTracer.js +++ b/tests/zkasm/helpers/InstructionTracer.js @@ -42,9 +42,9 @@ class InstructionTracer { // https://nodejs.org/api/fs.html#using-fswritefile-with-file-descriptors throw new Error("provide a file name (not descriptor) to write to"); } - // Writing in batches of 1000 instructions to limit memory usage, + // Writing in chunks of 1000 instructions to limit memory usage, // as raw traces might grow big. - dataDump.writeToFileInBatches(this.rawTrace, path, 1000); + dataDump.writeToFileInChunks(this.rawTrace, path, 1000); } } diff --git a/tests/zkasm/helpers/data-dump.js b/tests/zkasm/helpers/data-dump.js index 3600c4f1d9fd..632757837241 100644 --- a/tests/zkasm/helpers/data-dump.js +++ b/tests/zkasm/helpers/data-dump.js @@ -1,25 +1,25 @@ const fs = require('fs'); /** - * Writes `lines` to a file in batches to limit memory usage. + * Writes `lines` to a file in chunks to limit memory usage. * * @param {string[]} lines - each string in the array is written on its own line * @param {string} filePath - * @param {number} batchSize + * @param {number} chunkSize */ -function writeToFileInBatches(lines, filePath, batchSize) { +function writeToFileInChunks(lines, filePath, chunkSize) { // If the file already exists, clear it by writing empty string. if (fs.existsSync(filePath)) { fs.writeFileSync(filePath, "", "utf-8"); } - // Append batches to the file (will be created if it doesn't exist). - for (let i = 0; i < lines.length; i += batchSize) { - let batchedLines = lines.slice(i, i + batchSize).join("\n") + "\n"; - fs.appendFileSync(filePath, batchedLines, "utf-8"); + // Append chunks to the file (will be created if it doesn't exist). + for (let i = 0; i < lines.length; i += chunkSize) { + let linesToWrite = lines.slice(i, i + chunkSize).join("\n") + "\n"; + fs.appendFileSync(filePath, linesToWrite, "utf-8"); } } module.exports = { - writeToFileInBatches + writeToFileInChunks }