logger: Log even when connections are aborted. #760

Merged
merged 1 commit into from Sep 15, 2013

2 participants

@dylanahsmith

Problem

As issue #321 reported, aborted requests haven't been logged by connect's logger middleware. That issue was closed by the addition of immediate logging, which is a suitable fix for streaming, but isn't the ideal solution for the case where the client aborts the connection.

Solution

A listener on the 'close' events can be used to log aborted requests.

Since those aborted requests may not have sent the response code (e.g. by calling response.writeHead(200)), the status token will return null if res.headerSent isn't true, rather than the default of 200. This will also fix #378.

I used common function to write the request line to avoid duplicating code with immediate logging. I used the 'finish' event as proposed in pull #552 so the function could be reused for both the 'close' and 'finish' events.

@jonathanong

wow, overwriting res.end() in the original code is just terrible.

can you rebase?

@jonathanong jonathanong commented on the diff Sep 15, 2013
lib/middleware/logger.js
@@ -135,21 +135,19 @@ exports = module.exports = function logger(options) {
return function logger(req, res, next) {
req._startTime = new Date;
- // immediate
- if (immediate) {
+ function logRequest(){

you should do cleanup here so the same request isnt logged twice

function logRequest(){
  // ...
  res.removeListener('finish', logRequest);
  res.removeListener('close', logRequest);
  // ...
})

done, now it removes the listeners so it won't log twice.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
@jonathanong

also, when was the finish event added? 0.8 right?

@dylanahsmith

The finish event was being emitted as early as node v0.4.0.

@jonathanong

ah ok. i just remember it wasn't documented or something. can you squash into a single commit?

@dylanahsmith

The finish event was first documented in node v0.10.0, despite its presence in earlier versions.

Squashed into a single commit.

@jonathanong jonathanong commented on the diff Sep 15, 2013
lib/middleware/logger.js
// proxy end to output logging
} else {
- var end = res.end;
- res.end = function(chunk, encoding){
- res.end = end;
- res.end(chunk, encoding);
- var line = fmt(exports, req, res);
- if (null == line) return;
- stream.write(line + '\n');
- };
+ res.on('finish', logRequest);

i would use .once here but it doesn't matter :P

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
@jonathanong jonathanong merged commit 8984130 into senchalabs:master Sep 15, 2013

1 check passed

Details default The Travis CI build passed
@dylanahsmith dylanahsmith deleted the dylanahsmith:logger-close-event branch Sep 15, 2013
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment