Examples

This example ties together several of the techniques we have seen in this chapter. We return to the Person example, where we want to time several expensive methods:

	class Person
	  def refresh
	    # ... 
	  end

	  def dup 
	    # ... 
	  end
	end

In order to deploy this to a production environment, we may not want to leave our timing code in place all of the time because of overhead. However, we probably want to have the option to enable it when debugging. We will develop code that allows us to add and remove features (in this case, timing code) at runtime without touching the original source.

First, we set up methods wrapping each of our expensive methods with timing commands. As usual, we do this by monkeypatching the timing methods into Person from another file to separate the timing code from the actual model logic: [12].

	class Person
	  TIMED_METHODS = [:refresh, :dup]
	  TIMED_METHODS.each do |method|
	    # set up _without_timing alias of original method
	    alias_method :"#{method}_without_timing", method

	    # set up _with_timing method that wraps the original in timing code
	    define_method :"#{method}_with_timing" do
	      start_time = Time.now.to_f
	      returning(self.send(:"#{method}_without_timing")) do
	        end_time = Time.now.to_f

	        puts "#{method}: #{"%.3f" % (end_time-start_time)} s."
	      end
	    end
	  end
	end

We add singleton methods to Person to enable or disable tracing:

	class << Person
	  def start_trace
	    TIMED_METHODS.each do |method|
	      alias_method method, :"#{method}_with_timing"
	    end
	  end

	  def end_trace
	    TIMED_METHODS.each do |method|
	      alias_method method, :"#{method}_without_timing"
	    end
	  end
	end

To enable tracing, we wrap each method call in the timed method call. To disable it, we simply point the method call back to the original method (which is now only accessible by its _without_timing alias).

To use these additions, we simply call the Person.trace method:

	p = Person.new
	p.refresh # => (...)

	Person.start_trace
	p.refresh # => (...)
	# -> refresh: 0.500 s.

	Person.end_trace
	p.refresh # => (...)

Now that we have the ability to add and remove the timing code during execution, we can expose this through our application; we could give the administrator or developer an interface to trace all or specified functions without restarting the application. This approach has several advantages over adding logging code to each function separately:

  • The original code is untouched; it can be changed or upgraded without affecting the tracing code.

  • When tracing is disabled, the code performs exactly as it did before tracing; the tracing code is invisible in stack traces. There is no performance overhead when tracing is disabled.

However, there are some disadvantages to writing what is essentially self-modifying code:

The Rails routing code is perhaps some of the most conceptually difficult code in Rails. The code faces several constraints:

Because of the speed needed in both generation and recognition, the routing code modifies itself at runtime. The ActionController::Routing::Route class represents a single route (one entry in config/routes.rb). The Route#recognize method rewrites itself:

	class Route
	  def recognize(path, environment={})
	    write_recognition
	    recognize path, environment
	  end
	end

The recognize method calls write_recognition, which processes the route logic and creates a compiled version of the route. The write_recognition method then over-writes the definition of recognize with that definition. The last line in the original recognize method then calls recognize (which has been replaced by the compiled version) with the original arguments. This way, the route is compiled on the first call to recognize. Any subsequent calls use the compiled version, rather than having to reparse the routing DSL and go through the routing logic again.

Here is the body of the write_recognition method:

	def write_recognition
	  # Create an if structure to extract the params from a match if it occurs.
	  body = "params = parameter_shell.dup\n#{recognition_extraction * "\n"}\nparams" 
	  body = "if #{recognition_conditions.join(" && ")}\n#{body}\nend"

	  # Build the method declaration and compile it
	  method_decl = "def recognize(path, env={})\n#{body}\nend"
	  instance_eval method_decl, "generated code (#{__FILE__}:#{__LINE__})"
	  method_decl
	end

The local variable body is built up with the compiled route code. It is wrapped in a method declaration that overwrites recognize. For the default route:

	map.connect ':controller/:action/:id'

write_recognition generates code looking like this:

	def recognize(path, env={})
	  if (match = /(long regex)/.match(path))
	    params = parameter_shell.dup 
	    params[:controller] = match[1].downcase if match[1]
	    params[:action] = match[2] || "index"
	    params[:id] = match[3] if match[3]
	    params
	  end
	end

The parameter_shell method returns the default set of parameters associated with the route. This method body simply tests against the regular expression, populating and returning the params hash if the regular expression matches. If there is no match, the method returns nil.

Once this method body is created, it is evaluated in the context of the route using instance_eval. This overwrites that particular route's recognize method.



[12] This code sample uses variable interpolation inside a symbol literal. Because the symbol is defined using a double-quoted string, variable interpolation is just as valid as in any other double-quoted string: the symbol :"sym#{2+2}" is the same symbol as :sym4