Bug #5333: Coverage library giving wrong results

• Status: Third Party's Issue
• Assignee: mame (Yusuke Endoh)
• Target version: 1.9.2
• ruby -v: -

[colszowka (Christoph Olszowka)]

I'm the author of the simplecov gem, a wrapper on top of the Coverage library. You can find it on Github at https://github.com/colszowka/simplecov

I keep getting reports from users that code they have cleary tested is not reported as covered (you can find it a discussion at https://github.com/colszowka/simplecov/issues/60). This was very hard to trace back since no one was able to give me code samples so far. A couple of days ago, a user finally came up with a sample rails application where this problem was visible in conjunction with FactoryGirl.

I tried this out using the Coverage library directly, and the result was the same: Creating the record directly reported the file as covered, doing the same with FactoryGirl reported a coverage of 0 for certain lines - even though they were executed.

I forked the application and added some instructions to the readme. You can find it at https://github.com/colszowka/coverage-bug

I verified this on the latest 1.9.2 release as well as 1.9.3-preview1:

ruby 1.9.3dev (2011-07-31 revision 32789) [x86_64-darwin11.0.0]
ruby 1.9.2p290 (2011-07-09 revision 32553) [x86_64-darwin11.0.0]

I'm not sure why this happens in conjunction with FactoryGirl, but the code inside the if-statement is being executed in that case as well as I verified by adding a raise inside there and getting a correctly failing rspec suite.

Please let me know if you need any further information on this

[mame (Yusuke Endoh)]

• ruby -v changed from ruby 1.9.2p290 (2011-07-09 revision 32553) [x86_64-darwin11.0.0] to -

Hello, sorry for late reply. I had a short trip.

2011/9/17 Christoph Olszowka [e-mail]:

I'm the author of the simplecov gem, a wrapper on top of the Coverage library.

Thank you for the useful gem! simplecov is one of my favorite gems.

I forked the application and added some instructions to the readme. You can find it at https://github.com/colszowka/coverage-bug

Great, thank you for tracking the bug and providing the reproducing code!
But, I cannot repro very unfortunately. I explain what I did.

I tried to follow your instruction, but rake db:migrate failed.

$ ruby -v
ruby 1.9.2p290 (2011-07-09 revision 32553) [i686-linux]

$ git clone https://github.com/colszowka/coverage-bug.git

$ cd coverage-bug

$ bundle

$ rake db:migrate
(in /home/mame/work/ruby/coverage-bug)
rake aborted!
uninitialized constant Rake::DSL
snip

By searching the web, I knew it seems rake and rails version conflict.
So I added "gem 'rake', '0.8.7'" to Gemfile, and rake db:migrate succeeded:

$ bundle update rake

$ rake db:migrate

Then, I can see the results of rake spec:

$ rake spec
(in /home/mame/work/ruby/coverage-bug)
/home/mame/local/bin/ruby -S bundle exec rspec
./spec/requests/competitions_spec.rb ./spec/models/competition_spec.rb
No DRb server is running. Running in local process instead ...

Competition
GET /competitions/:id
should display basic information

Competition
validations
should require ends_at >= starts_at

Finished in 0.58459 seconds
2 examples, 0 failures
["/home/mame/work/ruby/coverage-bug/app/models/competition.rb",
[1, 1, nil, 1, 1, nil, 1, 1, 2, 2, nil, nil, nil]]

and with changing 1 == 2 to 1 == 1,

$ rake spec
snip
["/home/mame/work/ruby/coverage-bug/app/models/competition.rb",
[1, 1, nil, 1, 1, nil, 1, 1, 2, 2, nil, nil, nil]]

Looks like the two results are same. I'm not sure if it is correct,
though.
Please let me know if I did not do it right, or if anyone suceeded to
reproduce the bug.

The reproducing code is not so simple for me to read it directly as
I'm not familiar with rails and have no knowledge of factory_girl.
So, I'll frist try to follow the discussion of
https://github.com/colszowka/simplecov/issues/60.
Sorry for my sluggish action.

--
Yusuke Endoh [e-mail]

[mame (Yusuke Endoh)]

• Status changed from Open to Third Party's Issue

Hello,

Some people told me that the issue reproduces on os x. Thanks!

@nagachika (Tomoyuki Chikanaga), @n0kada and I investigated this issue. As a result,
I'm sad that I'd have to say this is third party's issue.

The following patch will show the mechanism of this issue.

diff --git a/app/models/competition.rb b/app/models/competition.rb
index 9c0ee55..04f1446 100644
--- a/app/models/competition.rb
+++ b/app/models/competition.rb
@@ -1,3 +1,4 @@
+p :load
class Competition < ActiveRecord::Base
has_many :news

@@ -7,6 +8,7 @@ class Competition < ActiveRecord::Base
private
def cannot_end_before_it_started
unless starts_at.nil? or ends_at.nil?

•  p :call
   errors.add(:ends_at, "can't be prior to start date") if ends_at < starts_at
  

  end
  end

With it applied, rake spec prints the following output (on my Ubuntu):

$ rake spec
(in /home/mame/work/ruby/coverage-bug)
:load

Competition
GET /competitions/:id
:load
:call
should display basic information

Competition
validations
:call
should require ends_at >= starts_at

Finished in 0.55506 seconds
2 examples, 0 failures
["/home/mame/work/ruby/coverage-bug/app/models/competition.rb",
[1, 1, 1, nil, 1, 1, nil, 1, 1, 2, 2, 2, nil, nil, nil]]

So we can see the events occur in the following order on Ubuntu:
:load -> :load -> :call -> :call

According to @nagachika (Tomoyuki Chikanaga), the trace on os x is:
:load -> :call -> :call -> :load

when factory_girl is used. Otherwise:
:load -> :call -> :load -> :call

Reloading the same file means clearing the coverage of the file
so far. To measure correct coverage, the event order should be:
:load -> :call -> :call

I'm not sure which library is ill-designed, but I suspect
active_support; it seems to load app/models/competition.rb
twice via const_missing, which also causes such an unstable
(platform-dependent) event order, I guess. You can see this
by replacing "p :load" with "p *caller" in the above patch.

Is active_support developer seeing this ticket?
Or could anyone inform them?

Thanks,

--
Yusuke Endoh [e-mail]

[tenderlovemaking (Aaron Patterson)]

Thanks for the information. I will try to understand active support better and fix this. :'(