feat: log stack trace when AS crash due to assert (#54)

Author: HerrCai0907

instrumentation/CoverageInstru.cpp

@@ -1,4 +1,7 @@
 #include "CoverageInstru.hpp"
+#include <binaryen-c.h>
+#include <fstream>
+#include <ostream>
 namespace wasmInstrumentation {
 
 void CoverageInstru::innerAnalysis(BasicBlockAnalysis &basicBlockAnalysis) const noexcept {
@@ -30,16 +33,14 @@ void CoverageInstru::innerAnalysis(BasicBlockAnalysis &basicBlockAnalysis) const
 
 InstrumentationResponse CoverageInstru::instrument() const noexcept {
   if (config->fileName.empty() || config->reportFunction.empty() || config->sourceMap.empty() ||
-      config->targetName.empty() || config->expectInfoOutputFilePath.empty()
-      ) {
+      config->targetName.empty() || config->expectInfoOutputFilePath.empty()) {
     std::cout << *config << std::endl;
     return InstrumentationResponse::CONFIG_ERROR; // config error
   }
-  std::filesystem::path filePath(config->fileName);
-  std::filesystem::path targetFilePath(config->targetName);
-  std::filesystem::path sourceMapPath(config->sourceMap);
-  if ((!std::filesystem::exists(filePath)) ||
-      (!std::filesystem::exists(sourceMapPath)) ||
+  const std::filesystem::path filePath(config->fileName);
+  const std::filesystem::path targetFilePath(config->targetName);
+  const std::filesystem::path sourceMapPath(config->sourceMap);
+  if ((!std::filesystem::exists(filePath)) || (!std::filesystem::exists(sourceMapPath)) ||
       (!std::filesystem::exists(targetFilePath.parent_path()))) {
     std::cout << *config << std::endl;
     return InstrumentationResponse::CONFIG_FILEPATH_ERROR; // config file path error
@@ -127,12 +128,15 @@ InstrumentationResponse CoverageInstru::instrument() const noexcept {
   MockInstrumentationWalker mockWalker(&module);
   mockWalker.mockWalk();
 
+  const std::string targetSourceMapPath = std::string{this->config->targetName} + ".map";
+  BinaryenSetDebugInfo(true);
   const BinaryenModuleAllocateAndWriteResult result =
-      BinaryenModuleAllocateAndWrite(&module, nullptr);
+      BinaryenModuleAllocateAndWrite(&module, targetSourceMapPath.c_str());
   std::ofstream wasmFileStream(this->config->targetName.data(), std::ios::trunc | std::ios::binary);
   wasmFileStream.write(static_cast<char *>(result.binary),
                        static_cast<std::streamsize>(result.binaryBytes));
-  wasmFileStream.close();
+  std::ofstream sourceMapFileStream(targetSourceMapPath, std::ios::trunc | std::ios::binary);
+  sourceMapFileStream << result.sourceMap << std::flush;
   free(result.binary);
   free(result.sourceMap);
   if (wasmFileStream.fail() || wasmFileStream.bad()) {

package-lock.json

@@ -36,6 +36,7 @@
     "glob": "^11.0.0",
     "ignore": "^7.0.3",
     "semver": "^7.5.3",
+    "source-map": "^0.7.4",
     "wasmparser": "5.11.1"
   },
   "peerDependencies": {

package.json

@@ -2,14 +2,15 @@ import { WASI } from "node:wasi";
 import { promises } from "node:fs";
 import { ensureDirSync } from "fs-extra";
 import { instantiate, Imports as ASImports } from "@assemblyscript/loader";
-import { ExecutionResult } from "../executionResult.js";
+import { ExecutionResultSummary } from "../executionResult.js";
 import { Imports, ImportsArgument, InstrumentResult } from "../interface.js";
 import { mockInstrumentFunc } from "../utils/import.js";
 import { supplyDefaultFunction } from "../utils/index.js";
 import { parseImportFunctionInfo } from "../utils/wasmparser.js";
-import { ExecutionRecorder, SingleExecutionResult } from "./executionRecorder.js";
+import { ExecutionRecorder, ExecutionResult } from "./executionRecorder.js";
 import { CoverageRecorder } from "./covRecorder.js";
 import assert from "node:assert";
+import { ExecutionError, handleWebAssemblyError } from "../utils/errorTraceHandler.js";
 
 const readFile = promises.readFile;
 
@@ -18,7 +19,7 @@ async function nodeExecutor(
   outFolder: string,
   matchedTestNames: string[],
   imports?: Imports
-): Promise<SingleExecutionResult> {
+): Promise<ExecutionResult> {
   const wasi = new WASI({
     args: ["node", instrumentResult.baseName],
     env: process.env,
@@ -48,36 +49,51 @@ async function nodeExecutor(
   importsArg.module = ins.module;
   importsArg.instance = ins.instance;
   importsArg.exports = ins.exports;
+
+  let isCrashed = false; // we don't want to crash any code after crash. AS' heap may be broken.
+
+  const exceptionHandler = async (error: unknown) => {
+    if (error instanceof WebAssembly.RuntimeError) {
+      isCrashed = true;
+      const errorMessage: ExecutionError = await handleWebAssemblyError(error, instrumentResult.instrumentedWasm);
+      executionRecorder.notifyTestCrash(errorMessage);
+      return;
+    }
+    // unrecoverable error, rethrow
+    if (error instanceof Error) {
+      console.error(error.stack);
+    }
+    throw new Error("node executor abort");
+  };
+
   try {
+    executionRecorder.startTestFunction(`${instrumentResult.baseName} - init`);
     wasi.start(ins);
-    const execTestFunction = ins.exports["executeTestFunction"];
-    assert(typeof execTestFunction === "function");
-    if (matchedTestNames.length === 0) {
-      // By default, all testcases are executed
-      for (const functionInfo of executionRecorder.registerFunctions) {
-        const [testCaseName, functionIndex] = functionInfo;
-        executionRecorder.startTestFunction(testCaseName);
+  } catch (error) {
+    await exceptionHandler(error);
+  }
+  executionRecorder.finishTestFunction();
+
+  const execTestFunction = ins.exports["executeTestFunction"];
+  assert(typeof execTestFunction === "function");
+
+  for (const functionInfo of executionRecorder.registerFunctions) {
+    if (isCrashed) {
+      break;
+    }
+    const [testCaseName, functionIndex] = functionInfo;
+    if (matchedTestNames.length === 0 || matchedTestNames.includes(testCaseName)) {
+      executionRecorder.startTestFunction(testCaseName);
+      try {
         (execTestFunction as (a: number) => void)(functionIndex);
-        executionRecorder.finishTestFunction();
-        mockInstrumentFunc["mockFunctionStatus.clear"]();
+      } catch (error) {
+        await exceptionHandler(error);
       }
-    } else {
-      for (const functionInfo of executionRecorder.registerFunctions) {
-        const [testCaseName, functionIndex] = functionInfo;
-        if (matchedTestNames.includes(testCaseName)) {
-          executionRecorder.startTestFunction(testCaseName);
-          (execTestFunction as (a: number) => void)(functionIndex);
-          executionRecorder.finishTestFunction();
-          mockInstrumentFunc["mockFunctionStatus.clear"]();
-        }
-      }
-    }
-  } catch (error) {
-    if (error instanceof Error) {
-      console.error(error.stack);
+      executionRecorder.finishTestFunction();
+      mockInstrumentFunc["mockFunctionStatus.clear"]();
     }
-    throw new Error("node executor abort.");
   }
+
   coverageRecorder.outputTrace(instrumentResult.traceFile);
   return executionRecorder.result;
 }
@@ -87,12 +103,12 @@ export async function execWasmBinaries(
   instrumentResults: InstrumentResult[],
   matchedTestNames: string[],
   imports?: Imports
-): Promise<ExecutionResult> {
-  const assertRes = new ExecutionResult();
+): Promise<ExecutionResultSummary> {
+  const assertRes = new ExecutionResultSummary();
   ensureDirSync(outFolder);
   await Promise.all<void>(
     instrumentResults.map(async (instrumentResult): Promise<void> => {
-      const result: SingleExecutionResult = await nodeExecutor(instrumentResult, outFolder, matchedTestNames, imports);
+      const result: ExecutionResult = await nodeExecutor(instrumentResult, outFolder, matchedTestNames, imports);
       await assertRes.merge(result, instrumentResult.expectInfo);
     })
   );

src/core/execute.ts

@@ -1,11 +1,14 @@
+import chalk from "chalk";
 import {
   UnitTestFramework,
   ImportsArgument,
   AssertFailMessage,
   AssertMessage,
-  IAssertResult,
+  IExecutionResult,
   FailedLogMessages,
+  CrashInfo,
 } from "../interface.js";
+import { ExecutionError } from "../utils/errorTraceHandler.js";
 
 class LogRecorder {
   #currentTestLogMessages: string[] = [];
@@ -18,7 +21,7 @@ class LogRecorder {
     this.#isTestFailed = true;
   }
 
-  onStartTest(): void {
+  reset(): void {
     this.#currentTestLogMessages = [];
     this.#isTestFailed = false;
   }
@@ -33,16 +36,16 @@ class LogRecorder {
   }
 }
 
-export class SingleExecutionResult implements IAssertResult {
+export class ExecutionResult implements IExecutionResult {
   total: number = 0;
   fail: number = 0;
   failedInfo: AssertFailMessage = {};
+  crashInfo: CrashInfo = new Set();
   failedLogMessages: FailedLogMessages = {};
 }
 
-// to do: split execution environment and recorder
 export class ExecutionRecorder implements UnitTestFramework {
-  result = new SingleExecutionResult();
+  result = new ExecutionResult();
 
   registerFunctions: [string, number][] = [];
   #currentTestDescriptions: string[] = [];
@@ -63,9 +66,10 @@ export class ExecutionRecorder implements UnitTestFramework {
     const testCaseFullName = this.#currentTestDescriptions.join(" ");
     this.registerFunctions.push([testCaseFullName, fncIndex]);
   }
+
   startTestFunction(testCaseFullName: string): void {
     this.#testCaseFullName = testCaseFullName;
-    this.logRecorder.onStartTest();
+    this.logRecorder.reset();
   }
   finishTestFunction(): void {
     const logMessages: string[] | null = this.logRecorder.onFinishTest();
@@ -76,11 +80,22 @@ export class ExecutionRecorder implements UnitTestFramework {
     }
   }
 
+  notifyTestCrash(error: ExecutionError): void {
+    this.logRecorder.addLog(`Reason: ${chalk.red(error.message)}`);
+    this.logRecorder.addLog(
+      error.stacks
+        .map((stack) => `  at ${stack.functionName} (${stack.fileName}:${stack.lineNumber}:${stack.columnNumber})`)
+        .join("\n")
+    );
+    this.result.crashInfo.add(this.#testCaseFullName);
+    this.result.total++; // fake test cases
+    this.#increaseFailureCount();
+  }
+
   collectCheckResult(result: boolean, codeInfoIndex: number, actualValue: string, expectValue: string): void {
     this.result.total++;
     if (!result) {
-      this.logRecorder.markTestFailed();
-      this.result.fail++;
+      this.#increaseFailureCount();
       const testCaseFullName = this.#testCaseFullName;
       const assertMessage: AssertMessage = [codeInfoIndex.toString(), actualValue, expectValue];
       this.result.failedInfo[testCaseFullName] = this.result.failedInfo[testCaseFullName] || [];
@@ -115,4 +130,9 @@ export class ExecutionRecorder implements UnitTestFramework {
       },
     };
   }
+
+  #increaseFailureCount(): void {
+    this.result.fail++;
+    this.logRecorder.markTestFailed();
+  }
 }