Introduce a verbose flag for debug output (#260)

This allows easier debugging of, e.g., custom bug detectors/hooks and can serve as an entry point for future debug features we do not want to have enabled by default. Co-authored-by: 0xricksanchez <christopher.krah@code-intelligence.com>
CodeIntelligenceTesting · Jan 10, 2023 · e57e514 · e57e514
1 parent 2250288
commit e57e514
Show file tree

Hide file tree

Showing 11 changed files with 414 additions and 102 deletions.
diff --git a/.github/workflows/run-all-tests.yaml b/.github/workflows/run-all-tests.yaml
@@ -1,4 +1,4 @@
-name: "\U0001F50D Tests"
+name: "🔍 Tests"
 on:
   pull_request:
     branches: [main]
@@ -38,9 +38,9 @@ jobs:
       - name: install dependencies (macos)
         if: contains(matrix.os, 'macos')
         run: |
-          brew install cmake llvm@11
-          LLVM_PATH=$(brew --prefix llvm@11)
-          LLVM_VERSION=11.1.0
+          brew install cmake llvm@14
+          LLVM_PATH=$(brew --prefix llvm@14)
+          LLVM_VERSION=14.0.6
           echo "SDKROOT=$(xcrun --sdk macosx --show-sdk-path)" >> $GITHUB_ENV
           echo "CPATH=$LLVM_PATH/lib/clang/$LLVM_VERSION/include/" >> $GITHUB_ENV
           echo "LDFLAGS=-L$LLVM_PATH/lib" >> $GITHUB_ENV

diff --git a/docs/fuzz-settings.md b/docs/fuzz-settings.md
@@ -100,7 +100,7 @@ level, custom hooks in Jazzer.js allow the user to
 To enable custom hooks in Jazzer.js, add either
 `-h <path_to_file_with_custom_hooks>.js` or
 `--custom_hooks <path_to_file_with_custom_hooks>.js` to the project
-configuration in package.json:
+configuration in `package.json`:
 
 ```json
 "scripts": {
@@ -182,3 +182,18 @@ The parameters of the `hookFn` are as follows:
 
 Several examples showcasing the custom hooks can be found
 [here](../examples/custom-hooks/custom-hooks.js).
+
+### Debugging hooks
+
+Debugging custom hooks can be tedious, hence the verbose logging option in
+Jazzer.js allows an insight into which hooks were applied, which hooking options
+are available in general, and which hooks could not be applied (e.g. due to the
+hooking point not being available). Check the section
+[Verbose logging](#verbose-logging) for information on how to enable this
+option.
+
+## Verbose logging
+
+To enable verbose logging in Jazzer.js, add either `-v`, or `--verbose` to the
+project configuration in the respective `package.json`. Currently, this only
+prints extra debug information on custom hooks (if provided).
diff --git a/examples/custom-hooks/custom-hooks.js b/examples/custom-hooks/custom-hooks.js
@@ -123,3 +123,14 @@ registerAfterHook(
 		);
 	}
 );
+
+/**
+ * An example of a hook that is not registered due to the target function being non-existent
+ */
+registerReplaceHook(
+	"JpegImage.jpegImage.constructor.prototype.parse.parse.NonExistingFunc",
+	"jpeg-js",
+	false,
+	// eslint-disable-next-line @typescript-eslint/no-empty-function
+	() => {}
+);
diff --git a/package-lock.json b/package-lock.json
diff --git a/packages/core/cli.ts b/packages/core/cli.ts
@@ -141,10 +141,21 @@ yargs(process.argv.slice(2))
 					group: "Fuzzer:",
 					default: [],
 				})
-				.hide("expected_errors");
+				.hide("expected_errors")
+				.boolean("verbose")
+				.option("verbose", {
+					describe: "Enable verbose debugging logs.",
+					type: "boolean",
+					alias: "v",
+					group: "Fuzzer:",
+					default: false,
+				});
 		},
 		// eslint-disable-next-line @typescript-eslint/no-explicit-any
 		(args: any) => {
+			if (args.verbose) {
+				process.env.JAZZER_DEBUG = "1";
+			}
 			// noinspection JSIgnoredPromiseFromCall
 			startFuzzing({
 				fuzzTarget: ensureFilepath(args.fuzzTarget),

diff --git a/packages/core/core.ts b/packages/core/core.ts
@@ -18,6 +18,7 @@ import path from "path";
 import * as fuzzer from "@jazzer.js/fuzzer";
 import * as hooking from "@jazzer.js/hooking";
 import { registerInstrumentor } from "@jazzer.js/instrumentor";
+import { trackedHooks } from "@jazzer.js/hooking";
 
 // libFuzzer uses exit code 77 in case of a crash, so use a similar one for
 // failed error expectations.
@@ -90,6 +91,10 @@ export async function startFuzzingNoInit(
 }
 
 function stopFuzzing(err: unknown, expectedErrors: string[]) {
+	if (process.env.JAZZER_DEBUG) {
+		trackedHooks.categorizeUnknown(HookManager.hooks).print();
+	}
+
 	// No error found, check if one is expected.
 	if (!err) {
 		if (expectedErrors.length) {

diff --git a/packages/fuzzer/.gitignore b/packages/fuzzer/.gitignore
@@ -1,3 +1,4 @@
+.cache
 build
 prebuilds
 cmake-build-debug
diff --git a/packages/hooking/hook.ts b/packages/hooking/hook.ts
@@ -16,6 +16,45 @@
 
 /*eslint @typescript-eslint/no-explicit-any: 0 */
 
+class hookTracker {
+	public applied: Set<string> = new Set();
+	public available: Set<string> = new Set();
+	public notApplied: Set<string> = new Set();
+
+	print() {
+		console.log("DEBUG: [Hook] Summary:");
+		console.log("DEBUG: [Hook]    Not applied:");
+		[...this.notApplied].sort().forEach((hook) => {
+			console.log(`DEBUG: [Hook]      ${hook}`);
+		});
+		console.log("DEBUG: [Hook]    Applied:");
+		[...this.applied].sort().forEach((hook) => {
+			console.log(`DEBUG: [Hook]      ${hook}`);
+		});
+		console.log("DEBUG: [Hook]    Available:");
+		[...this.available].sort().forEach((hook) => {
+			console.log(`DEBUG: [Hook]      ${hook}`);
+		});
+	}
+
+	categorizeUnknown(requestedHooks: Hook[]): this {
+		requestedHooks.forEach((hook) => {
+			if (!this.applied.has(hook.target) && !this.available.has(hook.target)) {
+				this.notApplied.add(hook.target);
+			}
+		});
+		return this;
+	}
+
+	clear() {
+		this.applied.clear();
+		this.notApplied.clear();
+		this.available.clear();
+	}
+}
+
+export const trackedHooks = new hookTracker();
+
 export enum HookType {
 	Before,
 	After,

diff --git a/packages/hooking/manager.ts b/packages/hooking/manager.ts
@@ -74,6 +74,10 @@ export class MatchingHooksResult {
 		}
 	}
 
+	hooks() {
+		return this.beforeHooks.concat(this.afterHooks, this.replaceHooks);
+	}
+
 	hasHooks() {
 		return (
 			this.hasBeforeHooks() || this.hasReplaceHooks() || this.hasAfterHooks()
@@ -94,28 +98,34 @@ export class MatchingHooksResult {
 }
 
 export class HookManager {
-	private hooks: Hook[] = [];
+	private _hooks: Hook[] = [];
 
 	registerHook(
 		hookType: HookType,
 		target: string,
 		pkg: string,
 		async: boolean,
 		hookFn: HookFn
-	) {
-		this.hooks.push(new Hook(hookType, target, pkg, async, hookFn));
+	): Hook {
+		const hook = new Hook(hookType, target, pkg, async, hookFn);
+		this._hooks.push(hook);
+		return hook;
+	}
+
+	get hooks() {
+		return this._hooks;
 	}
 
 	clearHooks() {
-		this.hooks = [];
+		this._hooks = [];
 	}
 
 	hookIndex(hook: Hook): number {
-		return this.hooks.indexOf(hook);
+		return this._hooks.indexOf(hook);
 	}
 
 	matchingHooks(target: string, filepath: string): MatchingHooksResult {
-		const matches = this.hooks
+		const matches = this._hooks
 			.filter((hook: Hook) => hook.match(filepath, target))
 			.reduce(
 				(matches: MatchingHooksResult, hook: Hook) => {
@@ -131,7 +141,9 @@ export class HookManager {
 	}
 
 	hasFunctionsToHook(filepath: string): boolean {
-		return this.hooks.find((hook) => filepath.includes(hook.pkg)) !== undefined;
+		return (
+			this._hooks.find((hook) => filepath.includes(hook.pkg)) !== undefined
+		);
 	}
 
 	callHook(
@@ -140,7 +152,7 @@ export class HookManager {
 		params: unknown[],
 		resultOrOriginalFunction: unknown
 	): unknown {
-		const hook = this.hooks[id];
+		const hook = this._hooks[id];
 		switch (hook.type) {
 			case HookType.Before:
 				(hook.hookFunction as BeforeHookFn)(thisPtr, params, this.callSiteId());