Merge pull request #10 from AckeeCZ/chng/refactor-1903

Pretty streams optimizations, refactoring
AckeeCZ · Jan 17, 2019 · c64c350 · c64c350
2 parents baad2ab + 332703e
commit c64c350
Show file tree

Hide file tree

Showing 5 changed files with 54 additions and 50 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -3,9 +3,13 @@
 ### Fixed
 - lint issue due to changes in tslint 5.12.0
 - stream write function type
+- pretty streams created only when needed
 
 ### Added
 - coveralls integration
+
+## Changed
+- refactoring of express handlers
 
 ## [1.0.3] - 2018-11-08
 

diff --git a/src/declarations.ts b/src/declarations.ts
@@ -8,7 +8,9 @@ declare module 'pick-deep' {
     export = pickDeep;
 }
 
-declare module 'pino-multi-stream' {}
+declare module 'pino-multi-stream' {
+
+}
 
 // there is a @typed/pino-multi-stream package, but it has wrong type in its Streams definition. So until its fixed, we use this
 /* declare module 'pino-multi-stream' {

diff --git a/src/express.ts b/src/express.ts
@@ -5,52 +5,59 @@ import { AckeeLogger } from '.';
 
 const errorSymbol = Symbol.for('error');
 
+type AckeeRequest = Request & { _startAt?: [number, number]; ackId?: string };
+type AckeeResponse = Response & { _startAt?: [number, number]; time?: string; out?: object; [errorSymbol]?: any };
+
 export type AckeeLoggerExpressMiddleware = (
     this: AckeeLogger,
-    req: Request & { _startAt?: [number, number]; ackId?: string },
-    response: Response & { _startAt?: [number, number]; time?: string; out?: object; [errorSymbol]?: any },
+    req: AckeeRequest,
+    response: AckeeResponse,
     next: any
 ) => void;
 
+const expressOnHeaders = (req: AckeeRequest, res: AckeeResponse) => () => {
+    res._startAt = process.hrtime();
+    const diffFromSeconds = (res._startAt[0] - req._startAt![0]) * 1e3;
+    const diffFromNanoseconds = (res._startAt[1] - req._startAt![1]) * 1e-6;
+    const ms = diffFromSeconds + diffFromNanoseconds;
+    res.time = ms.toFixed(3);
+};
+
+const expressOnFinished = (logger: AckeeLogger, req: AckeeRequest) => (_err: Error | null, res: AckeeResponse) => {
+    const error = res[errorSymbol];
+    const reqOut = `${res.statusCode} ${req.method} ${req.originalUrl} ${res.time} ms ${req.headers['user-agent']}`;
+    if (logger.options.ignoredHttpMethods && logger.options.ignoredHttpMethods.includes(req.method)) {
+        return;
+    }
+    const standardOutput = {
+        data: {
+            req,
+            res,
+            ackId: req.ackId,
+        },
+        message: `${reqOut} - Standard output`,
+    };
+
+    if (error) {
+        logger.error({ error, req, res, ackId: req.ackId }, `${reqOut} - Error handler at the end of app`);
+    } else if (res.out) {
+        logger.debug(standardOutput.data, standardOutput.message);
+    } else {
+        logger.info(standardOutput.data, standardOutput.message);
+    }
+};
+
 const expressMiddleware: RequestHandler = function(
     this: AckeeLogger,
-    req: Request & { _startAt?: [number, number]; ackId?: string },
-    response: Response & { _startAt?: [number, number]; time?: string; out?: object; [errorSymbol]?: any },
+    req: AckeeRequest,
+    response: AckeeResponse,
     next: any
 ) {
     const reqIn = `--- ${req.method} ${req.originalUrl} ${req.headers['user-agent']}`;
     this.debug({ req, ackId: req.ackId }, `${reqIn} - Request accepted`);
     req._startAt = process.hrtime();
-    onHeaders(response, () => {
-        response._startAt = process.hrtime();
-        const diffFromSeconds = (response._startAt[0] - req._startAt![0]) * 1e3;
-        const diffFromNanoseconds = (response._startAt[1] - req._startAt![1]) * 1e-6;
-        const ms = diffFromSeconds + diffFromNanoseconds;
-        response.time = ms.toFixed(3);
-    });
-    onFinished(response, (_err, res) => {
-        const error = res[errorSymbol];
-        const reqOut = `${res.statusCode} ${req.method} ${req.originalUrl} ${res.time} ms ${req.headers['user-agent']}`;
-        if (this.options.ignoredHttpMethods && this.options.ignoredHttpMethods.includes(req.method)) {
-            return;
-        }
-        const standardOutput = {
-            data: {
-                req,
-                res,
-                ackId: req.ackId,
-            },
-            message: `${reqOut} - Standard output`,
-        };
-
-        if (error) {
-            this.error({ error, req, res, ackId: req.ackId }, `${reqOut} - Error handler at the end of app`);
-        } else if (res.out) {
-            this.debug(standardOutput.data, standardOutput.message);
-        } else {
-            this.info(standardOutput.data, standardOutput.message);
-        }
-    });
+    onHeaders(response, expressOnHeaders(req, response));
+    onFinished(response, expressOnFinished(this, req));
     next();
 };
 

diff --git a/src/index.ts b/src/index.ts
@@ -52,16 +52,8 @@ const defaultLogger = (options: AckeeLoggerOptions = {}): AckeeLogger => {
     serializers.enablePaths(options.enableFields);
 
     const isTesting = process.env.NODE_ENV === 'test';
-    let defaultLevel: Level = 'debug';
-
-    if (options.defaultLevel) {
-        defaultLevel = options.defaultLevel;
-    } else if (isTesting) {
-        defaultLevel = 'silent';
-    }
-
+    const defaultLevel: Level = options.defaultLevel || (isTesting ? 'silent' : 'debug');
     const streams = initLoggerStreams(defaultLevel, options);
-    const defaultMessageKey = options.pretty ? 'msg' : 'message'; // "message" is the best option for Google Stackdriver
 
     if (!options.ignoredHttpMethods) {
         options.ignoredHttpMethods = ['OPTIONS'];
@@ -74,7 +66,7 @@ const defaultLogger = (options: AckeeLoggerOptions = {}): AckeeLogger => {
             {
                 base: {},
                 level: defaultLevel,
-                messageKey: defaultMessageKey,
+                messageKey: options.pretty ? 'msg' : 'message', // "message" is the best option for Google Stackdriver,
                 serializers: serializers.serializers,
                 timestamp: false,
             },

diff --git a/src/streams.ts b/src/streams.ts
@@ -31,15 +31,14 @@ const decorateStreams = <T extends Transform>(streams: AckeeLoggerStream[], stre
 };
 
 const initLoggerStreams = (defaultLevel: pino.LevelWithSilent, options: AckeeLoggerOptions = {}) => {
-    const pretty = pino.pretty();
-    pretty.pipe(process.stdout);
-    const prettyErr = pino.pretty();
-    prettyErr.pipe(process.stderr);
-
     let streams: AckeeLoggerStream[];
     if (options.streams) {
         streams = options.streams;
     } else if (options.pretty) {
+        const pretty = pino.pretty();
+        pretty.pipe(process.stdout);
+        const prettyErr = pino.pretty();
+        prettyErr.pipe(process.stderr);
         streams = [
             { level: defaultLevel, maxLevel: levels.warn, stream: pretty },
             { level: 'warn', stream: prettyErr },