Better support for asyncLocalStorage(request context)

[deanbiltup]

We can filter logs by request id in GCP like so (or email, or client id, or click id or etc. etc.) when developers simply do logs like

logger.info(processing ${type} url=${url} Admin=${proxyEmail} request=${JSON.stringify(req.body)});

and we end up with just the few logs for the request. Notice just 4 logs show up in this picture filtered by jsonPayload.url in this case instead of jsonPayload.requestId

Unfortunately, we tried doing it streams but it needs to be done before we log to console or log to google (TWO different streams, one for development and one for GCP). BOTH streams we want to have these values. In GCP, we log all the context and in dev, we log around 4 of the important ones.

export class CustomLogger extends Logger {

    constructor(
        private logger: Logger
    ) {
        super({
            name: "super-unused"
        });
    }

    addStream(stream: Logger.Stream): void {
        super.addStream(stream);
    }
    addSerializers(serializers: Logger.Serializers): void {
        throw new Error("unused");
    }
    child(options: Object, simple?: boolean): Logger {
        const child = this.logger.child(options, simple);
        const wrapper = new CustomLogger(child);
        return wrapper;
    }

    reopenFileStreams(): void {
        throw new Error("unused");
    }

    level(): number;
    level(value: Logger.LogLevel): void;

    // Single implementation
    level(value?: Logger.LogLevel): number | void {
        if (value === undefined) {
            return this.level();
        } else {
            this.level(value);
        }
    }
    levels(): number[];
    levels(name: number | string): number;
    levels(name: number | string, value: Logger.LogLevel): void;

    // Single implementation
    levels(name?: number | string, value?: Logger.LogLevel): number[] | number | void {
        if (name === undefined) {
            return this.logger.levels();
        } else if (value === undefined) {
            return this.logger.levels(name);
        } else {
            this.logger.levels(name, value);
        }
    }

// Helper method to create context
    private createContext(...args: any[]): { context: Object; restArgs: any[] } {
        const [firstArg, ...restArgs] = args;
        let context: Object;

        if (firstArg instanceof Error) {
            context = { err: {
                    name: firstArg.name,
                    message: firstArg.message,
                    stack: firstArg.stack
                }
            };
        } else if (typeof firstArg === 'object' && firstArg !== null) {
            context = firstArg;
        } else {
            context = {};
            restArgs.unshift(firstArg);
        }

        let enrichedContext = context;

        const store = asyncLocalStorage.getStore();

        if (store) {
            const traceId = store.get('traceId');
            const txId = store.get('txId');
            const method = store.get('method');
            const url = store.get('url');
            const email = store.get('email');
            const proxyAdminEmail = store.get('proxyEmail');
            const remoteAddr = store.get('remoteAddr');
            const clientId = store.get('clientId');
            const clickId = store.get('clickId');
            const clientVersion = store.get('clientVersion');
            const serverVersion = store.get('serverVersion');
            const userDbId = store.get('userDbId');
            const proxyAdminId = store.get('proxyAdminId');
            const roles = store.get('roles');

            enrichedContext = {
                ...enrichedContext,
                ...(traceId ? { traceId } : {}),
                ...(txId ? { txId } : {}),
                ...(method ? { method } : {}),
                ...(url ? { url } : {}),
                ...(remoteAddr ? { remoteAddr } : {}),
                ...(email ? { email } : {}),
                ...(proxyAdminEmail ? { proxyAdminEmail: proxyAdminEmail } : {}),
                ...(clientId ? { clientId } : {}),
                ...(clickId ? { clickId } : {}),
                ...(clientVersion ? { clientVersion } : {}),
                ...(serverVersion ? { serverVersion } : {}),
                ...(userDbId ? { userDbId } : {}),
                ...(proxyAdminId ? { proxyAdminId } : {}),
                ...(roles ? { roles } : {}),
            };
        }

        return { context: enrichedContext, restArgs };
    }

    // Overriding 'trace' method with overloads
    trace(): boolean;
    trace(error: Error, ...params: any[]): void;
    trace(obj: Object, ...params: any[]): void;
    trace(format: any, ...params: any[]): void;
    trace(...args: any[]): boolean | void {
        if (args.length === 0) {
            return this.logger.trace();
        }
        const { context, restArgs } = this.createContext(...args);
        this.logger.trace(context, ...restArgs);
    }

    // Implement similar overrides for other log levels
    debug(): boolean;
    debug(error: Error, ...params: any[]): void;
    debug(obj: Object, ...params: any[]): void;
    debug(format: any, ...params: any[]): void;
    debug(...args: any[]): boolean | void {
        if (args.length === 0) {
            return this.logger.debug();
        }
        const { context, restArgs } = this.createContext(...args);
        this.logger.debug(context, ...restArgs);
    }

    info(): boolean;
    info(error: Error, ...params: any[]): void;
    info(obj: Object, ...params: any[]): void;
    info(format: any, ...params: any[]): void;
    info(...args: any[]): boolean | void {
        if (args.length === 0) {
            return this.logger.info();
        }
        const { context, restArgs } = this.createContext(...args);

        this.logger.info(context, ...restArgs);
    }

    warn(): boolean;
    warn(error: Error, ...params: any[]): void;
    warn(obj: Object, ...params: any[]): void;
    warn(format: any, ...params: any[]): void;
    warn(...args: any[]): boolean | void {
        if (args.length === 0) {
            return this.logger.warn();
        }
        const { context, restArgs } = this.createContext(...args);
        this.logger.warn(context, ...restArgs);
    }

    error(): boolean;
    error(error: Error, ...params: any[]): void;
    error(obj: Object, ...params: any[]): void;
    error(format: any, ...params: any[]): void;
    error(...args: any[]): boolean | void {
        if (args.length === 0) {
            return this.logger.error();
        }

        const { context, restArgs } = this.createContext(...args);
        this.logger.error(context, ...restArgs);
    }

    fatal(): boolean;
    fatal(error: Error, ...params: any[]): void;
    fatal(obj: Object, ...params: any[]): void;
    fatal(format: any, ...params: any[]): void;
    fatal(...args: any[]): boolean | void {
        if (args.length === 0) {
            return this.logger.fatal();
        }
        const { context, restArgs } = this.createContext(...args);
        this.logger.fatal(context, ...restArgs);
    }

}

The context in GCP looks like this AND you can just one click filter on any of those fields in GCP which rocks

It just feels like have to create my own CustomLogger and override all these methods is not a very clean way and honestly bunyan should by default just have support for asyncLocalStorage as this is very common setup in servers

1. in filter add context to a request thing
2. in logger, retrieve all request context info to add to every log so developers are not typing the 14 things you see we have in our context.

clickId is event from angular on client (may be blank on some logs like startup logs)
userDbId is the current user in angular (may be blank like user not logged in)
txId is server generated id
serverVersion is great to know which versino the log came from (rolling restarts sometimes, different versions)
clientVersion is if log is on a client call so we can see mismatches
etc. etc. very good info that every server should have on every log