TS-ify logger (#4431)

* TS-ify logger

Also redoes some pretty nasty morgan workarounds in favour of an actual real stream.

* Fix tests. and actually write some

* Formatting

* Add clarifying comment

app.js

@@ -57,7 +57,7 @@ import {RouteAPI} from './lib/handlers/route-api';
 import {loadSiteTemplates} from './lib/handlers/site-templates';
 import {SourceHandler} from './lib/handlers/source';
 import {languages as allLanguages} from './lib/languages';
-import {logger, logToLoki, logToPapertrail, suppressConsoleLog} from './lib/logger';
+import {logger, logToLoki, logToPapertrail, makeLogStream, suppressConsoleLog} from './lib/logger';
 import {setupMetricsServer} from './lib/metrics-server';
 import {ClientOptionsHandler} from './lib/options-handler';
 import * as props from './lib/properties';
@@ -710,21 +710,21 @@ async function main() {
     router
         .use(
             morgan(morganFormat, {
-                stream: logger.stream,
+                stream: makeLogStream('info'),
                 // Skip for non errors (2xx, 3xx)
                 skip: (req, res) => res.statusCode >= 400,
             }),
         )
         .use(
             morgan(morganFormat, {
-                stream: logger.warnStream,
+                stream: makeLogStream('warn'),
                 // Skip for non user errors (4xx)
                 skip: (req, res) => res.statusCode < 400 || res.statusCode >= 500,
             }),
         )
         .use(
             morgan(morganFormat, {
-                stream: logger.errStream,
+                stream: makeLogStream('error'),
                 // Skip for non server errors (5xx)
                 skip: (req, res) => res.statusCode < 500,
             }),

lib/logger.js → lib/logger.ts

@@ -23,41 +23,45 @@
 // POSSIBILITY OF SUCH DAMAGE.
 
 import os from 'os';
+import {Writable} from 'stream';
 
 import {LEVEL, MESSAGE} from 'triple-beam';
 import winston from 'winston';
 import LokiTransport from 'winston-loki';
 import {Papertrail} from 'winston-papertrail';
-import TransportStream from 'winston-transport';
+import TransportStream, {TransportStreamOptions} from 'winston-transport';
 
 const consoleTransportInstance = new winston.transports.Console();
 export const logger = winston.createLogger({
     format: winston.format.combine(winston.format.colorize(), winston.format.splat(), winston.format.simple()),
     transports: [consoleTransportInstance],
 });
 
-logger.stream = {
-    write: message => {
-        logger.info(message.trim());
-    },
-};
-
-logger.warnStream = {
-    write: message => {
-        logger.warn(message.trim());
-    },
-};
-
-logger.errStream = {
-    write: message => {
-        logger.error(message.trim());
-    },
-};
-
-// Our own transport which uses Papertrail under the hood but better adapts it to work
-// in winston 3.0
+// Creates a log stream, suitable to passing to something that writes complete lines of output to a stream, for example
+// morgan's http logger. We look for complete text lines and output each as a winston log entry.
+export function makeLogStream(level: string, logger_: winston.Logger = logger): {write: (string) => void} {
+    let buffer = '';
+    return new Writable({
+        write: (chunk: string, encoding, callback: () => void) => {
+            buffer += chunk;
+            while (buffer.length > 0) {
+                const eol = buffer.indexOf('\n');
+                if (eol < 0) break;
+                logger_.log(level, buffer.substring(0, eol));
+                buffer = buffer.substring(eol + 1);
+            }
+            callback();
+        },
+    });
+}
+
+// Our own transport which uses Papertrail under the hood but better adapts it to work in winston 3.0
 class MyPapertrailTransport extends TransportStream {
-    constructor(opts) {
+    private readonly hostname: string;
+    private readonly program: string;
+    public readonly transport: Papertrail;
+
+    constructor(opts: TransportStreamOptions & {host: string; port: number; identifier: string}) {
         super(opts);
 
         this.hostname = os.hostname();
@@ -70,7 +74,7 @@ class MyPapertrailTransport extends TransportStream {
         });
     }
 
-    log(info, callback) {
+    override log(info: any, callback: () => void) {
         setImmediate(() => {
             this.emit('logged', info);
         });
@@ -98,7 +102,7 @@ export function logToLoki(url) {
     logger.info('Configured loki');
 }
 
-export function logToPapertrail(host, port, identifier) {
+export function logToPapertrail(host: string, port: number, identifier: string) {
     const transport = new MyPapertrailTransport({
         host: host,
         port: port,
@@ -116,7 +120,7 @@ export function logToPapertrail(host, port, identifier) {
 }
 
 class Blackhole extends TransportStream {
-    log(info, callback) {
+    override log(info: any, callback: () => void) {
         callback();
     }
 }

test/utils-tests.js

@@ -25,7 +25,7 @@
 import path from 'path';
 import {fileURLToPath} from 'url';
 
-import {logger} from '../lib/logger';
+import {logger, makeLogStream} from '../lib/logger';
 import * as utils from '../lib/utils';
 
 import {fs} from './utils';
@@ -372,14 +372,35 @@ describe('Anonymizes all kind of IPs', () => {
 });
 
 describe('Logger functionality', () => {
-    it('has info stream with a write function', () => {
-        logger.stream.write.should.a('function');
-    });
-    it('has warning stream with a write function', () => {
-        logger.warnStream.write.should.a('function');
+    it('correctly logs streams split over lines', () => {
+        const logs = [];
+        const fakeLog = {log: (level, msg) => logs.push({level, msg})};
+        const infoStream = makeLogStream('info', fakeLog);
+        infoStream.write('first\n');
+        infoStream.write('part');
+        infoStream.write('ial\n');
+        logs.should.deep.equal([
+            {
+                level: 'info',
+                msg: 'first',
+            },
+            {
+                level: 'info',
+                msg: 'partial',
+            },
+        ]);
     });
-    it('has error stream with a write function', () => {
-        logger.errStream.write.should.a('function');
+    it('correctly logs streams to the right destination', () => {
+        const logs = [];
+        const fakeLog = {log: (level, msg) => logs.push({level, msg})};
+        const infoStream = makeLogStream('warn', fakeLog);
+        infoStream.write('ooh\n');
+        logs.should.deep.equal([
+            {
+                level: 'warn',
+                msg: 'ooh',
+            },
+        ]);
     });
 });