reporting pass in console, but syntax error in log #31

Closed
clouder opened this Issue Feb 2, 2012 · 11 comments

Comments

Projects
None yet
2 participants

clouder commented Feb 2, 2012

it 'looks like it passes in tork output' do
  [1 2, 3, 4]
  true.should_not be
end

tork will show

TEST spec/models/broom_spec.rb:128
PASS spec/models/broom_spec.rb:128 {}

the log will have

Finished in 0.00009 seconds
0 examples, 0 failures
/home/clouder/.rvm/gems/ruby-1.9.3-p0/gems/tork-17.1.0/lib/tork/master.rb:57:in `load': spec/models/broom_spec.rb:127: syntax error, unexpected tINTEGER, expecting ']' (SyntaxError)
    [1 2, 3, 4]
        ^

kind of threw me for a loop, when stuff I knew should be failing was being reported as passing

Owner

sunaku commented Feb 2, 2012

There's probably some at_exit handler masking the failed exit status propagation. Unfortunately, Rails makes Process::Status#to_json less useful so please edit the SIGCHLD handler in your lib/tork/master.rb as follows:

diff --git a/lib/tork/master.rb b/lib/tork/master.rb
index fba8ce1..6ac915a 100644
--- a/lib/tork/master.rb
+++ b/lib/tork/master.rb
@@ -86,7 +86,7 @@ private
         if command = @command_by_worker_pid.delete(child_pid)
           @worker_number_pool.push command.last
           command[0] = if child_status.success? then :pass else :fail end
-          @client.send command.push(child_status)
+          @client.send command.push(child_status.inspect)
         else
           warn "tork-master: unknown child exited: #{wait2_array.inspect}"
         end

Let's see what exit status is really being sent back from the worker to the master. Thanks.

clouder commented Feb 3, 2012

after making the change, the output looks like this

TEST spec/models/broom_spec.rb:121
PASS spec/models/broom_spec.rb:121 #<Process::Status: pid 22224 exit 0>
Owner

sunaku commented Feb 3, 2012

Thanks for your feedback. As I suspected, something is masking the failed exit status. Tork sees exit status 0 so it thinks your test file has passed.

Please try running your test file directly:

ruby -I lib:test:spec spec/models/broom_spec.rb
echo "exit status: $?"

If you get 0 again, then you need to debug your test environment (spec helper, libraries you use, etc).

clouder commented Feb 3, 2012

clouder@dillen-vbox:~/Code/Ruby/Rails/pushbroom$ ruby -I lib:test:spec spec/models/broom_spec.rb
spec/models/broom_spec.rb:121: syntax error, unexpected tINTEGER, expecting ']'
    [1 2, 3, 4]
        ^
clouder@dillen-vbox:~/Code/Ruby/Rails/pushbroom$ echo "exit status: $?"
exit status: 1
Owner

sunaku commented Feb 3, 2012

That's strange. What version of Ruby, RSpec, and Rails are you using?

A syntax error in a forked child propagates correctly to its parent here:

## ruby 1.9.3p0 (2011-10-30 revision 33570) [x86_64-linux]
>> fork { eval "[1 2, 3]" }
13780
>> (irb):5:in `eval': (eval):1: syntax error, unexpected tINTEGER, expecting ']' (SyntaxError)
[1 2, 3]
    ^
        from (irb):5:in `block in irb_binding'
        from (irb):5:in `fork'
        from (irb):5:in `irb_binding'
        from /usr/lib/ruby/1.9.1/irb/workspace.rb:80:in `eval'
        from /usr/lib/ruby/1.9.1/irb/workspace.rb:80:in `evaluate'
        from /usr/lib/ruby/1.9.1/irb/context.rb:254:in `evaluate'
        from /usr/lib/ruby/1.9.1/irb.rb:159:in `block (2 levels) in eval_input'
        from /usr/lib/ruby/1.9.1/irb.rb:273:in `signal_status'
        from /usr/lib/ruby/1.9.1/irb.rb:156:in `block in eval_input'
        from /usr/lib/ruby/1.9.1/irb/ruby-lex.rb:243:in `block (2 levels) in each_top_level_statement'
        from /usr/lib/ruby/1.9.1/irb/ruby-lex.rb:229:in `loop'
        from /usr/lib/ruby/1.9.1/irb/ruby-lex.rb:229:in `block in each_top_level_statement'
        from /usr/lib/ruby/1.9.1/irb/ruby-lex.rb:228:in `catch'
        from /usr/lib/ruby/1.9.1/irb/ruby-lex.rb:228:in `each_top_level_statement'
        from /usr/lib/ruby/1.9.1/irb.rb:155:in `eval_input'
        from /usr/lib/ruby/1.9.1/irb.rb:70:in `block in start'
        from /usr/lib/ruby/1.9.1/irb.rb:69:in `catch'
        from /usr/lib/ruby/1.9.1/irb.rb:69:in `start'
        from /usr/bin/irb:12:in `<main>'
>> Process.wait2(-1, Process::WNOHANG)
[
    [0] 13780,
    [1] #<Process::Status: pid 13780 exit 1>
]
Owner

sunaku commented Feb 3, 2012

Oh I see you have this project on GitHub. I'll try to debug too. :)

Owner

sunaku commented Feb 3, 2012

Got it! I was able to reproduce the error here. Will debug and let you know.

Owner

sunaku commented Feb 3, 2012

Found the bug! The culprit is RSpec! 👊

Because there was a syntax error, none of the specs in that Ruby file are registered with RSpec. So when RSpec's at_exit handler runs, it finds no specs to run and simply calls exit 0. It doesn't bother to check why its at_exit handler was called in the first place: because of an uncaught exception.

Run options: include {:line_numbers=>[117]}

All examples were filtered out


Finished in 0.0001 seconds
0 examples, 0 failures
{:exit=>
  {:$!=>nil,
   :args=>[0],
   :self=>RSpec::Core::Runner,
   :caller=>
    ["/home/stash/app/rubygems/gems/rspec-core-2.8.0/lib/rspec/core/runner.rb:10:in `block in autorun'",
     "/home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/master.rb:35:in `fork'",
     "/home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/master.rb:35:in `test'",
     "/home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/server.rb:18:in `block in loop'",
     "/home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/client.rb:29:in `block in initialize'"]}}
/home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/master.rb:57:in `load': spec/models/broom_spec.rb:117: syntax error, unexpected tINTEGER, expecting ']' (SyntaxError)
      [1 2, 3]
          ^
    from /home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/master.rb:57:in `block in test'
    from /home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/master.rb:35:in `fork'
    from /home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/master.rb:35:in `test'
    from /home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/server.rb:18:in `block in loop'
    from /home/sunny/app/rubygems/gems/tork-17.1.0/lib/tork/client.rb:29:in `block in initialize'

I found this by adding the following monkey patch at the top of your spec/spec_helper.rb file:

module Kernel
  alias _63c4ec09_258b_46a9_b39c_98620916c755 exit
  def exit *args
    require 'pp'
    pp __method__ => {
      :$! => $!,
      :args => args,
      :self => self,
      :caller => caller,
    }
    _63c4ec09_258b_46a9_b39c_98620916c755 *args
  end
end
Owner

sunaku commented Feb 3, 2012

Submitted a patch to RSpec that fixes this bug. Closing.

sunaku closed this Feb 3, 2012

clouder commented Feb 3, 2012

Awesome :) Thanks for tork and taking the time

Owner

sunaku commented Feb 3, 2012

You're welcome!

sunaku referenced this issue Feb 7, 2012

Closed

tork cucumber #27

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment