Return to Blog Home

Express Middleware Logger

Source 

Express Middleware Logger

Seeing what middllewares do what in an Express Application!

As useful as middleware are, when looking at a project for the first time or the first time in a long time, it can be difficult to track down what middleware is doing what - not to mention the presence of custom middleware.

Middleware Architexture

Express middleware is a stack of functions that are called in order - where each function can modify the request and response objects, and can call the next function in the stack if the previous one signals to do so.

There is more to it involving routing, and all this is all internal of course, so I didn't have direct access to this stack - but as JavaScript doesn't have true private variables, I could access it by using the ._router.stack property of the Express Application.

Middleware Logger

The way the logger works is by accessing the stack and injecting itself before and after each middleware, getting the before state of the request & response, calling the original middleware, and then logging the difference between the before and after request & response.

Of course as the request and response objects contain a plethora of information, I couldn't log everything - so had to pick and choose what I wanted to log, first ditching any circular references, raw connections, and providing the ability to filter additional property keys via an array of regexes.

Here's an example of the logger in action - truncated for readability:

query +0ms
request:
  query: undefined -> {} +2ms
expressInit +2ms
request:
  ip: undefined -> '::1'
  path: undefined -> '/'
  hostname: undefined -> 'localhost'
  host: undefined -> 'localhost'
response:
  locals: undefined -> [Object: null prototype] {}
jsonParser +1ms
request:
  body: undefined -> {} +0ms
methodOverride +2ms
request:
  originalMethod: undefined -> 'GET' +0ms
logger +2ms
request:
  _startAt: undefined -> [ 20499, 284701377 ]
  _startTime: undefined -> 2022-10-20T17:32:29.935Z +1ms
response:
  _eventsCount: 1 -> 2
  writeHead: [Function: writeHead] -> [Function: writeHead]
  __onFinished: undefined -> [Function: listener] { queue: [ [Function: logRequest] ] } +0ms
serveStatic +3ms
request:
  complete: false -> true
  _parsedOriginalUrl: undefined -> Url {
    pathname: '/',
    path: '/',
    href: '/',
  } +0ms
cookieParser +1ms
request:
  cookies: undefined -> [Object: null prototype] {}
  signedCookies: undefined -> [Object: null prototype] {} +0ms
session +3ms
request:
  sessionStore: undefined -> FileStore {
  }
  sessionID: undefined -> '6351862dff4b6cb090893f6d'
  session: undefined -> Session {
    cookie: { path: '/', _expires: null, originalMaxAge: null, httpOnly: true }
  } +1ms
response:
  writeHead: [Function: writeHead] -> [Function: writeHead]
  end: [Function: end] -> [Function: end] +0ms
initialize +2ms
request:
  logIn: undefined -> [Function (anonymous)]
  login: undefined -> [Function (anonymous)]
  logOut: undefined -> [Function (anonymous)]
  logout: undefined -> [Function (anonymous)]
  isAuthenticated: undefined -> [Function (anonymous)]
  isUnauthenticated: undefined -> [Function (anonymous)]
  _sessionManager: undefined -> SessionManager { _key: 'passport', _serializeUser: [Function: bound ] }
  _passport: undefined -> {
    instance: Authenticator {
    }
  } +0ms
createAnonymousUser +3ms
request:
  user: undefined -> { _id: '6351862dff4b6cb090893f6d', hasOnlyOAuth: false } +0ms
trackOldSessionID +1ms
request:
  oldSessionId: undefined -> '6351862dff4b6cb090893f6d' +0ms
GET / 200 796.891 ms - 3925

Now this is quite verbose, but that's the point - I could see what middleware is doing what, what it's modifying in the request and response objects, and the last middleware that was executed.

A few intresting examples that one can see from a glance are:

Future

At the very least this has helped me quickly debug issues in completly new projects, and while it was too raw for any educational/public purposes, I was confident that with a bit of work it could be made into a useful development tool.