On Heroku, why can't I see all the request headers with nodejs?

I'm trying to control static files cache headers in my nodejs app like described here https://devcenter.heroku.com/articles/increasing-application-performance-with-http-cache-headers#conditional-requests. I would like to use the "etag"/"if-none-match" method.

The problem is my request's "if-none-match" header is always undefined on Heroku. It works fine on my dev server.

Here is my fs.readFile call :

fs.readFile(SERVERDIR+'client/'+file, function(err, data) {
    if(err) {
        console.log(currTime() + ' [STATIC] ... ' + err);
        if(err.code === "ENOENT") {      // file is simply missing
            resNotFound(res,'file not found',err);
        } else {                        // other error; could be EACCES or anything
            resInternalError(res,'internal server error',err);
        }
    }
    else {
        fs.stat(SERVERDIR+'client/'+file, function (err, stat) {
            if (err) {
                resInternalError(res,'internal server error',err);
            }
            else {
                var etag = stat.size + '-' + Date.parse(stat.mtime);
                res.setHeader('Last-Modified', stat.mtime);
                if(LOGSTATIC) { console.log(currTime() + ' [STATIC] ... etag : ' + etag); }
                if(LOGSTATIC) { console.log(currTime() + ' [STATIC] ... req.if-none-match : ' + req.headers['if-none-match']); }
                if(LOGSTATIC) { console.log(req.headers); }

                if (req.headers['if-none-match'] === etag) {
                    res.statusCode = 304;
                    res.end();
                }
                else {
                    res.setHeader('Content-Length', data.length);
                    res.setHeader('ETag', etag);
                    res.statusCode = 200;
                    res.end(data);
                }
            }
        });
    }
});

Here are the heroku logs for a single file request :

2013-05-03T10:32:05.461070+00:00 heroku[router]: at=info method=GET path=/css/common.css host=www.chess-hub.net fwd="193.252.157.50" dyno=web.1 connect=0ms service=5ms status=200 bytes=792
2013-05-03T10:32:05.455619+00:00 app[web.1]: 10:32 [STATIC] ... serving client//css/common.css
2013-05-03T10:32:05.457981+00:00 app[web.1]: { 'x-request-start': '1367577125454',
2013-05-03T10:32:05.457981+00:00 app[web.1]:   'x-forwarded-port': '80',
2013-05-03T10:32:05.455443+00:00 app[web.1]: 10:32 [STATIC] client file request
2013-05-03T10:32:05.457981+00:00 app[web.1]:   'x-forwarded-proto': 'http',
2013-05-03T10:32:05.456127+00:00 app[web.1]: 10:32 [STATIC] ... req if-none-match : undefined
2013-05-03T10:32:05.457981+00:00 app[web.1]:   cookie: 'BCSI-CS-56C420186ECC3F22=2',
2013-05-03T10:32:05.457981+00:00 app[web.1]:   dnt: '1',
2013-05-03T10:32:05.457981+00:00 app[web.1]:   'cache-control': 'max-age=0',
2013-05-03T10:32:05.457981+00:00 app[web.1]:   'x-forwarded-for': '193.252.157.50',
2013-05-03T10:32:05.456046+00:00 app[web.1]: 10:32 [STATIC] ... etag : 792-1367572582000
2013-05-03T10:32:05.457981+00:00 app[web.1]:   host: 'www.chess-hub.net',
2013-05-03T10:32:05.458231+00:00 app[web.1]:   accept: 'text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8' }
2013-05-03T10:32:05.457981+00:00 app[web.1]:   'user-agent': 'Mozilla/5.0 (Windows NT 5.1; rv:19.0) Gecko/20100101 Firefox/19.0',
2013-05-03T10:32:05.458231+00:00 app[web.1]:   'accept-language': 'fr-FR,en-us;q=0.5',
2013-05-03T10:32:05.457981+00:00 app[web.1]:   connection: 'close',
2013-05-03T10:32:05.458231+00:00 app[web.1]:   'accept-encoding': 'gzip, deflate',

... and that is it. Not sure how heroku truncates the output when saving the logs.

Thanks for your help.

Edit : It looks like the issue is somehow linked to the fact that I am connecting via a proxy. When I skip it, the heroku logs correctly display the "if-none-match" header and my app returns the http/304 code. My proxy adds a huge "Proxy-Authorization" token to the request, could it be a length limitation in the headers ?

There are two problems that may be causing the behavior you are observing:

  • Etag and Last-Modifed are redundant headers, you should be using only one of the two. Because your are returning both, a browser may be sending if-modified-since instead of if-none-match. It seems that in your case Last-Modified header is more suitable than Etags.
  • You are not explicitly configuring responses to be cacheable, so a browser may decide not to cache at all. Try returning Cache-Control:public, max-age=2592000, must-revalidate or Expires (but not both)

See also this guide for a good explanation of cache control headers.

A tool like firebug will help you greatly to check what headers the browser sends and receives.