Best way to debug 'Can't set headers after they are sent' error in Express / Node.js?

Question

I'm trying to debug the dreaded Can't set headers after they are sent error in a node.js Express application. Specifically, I'm using the knox library to talk to s3.

Roughly, I have this Express handler, using a global instance of a knox s3client:

function foo(req, res) {
    //Region A
    var s3req = global.s3client.get('foo').on('response', function(s3res){
        //Region B
        res.set('content-length', s3res.headers['content-length']); //This will fail
        s3res.on('data', function(chunk){
            res.write(chunk);
        });
    });
    //Region C
    s3req.end();
}

If I set any header or status code on res in Region A, everything works fine. If I try any of that in Region B, I get the "Can't set headers after they are sent" error. Note that I want to set headers on res, not s3res

Presumably response.writeHead is being called or triggered somewhere before the on response callback of the knox s3client is being called. Is there some debug flag or other way to get Node to spit out when/where writeHead has been called? Node 0.10 adds a response.headersSent, but it would be prohibitively hard to fill my code and all 3rd party libraries with a check of this flag to figure out where this is getting called. Or is there someway else to figure out this problem?

Answer 1

You could try to include a simple middleware that dumps a stack trace to stdout when writeHead is called:

app.use(function(req, res, next) {
  res.on('header', function() {
    console.trace('HEADERS GOING TO BE WRITTEN');
  });
  next();
});

You have to insert that before routes/middleware that might trigger your problem.

FWIW, my guess would be that the problem is triggered by something happening in region C (either a res.send, res.end, res.json or res.render that's being called there):

function foo(req, res) {
    //Region A
    var s3req = global.s3client.get('foo').on('response', function(s3res){
        //Region B
        res.set('content-length', s3res.headers['content-length']);
    }); 
    //Region C
}

EDIT if s3res is a proper stream, you can try this:

function foo(req, res) {
  global.s3client.get('foo').on('response', function(s3res) {
    s3res.pipe(res);
  }).end();
}

But be aware that all headers returned by the S3 request will be passed to the Express response.

Answer 2

I'm not sure if it applies here, but what I immediately thought of when seeing the error, was a simple very simple mistake in "callback-logic" somewhere in the "model layer". I had been head scratching over this in two separate instances, in both instances it turned out to be that I called a callback (i.e. one that eventually would call the response-writing callback) twice. This would happen only on an error in my model layer, because it was code like:

if (err) cb(err) // note the missing "return" here
cb(null,result) // alternatively, also no "else"

If I were to run into such an error now, the first thing I do would be to check if the response-writing callback is called twice for any operation. Simply two console.log statements one in region A (the scope where the Knox request is initiated) and one in region C (the response-writing callback) would suffice for at least eliminating this possibility.

In principle, your res object should be pretty protected. Only connect / express middleware has access to it, and this particular request handler of course. So there are only a limited number of places that have the power of having a header being written.