Rails test hanging - how can I print the test name before execution?

Question

I'm having a test hang in our rails app can't figure out which one (since it hangs and doesn't get to the failure report). I found this blog post http://bmorearty.wordpress.com/2008/06/18/find-tests-more-easily-in-your-testlog/ which adds a setup hook to print the test name but when I try to do the same thing it gives me an error saying wrong number of arguments for setup (1 for 0). Any help at all would be appreciated.

Answer 1

can you just hit ctrl+c to halt the execution and it will display the stack trace of where you halted the execution?

Answer 2

The stack trace is only about 15 lines, all of which are deep in some gem so I can't see what test is actually causing the problem.

Answer 3

Okay, that's grand, if we didn't already have 500 tests written with Test/Unit we might consider it. Test/Unit also displays a report at the end which shows what tests failed and on which lines, the problem is the test is HANGING so it doesn't get to the reporting stage. RSpec would have the same problem if the test hung.

Answer 4

The definition in the blog post is shoulda specific (the setup(&block) method is defined in the module Thoughtbot::Shoulda in context.rb. shoulda.rb then has TestCase extend that module).

The definition for pure test::unit is

# File test/unit/testcase.rb, line 100
      def setup
      end

what you could do is

def setup
  log_test
end  

private   

def log_test   
  if Rails::logger  
    # When I run tests in rake or autotest I see the same log message multiple times per test for some reason.   
    # This guard prevents that.   
  unless @already_logged_this_test  
    Rails::logger.info "\n\nStarting #{@method_name}\n#{'-' * (9 + @method_name.length)}\n"  
  end  
  @already_logged_this_test = true  
end

---

edit

if you really don't want to edit your files you can risk reopenning test case and extend run instead :

class Test::Unit::TestCase   
  alias :old_run :run
  def run 
    log_test
    old_run
  end
end

this should work (I don't have ruby around to test though)

---

I give up ! (in frustration)

I checked the code and rails actually does magic behind the scene which is probably why redefining run doesn't work.

The thing is : part of the magic is including ActiveSupport::CallBack and creating callbacks for setup and teardown.

which means

class Test::Unit::TestCase
  setup :log_test  

  private   

  def log_test   
    if Rails::logger  
      # When I run tests in rake or autotest I see the same log message multiple times per test for some reason.   
      # This guard prevents that.   
      unless @already_logged_this_test  
        Rails::logger.info "\n\nStarting #{@method_name}\n#{'-' * (9 + @method_name.length)}\n"  
      end  
      @already_logged_this_test = true  
    end  
  end  
end

should definitely work

and actually running tests with it does work. where I am confused is that this is the first thing I tried and it failed with the same error you got

Answer 5

@Jean - if I just define setup in testcase.rb it will get blown away when we define setup in the actual test (or will override the setup in the individual tests). I could go through each of our test files and add log_test to each setup method, that's pretty annoying though, figured there would be an easier way to hook into that with ruby.

edit

@Jean - We went through the same thought process :). Trying that worked when running an individual test class, but when running the whole suite i got a stack error, it seemed to be caught in a loop on the run call (it output the first tests name 30 times before crashing).

Answer 6

The printing of the test name is the responsibility of the TestRunner. If you are running your tests from the command line you can specify the -v option, to print out the test case names.

example:

ruby test_Foo.rb -v
Loaded suite test_Foo
Started
test_blah(TestFoo): .
test_blee(TestFoo): .

Finished in 0.007 seconds.

2 tests, 15 assertions, 0 failures, 0 errors

Answer 7

This is what I use, in test_helper.rb

class Test::Unit::TestCase
  # ...

  def setup_with_naming 
    unless @@named[self.class.name]
      puts "\n#{self.class.name} "
      @@named[self.class.name] = true
    end
    setup_without_naming
  end
  alias_method_chain :setup, :naming unless defined? @@aliased
  @@aliased = true  
end

The @@aliased variable keeps it from being re-aliased when you run it on multiple files at once; @@named keeps the name from being displayed before every test (just before the first to run).

Answer 8

Thanks everyone for the help, I ended up going through the tests and adding a call to log_name in each of the setup methods for each test file before these last couple answers came up. Thanks again.

Answer 9

If you run test using rake it will work:

rake test:units TESTOPTS="-v"