Controller file being unexpectedly ignored

[jagthedrummer]

We have one particular controller file that is not showing up in our coverband reports and we're trying to figure out why.

I've looked at this, but it doesn't offer any clues:

> Coverband.configuration.ignore
=> [".erb$", ".slim$", "/tmp", "vendor/ruby-*"]

The controller in question is app/controllers/users/registrations_controller.rb and coverage data for it IS generated locally, but not in production. And we know that it's used in production and handling traffic.

We also have a file at app/controllers/registrations_controller.rb. (Yeah, I know, don't ask...) Is it possible that there's a name collision of some sort?

Any suggestions for how to debug this since it's only happening in prod?

[kbaum]

Interesting try looking at what comes back from this in production rails console

Coverband.configuration.store.coverage

Also, might want to look to see if the underlying ruby coverage library is tracking it by executing this in production rails console:

Coverage.peek_result

[danmayer]

hmmm this is pretty similar issue I just debugged in another PR, but that was related to the default vendor ignore.

#346

If you have config.web_debug = true looking if both files have any mention in the debug JSON would be a good start.

I don't believe it would be a name collision, but I can't rule that out. Any chance that the controller is hooked up to an authentication gem, like devise or omniauth? If so my best guess or thinking would be that file is getting loaded before Coverband can start Coverage. If you aren't manually requiring Coverband, but only relying on the Gemfile, you could try ensuring that Coverband is above the auth related Gem in the Gemfile, to ensure we enable Coverage before the file is loaded.

[jagthedrummer]

Coverband.configuration.store.coverage returns a huge data structure but it doesn't seem to contain anything about the file in question.

> data = Coverband.configuration.store.coverage
# More data than will fit in my terminal scrollback history
> data["./app/controllers/application_controller.rb"]
=> {"first_updated_at"=>1556726536, "last_updated_at"=>1557248509,...}
> data["./app/controllers/users/registrations_controller.rb"]
=> nil

And Coverage.peek_result doesn't work for me:

> Coverage.peek_result
NameError: uninitialized constant Coverage
Did you mean?  Coverband
	from (irb):9

Same result if I try Coverband.peek_result.

[kbaum]

Hmmm.. When you start rails console make sure that coverband is getting started. Coverband should require the ruby coverage library.

[danmayer]

Coverband is loaded, guessing it is name space you could try ::Coverage.peek_result

Thanks for checking that, so the file is definitely not getting into Coverband... The peak_result would be helpful. Did you have anymore info if that control is used / tied to another gem that might get loaded before Coverband?

[jagthedrummer]

Hmm, still no luck with the ::.

> ::Coverage.peek_result
NameError: uninitialized constant Coverage
Did you mean?  Coverband
	from (irb):1

Yes, that is a customized Devise controller, and we do have Coverband listed before devise in theGemfile. Oddly enough we have other custom Devise controllers likesubscribers/registrations_controller.rb that DO show up on the Coverband coverage. Also another custom Devise controller for users/sessions_controller.rb also does show up in the Coverband coverage.

[kbaum]

If you have coverband required and started within that rails console, you should also have the Coverage class. By default, coverband will auto-start if required unless you explicitly disable auto-start with the environment variable. Can you try:

Coverband.start
Coverage.peek_result

[danmayer]

or honestly... What about require 'coverage'? If that returns true it was never setup.... but if you are in the console, we do generally try to detect that and do some different things, so not sure this will show us exactly what happens on the webserver.

[jagthedrummer]

irb(main):002:0> Coverband.start
=> #<Thread:0x000000000ed4bb48@/app/vendor/bundle/ruby/2.3.0/gems/coverband-4.2.0/lib/coverband/integrations/background.rb:30 run>
irb(main):003:0> Coverage.peek_result
=> {}

I suspect we were hoping for something more informative?

[danmayer]

ha yeah... I think what this shows @jagthedrummer is that Coverband doesn't startup the same way in IRB or Console... So it won't help us get to why that file is being skipped / loaded in an unexpected order.

I am trying to think of ways to remote / async debug this. I have had to debug issues like this on some of my own apps, and I just drop a debugger in and run it in local development... If you are comfortable giving that a shot, I could try to write up a debugging step by step guide... Which shows where to add the debugger, how to limit it to the file in question, and how to determine if that file reaches Coverband or even reaches Coverage.

Let me know if you would try to run through the guide, if I took the time to write it up.

[jagthedrummer]

Well, the weird thing (one of the weird things?) is that the file does show up in the Coverband data locally. It's only missing in prod.

I'll spend a little time seeing if I can reproduce the problem in a review app, and if so then maybe I can drop in some logging calls to help us figure out what's going on.

[kbaum]

Interesting.. in my production rails c, I see coverband auto-starting and I see a ton of data returning from Coverage.peek_result. I would think if @jagthedrummer had eager_loading and coverband required, he would see same. @danmayer - is there some difference I am forgetting about when running coverband in the console?

[danmayer]

We might have already asked, but is it require: false in your Gemfile that could effect load order and console?

Do you have any coverband related ENV vars set for console?

The difference between development and production is also interesting most likely that is related to these settings which are different in dev and prod...

config.cache_classes = true
 config.eager_load = false

you could try to set those the same in your dev environment as production and see if that causes the same error locally... That would in theory isolate the issue to load order issues.

[iuriialekseev]

If you are comfortable giving that a shot, I could try to write up a debugging step by step guide... Which shows where to add the debugger, how to limit it to the file in question, and how to determine if that file reaches Coverband or even reaches Coverage.
Let me know if you would try to run through the guide, if I took the time to write it up.

It would be great. We have a similar problem in our production environment.

[danmayer]

I fell behind on various things and forgot to ever write up the debugging flow, to understand Coverage vs coverband and how to gather additional details in dev. I assigned this to myself and will try to get back to it.

If anyone figured out their production issues please let me know.

[jasdeepgosal]

I ran into a similar issue but almost all of my code outside of production.rb was being ignored and it turned out to be this configuration option: https://docs.scoutapm.com/#autoinstruments, which rewrites some code, thus preventing Coverage from working.

This specific problem felt like an issue with the scout library so I filed an issue there: scoutapp/scout_apm_ruby#343

[danmayer]

thanks folks I believe I fixed some issues between simplecov and coverband as well as resque, and hopefully the 5.0 release resolves any issues with missed files... @jagthedrummer / @yuriyalekseyev when you have time upgrade to Coverband 5.0 and let me know if you still see any issues like this.

I don't think I can't solve the scout issue since it breaks Ruby's Coverage itself... Thanks for pionting that out @jasdeepgosal