Under the Hood of the script/server --debugger Option

In Rails you can put debugger calls in your code which will cause a debugger breakpoint if you are running with the --debug option, but do nothing (actually it writes an info level entry to the log ) if you aren't.

The latter is pretty easy, during initialization, ActiveSupport asks Kernel if it responds to :debugger, and if not defines the method to do the log.

The other part involves script/server running this code when it starts up if -u or --debugger was one of the command line options:

  begin
    require_library_or_gem 'ruby-debug'
    Debugger.start
    Debugger.settings[:autoeval] = true if Debugger.respond_to?(:settings)
    puts "=> Debugger enabled"
  rescue Exception
    puts "You need to install ruby-debug to run the server in debugging mode. With gems, use 'gem install ruby-debug'"
    exit
  end

And the rspec command does pretty much the same thing since David picked up my contribution a few releases ago.

Rails 2.2 vs Rails 2.3

My epiphany came when I looked at Rails 2.3.1, and didn't have as much of a deja-vu as I expected. The difference is how that code to conditionally install and start the debugger gets executed.

In Rails 2.2, script/server looks at the first argument to determine whether to run mongrel, lighty, thin, or webrick. If that's not specified it goes through some sniff tests to infer which to run.

It then requires a specific server based script to actually run the server. The mongrel and webrick scripts support the debugger option and run the load code if it is specified.

Rails 2.3.1 does things a bit differently. The script/server program parse the options, then loads the debugger with this snippet of code:

app = Rack::Builder.new {
  use Rails::Rack::LogTailer unless options[:detach]
  use Rails::Rack::Debugger if options[:debugger]
  map map_path do
    use Rails::Rack::Static 
    run inner_app
  end
}.to_app

So the debugger is turned on by inserting a rack middleware, what does this look like?

module Rails
  module Rack
    class Debugger
      def initialize(app)
        @app = app

        require_library_or_gem 'ruby-debug'
        ::Debugger.start
        ::Debugger.settings[:autoeval] = true if ::Debugger.respond_to?(:settings)
        puts "=> Debugger enabled"
      rescue Exception
        puts "You need to install ruby-debug to run the server in debugging mode. With gems, use 'gem install ruby-debug'"
        exit
      end

      def call(env)
        @app.call(env)
      end
    end
  end
end

The code in the initialize method does give me deja-vu!

This is an interesting approach. It's consistent with Rails move to improved configurability using Rack. There's a slight overhead (1 method call per request) due to the passthrough, but that's insignificant in the overall scheme of things, particularly since it's only inserted when you are running with the debugger.

This was a completely blind sampling. I have no idea who the consultant was who wrote this app, nor even the identity of the client who had funded it.

I noticed that there was both a spec and a stories directory in the project a good sign. Looking closer though the specs all seemed to have been generated automatically by the restful_authentication plugin, same thing for the stories.

And the tests were the standard useless stub tests generated by the Rails model/controller generators.

There was some very suspect code in some of the controllers I looked at, one was creating a model in the new action. Normally the new action instantiates an unsaved model instance for use by an edit/creation form, leaving the actual creation of the model in the database to the create action after the form is posted.

The Application controller had some strange looking code, which looked like it might be boilerplate from somewhere. When I googled for a snippet from the code, it looks like it came from somebody’s rails 2.3 template for generating a new rails app using shoulda.

So we have an app which can’t seem to decide which testing framework to use and then not really use any of them to any effect.

Now I know that shoulda, rspec and test::unit can be used in combination by a sophisticated developer, but I don’t think that’s what was going on here.

I poked around in a few models. I found one which really flummoxed me. The model purported to be representing a currency exchange rate for a particular currency on a particular date. The model had a class method average which took a currency and a date range as arguments. Now from the name, I’d expect that this would maybe calculate the average rate for instances for that currency between the first and last dates of the range. Lacking any tests/specs I’ll assume that’s what it would do.

What did it do?

def self.average(currency, date_range)
     first = find(:first, :conditions => ["currency = ? AND issued_on = ?", currency, date_range[0].to_date])
     first ||= find(:first, :conditions => ["currency = ?", currency] , :order => "issued_on"
     last = find(:first, :conditions => ["currency = ? AND issued_on = ?", currency, date_range[1].to_date])
     first ||= find(:first, :conditions => ["currency = ?", currency] , :order => "issued_on ASC"

     median(first.rate, last.rate)
end

protected
def median(a, b)
    (a + b) / 2
end

See anything strange here? Actually I see several.

1. To find the first it looks for an instance for the currency which happened exactly on the starting date. If it doesn’t find one then it finds the first instance for that currency in the database. I would have expected to find the first instance on or after the starting date, which could have been done with a single find call with the right condition.

1. Then to find the last it does what looks like a simple variant of the code to find the first, but is it a variant, instead of finding the last instance for the currency in the database rather than the first it’s going to again find the first. He wanted :order => “issued_on DESC”.

1. What kind of average is being computed here anyway? Average is a generic term, normally we take it to denote the mean, which is the summation of a series of values divided by the number of elements in the series. We’re not doing that here, since we look at only two elements. Now the method being called is median, which is another type of average. You get the medium by sorting the series and picking either the middle element if the series has an odd number of elements, or the mean of the two middle elements. But that’s certainly not what this median method is doing.

Having specs or tests would have helped this guy both think through what he was trying to do, and to realize that it wasn’t working.

So to me it looks like the client had paid for some guy generating a rails app from some templates and plugins and then floundering around with no real idea of how to understand, let alone achieve, the goals of the application.

Like I said in the beginning, it’s not really that you get what you pay for, more like you sometimes get what you pay for. Since I don’t know the rate the client was charged, I don’t know whether he got what he paid for by hiring someone deservedly cheap, or just didn’t get what he paid for.

It’s always a shame when customers don’t get what they pay for, but in the current economy, it’s a real shame when a client burns money hiring someone on the cheap or without real credentials instead of paying someone who might at first look more expensive but would be a bargain in comparison in terms of value for money.

Installing Passenger on Ubuntu 8.10

A bit of help from my friend google, led me to this how-to which I followed. I'm not entirely happy with the approach, since it installs Ruby using the debian package, and I generally prefer to install it from source. I also thought that it installed Rubygems from a package, but looking at it now it seems to have installed it from source, but installed in in /usr/bin which may not be the wisest place on a debian system, it really should be in /usr/local/bin or somewhere else that dpkg/apt-get doesn't muck with. I might need to straighten that out.

I had to hack his scripts a bit as well. They assume that the current directory is on the path, which is something I don't like to do, so I went through and added './' where necessary.

Finally, his script for upgrading to enterprise Ruby for improved performance didn't work, so that's a job for later.

I posted a few comments on the article about this, but as of now they are waiting for moderation.

Typo Upgrade

For those who haven't used it typo comes a a gem which provides a typo command, you use it to either install typo

typo install typo_dir

Either installs the latest version of typo, which is really just a rails app, in typo_dir, or upgrade an existng version.

One of the first things the upgrade does is to backup the database to a yml file. For a blog like mine with a lot of content, this took forever. As I sat there waiting, it occurred to me that I already had a mysql backup, which I'd already used to recreate the database, so I killed the upgrade and hacked the rails-app-installer gem (which typo uses) to skip the backup.

The next hurdle was a gem version problem. I got to the point where the upgrade script was trying to migrate the database, but Rake was failing

	Migrating Typo's database to newest release
	rake aborted!
	RubyGem version error: actionpack(1.13.3 not = 1.13.6)

This was particularly strange since Typo 5.2 runs on Rails 2.2. Somebody was loading the wrong version of rails, and then complaining about the wrong version of actionpack. And the 1.13.6 version of the actionpack gem doesn't seem to be around anymore, probably left behind when Rails moved to github.

So I asked on the typo mailing list, and my former co-worker Ben Burdick gave me the solution:

	sudo gem install datanoise-actionwebservice --source http://gems.github.com

This got me up to the point where I could run the blog on the MacBook. I used the very nice Passenger pane, you just drag the folder containing your rails project into the pane, and restart, and your app is running! Since I wanted to urls to match up. I told passenger pane to use a url of talklikeaduck.denhaven2.com instead of something.local, and put an entry into /etc/hosts to point that name to local host.

Once I was there, it was a matter of recreating the articles which had been lost since the last backup. Mark Imbriacco emailed me what he had cached for each article in his RSS reader. It turned out to be a pretty simple job of cutting and pasting, and telling Typo to publish the articles on their original dates which could be determined by the permalink urls. I didn't worry about the exact time.

I then did a mysqldump of the database, shipped it over to the server with scp, and recreated the database on the server.

Capistrano Deployment

Now the task was setting up Capistrano and having it get the code from git. For the time being I set up a git repository in my home directory on the server, and pushed the code to it from the MacBook over ssh.

The next step was to allow the apache user (which is www-data on debian based systems) to access the repo. This was a matter of generating a public/private key pair in the www-data users home directory, adding the public key part in the .ssh/authorized_keys file in MY home directory, and a

	sudo su - www-data
	ssh rick@localhost
	# answer yes to the prompt to add the host being connected to
	exit

I then upgraded my capistrano gem and capified my typo project. Then I edited the config/deploy.rb based on a couple of blog posts and some trial and error.

  set :application, "talklikeaduck" 
  set :repository, "ssh://rick@aaa.bbb.ccc.ddd/home/rick/git/tlad.git"
  set :scm, :git
  set :branch, "master"
  set :deploy_via, :remote_cache
  set :user, "www-data"
  set :runner, "www-data"
  set :deploy_to, "/var/www/rails/#{application}"

  role :app, "aaa.bbb.ccc.ddd"
  role :web, "aaa.bbb.ccc.ddd"
  role :db,  "aaa.bbb.ccc.ddd", :primary => true

  namespace :deploy do
    desc "Restarting mod_rails with restart.txt"
    task :restart, :roles => :app, :except => { :no_release => true } do
      run "touch #{current_path}/tmp/restart.txt"
    end

    [:start, :stop].each do |t|
      desc "#{t} task is a no-op with mod_rails"
      task t, :roles => :app do ; end
    end
  end

  desc "Link in the production database.yml" 
  task :after_update_code do
    run "ln -nfs #{deploy_to}/#{shared_dir}/config/database.yml #{release_path}/config/database.yml" 
  end

Note that I've replaced the lan address of the server with aaa.bbb.ccc.ddd, it probably wouldn't be a security exposure to show the real address behind the nat, but paranoia is paranoia. Normally I'd use a local dns server name, but I haven't gotten around to setting that back up.

Getting this working was a matter of trying cap deploy:check until I ironed out permissions issues, usually by sshing into the server creating files using sudo, then chowning them to www-data.www-data, since www-data doesn't have sudo privileges.

Then I worked on getting cap deploy:cold to work. More sshing, mkdiring, and chowning to set up the current, releases and shared subdirectories. I'd scratched my head a bit about what to do with config/database.yml which I'd gitignored as usual. Ben pointed me to a blog article which added a post setup task to upload it to the shared directory, but it turned out to be easier to just do it via scp and ssh.

If I recall correctly, the next hurdle was familiar, cap:deploy cold was failing for the same reasons as on the Mac, the gem version problem killing Rake. The solution here was to rake gems:push, git a

	rake gems:unpack
	git add vendor/gems
	git commit
	git push origin
	cap deploy:cold

Now I ran into a problem because I'd missed a bit of code in the deploy.rb from the article I was using a model. It was this piece:

[:start, :stop].each do |t|
  desc "#{t} task is a no-op with mod_rails"
  task t, :roles => :app do ; end
end

Without this capistrano was trying to get the www-data user to sudo to run script/spinner. Before I noticed the omission I was considering writing scripts to stop the server by disabling the virtual host, and reloading apache, and starting in in a similar manner, and giving www-data limited sudo privileges to run those scripts. It turns out that this is unnecessary using Passenger, so it was just a matter of overriding the default capistrano tasks to do nothing.

So now there was joy in Mudville. The cap deploy:cold worked. At this point I created a vhost configuration in /etc/apache2/sites-available, used a2ensite to enable it, and reloaded apache. Now to check it out.

One Last Wafer Thin Mint

Back on the MacBook, I edited /etc/hosts to now point to the servers lan address. I still wasn't ready to expose port 80 of the server to the internets.

I cranked up my browser and reloaded the url. Everything was working! But being the suspicious type, I wanted to make sure. Tailing the log on the server showed no acivity, hmmmm?

I pinged talklikeaduck.denhaven2.com on the MacBook, and it was pinging 127.0.0.1. I knew that I'd changed /etc/hosts. Ben told me over ichat to try dscacheutil -flushcache, which seemed to have no effect. So I rebooted the MacBook, and it was still resolving talklikeaduck.denhaven2.com to localhost.

At that point I tried:

$ dscacheutil -q host 127.0.0.1

Which produced:

name: talklikeaduck.denhaven2.com
ip_address: 127.0.0.1
name: localhost
ip_address: 127.0.0.1
name: talklikeaduck.denhaven2.com
ip_address: aaa.bbb.ccc.ddd

So there were two cache entries, and the local host one was winning.

I finally got a clue when I grepped /etc for references to talklikeaduck, and found one in /etc/hosts, but also one in /etc/apache2/sites-available/tlad which was the vhost configuration generated by Passenger pane. When I removed the blog project directory from the Passenger pane, and hit restart, then did the dscacheutil -flushcache, the name was now resolving to the server.

Now I was hitting the server, and I did a little more prodding to make sure things were working, including writing my resurrection announcement.

Now I was finally ready to unblock port 80 on the router.

Hopefully someone will find something useful in this post, at least I've captured the lessons I learned from the exercise.