bitmonkey

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.

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.

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/'