feat(logger): Integrate logger with sanitizing (#4474)

lib/logger/index.ts

@@ -5,7 +5,7 @@ import { RenovateStream } from './pretty-stdout';
 import configSerializer from './config-serializer';
 import errSerializer from './err-serializer';
 import cmdSerializer from './cmd-serializer';
-import { ErrorStream } from './utils';
+import { ErrorStream, withSanitizer } from './utils';
 
 let meta = {};
 export interface LogError {
@@ -49,7 +49,7 @@ const bunyanLogger = bunyan.createLogger({
       stream: errors as any,
       type: 'raw',
     },
-  ],
+  ].map(withSanitizer),
 });
 
 const logFactory = (level: bunyan.LogLevelString): any => {
@@ -105,7 +105,7 @@ export function setMeta(obj: any) {
 export /* istanbul ignore next */ function addStream(
   stream: bunyan.Stream
 ): void {
-  bunyanLogger.addStream(stream);
+  bunyanLogger.addStream(withSanitizer(stream));
 }
 
 export function levels(name: string, level: bunyan.LogLevel): void {

lib/logger/utils.ts

+import fs from 'fs-extra';
+import bunyan from 'bunyan';
 import { Stream } from 'stream';
+import { sanitize } from '../util/sanitize';
 
 export interface BunyanRecord extends Record<string, any> {
   level: number;
@@ -32,3 +35,67 @@ export class ErrorStream extends Stream {
     return this._errors;
   }
 }
+
+function sanitizeValue(value: any, seen = new WeakMap()) {
+  if (Array.isArray(value)) {
+    const length = value.length;
+    const arrayResult = Array(length);
+    seen.set(value, arrayResult);
+    for (let idx = 0; idx < length; idx += 1) {
+      const val = value[idx];
+      arrayResult[idx] = seen.has(val)
+        ? seen.get(val)
+        : sanitizeValue(val, seen);
+    }
+    return arrayResult;
+  }
+
+  const valueType = typeof value;
+
+  if (value != null && valueType !== 'function' && valueType === 'object') {
+    const objectResult: Record<string, any> = {};
+    seen.set(value, objectResult);
+    for (const [key, val] of Object.entries<any>(value)) {
+      objectResult[key] = seen.has(val)
+        ? seen.get(val)
+        : sanitizeValue(val, seen);
+    }
+    return objectResult;
+  }
+
+  return valueType === 'string' ? sanitize(value) : value;
+}
+
+export function withSanitizer(streamConfig): bunyan.Stream {
+  if (streamConfig.type === 'rotating-file')
+    throw new Error("Rotating files aren't supported");
+
+  const stream = streamConfig.stream;
+  if (stream && stream.writable) {
+    const write = (chunk: BunyanRecord, enc, cb) => {
+      const raw = sanitizeValue(chunk);
+      const result =
+        streamConfig.type === 'raw'
+          ? raw
+          : JSON.stringify(raw, bunyan.safeCycles()).replace(/\n?$/, '\n');
+      stream.write(result, enc, cb);
+    };
+
+    return {
+      ...streamConfig,
+      type: 'raw',
+      stream: { write },
+    };
+  }
+
+  if (streamConfig.path) {
+    const fileStream = fs.createWriteStream(streamConfig.path, {
+      flags: 'a',
+      encoding: 'utf8',
+    });
+
+    return withSanitizer({ ...streamConfig, stream: fileStream });
+  }
+
+  throw new Error("Missing 'stream' or 'path' for bunyan stream");
+}

test/logger/index.spec.ts

-import { logger, setMeta, levels, getErrors } from '../../lib/logger';
+import _fs from 'fs-extra';
+import {
+  logger,
+  setMeta,
+  levels,
+  getErrors,
+  addStream,
+} from '../../lib/logger';
+import { add } from '../../lib/util/host-rules';
 
 jest.unmock('../../lib/logger');
 
+jest.mock('fs-extra');
+const fs: any = _fs;
+
 describe('logger', () => {
   it('inits', () => {
     expect(logger).toBeDefined();
@@ -31,4 +42,96 @@ describe('logger', () => {
     logger.error({ some: 'meta' }, 'message');
     expect(getErrors()).toMatchSnapshot();
   });
+
+  it('should contain path or stream parameters', () => {
+    expect(() =>
+      addStream({
+        name: 'logfile',
+        level: 'error',
+      })
+    ).toThrow("Missing 'stream' or 'path' for bunyan stream");
+  });
+
+  it("doesn't support rotating files", () => {
+    expect(() =>
+      addStream({
+        name: 'logfile',
+        path: 'file.log',
+        level: 'error',
+        type: 'rotating-file',
+      })
+    ).toThrow("Rotating files aren't supported");
+  });
+
+  it('supports file-based logging', () => {
+    let chunk = null;
+    fs.createWriteStream.mockReturnValueOnce({
+      writable: true,
+      write(x) {
+        chunk = x;
+      },
+    });
+
+    addStream({
+      name: 'logfile',
+      path: 'file.log',
+      level: 'error',
+    });
+
+    logger.error('foo');
+
+    expect(JSON.parse(chunk).msg).toEqual('foo');
+  });
+
+  it('handles cycles', () => {
+    let logged = null;
+    fs.createWriteStream.mockReturnValueOnce({
+      writable: true,
+      write(x) {
+        logged = JSON.parse(x);
+      },
+    });
+
+    addStream({
+      name: 'logfile',
+      path: 'file.log',
+      level: 'error',
+    });
+
+    const meta = { foo: null, bar: [] };
+    meta.foo = meta;
+    meta.bar.push(meta);
+    logger.error(meta, 'foo');
+    expect(logged.msg).toEqual('foo');
+    expect(logged.foo.foo).toEqual('[Circular]');
+    expect(logged.foo.bar).toEqual(['[Circular]']);
+    expect(logged.bar).toEqual('[Circular]');
+  });
+
+  it('sanitizes secrets', () => {
+    let logged = null;
+    fs.createWriteStream.mockReturnValueOnce({
+      writable: true,
+      write(x) {
+        logged = JSON.parse(x);
+      },
+    });
+
+    addStream({
+      name: 'logfile',
+      path: 'file.log',
+      level: 'error',
+    });
+    add({ password: 'secret"password' });
+
+    logger.error({
+      foo: 'secret"password',
+      bar: ['somethingelse', 'secret"password'],
+    });
+
+    expect(logged.foo).not.toEqual('secret"password');
+    expect(logged.bar[0]).toEqual('somethingelse');
+    expect(logged.foo).toContain('redacted');
+    expect(logged.bar[1]).toContain('redacted');
+  });
 });