Feature request: log both before & after the request

[thomas-riccardi]

The usual request loggers log after the request was responded, because at this point we have all the data: response time, return code, etc... This is what morgan does by default.

But for debug purpose it's often useful to have a log entry when the request was just received, morgan also provides this feature with the immediate flag.

However, what we really need when debugging it immediate log and all the response information. The only way to implement this is to log two times: one like immediate, and one like the default.
We then need something to correlate both logs (a correlation id: a counter, or some other thing).
And finally: something to distinguish between both logs entries (a visual clue like a prefix).

Without this feature the immediate feature is usually useless. Or am I missing a standard use-case?

[dougwilson]

I'll have to think of a good way to do this. So the use-case for immediate is to log up front so you'll get the access log before your server crashes, if it does, and then you'll better know what requests could have crashed the server if necessary.

As for the request, I believe you can do everything you want with the library as-is. I'm going to look into it and see and also see if anything needs to be changed to accommodate your use-case.

[dougwilson]

How about just doing the following?

var express = require('express')
var fs = require('fs')
var morgan = require('morgan')
var uuid = require('node-uuid')

var app = express()
var accessLogStream = fs.createWriteStream(__dirname + '/access.log', {flags: 'a'})

app.use(function requestId(req, res, next) {
  req.id = uuid.v4()
  next()
})

morgan.token('id', function (req) {
  return req.id
})

app.use(morgan('--> :id [:date] :remote-addr :remote-user ":method :url HTTP/:http-version"', {
  immediate: true,
  stream: accessLogStream
}))
app.use(morgan('<-- :id [:date] :status :res[content-length]', {
  immediate: false,
  stream: accessLogStream
}))

app.get('/', function (req, res) {
  res.send('hello, world!')
})

app.listen(3000)

[thomas-riccardi]

I was just testing something like that, but wanted to avoid a full uuid: I just used a counter:

var counter = 0;
app.use(function requestId(req, res, next) {
  req.id = counter;
  counter += 1;
  next();
})

But I ran into issue #41.

Anyway, the only drawback with your solution is that I have to duplicate the format from the predefined ones (I usually use dev in this case). But since I can't find an easy solution to that, then I'll gladly accept your solution, thanks!