Love Your Logs

Log files are an invaluable tool. They are snapshots in time of so many different components of your application and can be, or should be, key elements in debugging and evaluating the overall health of your app. And I’m here to admit that I haven’t relied on them nearly as much as I should have.

For the past few months (yes, months), I’ve had ongoing issues with my local development environment. I would rarely get through a day without having to restart Apache… usually more than once. What would happen is that I’d be working, reloading the site in a browser, and eventually my stylesheets wouldn’t load, or certain images on the page didn’t load. At that point, I knew I’d need to restart Apache. This “fix” worked, but was a band-aid as opposed to an actual cure.

My setup is OS X (10.6.8), Railo 3.2, Tomcat 6.0, and Apache 2.2. My boss was running the exact same setup, pulling from the same Git repository, but was not experiencing the same need to frequently restart Apache. I chalked it up to “something’s not right” (my wisdom knows no bounds), but was content to continue restarting Apache as needed.

Yesterday, my hand was forced.

I was still able to work… with the need to restart Apache every so often… but when I tried to run a build (which is a combination of unit tests, integration tests, and Selenium tests), I could not successfully complete the process. Apache would die during the Selenium tests, resulting in numerous failures. Even restarting Apache right before running the build, the service would fail before the build finished running.

My first course of action was shutting everything down and rebooting. I grew up on Windows machines, and old habits die hard. Of course, that didn’t work. Whatever had been brewing for the past few months needed to be addressed. It finally occurred to me to check my Apache log files.

The first thing I noticed was that my error_log was 300MB. That’s a pretty sizable log file. I fired up a new terminal window and did a tail -f /private/var/log/apache2/error_log and immediately saw the following:

[Wed Jul 06 19:24:08 2011] [notice] jrApache[1214: 48122]  could not initialize proxy for
[Wed Jul 06 19:24:08 2011] [notice] jrApache[1214: 48122]  could not initialize proxy for
[Wed Jul 06 19:24:08 2011] [notice] jrApache[1214: 48122]  could not initialize proxy for
[Wed Jul 06 19:24:08 2011] [notice] jrApache[1214: 48122]  Couldn't initialize from remote server, JRun server(s) probably down.

Those notices were showing up fast and furious. A lot. What was happening was that the Adobe ColdFusion installer sets up the Apache connector in the httpd.conf file. But because I didn’t have Adobe ColdFusion running locally, and haven’t for some time, these notices were adding up in the log file. Commenting out the following line from my httpd.conf made Apache run much happier:

# LoadModule jrun_module /Applications/JRun4/lib/wsconfig/1/

As Sean pointed out to me, given that I’m running both Railo and Adobe ColdFusion, it would be better to move the JRun configurations out of httpd.conf and into the VirtualHost settings for each site that’s running under ACF.

The moral of the story, having nothing to do with Apache or JRun or Tomcat or ColdFusion or Railo, is that I could have addressed the issue when it first arose, back when it was a mere inconvenience rather than a show-stopper. It didn’t have to get to that point, and it never should have. I knew Apache was failing on me at least once per day. I knew there was something wrong. Had I simply had the presence of mind to tail the Apache error_log back then, I would have saved myself quite a bit of time in restarting the Apache service so many times over the last few months.

There really is a wealth of information in your log files. Even if you’re not currently experiencing an issue, they’re worth looking at, as you might find something before it becomes an issue. From now on, I’ll certainly have terminal windows open tailing both my Tomcat log (catalina.out) as well as my Apache error_log.