Debugging chrome extensions with system-level logging

I've been working on a Chrome extension lately that's getting closer to a public release. That shifts my workflow from blue sky design to the basement - fighting every last bug.

Extensions are basically mini web applications these days, just with access to a chrome global variable that can interact with some browser-level functionality. Aside from that - it's all familiar. That extends to the debugging experience. Since extensions run in the regular V8 Chrome runtime, Chrome exposes the same debugging tools that you're used to on the web: profiling, stack tracing, code mapping, etc.

Unlike a regular website, however, the potential edge cases of an extension are practically infinite. They need to tolerate the whole universe of pages where you're applying them. I've found one of the best ways to catch these edge cases and diagnose them after the fact is to capture verbose logging to disk. You can browse the web as you test your extension and then review the workflow session logs afterward. The Inspector console of the background process is fleeting and often crashes if your logging volume is too high.

Enabling Verbosity

Per the Chromium docs, you can add verbosity on application startup. This logic works on Chrome as well:

/Applications/Google Chrome.app/Contents/MacOS/Google Chrome --enable-logging --v=1

This logging file will be accessible during your run and after. It gets cleared the next time you launch Chrome with this logging command, however, so make sure to copy over what you need to a new file. You can inspect it (or pipe it) in realtime by running tail:

tail -f ~/Library/Application Support/Google/Chrome/chrome_debug.log

This should produce extension logs whether you're actively inspecting your service worker or just have it running in the background. From there you can open it in a log utility, duckdb, or just a simple grep.

grep "extension-error" ./chrome_debug.log

Logging Utility

This strategy is most useful if you log aggressively. If your logs aren't precise enough to pin down the bug, this approach loses much of the merit. I suggest a tunable logging class where your development builds will log every page URL, primary function call, expected value, etc. Your build pipeline can then clear these out before production.

Internally, we have a logging class a lot like this. It extends the default javascript console with a bit of syntax sugar to let flags determine whether messages actually make it to the console or are dropped.

The process.env variable default can be set by your build pipeline so you increase verbosity during development and scale it back for production. es-build makes this pretty easy.

export enum LOG_LEVELS {
    NONE = 0,
    ERROR = 1,
    WARN = 2,
    INFO = 3,
    DEBUG = 4,
}

const logToLevel = {
    NONE: LOG_LEVELS.NONE,
    ERROR: LOG_LEVELS.ERROR,
    WARN: LOG_LEVELS.WARN,
    INFO: LOG_LEVELS.INFO,
    DEBUG: LOG_LEVELS.DEBUG,
};

interface CustomConsole extends Console {
    logLevel?: string;
}

class CustomLogger {
    systemLogLevel: LOG_LEVELS;

    constructor() {
        const envDefault = process.env.PUBLIC_ENV_LOG_LEVEL! || 'INFO';
        let enumValue = logToLevel[envDefault as keyof typeof LOG_LEVELS];
        if (enumValue === undefined) {
            console.log(`Invalid log level ${envDefault}, defaulting to INFO`);
            enumValue = LOG_LEVELS.INFO;
        }

        this.systemLogLevel = enumValue;
    }

    setLogLevel(level: LOG_LEVELS) {
        this.systemLogLevel = level;
    }

    error(...args: any[]) {
        if (this.systemLogLevel >= LOG_LEVELS.ERROR) {
            console.error(...args);
        }
    }

    warn(...args: any[]) {
        if (this.systemLogLevel >= LOG_LEVELS.WARN) {
            console.warn(...args);
        }
    }

    info(...args: any[]) {
        if (this.systemLogLevel >= LOG_LEVELS.INFO) {
            console.info(...args);
        }
    }

    debug(...args: any[]) {
        if (this.systemLogLevel >= LOG_LEVELS.DEBUG) {
            console.log(...args);
        }
    }
}
export const defaultLogger = new CustomLogger();

Additional Notes

• Make sure to format any important console.log values as JSON strings instead of the raw objects themselves. When Chrome saves the logs to disk it will format everything as strings which means that your rich objects will be serialized to [object Object], which doesn't make for the easiest debugging.
• A heavy day of Chrome use will result in a log file of around 2GB. Maybe more maybe less depending on your logging verbosity. I periodically copy this over to another scratch location on disk so I don't lose any intermediate logs, but I haven't had an issue with data loss yet from the core logging file.