Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How to properly split logging between requests and responses with Morgan?

Morgan's documentation describes that it's possible to split the logging of requests and responses:

split / dual logging

The morgan middleware can be used as many times as needed, enabling combinations like:

  • Log entry on request and one on response
  • Log all requests to file, but errors to console

In their only related example, there are some comments describing that one middleware will log error responses to console, and another requests to file:

// log only 4xx and 5xx responses to console
app.use(morgan('dev', {
  skip: function (req, res) { return res.statusCode < 400 }
}))

// log all requests to access.log
app.use(morgan('common', {
  stream: fs.createWriteStream(path.join(__dirname, 'access.log'), {flags: 'a'})
}))

Which seems to achieve the second example of logging all requests to file and errors to console, but not the first one.

I'm a bit lost, I couldn't understand what's telling morgan to log only request or only responses. Do I have to concern where to place those middlewares properly?

Currently, I have a single log entry for both request and response, I guess:

morgan('[:date[clf]] :remote-addr :url :method HTTP/:http-version :status :remote-user :res[content-length] :referrer :user-agent :response-time ms', {
  stream: {
    write: (message) => {
      winston.silly(message.trim());
    }
  }
});

So, how can I properly log requests in a morgan middleware call, and responses in another?

like image 849
falsarella Avatar asked Jan 16 '18 13:01

falsarella


1 Answers

I've managed to split Morgan logging between requests and responses with immediate option:

immediate

Write log line on request instead of response. This means that a requests will be logged even if the server crashes, but data from the response (like the response code, content length, etc.) cannot be logged.

So, instead of having this mixed logging:

app.use(morgan(':remote-addr :url :method HTTP/:http-version :status :res[content-length] :user-agent :response-time ms', {
  stream: {
    write: (message) => {
      winston.info(message.trim());
    }
  }
}));

It's possible to separate them, and log in their correct order:

// Logs requests
app.use(morgan(':remote-addr :url :method HTTP/:http-version :user-agent', {
  // https://github.com/expressjs/morgan#immediate
  immediate: true,
  stream: {
    write: (message) => {
      winston.info(message.trim());
    }
  }
}));

// Logs responses
app.use(morgan(':remote-addr :url :method :status :res[content-length] :response-time ms', {
  stream: {
    write: (message) => {
      winston.info(message.trim());
    }
  }
}));

Note: since express just enhances Node's own request and response objects, I believe it internally does res.on('finish', req => { /* log stuff */ }), when it's not set to immediate.

like image 51
falsarella Avatar answered Nov 15 '22 02:11

falsarella