Logging non-proxy IP addresses in Heroku and Express for node.js

Back when I built the Is Septa Fucked? website, I decided to use Heroku seeing how they supported node.js and I wouldn't have to worry about sysadmin tasks. Heroku proved to be a great choice, but along the way I noticed some strange log entries like these:

2013-01-05T03:26:41+00:00 app[web.1]: 10.44.130.226 - - 
   [Sat, 05 Jan 2013 03:26:41 GMT] "GET /favicon.ico HTTP/1.1" 200 
   - "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_6_8)"

Net 10.0.0.0/8 is normally non-routable, so it shouldn't be showing up in server logs like that. It turns out that Heroku uses reverse HTTP proxies to handling incoming traffic for their customer apps. That proxy then forwards the traffic to your application after storing the original client's IP address in the HTTP "X-Forwarded-For:" header.

To change how logfiles are written in Express, you have to mess around with the logger module, which is part of the connect library, and available within express as express.logger.

The first thing to do in node.js is to create a new "token" in the logger module which will extract the IP address from the X-Forwarded-For header:


//
// Create an IP token for the logging system that lists the original IP, 
// if there was a proxy involved.
//
express.logger.token("ip", function(request) {

   var retval = "";

   if (request["headers"] && request["headers"]["x-forwarded-for"]) {
      //
      // Proxied request
      //
      retval = request["headers"]["x-forwarded-for"];

   } else if (request["socket"] && request["socket"]["remoteAddress"]) {
      //
      // Direct request
      //
      retval = request["socket"]["remoteAddress"];

   } else if (request["socket"] && request["socket"]["socket"]
      && request["socket"]["socket"]["remoteAddress"]) {
      //
      // God only knows what happened here...
      //
      retval = request["socket"]["socket"]["remoteAddress"];

   }

   return(retval);

});

Next, you need to tell the logger module to write that new token out in log entries. You can only list the source IP if you want, but I like to include the proxy IP as well for debugging purposes:

express.logger.format("default", 
   ':ip :remote-addr - - [:date] ":method :url HTTP/:http-version" '
   + ':status :res[content-length] ":referrer" ":user-agent"'
);

Finally, create your server and include the logger. This is from Express 2.x, but should also work under Express 3.x:

var app = express.createServer(express.logger());

Restart your server, and you'll see your logs now looking like this:

2013-01-05T03:28:41+00:00 app[web.1]: 71.220.110.202 10.44.130.226 
   - - [Sat, 05 Jan 2013 03:26:41 GMT] "GET /favicon.ico HTTP/1.1" 200 - "-" 
   "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_6_8)"

If you have any questions or run into any problems, feel free to drop me a line. Otherwise, enjoy!

3
Average: 3 (4 votes)
Your rating: None