Feature: Allow multiple instances of middleware #263

mmadson · 2022-12-07T20:41:20Z

PR to address Issue #260

scope pino loggers to lambda closures instead of function properties
set request and response log property to first middleware pino logger but capture additional middleware pino loggers in new allLogs request and response property
unit tests to confirm each middleware redact properties are independent

- scope pino loggers to lambda closures instead of function properties - set request and response log property to first middleware pino logger but capture additional middleware pino loggers in new allLogs request and response property - unit tests to confirm each middleware redact properties are independent

mmadson · 2022-12-07T20:48:05Z

index.test-d.ts

@@ -18,7 +18,6 @@ pinoHttp({ genReqId: (req: IncomingMessage, res: ServerResponse) => res.statusCo
 pinoHttp({ genReqId: (req: IncomingMessage, res: ServerResponse) => 'foo' });
 pinoHttp({ genReqId: (req: IncomingMessage, res: ServerResponse) => Buffer.allocUnsafe(16) });
 pinoHttp({ useLevel: 'error' });
-pinoHttp({ prettyPrint: true }); // deprecated but still present in pino.


git hooks, tests and compilation failed unless I removed this line; not sure still required and still present in upstream pino

mmadson · 2022-12-07T20:49:20Z

index.d.ts

@@ -80,6 +80,7 @@ declare module "http" {
    interface IncomingMessage {
      id: ReqId;
      log: pino.Logger;
+      allLogs: pino.Logger[];


when multiple pino-http middleware are registered, the first registered middleware's pino logger will be attached to the req.log property. The remaining middleware's pino loggers (as well as the first) will be available in this new allLogs property.

mmadson · 2022-12-07T20:51:10Z

logger.js

-    this.removeListener('close', onResFinished)
-    this.removeListener('error', onResFinished)
-    this.removeListener('finish', onResFinished)
+  const result = (req, res, next) => {


instead of attaching the pino logger to the statically defined loggingMiddleware function and returning the single reference to it, we create a new closure called result and attach the pino logger to the result. Each call to pinoHttp will create a new result closure so each call gets it's own closure rather than sharing the loggingMiddleware function and it's logging property.

mmadson · 2022-12-07T20:53:32Z

logger.js

    let shouldLogSuccess = true

-    req.id = genReqId(req, res)
+    req.id = req.id || genReqId(req, res)


when multiple middleware are registered we have to decide how the req.id is to be set. Convention established here is that the first middleware's genReqId function will set the req.id, subsequent middleware's genReqId functions will be ignored, so the req.id will be set only once per request.

This may warrant additional discussion.

mmadson · 2022-12-07T20:54:08Z

logger.js

    )
  }

-  function loggingMiddleware (req, res, next) {
+  function loggingMiddleware (logger, req, res, next) {


since the logger is attached to the result closure instead of this function, we pass the logger into the function as a param instead of assuming it is attached as function property.

mmadson · 2022-12-07T20:58:06Z

logger.js

-    if (err || this.err || this.statusCode >= 500) {
-      const error = err || this.err || new Error('failed with status code ' + this.statusCode)
+    if (err || res.err || res.statusCode >= 500) {
+      const error = err || res.err || new Error('failed with status code ' + res.statusCode)

      log[level](


the current implementation emits the final log message on the single logger attached to the response object. Instead we have passed the intended logger in as a parameter from a new closure onResponseComplete so that each middleware generates it's logs to its own pino logger, not relying on the logger attached to the response object.

mcollina

lgtm

- changing usage of modern js features to pass CICD tests

mmadson · 2022-12-08T04:39:42Z

lgtm

Looks like CICD had some tests that either don't run by default locally or at least aren't run the same way and they didn't like my usage of the nullish coalescing operator ??=. I went ahead and replaced it with and if check to instantiate the allLogs array. Hopefully that gets us past the CICD checks. If there is a way for me to run them locally just let me know and I'll try to resolve any other failures before pushing more code. As far as I can tell yarn test passes for me locally.

- reverting removal of prettyPrint property

mmadson · 2022-12-08T22:55:58Z

@mcollina Whenever you have a free moment would you mind kicking off the workflow again? I don't seem to have permission but hoping that my fix has addressed the CICD issue. 🙏

- removing deprecated usage of prettyPrint as it is failing on CICD as well

mmadson · 2022-12-09T21:42:53Z

@mcollina Oof; okay so what is the saying? Third time is the charm? I was worried that perhaps my removal of the prettyPrint property typescript test may have been premature and although it wasn't passing for me locally perhaps it would pass on CICD -- so I restored the line while fixing the ??= operator compiler error. However, it looks like the prettyPrint issue is not only an issue for me locally but also an issue on CICD so I went ahead and removed it again. I think now everything should be good to go and hopefully the next run will be a clean CICD run. 🤞

- removing another instance of ??=

mmadson · 2022-12-09T22:03:35Z

.github/workflows/ci.yml

@@ -1,6 +1,7 @@
 name: CI

 on:
+  workflow_dispatch:


This allows you to manually run your GItHub CICD workflow from the Actions tab without pushing a commit. If you would prefer me to revert this change I can. Just LMK.

mmadson · 2022-12-09T22:05:04Z

@mcollina I just realized that I can enable the same GitHub Actions CICD pipeline on my fork. So I went ahead and did that and found another ??= that I needed to replace and verified that the CICD all passes on my forked repo

So feel free to start the CICD workflow whenever you are ready we should be green. =)

mmadson · 2022-12-10T09:56:31Z

@mcollina Latest failure seems to be a problem with how the test was written. The test assumes the sample server will always result in a 0 latency response time but in this particular test run. The response time turned out to be 1. I'll go ahead and update the test to match any digits instead of just 0 which should make the test more robust.

            --- expected
            +++ actual
            @@ -1,1 +1,1 @@
            -Response time is: 0 GET
            +Response time is: 1 GET

- update test to account for potential test server latency

mmadson · 2022-12-12T18:11:33Z

Yay, finally an all green CICD run. Guess it's up to y'all (@mcollina) to decide when to merge and cut a release. Thanks again for releasing this project to OSS, it's proven very beneficial for our request / response logging. 🎉

kohtala · 2023-07-13T13:53:39Z

People modify the req.log to add properties into log. #30 With this change, the properties are no longer logged.

mmadson mentioned this pull request Dec 7, 2022

Multiple middleware instances with different redact config #260

Closed

mmadson commented Dec 7, 2022

View reviewed changes

mcollina approved these changes Dec 7, 2022

View reviewed changes

Feature: Allow multiple instances of middleware

fff8fd7

- changing usage of modern js features to pass CICD tests

Feature: Allow multiple instances of middleware

3a5b81e

- reverting removal of prettyPrint property

mmadson requested a review from mcollina December 8, 2022 06:08

Feature: Allow multiple instances of middleware

075c618

- removing deprecated usage of prettyPrint as it is failing on CICD as well

mmadson and others added 3 commits December 9, 2022 13:58

Update ci.yml

0ab984d

Feature: Allow multiple instances of middleware

76c1c4e

- removing another instance of ??=

Merge remote-tracking branch 'origin/master'

638182f

mmadson commented Dec 9, 2022

View reviewed changes

Feature: Allow multiple instances of middleware

3c64857

- update test to account for potential test server latency

mcollina merged commit 728430d into pinojs:master Dec 15, 2022

GyanendroKh mentioned this pull request Jan 3, 2023

Support for pino-http multi instance iamolegga/nestjs-pino#1260

Merged

sawood14012 mentioned this pull request Jul 17, 2024

[Snyk] Upgrade pino-http from 8.2.0 to 8.6.1 redhat-appstudio/tssc-sample-templates#60

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Feature: Allow multiple instances of middleware #263

Feature: Allow multiple instances of middleware #263

mmadson commented Dec 7, 2022 •

edited

Loading

mmadson Dec 7, 2022

mmadson Dec 7, 2022

mmadson Dec 7, 2022

mmadson Dec 7, 2022

mmadson Dec 7, 2022

mmadson Dec 7, 2022

mcollina left a comment

mmadson commented Dec 8, 2022

mmadson commented Dec 8, 2022

mmadson commented Dec 9, 2022

mmadson Dec 9, 2022

mmadson commented Dec 9, 2022

mmadson commented Dec 10, 2022

mmadson commented Dec 12, 2022

kohtala commented Jul 13, 2023

Feature: Allow multiple instances of middleware #263

Feature: Allow multiple instances of middleware #263

Conversation

mmadson commented Dec 7, 2022 • edited Loading

mmadson Dec 7, 2022

Choose a reason for hiding this comment

mmadson Dec 7, 2022

Choose a reason for hiding this comment

mmadson Dec 7, 2022

Choose a reason for hiding this comment

mmadson Dec 7, 2022

Choose a reason for hiding this comment

mmadson Dec 7, 2022

Choose a reason for hiding this comment

mmadson Dec 7, 2022

Choose a reason for hiding this comment

mcollina left a comment

Choose a reason for hiding this comment

mmadson commented Dec 8, 2022

mmadson commented Dec 8, 2022

mmadson commented Dec 9, 2022

mmadson Dec 9, 2022

Choose a reason for hiding this comment

mmadson commented Dec 9, 2022

mmadson commented Dec 10, 2022

mmadson commented Dec 12, 2022

kohtala commented Jul 13, 2023

mmadson commented Dec 7, 2022 •

edited

Loading