How do you get the activerecord tests to NOT eat stdout or useful stack trace information?

Rails
1

I am trying to debug a database adapter for active record, and I have a
case where it spits back after all tests have run a partial error
message with no context at all.

For example:

Exception raised:
<#<ActiveRecord::StatementInvalid: NoMethodError: undefined method []' for nil:NilClass: INSERT INTOsubscribers(books_count,name,nick`) VALUES (?, ?, ?)>>.

It would be nice if the test framework for rails AT LEAST spit out the
line where this happened.

So, without any useful information from the test suite, what I wanted to
do was to find out blow by blow when bad things happen so I can
correlate it to the step-wise actions in a debugger, and so trace WHERE
the bad thing is happening. But no, the test suite eats all STDOUT and
only spits it out after all tests have completed.

Does anyone know how to get Rails to emit all stdout immediately instead
of buffering it until after ALL tests have completed?

Bob

2

On Fri, Nov 30, 2012 at 12:13 PM, Robert B. [email protected]
wrote:

It would be nice if the test framework for rails AT LEAST spit out the
line where this happened.

You are blaming Rails for a problem created by another person?

So, without any useful information from the test suite, what I wanted to
do was to find out blow by blow when bad things happen so I can
correlate it to the step-wise actions in a debugger, and so trace WHERE
the bad thing is happening. But no, the test suite eats all STDOUT and
only spits it out after all tests have completed.

There is plenty of useful information, that is what logs are for, and
a test log is kept, try looking in log/test.log which will have all
that in there from start to finish of each request.

Does anyone know how to get Rails to emit all stdout immediately instead
of buffering it until after ALL tests have completed?

With RSpec use fail fast.

3

On Sat, Dec 1, 2012 at 9:29 AM, Frederick C.
[email protected] wrote:

Rails doesn’t use rspec. It uses minitest (which is what test::unit is
on 1.9). I don’t think it has an equivalent fail fast option although
there do appear to be some monkey patches floating around

What has what Rails uses to do with what you use personally? Are you
saying that because Rails uses Minitest I/(s)he/they/we can’t use
RSpec, because all my Rails projects would like to have a word with
you if that’s the case. Side note: Test::Unit is Minitest in 1.9. In
1.8 is when they /actually/ use Test::Unit (though I don’t know if
that is the case with later versions of 1.8 since I took out about 1.8
something)

That said, if Minitest doesn’t have a FF option then use
plymouth | RubyGems.org | your community gem host and I believe you’ll be able to
throw out the wtf?!?!?!?!?!!? command right away and get the full
context around the last exception that happened and even run the REPL
to see how and why it happened.

4

On Nov 30, 2:56pm, Jordon B. [email protected] wrote:

There is plenty of useful information, that is what logs are for, and
a test log is kept, try looking in log/test.log which will have all
that in there from start to finish of each request.

Does anyone know how to get Rails to emit all stdout immediately instead
of buffering it until after ALL tests have completed?

With RSpec use fail fast.

Rails doesn’t use rspec. It uses minitest (which is what test::unit is
on 1.9). I don’t think it has an equivalent fail fast option although
there do appear to be some monkey patches floating around

If you’re getting error messages with no context i’d guess that they
are occurring outside of an actual unit test, for example in the code
that inserts fixtures or something along those lines.

Fred

5

On Dec 1, 11:40am, Jordon B. [email protected] wrote:

On Sat, Dec 1, 2012 at 9:29 AM, Frederick C.

[email protected] wrote:

Rails doesn’t use rspec. It uses minitest (which is what test::unit is
on 1.9). I don’t think it has an equivalent fail fast option although
there do appear to be some monkey patches floating around

What has what Rails uses to do with what you use personally?

Because it looks to me like they are trying to run the active record
test suite against their database driver (the schema used in the error
messages matches one of the tables used in the active record tests.

Fred

6

Frederick C. wrote in post #1087442:

On Dec 1, 11:40am, Jordon B. [email protected] wrote:

On Sat, Dec 1, 2012 at 9:29 AM, Frederick C.

[email protected] wrote:

Rails doesn’t use rspec. It uses minitest (which is what test::unit is
on 1.9). I don’t think it has an equivalent fail fast option although
there do appear to be some monkey patches floating around

What has what Rails uses to do with what you use personally?

Because it looks to me like they are trying to run the active record
test suite against their database driver (the schema used in the error
messages matches one of the tables used in the active record tests.

Yes, I am trying to run the test suite against our new driver. So this
may not be your conventional “run your own app tests with ruby rails”
scenario, this is a “run the RoR AR Adapter compliance tests” to see if
our adapter is up to snuff sort of scenario.

I think this is in the RoR test fixture code, and I see some places
where it goes out of its way to deliberately eat STDOUT and STDERR
during tests, and I would guess it similarly eats information on the
rescue exception front.

From my experience, where we use RSpec exclusively, one of the
attractive things about it is that it does NOT run in buffered mode for
STDOUT/STDERR, rather you see the blow-by-blow. Beyond the immediately
obvious, it also provides you with all the line numbers where bad things
happen so that you can immediately add breakpoints to the sources at the
right places rather than resorting to a binary search (spelunking)
through the code.

I see other projects do the same thing, and have very excellent test
suites. So I am a bit surprised at the way the RoR test suite was
written.

So I am sure you can hear what my gripes are:

  • no line numbers or stack trace info when bad things happen
  • no unbuffered output, and it eats my C extension trace info (printf)
  • very little documentation in the README or RUNNING TESTS doc for folks
    authoring an adapter (few to none of the necessary hooks are documented)

If folks have specific links to documentation on how to hack the RoR
test suite to do the right thing, diffs preferred, I’d appreciate it.

I hobble along with this, but I just wanted to be one voice calling out
from the wilderness, “have mercy!”.

7

On Dec 2, 9:21am, Robert B. [email protected] wrote:

happen so that you can immediately add breakpoints to the sources at the

  • no unbuffered output, and it eats my C extension trace info (printf)
    You do normally get those. I seem to recall that logging (and perhaps
    stdout) is silenced during fixture insertion because normally it
    creates a lot of noise. You could try hobbling that silencing - all
    the code relating to fixtures is in a file called fixtures.rb, if my
    memory correct.
    You should also be getting backtraces but if the exception is being
    throw outside of the test case itself, weird stuff can happen (I’ve
    had similar experiences with rspec in that sort of scenario) and it
    ends up being handled differently to a normal test failure.
  • very little documentation in the README or RUNNING TESTS doc for folks
    authoring an adapter (few to none of the necessary hooks are documented)

You can usually find some knowledgable people on #rails-contrib
although writing database adapters from scratch isn’t something that
many have done.

Fred

8

Thanks, Fred.

I don’t know if this is a mini-test thing or what. But having dots show
instead of test names is annoying. Do you know of a way to completely
disable that behavior.

For example, this morning I am trying to diagnose a “socket is broken”
issue. What I really need to know is what test was executing immediately
before the first of these. I really need a full log of all output blow
by blow. I will try disabling the fixtures.

Should I consider looking elsewhere too?

Bob

Frederick C. wrote in post #1087528:

On Dec 2, 9:21am, Robert B. [email protected] wrote:

happen so that you can immediately add breakpoints to the sources at the

  • no unbuffered output, and it eats my C extension trace info (printf)
    You do normally get those. I seem to recall that logging (and perhaps
    stdout) is silenced during fixture insertion because normally it
    creates a lot of noise. You could try hobbling that silencing - all
    the code relating to fixtures is in a file called fixtures.rb, if my
    memory correct.
    You should also be getting backtraces but if the exception is being
    throw outside of the test case itself, weird stuff can happen (I’ve
    had similar experiences with rspec in that sort of scenario) and it
    ends up being handled differently to a normal test failure.
  • very little documentation in the README or RUNNING TESTS doc for folks
    authoring an adapter (few to none of the necessary hooks are documented)

You can usually find some knowledgable people on #rails-contrib
although writing database adapters from scratch isn’t something that
many have done.

Fred

9

On Dec 3, 12:02pm, Robert B. [email protected] wrote:

You might try the turn gem - I think that adds some output options to
minitest.

Fred

10

On 30 November 2012 18:13, Robert B. [email protected] wrote:

I am trying to debug a database adapter for active record, and I have a
case where it spits back after all tests have run a partial error
message with no context at all.

You could try asking this on the rails core forum since it is
specifically to do with testing rails itself, if I understand the
problem correctly.

Colin

11

I just looked at the debug.log file – utterly useless information
there, no correlation to what test is running WRT the debug output.

Robert B. wrote in post #1087662:

Thanks, Fred.

I don’t know if this is a mini-test thing or what. But having dots show
instead of test names is annoying. Do you know of a way to completely
disable that behavior.

For example, this morning I am trying to diagnose a “socket is broken”
issue. What I really need to know is what test was executing immediately
before the first of these. I really need a full log of all output blow
by blow. I will try disabling the fixtures.

Should I consider looking elsewhere too?