test failure for "IceNine::Freezer::NilClass.deep_freeze with a nil object"

[ktdreyer]

I think the --order random line in the .rspec file might be disguising a test failure.

When I remove --order random from .rspec, I see this test consistently fail:

  1) IceNine::Freezer::NilClass.deep_freeze with a nil object behaves like IceNine::Freezer::NoFreeze.deep_freeze does not freeze instance variables
     Failure/Error: expect(subject.instance_variable_get(:@a)).to_not be_frozen
       expected frozen? to return false, got true
     Shared Example Group: "IceNine::Freezer::NoFreeze.deep_freeze" called from ./spec/unit/ice_nine/freezer/nil_class/class_methods/deep_freeze_spec.rb:16
     # ./spec/shared/no_freeze_deep_freeze_shared_spec.rb:17:in `block (2 levels) in <top (required)>'

Even with the random ordering, I see the test fail sometimes and pass sometimes.

I'm running ruby 1.9.3p327 (2012-11-10 revision 37606) [x86_64-linux] on CentOS 6 with Red Hat's Ruby 1.9.3 SCL.

[dkubb]

@ktdreyer I assume this is with edge ice_nine? Can you try with 2.0 and 2.1?

I just tried quickly to reproduce it here with 2.1 and 1.9.3, and it passed in both cases, so I wanted to see if there was some common setup we could find where I can see the error.

[ktdreyer]

I tried again with ruby 2.0.0p353 (2013-11-22 revision 43784) [i386-linux] in a Fedora 20 chroot on a different computer. The result was that actually more tests failures:

  1) IceNine::Freezer::Numeric.deep_freeze with a Bignum object behaves like IceNine::Freezer::NoFreeze.deep_freeze does not freeze instance variables
     Failure/Error: expect(subject.instance_variable_get(:@a)).to_not be_frozen
       expected frozen? to return false, got true
     Shared Example Group: "IceNine::Freezer::NoFreeze.deep_freeze" called from ./spec/unit/ice_nine/freezer/numeric/class_methods/deep_freeze_spec.rb:18
     # ./spec/shared/no_freeze_deep_freeze_shared_spec.rb:17:in `block (2 levels) in <top (required)>'

  2) IceNine::Freezer::Numeric.deep_freeze with a Float object behaves like IceNine::Freezer::NoFreeze.deep_freeze does not freeze instance variables
     Failure/Error: expect(subject.instance_variable_get(:@a)).to_not be_frozen
       expected frozen? to return false, got true
     Shared Example Group: "IceNine::Freezer::NoFreeze.deep_freeze" called from ./spec/unit/ice_nine/freezer/numeric/class_methods/deep_freeze_spec.rb:18
     # ./spec/shared/no_freeze_deep_freeze_shared_spec.rb:17:in `block (2 levels) in <top (required)>'

  3) IceNine::Freezer::Numeric.deep_freeze with a Fixnum object behaves like IceNine::Freezer::NoFreeze.deep_freeze does not freeze instance variables
     Failure/Error: expect(subject.instance_variable_get(:@a)).to_not be_frozen
       expected frozen? to return false, got true
     Shared Example Group: "IceNine::Freezer::NoFreeze.deep_freeze" called from ./spec/unit/ice_nine/freezer/numeric/class_methods/deep_freeze_spec.rb:18
     # ./spec/shared/no_freeze_deep_freeze_shared_spec.rb:17:in `block (2 levels) in <top (required)>'

  4) IceNine::Freezer::NilClass.deep_freeze with a nil object behaves like IceNine::Freezer::NoFreeze.deep_freeze does not freeze instance variables
     Failure/Error: expect(subject.instance_variable_get(:@a)).to_not be_frozen
       expected frozen? to return false, got true
     Shared Example Group: "IceNine::Freezer::NoFreeze.deep_freeze" called from ./spec/unit/ice_nine/freezer/nil_class/class_methods/deep_freeze_spec.rb:16
     # ./spec/shared/no_freeze_deep_freeze_shared_spec.rb:17:in `block (2 levels) in <top (required)>'

There are two details that are weird about my experience.

The first odd thing that stands out to me is that on both platforms (CentOS 6 with Ruby 1.9.3, and Fedora 20 with Ruby 2.0.0), I get the following error when I run "bundle install":

Could not find gem 'rubysl-json (~> 2.0.2) ruby' in the gems available on this
machine.

I'm using Bundler version 1.5.2 on both the Ruby 1.9.3 box and the Ruby 2.0.0 box. The only way I can get either of them to complete bundle install is if I comment out the rubysl-json line. Then bundle install works fine.

The second odd thing that stands out to me is that I see the following warning during the test runs on Ruby 1.9.3:

ice_nine/spec/shared/no_freeze_deep_freeze_shared_spec.rb:17: warning: instance variable @a not initialized

This warning prints to STDOUT immediately before rspec prints the test "F".

And on Ruby 2.0.0, I see an additional three warnings immediately after this one:

/builddir/ice_nine/spec/shared/no_freeze_deep_freeze_shared_spec.rb:17: warning: instance variable @a not initialized
F../builddir/ice_nine/spec/shared/no_freeze_deep_freeze_shared_spec.rb:17: warning: instance variable @a not initialized
F../builddir/ice_nine/spec/shared/no_freeze_deep_freeze_shared_spec.rb:17: warning: instance variable @a not initialized
F........................................................................./builddir/ice_nine/spec/shared/no_freeze_deep_freeze_shared_spec.rb:17: warning: instance variable @a not initialized
F...................................................................................

Which would seem to correspond to the additional three test failures on Fedora.

I'm happy to test other things if you want.

[ktdreyer]

Hi Dan, just FYI these tests are still failing for me, and I'm happy to test other things if you have ideas.

Here's the full log from Fedora's build system: http://kojipkgs.fedoraproject.org//work/tasks/3487/6513487/build.log

[mbj]

@dkubb I just reproduced it and also found the root cause.

The freeze cache is subjected to race conditions when a non cached freezer gets looked up by two threads under concurrency: https://github.com/dkubb/ice_nine/blob/master/lib/ice_nine/freezer.rb#L10-L15

When two threads resolve the cache the same time they race on writing nil and the resolved freezer to the cache. Depending on scheduling nil gets read from cache.

I'll PR a fix as mutant with latest concurrency improvements triggers this often.

[ktdreyer]

Thanks @mbj, I've confirmed that the test failures on Fedora are gone with your fix in #18 .