troubleshooting rails

So, I had been tracking down a phantom. My error messages didn’t make sense. Everything FastCGI-related seemed to be in tippy top shape. When I launched Webrick instead of trying to run Typo through Apache, I got the weirdest thing ever: Instead of an error, I got a page that simply said:

BRB

        <span id="more-3662"></span>

What the hey, says I!

It so happens that an arrow pierced my Achilles heel. I was disabled not by FastCGI, not by that thing I spent hours troubleshooting and cursing and pleading to, in fact, but by the upgrade to MySQL 4.1 that was performed by the sneaky server ninjas when I had my back turned. And I didn’t find the problem because I was looking in the wrong places.

Interpreting HTTP Errors

HTTP error code 500 means that there’s a server misconfiguration somewhere—it’s almost surely not your Rails code, even though the error page you’ll get (if you haven’t replaced the default) says “Application Error.” If you get one of these, the first place to look is the logs. Your first bet is RAILSROOT/log/.

Note: When you see RAILSROOT somewhere, the author means /path/to/your/railsapp plus whatever else is appended after that. So, the root directory of your Rails application. All-caps signifiers save much uncertainty! Now there’s a phrase we can rally behind!

If you’re lucky and get a more specific error, you can begin to Google for clues. Otherwise, it’s time to hit the error logs. (You may need to hit the error logs even if you can Google your error, but you have no other choice if you have nothing Googleable.)

Super Sleuthing

Ideally you’ll find some files like development.log and maybe production.log and maybe, if you’re really lucky, fastcgi.crash.log or something else that indicates a general sense of malaise. Unless you’ve got a crash log, try the log that suits the mode you’re running in (development, production, or test). I suggest that you read the whole file, or tail it with this command line command:

tail -f 35 production.log

The -f 35 indicates that tail should show you the last 35 lines in the file. If that yields nothing useful, you’ll want to go to your regular Apache (or lighttpd) error logs. In my case, FastCGI is set up in the main httpd.conf file because it doesn’t seem to allow much in the way of settings inside the <VirtualHost> blocks. So, I have to look in the all-inclusive mondo error log:

tail -f 35 /var/log/apache/error_log

Part of the reason it took me so long to realize it was a MySQL connection problem was because I didn’t tail far enough back in the logs. When Ruby on Rails apps go down, they leave a huge trail—a fact I was unaware of until recently. It’s like cheesy extended death scenes in old movies; Robby Rails App is mortally wounded, even though the knife appears suspiciously close to his armpit. Robby Rails App staggers, falls to his knees, looks heavenward, asks us to tell DHH he loves him, and then proceeds to vomit all over the error log, “I’m dying! I’m dying!” for a good 30-40 lines. That’s why I’m suggesting you tail at least 35 lines, and if you don’t see the start of the error then, go back even further! Or just open the whole file, if you dare.

Hunt the Wum—er, Error

“Packets out of Order”

Finally! An error I can work with!

There was a Googleable error in the logs, just 33 lines up. It seemed that the error barfing occurred after the phrase “Packets out of order.” Now that was something I could search for. Although oddly phrased, that’s an error you may get when you have MySQL 4.1 and don’t have the MySQL rubygem installed. While most web apps will continue to work with 4.1 as long as you use the OLD_PASSWORD() trick to make the new 4.1 passwords backwards-compatible, Rails will, instead, give you a “Packets out of order” error. The solution is simple:

sudo gem install mysql

Since FastCGI crashed, it might require you to restart Apache (or lighttpd). But in the end, the solution was simple. It was finding the problem that took the time.

No Comments

  1. anon says:

    tail -f 35 filename isn’t quite the command line you want.

    tail -35 filename will get you the last 35 lines. tail -f filename will get you the last ten lines or so, then continue to watch the file for new lines. tail -35f filename will get you the last 35 lines, then continue to watch the file.

  2. Brad Pauly says:

    tail -n 35 filename

    Will also work. I didn’t know you could use -35. Neat.

Hey, why not get a shiny
Freckle Time Tracking
account?