www.flickr.com
Michael Kovacs' photos More of Michael Kovacs' photos
Recommend Me Cable Car Software logo

Saturday, April 22, 2006

Rails realities part 11 (semi-frozen rails)

You know those times when something all of a sudden stops working for seemingly no reason at all? Well about a half hour ago was one of those times for my rails app. Here I was making what should've been a minor and harmless change to one of my controllers to validate some session data before calling an action. I made my change, ran my tests, everything was fine. Went to restart my production application and bam! I get this:

$ restart.sh
Stopping lighttpd.
Waiting for PIDS: 52846.
No matching processes belonging to you were found
Starting lighttpd.
Rails running in: productionspawn-fcgi.c.186: child spawned successfully: PID: 53350
Rails running in: productionspawn-fcgi.c.186: child spawned successfully: PID: 53353
$ /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:200:in `const_missing': uninitialized constant Builder (NameError)
from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view/helpers/prototype_helper.rb:733
from /usr/local/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:21:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:214:in `require'
from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view/base.rb:202:in `load_helpers'
from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view/base.rb:200:in `load_helpers'
from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view.rb:32
from /usr/local/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:21:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:214:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/actionpack/lib/action_controller.rb:58
from /usr/local/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:21:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:214:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/railties/lib/initializer.rb:125:in `require_frameworks'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/railties/lib/initializer.rb:125:in `require_frameworks'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/railties/lib/initializer.rb:80:in `process'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/railties/lib/initializer.rb:42:in `run'
from /users/home/mkovacs/loanback_current/public/../config/environment.rb:11
from /users/home/mkovacs/loanback_current/public/dispatch.fcgi:21
using frozen rails/users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:200:in `const_missing': uninitialized constant Builder (NameError)
from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view/helpers/prototype_helper.rb:733
from /usr/local/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:21:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:214:in `require'
from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view/base.rb:202:in `load_helpers'
from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view/base.rb:200:in `load_helpers'
from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view.rb:32
from /usr/local/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:21:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:214:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/actionpack/lib/action_controller.rb:58
from /usr/local/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:21:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:214:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/railties/lib/initializer.rb:125:in `require_frameworks'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/railties/lib/initializer.rb:125:in `require_frameworks'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/railties/lib/initializer.rb:80:in `process'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/railties/lib/initializer.rb:42:in `run'
from /users/home/mkovacs/loanback_current/public/../config/environment.rb:11
from /users/home/mkovacs/loanback_current/public/dispatch.fcgi:21
using frozen rails


Huh? WTF? I just did a simple update. The site's been running for weeks just fine. I have rails frozen to 1.0 so that shouldn't be an issue. Or is it? Well for those keeping score at home, looking at the above stack trace you can see that my "frozen" rails is melting and leaking outside of the /vendor/rails directory for initialization. Now I'm not an expert at how rails is put together and quite honestly I don't know that I want to be but there appears to be something wrong right here:

from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view.rb:32
from /usr/local/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:21:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:214:in `require'

and here:

from /usr/local/lib/ruby/gems/1.8/gems/actionpack-1.12.1/lib/action_view/helpers/prototype_helper.rb:733
from /usr/local/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:21:in `require'
from /users/home/mkovacs/loanback_current/public/../config/../vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:214:in `require'

Those two areas of the stacktrace show that a require is going outside of the /vendor/rails installation and leaking on to the local gems for actionpack.

Obviously my belief that checking out the tagged 1.0 release of rails into my app's vendor/rails directory as being frozen was wrong. It was also wrong for me to be sleeping well thinking that it's not possible for textdrive to change the version of rails on the server and have my app break out from under me. Welp, guess I was wrong about that one. My app is using the frozen version to start, as you can tell by both my stack trace and my print statement "using frozen rails".

So when folks talk about something being "enterprise ready" this is the stuff that they're referring to. So I'm not certain that this isn't somehow my fault because I've not heard of another single person that's come across this problem. The only thing that I can think of is that I didn't do my "freeze" properly? A directory listing of /vendor/rails shows the following:

mkovacs@production_machine$ cd vendor/rails/
mkovacs@production_machine$ ls -la
total 24
drwxr-xr-x 9 mkovacs mkovacs 512 Mar 29 13:44 .
drwxr-xr-x 5 mkovacs mkovacs 512 Mar 29 13:44 ..
drwxr-xr-x 7 mkovacs mkovacs 512 Mar 29 13:44 .svn
drwxr-xr-x 5 mkovacs mkovacs 512 Mar 29 13:44 actionmailer
drwxr-xr-x 6 mkovacs mkovacs 512 Mar 29 13:44 actionpack
drwxr-xr-x 6 mkovacs mkovacs 512 Mar 29 13:44 actionwebservice
drwxr-xr-x 7 mkovacs mkovacs 512 Mar 29 13:44 activerecord
drwxr-xr-x 5 mkovacs mkovacs 512 Mar 29 13:44 activesupport
-rwxr-xr-x 1 mkovacs mkovacs 75 Mar 29 13:44 cleanlogs.sh
-rwxr-xr-x 1 mkovacs mkovacs 489 Mar 29 13:44 pushgems.rb
drwxr-xr-x 13 mkovacs mkovacs 512 Mar 29 13:44 railties
-rwxr-xr-x 1 mkovacs mkovacs 901 Mar 29 13:44 release.rb
mkovacs@production_machine$

That looks like everything is there to me. Has anyone else had this problem? Unfortunately this forced me to upgrade my app to 1.1.2 on my production server right now in order for my site to get back up and running. Luckily I was able to do this after fixing a few problems that came up in the upgrade. Even though I fixed it and the site was down for only 30 minutes this is NOT the type of problem that I take lightly as it takes years off of your life as you scramble to fix things, all the while cursing rails and how you were lied to about your rails gems being frozen.

Rails team, I love the new features in 1.1. You guys have been totally crankin and are doing a hell of a job. That said please take the time to ensure that things like this are not issues. It doesn't matter how many cool new features are added to the framework if things like error messages, load paths, and other fundamental mechanisms aren't robust. I realize that rails is not even 2 years old and this pain is part of being an early adopter but these kinds of problems are showstoppers when it comes to trusting your business to a framework.

Comments:
I'm sorry to hear that you had a problem with a Rails app. It's never fun to have problems with your applications. Whether they're writing with Rails or something else.

But let me get this straight. You hit what looked like a bug, you upgraded to the latest version where the bug was fixed, yet still this has something to do with "enterprisey ready"? What?

I'm all for theatrics, they can be fun and sometimes even effective, but really now. You must have had the good fortune never to wrangle classpath lizards with Java or ever hit bug on some system that was caused by upgrading a library, or other shared piece, on a shared host no less, if this can cause such drama.

In that case, I envy your shielded life ;)
 
Hey David,

Unfortunately I missed your comment back a couple of months ago. Of course I've had my share of classpath lizards, but my point here was that rails being frozen doesn't appear to be the truth. Now to be fair I'm not so sure that this isn't a problem to take up with my host, TextDrive, as it maybe was environment, but at the same time I don't think you can deny that there was definitely an issue here that was unrelated to my change.

The fundamental issue is that you can *think* that you're running a version of rails but don't have a way to verify that to be the truth. Of course this problem exists in the Java world with classpath problems, but in this instance it would be pretty easy to be able to have some sort of monitoring tool where I can validate that the version of rails I think I'm running is actually that version. Maybe there is something to do that with that I don't yet know about.

And as far as shielding goes, it's actually because of the past pain that I want something to shield me from the nightmare of incorrect libraries and load paths. But actually yes, this is my first venture into deploying on a shared host so perhaps I have been shielded ;-) I'm all for removing unecessary burden and process but as much as I enjoy writing my rails apps (again thumbs up for all your work on rails David), I still think that there's more that could be done to make rails even better (improvements in deployment and AR) and take it to that place you deny you want to go (mainstream), but I don't believe you ;-)
 
Hi Michael,
I can see it's quite an old post, but your last comment suggests you still had no clue about what was going on. Since I've been bitten by the same problem recently (freezing on 1.1.6), I can tell you that the most likely source of your woes is the Engines plugin messing with internal Rails dependency loading machinery. Are you using any engine? Engines guys are quite quick in fixing their stuff (I was actually running an old version), but you should be aware Engines is not a Rails supported technology and a using it is considered an evil
thing you shouldn't be doing
by someone :)
 

Post a Comment





<< Home

This page is powered by Blogger. Isn't yours?