bitmonkey

Make your library a better citizen

Sat, 27 Mar 2010 14:52:36 -0700

I’ve recently ran into a case where I wanted the Rails logger to be at :debug level, but really didn’t care about the debug output from the Hoptoad plugin. It kept giving a big XML dump every time it reported an exception which just added noise to the log file that wasn’t relevant.

I’ve found many plugins including Dash (may it rest in peace) and Hoptoad who would steal the logger from Rails and reference that internally.

Here’s the logger in hoptoad:

# Look for the Rails logger currently defined
def logger
  if defined?(Rails.logger)
    Rails.logger
  elsif defined?(RAILS_DEFAULT_LOGGER)
    RAILS_DEFAULT_LOGGER
  end
end

Many times it’s useful to run your staging environment (or even production) with debug logging enabled, but the downside was that now all of these plugins would be logging at that level as well.

One little change that plugin authors can start to do to help the rest of us out is make sure you #dup the logger before you grab a copy.

def logger
  @logger ||= if defined?(Rails.logger)
    Rails.logger.dup
  elsif defined?(RAILS_DEFAULT_LOGGER)
    RAILS_DEFAULT_LOGGER.dup
  end
end

This would allow us to then say:

Hoptoad.logger.level = Logger::WARN

and escape all of the noise from plugins that we don’t care about.

Much thanks to Bruce Williams for first proposing this trick.

PSA: Doing less is more with system and exec

Wed, 20 Jan 2010 14:01:49 -0800

I’ve come across a lot of cases where people take an array of arguments and turn it into a string before passing them to system or exec. I want to spread the news that it isn’t needed and that we can save ourselves from bugs in the future with a little less code.

I don’t mean to pick on defunkt specifically — it’s a pattern I see all the time, but this example is one I had available:

def self.perform(*args)
  script = args.join(' ')
  puts "$ #{script}"
  Open3.popen3(args.join(' ')) do |stdin, stdout, stderr|
    puts stdout.read.inspect
  end
end

You can see the code on GitHub here.

What is Open3.popen3 really doing? It calls a bunch of stuff, like IO::pipe, but in the end, it calls exec with the same arguments that were passed to it:

exec(*cmd)

You can see the whole source for popen3 here.

What happens if we pass a multi-word argument to perform?

ShellJob.perform('rm', '/Library/Keyboard Layouts/Qwerty.bundle')

The arguments are joined and turn into:

"rm /Library/Keyboard Layouts/Qwerty.bundle"

When this is passed to the ruby exec method, the results are parsed with the ruby shell argument parser and it ends up with a child process holding an ARGV of:

["rm", "/Library/Keyboard", "Layouts/Qwerty.bundle"]

…but this isn’t what we wanted!

To understand the basics of what is going on, we have to understand the underlying call that the ruby interpreter calls: execv(3):

int
execv(const char *path, char *const argv[]);

The argv[] array that is passed into execv(3) is copied into the child process as ARGV. Handy isn’t it?

The problem is, there is no version of the C function that takes a single char * of all of the arguments and Does The Right Thing. Because of this, the ruby interpreter has to fake it, using an approximation of how the shell parses arguments.

But there is a better way.

From the documentation for Kernel#exec (emphasis mine):

Replaces the current process by running the given external command. If exec is given a single argument, that argument is taken as a line that is subject to shell expansion before being executed. If multiple arguments are given, the second and subsequent arguments are passed as parameters to command with no shell expansion.

What’s great is, in this case (and in a lot of them), we actually already have an array with all of the arguments in it.

So, we can actually just change the popen3 line to say:

Open3.popen3(*args) do |stdin, stdout, stderr|

and everything will work the way we want.

You can see the full code on GitHub here.

Making it easy to run a single test

Fri, 15 Jan 2010 15:48:10 -0800

In the course of normal development I find myself focusing on specific tests that I want to make sure work properly before moving on to testing the entire test suite.

There is a really great argument to test/unit called --name which will allow you to specify the test to run.

The test/unit rake tasks provide the TESTOPTS environment variable as a means to pass options to the tests runner. To run a specific test we can add our --name option to TESTOPTS like this:

$ rake test:units TEST=test/unit/user_test.rb TESTOPTS="--name=test_should_create_user"

The --name option even takes a regular expression, so we can even do this:

$ rake test:units TEST=test/unit/user_test.rb TESTOPTS="--name='/create_user/'"

Because it’s a pain in the ass to remember the option as well as doing the right amount of escaping and quoting, I created a simple rake task that you can have run before your real test tasks to set TESTOPTS for you. It looks in the TESTNAME environment variable and if it exists, sets TESTOPTS with the correct value.

To pull this off, you can just put the following in lib/tasks/test_name.rake:

namespace :test do
  task :populate_testopts do
    if ENV['TESTNAME'].present?
      ENV['TESTOPTS']  = ENV['TESTOPTS'] ? "#{ENV['TESTOPTS']} " : ''
      ENV['TESTOPTS'] += "--name=#{ENV['TESTNAME'].inspect}"
    end    
  end
end

%w(test:units test:functionals test:integration).each do |task_name|
  Rake::Task[task_name].prerequisites << 'test:populate_testopts'
end

You can find the gist here.

The only thing tricky about this code is that we go and stick an entry in the prerequisites array that each Rake::Task has to make sure that it runs our environment filter code before it runs the task itself.

Once we’ve done that, we can run the tests we want with:

$ rake test:units TEST=test/unit/user_test.rb TESTNAME='/create_user/'

Quick tip for up-to-date Scout graphs

Thu, 07 Jan 2010 16:34:00 -0800

One of the things that’s always made me sad when using Scout has been having to refresh the page to reload the graphs.

Fortunately amcharts, the charting engine used by Scout, has the ability to do refreshing.

Here’s a nice little bookmarklet to make the Scout graphs refresh every 60 seconds.

Drag this link: Scout Reload

To install the bookmarklet, drag the “Scout Reload” link to your bookmark bar.

To use it, click on the bookmarklet when you are on a Scout graph page.

For more hints on how to install bookmarklets, you can see how to install the Delicious bookmarklet here.

What is it doing?

Amcharts provides all sorts of great functionality, including a simple refresh mechanism.

What we do is update the XML configuration via javascript with this chunk:


  
    60
    false
    true

To send that chunk of XML to the chart is very strait forward. We just get a reference to the DOM object that is the chart and call setSettings on it, passing it the XML we want:

$("#amstock").get(0).setSettings(xml_settings_string);

Abusing HTTParty for a Tender client

Wed, 06 Jan 2010 21:22:05 -0800

We all know how great Tender is and had a chance to play with their great API while writing a tool to send out an email every morning with any pending issues.

They’ve done some really great stuff with it, especially with their use of URI Templates.

If you haven’t played with URI Templates before, an example of their JSON with a template in it looks like:

{"site_href": "http://api.tenderapp.com/{site_permalink}"}

which, with the Addressable gem would allow us to say:

>> require 'addressable/template'
>> tmpl = Addressable::Template.new('http://api.tenderapp.com/{site_permalink}')
>> tmpl.expand('site_permalink' => 'help').to_s
=> http://api.tenderapp.com/help

To make things nice and strait forward, Tender follows the convention of using _href as the suffix for any key that contains a template. I was able to use this along with a little magic I snuck into Hash to make my code that much prettier.

All that was required to expand the templates was a little module:

module JsonHelpers
  def href(key, opts = {})
    Addressable::Template.new(self["#{key}_href"]).expand(opts).to_s
  end
end

which I was able to mix in to any Hash that was returned:

# Make the JSON a litte bit more fun to work with
def self.add_json_helpers(data)
  case data
  when Hash
    data.send(:extend, TenderSummary::JsonHelpers)
    data.each { |_, value| add_json_helpers(value) }
  when Array
    data.each { |elem| add_json_helpers(elem) }
  end
  data
end

and then tell HTTParty to use it by specifying a custom parser:

module TenderSummary
  class TenderApi
    include HTTParty

    headers  'Accept' => 'application/vnd.tender-v1+json'
    format   :json
    parser   Proc.new { |b| add_json_helpers(Crack::JSON.parse(b)) }

    # ...

With all this done, it made it very simple to generate the URLs to the resources I wanted access to.

# assuming `site` holds the JSON returned from
# 'http://api.tenderapp.com/{site_permalink}'
discussion_url = site.href(:discussions, :state => :pending)

You can see the entire class of TenderApi on GitHub.

Tracking initial memory usage by file in Ruby

Wed, 30 Dec 2009 11:21:00 -0800

I’ve found that as a project progresses, the initial memory usage of a Rails application seems to grow more and more.

The more time I spend trying to track down memory leaks (or just pieces of code that use more memory than they should) the more I realize that it’s a fairly imprecise science. I’ve had the best luck using tools to give me a good idea of where to start poking around. From there it’s just a matter of looking at the code and finding what silly things people are doing.

If I wanted to see what was contributing to the large memory footprint of an application on startup, tracking how much memory was allocated during each require would give me a good place to start.

The code to do this is amazingly strait forward:

module RequireTracking
  def require(*args)
    start_size = GC.allocated_size
    super
  ensure
    $require_stats[args.first] += (GC.allocated_size - start_size)
  end
end

Object.send(:include, RequireTracking)
Kernel.send(:include, RequireTracking)

The entire implementation is available as a gist on GitHub.

The GC.allocated_size method is included in the RailsBench GC patch which is part of the Ruby Enterprise Edition interpreter.

One thing to understand is this is only tracking how much memory was allocated but not how much was freed. This will cause these statistics to include memory that was temporarily allocated and then no longer referenced. This can be useful because even temporarily using lots of memory can negatively impact startup time.

Another aspect to understand is the numbers we are tracking are what are normally called “self + children” in profilers. This means that all memory allocated by a file as well as anything allocated by files that are required from it are included in the statistics. This results in the same memory being counted multiple times, but is useful in understanding the total memory implications of requiring a file.

Running this on one of the projects I was working on found this little gem:

class Webster
  DICTIONARY = File.open(File.join(File.dirname(__FILE__), 'words')) do |file|
    file.readlines.collect {|each| each.chomp}
  end

  def random_word
    DICTIONARY[rand(DICTIONARY.size)]
  end
end

You can find the source on GitHub here.

This would be a prime candidate for refactoring if you are worried about your memory usage.

Add NewRelic instrumentation for ThinkingSphinx

Tue, 29 Dec 2009 17:11:00 -0800

NewRelic provides a really great mechanism in their plugin to instrument just about anything.

One of the things I found when analyzing actions in NewRelic was that all of the time that was being spent in the ThinkingSphinx methods were being attributed to the template instead of the model. As we all know, mis-attribution of time spent can make tracking down trouble spots in your code much more difficult.

It ends up that all that is required to start tracking the time you are searching in ThinkingSphinx is a couple calls to add_method_tracer:

  add_method_tracer :search, 'ActiveRecord/#{self.name}/search'
  add_method_tracer :search, 'ActiveRecord/search', :push_scope => false
  add_method_tracer :search, 'ActiveRecord/all', :push_scope => false

You can see the full code here.

Once you’ve required the code, you’ll start to see the #search and #search_count methods show up in your Performance Breakdowns:

Isn’t that sweet?

Update: NewRelic has some great documentation for Custom Metric Collection if you want to do more.