Complete backtrace?

[Dagnan]

Hi.

My test raises an exception, due to active record, but the backtrace contains only one line so I can't see where it has been raised. Is there a way to expand the backtrace output?

[trans]

If you use turn command line to run the tests instead of using the require form, you can always run the tests without turn too.

Also try some of Turn's other output formats and see what you get --I can't recollect offhand the exact output of each so just try them out.

Maybe a --verbose option might be useful for future version.

[Dagnan]

But I can't use the turn command, I get

/home/me/.rvm/rubies/ruby-1.9.2-p136/lib/ruby/1.9.1/test/unit/assertions.rb:5:in <module:Test>': Unit is not a module (TypeError) from /home/michel/.rvm/rubies/ruby-1.9.2-p136/lib/ruby/1.9.1/test/unit/assertions.rb:4:in<top (required)>'

I did not take the time to figure out why yet. Do you have an idea?

[trans]

Hmm... what are you requiring in your tests/test_helper?

Is your code online by chance?

[trans]

My first guess is that it has something to do with Test::Unit being used when MiniTest should be. Not sure though without more info.

[Dagnan]

Hi. Sorry I did not respond earlier.

I still have this problem with the turn command. I'm using default files generated by Rails 3.0.4 (I'm using Ruby 1.9.2p136)
rails/test is required in test_helper.
So nothing very fancy.

[trans]

Try the --debug option to get more info on the problem. Also a recent patch that adds --trace option would help, but has not been release yet.

[Dagnan]

Looks like the same output:

$ bundle exec turn -Itest test/unit/place_test.rb --debug
/path/.rvm/rubies/ruby-1.9.2-p136/lib/ruby/1.9.1/test/unit/assertions.rb:5:in `': Unit is not a module (TypeError)
    from /path/.rvm/rubies/ruby-1.9.2-p136/lib/ruby/1.9.1/test/unit/assertions.rb:4:in `'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `require'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `block in require'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:227:in `load_dependency'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `require'
    from /path/.rvm/rubies/ruby-1.9.2-p136/lib/ruby/1.9.1/test/unit.rb:4:in `'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `require'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `block in require'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:227:in `load_dependency'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `require'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/railties-3.0.4/lib/rails/test_help.rb:5:in `'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `require'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `block in require'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:227:in `load_dependency'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/dependencies.rb:239:in `require'
    from /path/ruby/project/dev/test/test_helper.rb:16:in `block in '
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/spork-0.9.0.rc7/lib/spork.rb:24:in `prefork'
    from /path/ruby/project/dev/test/test_helper.rb:5:in `'
    from /path/ruby/project/dev/test/unit/place_test.rb:2:in `require'
    from /path/ruby/project/dev/test/unit/place_test.rb:2:in `'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/lib/turn/runners/minirunner.rb:23:in `require'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/lib/turn/runners/minirunner.rb:23:in `block in initialize'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/lib/turn/runners/minirunner.rb:23:in `each'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/lib/turn/runners/minirunner.rb:23:in `initialize'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/lib/turn/controller.rb:148:in `new'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/lib/turn/controller.rb:148:in `start'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/lib/turn/command.rb:221:in `main'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/lib/turn/command.rb:37:in `main'
    from /path/.rvm/gems/ruby-1.9.2-p136/gems/turn-0.8.2/bin/turn:3:in `'
    from /path/.rvm/gems/ruby-1.9.2-p136/bin/turn:19:in `load'
    from /path/.rvm/gems/ruby-1.9.2-p136/bin/turn:19:in `'

[trans]

I think I found the culprit:

https://github.com/TwP/turn/blob/master/lib/turn/runners/minirunner.rb#L8

And the reason is simply that the old TestUnit system defined Test::Unit as a module, where as MiniTest::Unit it as a class.

If correct, then now we just have to figure out how to fix it. The problem with just removing this line is that it is what allowed turn to run tests that use the old Test::Unit::TestCase class (rather than the new MiniTest::Unit::TestCase) without having require 'test/unit'. But I see now, that is really what needs to happen. I did not want to load test/unit if it wasn't necessary b/c it is legacy compatibility code for TestUnit 1.x that came with Ruby 1.8. Though I avoid #autoload at almost all costs (b/c it has its own issues), a work around might be:

autoload "Test", 'test/unit'  #Test = MiniTest

Not a great solution, really. But I think it will suffice for now.

NOTE: There are actually much larger issue here. Because of MiniTest, test-unit-2.x gem can never be loaded properly, and that drags up questions about the wisdom of MiniTest emulating TestUnits path, and Ruby's load system.

[Dagnan]

Thanks for your investigation!

I am testing the new version on your master branch.
It seems to almost work, because the instruction 'skip' renders an error:

undefined method skip!' for test_my_test:Turn::TestMethod STDERR: ExceptionNoMethodError' at /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/testing/setup_and_teardown.rb:35:in block in run' /path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/callbacks.rb:448:in_run_setup_callbacks'
/path/.rvm/gems/ruby-1.9.2-p136/gems/activesupport-3.0.4/lib/active_support/testing/setup_and_teardown.rb:34:in `run'


Also, when a test fails, the false assertion is not located on the test file itself but in the source code of the method that uses the method assert. Eg.

Expected response to be a <:unauthorized>, but was <200>.
Expected block to return true value.
STDERR:
Assertion at /path/.rvm/gems/ruby-1.9.2-p136/gems/actionpack-3.0.4/lib/action_dispatch/testing/assertions/response.rb:43:in `assert_response'

But I think this problem is related to turn in general, isn't it?

edit:

Hmm, having the gem in the Gemfile, and using ruby -Itest, the output is not the same as bundle exec turn -Itest.
And there is no longer an issue with "skip".
Is it normal?

[trans]

Ok. I just added a #skip! method to the TestMethod class. Let's see if that takes care of it.

As for the error message, yes that can be tricky. I think the only ways to work this are:

1. Have the support method that calls the assertion pass along a backtrace (is that's possible with MiniTest?)
2. Use some sort of filter on the backtrace (but how do you decided what to filter?)
3. Use the new --trace option to get a full backtrace.

Until someone has a light bulb moment on this I think 3 might be the only option at this point.

[michaelcm]

I'm running into this same issue. We have our own option parser to run test and set everything up, so unfortunately the turn command line isn't an option for us at this point.

I read all the responses here and dug through the code. We use Test::Unit which typically does a full trace. I looked though filter_backtrace and it doesn't look like it is filtering anything it shouldn't be, but I still only get a single line of where the actual error called - which isn't very useful as we call into other external support methods at times.

Any updates?

[michaelcm]

On a side, but related note, is there a way to control which reporter is used when requiring the turn gem and not using the command line? I wasn't able to do extensive testing to see if all the reporters are the same because, as I mentioned before, we're not able to test with the turn command line.

[trans]

That would be a nice feature, but it's not currently possible. I posted a ticket about integrating the autorunners with the regular runners. If someone took up that task then a way to do it might be possible.

[michaelcm]

So just to recap, my tests are requiring:
require 'minitest/unit'

And using:
class MyTests < MiniTest::Unit::TestCase

I'm using turn 0.8.2 and am still getting a single line of backtrace on failures. --verbose is not an option, what is it that I need to do to see the full backtrace?

[trans]

How are you running your tests, via Rake?

[michaelcm]

No, not rake. We have a run.rb script we use that installs/configures the product and then runs tests on it.
The tests are run after configuration is complete simply by requiring minitest/unit, using the autorun method and including the requested test files.

[trans]

Probably in run.rb you could do this instead:

require 'turn/command'
argv = %w{ ... } # fill out as if the command line
Turn::Command.main(*argv)

[michaelcm]

Thanks! That does allow me to run the command line passing in custom arguments and will definitely be useful to have more control over the turn reporters and runners that that provides.

[michaelcm]

On the issue of complete backtrace. We love the output provided by the pretty reporter and plan to continue using turn. I originally comment on this issue because while running tests I was only receiving the first line of backtrace, for example:

     FAIL testDeleteDependencies (12.95s) 
          Watir::Exception::UnknownObjectException: Unable to locate element, using :name, /SUBMIT-PREQGENERAL/

The issue with a single line is that when we use it with Watir/Firewatir/Watir Webdriver the exception that occurred is in the watir code, and doesn't say which line in the test produced the error.

One line of backtrace is not the default level provided by MiniTest. Tracing the issue led me to pretty_reporter.rb (and the other turn reporters), which only prints out the first line of the backtrace:

        trace = filter_backtrace(exception.location).first

My original question in here was how to get the regular level of backtrace with the pretty reporter. The verbose/debug options for turn give complete backtrace including minitest and turn libraries. My temporary solution (possibly permanent if there are no plans to add an option to get a more detailed backtrace with the pretty reporter) is to overwrite MiniTest.filter_backtrace to combine all the lines of backtrace I desire into the first array element, such that turn will grab the first element and output it.

module MiniTest
  def self.filter_backtrace bt
    return ["No backtrace"] unless bt

    new_bt = []

    unless $DEBUG then
      # Only include minitest trace if no other trace available
      new_bt = bt.reject { |line| line.rindex 'minitest' }
      new_bt = bt.dup if new_bt.empty?
    else
      new_bt = bt.dup
    end

    # Turn pretty reporter uses bt.first, so must make all desired output be first array element
    ["  " + new_bt.join( "\n            " )]
  end
end

This gives me the desired output when an issue occurs of:

    ERROR testDeleteDependencies (4.77s) 
          Watir::Exception::UnknownObjectException: Unable to locate element, using :name, /SUBMIT-PREQGENERAL/
            C:/Ruby192/lib/ruby/gems/1.9.1/gems/watir-1.8.1/lib/watir/element.rb:58:in `assert_exists'
            C:/Ruby192/lib/ruby/gems/1.9.1/gems/watir-1.8.1/lib/watir/element.rb:275:in `click!'
            C:/Ruby192/lib/ruby/gems/1.9.1/gems/watir-1.8.1/lib/watir/element.rb:230:in `click'
            C:/michael/projects/fox/trunk/test/watir/actions/psa/workflow/PredefRequests.delete.rb:9:in `delete'
            C:/michael/projects/fox/trunk/test/watir/tests/workflow/preq.rb:13:in `finalTeardown'

If there is a better way to do this please let me know. Are there plans of adding more complete backtraces to the pretty_reporter without getting the full debug/verbose backtrace?

I'm a software engineer and am happy to provide debugging and patches for any issues we run into. We're about to ramp up our regression and unit testing to all 30+ developers here, so I'm trying to iron our all the issues in our framework. Let me know if you need a hand. :-)

[michaelcm]

After some more testing it seems that we're not using reporters/pretty_reporter.rb but rather the reporting style included in autorun/minitest.rb.

[trans]

Yes, complete backtrace support should be made part of evey runner. There have been a few patches of late that address this issue, but contributors have thus far tended toward only adjusting the parts that directly concern them (more or less). Someone really needs to take the reigns here and finish off the last few major issues that Turn needs addressed in a comprehensive fashion. I have been the main contributing developer for a while, but I no longer really have the time to devote to it, so someone else really needs become familiar with the code. I would be happy to provide guidance to anyone who wanted to take up the endeavor. I'm sure all the outstanding issues could be done in a couple of days if someone really put in the effort. Let me know if you would like to do so.

[trans]

That would be the outline reporter.

[trans]

The most recent code should address some of the issues you mentioned. For instance the format will be configurable now even when using the autorunner via Turn.config.

[gtd]

+1 on solving this on getting a comprehensive solution. Turn is nice, but it's quite painful to have to disable it in my Gemfile every time the single line backtrace is not enough. Unfortunately I also find myself without time to devote to this.

[trans]

Many of the current issues have been addressed, if you can convince Tim to make a new release.

[moiristo]

Tim, could you please create a new release? ... Commit access? <3

[TwP]

New release has been pushed!

[moiristo]

No commit access? :( ;)