Calling self.save in an ActiveRecord after_update callback causes a crash

[cjeffries]

For example:

class SomeModel < ActiveRecord::Base
  after_update :crash_guard

  def crash_guard
    self.save
  end
end

with rspec and FactoryGirl spec:

# assume name exists
it 'crashes guard' do
  some_model = FactoryGirl.create(:some_model)
  some_model.update(name: "lets crash guard")
end

with exception:

> [#] NoMethodError: undefined method `match' for nil:NilClass
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec/notifier.rb:32:in `_parse_summary'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec/notifier.rb:12:in `notify'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec/runner.rb:106:in `_process_run_result'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec/runner.rb:45:in `block in _run'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec/runner.rb:44:in `tap'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec/runner.rb:44:in `_run'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec/runner.rb:31:in `run'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec.rb:42:in `block in run_on_modifications'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec.rb:48:in `_throw_if_failed'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-rspec-4.5.0/lib/guard/rspec.rb:42:in `run_on_modifications'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:82:in `block in _supervise'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:79:in `catch'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:79:in `_supervise'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:61:in `block (3 levels) in run_on_changes'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:56:in `each'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:56:in `block (2 levels) in run_on_changes'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:119:in `block (2 levels) in _run_group_plugins'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:117:in `each'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:117:in `block in _run_group_plugins'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:116:in `catch'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:116:in `_run_group_plugins'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:54:in `block in run_on_changes'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:53:in `each'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/runner.rb:53:in `run_on_changes'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/internals/queue.rb:23:in `process'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/commander.rb:43:in `start'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/cli/environments/valid.rb:16:in `start_guard'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/cli.rb:113:in `start'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/thor-0.19.1/lib/thor/command.rb:27:in `run'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/thor-0.19.1/lib/thor/invocation.rb:126:in `invoke_command'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/thor-0.19.1/lib/thor.rb:359:in `dispatch'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/thor-0.19.1/lib/thor/base.rb:440:in `start'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/aruba_adapter.rb:32:in `execute'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/lib/guard/aruba_adapter.rb:19:in `execute!'
> [#] /Users/christian/.rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/guard-2.12.1/bin/_guard-core:11:in `<main>'

This is dumb logic on the model because of the infinite loop, but figured it'd be worthwhile mentioning it as an issue.

[e2]

Thanks @cjeffries - could you setup a simple repo reproducing the problem? I want to be sure I actually fix the problem and it's not something else (it looks like RSpec is producing some unexpected output because of the crash).

[bopm]

In my case same story ended by manual run command from guard :rspec, cmd: cmd do block of Guard file and finding out that I forget to configure spring correctly.

[leods92]

@e2 I've also stumped on this issue.

I don't know the ins-and-outs of guard-spec but #_process_run_result receives sometimes false as the first argument and that's not being handled properly.

How about in runner.rb at #_command_success?,
instead of: return false if success.nil?
we used: return false if success.nil? || success == false

[e2]

@leods92 - "success == false" can't be used there, because "success" here means it was possible to run RSpec - even though tests failed (as opposed to not being able to run RSpec). success is false when there's an error code - but 2 (Command::FAILURE_EXIT_CODE) is considered a success, even though success is false in this case.

It seems like RSpec is failing because of failing tests - and that's fine. What's wrong is that the RSpec output doesn't seem to be handled properly (the summary).

Could you create a repository recreating the same error? The _command_output method has a bad rescue clause that should be removed/fixed - and I need to create tests that reproduce the problem.

Basically, the formatter output file is "strange" in some way - and this should be handled properly (I just need to know how to reproduce the same problem, and I can take it from there).

[leods92]

@e2 The error seems to be random. Sometimes if I run the specs twice very fast it happens, for instance. I'm afraid that therefore I couldn't provide a repo.

I monkey patched the gem though and logged the $CHILD_STATUS.exitstatus and that was "202:28:53 - ERROR".
That happened at 02:28:53, so I guess the exit code was "2" (the first number).

There's some agglutination going on in the output.
I think this is either a guard or guard-spec problem or their dependencies.
It's worth noting that sometimes with the most recent version of guard and guard-rspec OS X's Terminal doesn't respond properly to any input and output line-breaks are messy. Maybe that's related.

How about replacing [Command::FAILURE_EXIT_CODE, 0].include?($CHILD_STATUS.exitstatus) by [Command::FAILURE_EXIT_CODE, 0].include?($CHILD_STATUS.exitstatus.to_s[0])?
It'd solve the problem, but it doesn't feel right.

We should probably tackle this output agglutination thing, do you have any ideas about it?

[e2]

@leods92 - I'll need to reproduce the error no matter what, even if it's just to add a unit test.

If it's random, it may be that the specs are run in a random order - you can set the RSpec seed to a fixed number.

Other than that, in the _command_output method you can:

1. remove the rescue [nil, nil] lines
2. remove the ensure block (to keep the output file, so you can inspect it)

That should help bring about the actual error and we can investigate from there.

[leods92]

@e2 Thanks for your tips! :) I haven’t been able to reproduce the error again though. I’m not developing that intensively in the last few days anyway. I removed those blocks and I’ll let you know about how it goes if I get any error message.

Am 24.Apr..2015 um 11:10 schrieb Cezary Baginski notifications@github.com:

@leods92 https://github.com/leods92 - I'll need to reproduce the error no matter what, even if it's just to add a unit test.

If it's random, it may be that the specs are run in a random order - you can set the RSpec seed to a fixed number.

Other than that, in the _command_output method you can:

1. remove the rescue [nil, nil] lines
2. remove the ensure block (to keep the output file, so you can inspect it)

That should help bring about the actual error and we can investigate from there.

—
Reply to this email directly or view it on GitHub #316 (comment).

[leods92]

@e2 Here's the error:

[#] Errno::ENOENT: No such file or directory @ rb_sysopen - tmp/rspec_guard_result
[#] /Users/leods92/.rvm/gems/ruby-2.1.3/gems/guard-rspec-4.5.0/lib/guard/rspec/runner.rb:71:in `readlines'

I'll be investigating it and I'll try to send you an error reproduction. Anyway, that seems to happen pretty randomly: sometimes when running a specific spec file, or multiple, sometimes at the beginning of specs (even before outputting anything), sometimes at the end.

[e2]

@leods92 - that explains things a bit. Are you using Dir.chdir somewhere in your code? You could try changing:

lines = File.readlines(formatter_tmp_file)

into:

lines = File.readlines(File.expand_path(formatter_tmp_file))

Also in rspec_formatter.rb remove the rescue clause in dump_summary.

(All such rescue methods should be removed everywhere - I'll check them once we get close to fixing this issue).

[e2]

I'm closing this since I've reworked handling results files (v4.5.2), so please report any crashes as new issues (they'll be different). Thanks!