Interesting before(:each) order observation when using config.include

[tovodeverett]

The following code produces some interesting output. I'm not sure if this is the desired behavior or if it is a true bug, but it definitely caught me by surprise. I couldn't find anything in https://www.relishapp.com/rspec/rspec-core/docs/hooks/before-and-after-hooks! that addressed this specific issue, and I couldn't spot anything in the issues either. I did take note of #607 (comment), but I still feel the issue is at least worth discussing.

module Helper
  def self.included(klass)
    klass.class_exec do
      before(:each) { puts "concern before each" }
      after(:each)  { puts "concern after each" }
    end
  end
end

RSpec.configure do |config|
  config.before(:each) { puts "config before each" }
  config.after(:each)  { puts "config after each" }

  config.include Helper
end

describe "before and after callbacks" do
  before(:each) { puts "local before each" }
  after(:each)  { puts "local after each" }

  it "gets run in order" do
  end
end

The output I get is:

concern before each
config before each
local before each
local after each
concern after each
config after each

I would have expected it to instead order it like so:

config before each
concern before each
local before each
local after each
concern after each
config after each

Notice that the before(:each) that gets included by the concern runs before the one defined using config. I would have expected all before(:each) blocks defined by the config to run first, followed by those introduced by the concern and then the local. I did notice that the order of the after(:each) blocks corresponds to what I would have expected.

I noticed this because I'm using an approach to database cleaning suggested by Avdi Grimm in http://devblog.avdi.org/2012/08/31/configuring-database_cleaner-with-rails-rspec-capybara-and-selenium/. When I extracted some code that uses FactoryGirl.create into a concern, I observed that the database started accumulating records from test to test! I solved the issue by using config.before(:suite) to do the initial wipe and then using a separate concern with the before(:each) and after(:each) blocks to do the rest of the database cleaner work and making sure I call config.include on that concern first.

[tovodeverett]

One other note - my work around is causing issues with the JavaScript test suite because it is executing before Capybara sets the current driver! I'll have to revert to relying upon tags (which isn't as reliable because there are multiple tags that could be used to adjust the Capybara driver).

[JonRowe]

Hi, you've used the term concern are you using ActiveSupport? I ask because we have a bug with rspec-rails caused by ActiveSupport which @alindeman is looking into, that affects module load order...

Out on interest what happens when you run this:

module Helper
  def self.included(klass)
    klass.class_exec do
      before(:each) { puts "concern before each" }
      after(:each)  { puts "concern after each" }
    end
  end
end

RSpec.configure do |config|
  config.before(:each) { puts "config before each" }
  config.after(:each)  { puts "config after each" }
end

describe "before and after callbacks" do
  include Helper

  before(:each) { puts "local before each" }
  after(:each)  { puts "local after each" }

  it "gets run in order" do
  end
end

[tovodeverett]

I am indeed using ActiveSupport, but to simplify the demonstration code (and to eliminate a potential third-party effect) I modified it to use self.included instead of using ActiveSupport::Concern.

When I run the above code, I do indeed get the desired order:

config before each
concern before each
local before each
local after each
concern after each
config after each

So the issue, if it is one, is that before(:each) statements in config.include takes precedence over config.before(:each) independent of the order in which they are encountered in RSpec.configure blocks.

Out of curiosity, I went through the rspec-rails issues to see if I could figure out which one you were referring to. I suspect it was rspec/rspec-rails#738, but while I was looking through all the issues to be thorough, I came across rspec/rspec-rails#662. The latter mentioned that "the existing mixins could easily be rewritten as shared contexts (which would decouple them from ActiveSupport::Concern)." This struck me as a potential alternative workaround, so I tried it. Unfortunately, it runs into the same issue!

I used the following code:

RSpec.configure do |config|
  config.before(:each) { puts "config before each" }
  config.after(:each)  { puts "config after each" }
end

shared_context a: :b do
  before(:each) { puts "shared_context before each" }
  after(:each)  { puts "shared_context after each" }
end

describe "before and after callbacks", a: :b do
  before(:each) { puts "local before each" }
  after(:each)  { puts "local after each" }

  it "gets run in order" do
  end
end

And got the following response:

shared_context before each
config before each
local before each
local after each
shared_context after each
config after each

[JonRowe]

And this is the order you get when there is no activesupport loaded? e.g. in a Clean environment?

[tovodeverett]

I believe so. I currently have the three test files in an isolated directory. I have a whole bunch of gems installed on the system, but no Gemfile in that directory. I am running rspec filename.rb. Unless rspec is somehow asking for activesupport, I don't think it is making it in. Running rspec --version returns 2.13.1. If you would like, I can attempt to run against the github version, but I suspect I'm going to see the same results.

If I run this using rspec filename.rb:

RSpec.configure do |config|
  config.before(:each) { puts "config before each" }
  config.after(:each)  { puts "config after each" }
end

shared_context a: :b do
  before(:each) { puts "shared_context before each" }
  after(:each)  { puts "shared_context after each" }
end

describe "before and after callbacks", a: :b do
  before(:each) { puts "local before each" }
  after(:each)  { puts "local after each" }

  it "gets run in order" do
    modules = []
    ObjectSpace.each_object(Module) do |object|
      modules << object.name unless
        object.name =~ /^(?:Diff|Encoding|ERB|Errno|Gem|IO|IRB|OptionParser|Process|RSpec|RubyToken)::/
    end
    p modules.reject(&:nil?).sort
  end
end

I get:

shared_context before each
config before each
local before each
["ARGF.class", "ArgumentError", "Array", "BasicObject", "Bignum", "Binding", "Class", "Comparable", "Complex", "Data", "Date", "Diff", "Dir", "EOFError", "ERB", "Encoding", "EncodingError", "Enumerable", "Enumerator", "Enumerator::Generator", "Enumerator::Yielder", "Errno", "Etc", "Exception", "FalseClass", "Fiber", "FiberError", "File", "File::Constants", "File::Stat", "FileTest", "FileUtils", "FileUtils::DryRun", "FileUtils::Entry_", "FileUtils::LowMethods", "FileUtils::NoWrite", "FileUtils::StreamUtils_", "FileUtils::Verbose", "Fixnum", "Float", "FloatDomainError", "GC", "GC::Profiler", "Gem", "Hash", "IO", "IOError", "IndexError", "Integer", "Interrupt", "Kernel", "KeyError", "LoadError", "LocalJumpError", "Marshal", "MatchData", "Math", "Math::DomainError", "Method", "Module", "Mutex", "NameError", "NameError::message", "NilClass", "NoMemoryError", "NoMethodError", "NotImplementedError", "Numeric", "Object", "ObjectSpace", "OptionParser", "PP", "PP::ObjectMixin", "PP::PPMethods", "PP::SingleLine", "Pathname", "PrettyPrint", "PrettyPrint::Breakable", "PrettyPrint::Group", "PrettyPrint::GroupQueue", "PrettyPrint::SingleLine", "PrettyPrint::Text", "Proc", "Process", "RSpec", "Random", "Range", "RangeError", "Rational", "RbConfig", "Regexp", "RegexpError", "RubyVM", "RubyVM::Env", "RubyVM::InstructionSequence", "RuntimeError", "ScriptError", "SecurityError", "Set", "Shellwords", "Signal", "SignalException", "SortedSet", "StandardError", "StopIteration", "String", "StringIO", "StringScanner", "StringScanner::Error", "Struct", "Struct::Group", "Struct::Passwd", "Struct::Tms", "Symbol", "SyntaxError", "SystemCallError", "SystemExit", "SystemStackError", "Thread", "ThreadError", "ThreadGroup", "Time", "TrueClass", "TypeError", "UnboundMethod", "ZeroDivisionError", "fatal"]
local after each
shared_context after each
config after each

I don't see any Rails stuff in there (I'm filtering out a bunch of common namespace modules to keep the list manageable, but you can refer those in the regex up above).

[alindeman]

rspec/rspec-rails#738 is not related to ActiveSupport::Concern, actually. It's more about how rspec-rails' example groups call subject (a.k.a. let) as a hook to being included. The fact that we use included from AS::Concern is not really the cause.

I'm still trying to figure out the best way to solve the rspec-rails issue. My gut reaction is that there really is a problem that should be solved in rspec-core, but I don't have a specific solution yet.

[myronmarston]

I believe this was fixed by #845, which was included in 2.14.0.rc1. To confirm, I ran your original example against rspec-core HEAD and this is the output I get:

config before each
concern before each
local before each
local after each
concern after each
config after each

...so it appears this is indeed fixed. Closing. If the fix doesn't work for you for some reason, comment here and we're happy to re-open.

[tovodeverett]

Sorry for the delay in responding, but I finally got around to testing my original issue against 2.14.0.rc1 and I can confirm that it does indeed resolve the issue. I reverted my DatabaseCleaner code, instrumented things well enough to confirm that I was indeed having issues due to the sequencing of the before(:each) blocks, and then updated to 2.14.0.rc1 and watched the issues disappear!

[myronmarston]

Glad to hear your issues been resolved :).