Coverband tries to report before reading config/coverband.rb resulting in error spam

[2called-chaos]

Describe the bug In certain tasks (rails console, rake tasks like delayed_job:restart) we get "coverage failed to store" errors. Taking the rails console (via pry) example:

[www-data@www(pts-1)] ~/tomatic/current[master]$ RAILS_ENV=production bundle exec pry -r ./config/environment
E, [2021-05-15T23:21:24.301764 #304880] ERROR -- : coverage failed to store
E, [2021-05-15T23:21:24.303390 #304880] ERROR -- : Coverband Error: #<Redis::CannotConnectError: Error connecting to Redis on 127.0.0.1:6379 (Errno::ECONNREFUSED)> Error connecting to Redis on 127.0.0.1:6379 (Errno::ECONNREFUSED)
Hello from config/coverband.rb
[1] pry(main)>

~/code/hotfix_tomatic[master]$ rails c
E, [2021-05-15T23:28:31.628322 #31609] ERROR -- : coverage failed to store
E, [2021-05-15T23:28:31.628429 #31609] ERROR -- : Coverband Error: #<Redis::CannotConnectError: Error connecting to Redis on 127.0.0.1:6379 (Errno::ECONNREFUSED)> Error connecting to Redis on 127.0.0.1:6379 (Errno::ECONNREFUSED)
Hello from config/coverband.rb
Loading development environment (Rails 6.1.3.2)
[1] pry(main)>

To Reproduce

I'm not quite sure if we do something odd but it should be reproducible with a Rails 6.1 app and a custom config/coverband.rb (and rails c)

Expected behavior No reporting should be attempted before Redis config has been loaded.

It's not an issue per se but seeing "ERROR" in deployment output is always unsettling.

Additional context

My coverband.rb for reference

redis_config = YAML.load_file(Rails.root.join("config", "redis.yml"))[Rails.env]

puts "Hello from config/coverband.rb"

Coverband.configure do |config|
  config.store = Coverband::Adapters::RedisStore.new(Redis.new(redis_config))
  config.logger = Rails.logger

  config.verbose = false
  config.web_enable_clear = true
  config.track_views = true

  config.ignore += %w[
    config/application.rb
    config/boot.rb
    config/puma.rb
    config/unicorn.rb
    config/spring.rb
    config/schedule.rb
    config/environments/*
    config/deploy.rb
    config/deploy/*
    config/settings/*
    lib/mailer_previews/previews/*
  ]
end

[sirwolfgang]

For rails, putting in the classic config/initializers/coverband.rb seems to work.

[2called-chaos]

For rails, putting in the classic config/initializers/coverband.rb seems to work.

@sirwolfgang Hmm doesn't work for me. The same file as above, just moved to initializers, still the same problem.

E, [2021-07-31T15:16:15.040840 #2580547] ERROR -- : coverage failed to store
E, [2021-07-31T15:16:15.042429 #2580547] ERROR -- : Coverband Error: #<Redis::CannotConnectError: Error connecting to Redis on 127.0.0.1:6379 (Errno::ECONNREFUSED)> Error connecting to Redis on 127.0.0.1:6379 (Errno::ECONNREFUSED)
[1] pry(main)> Coverband.configuration.store.send(:redis)
=> #<Redis client v4.2.5 for redis://146.xxx.xxx.183:6379/0>

[kbaum]

Assuming you only see this error when redis is not running at 127.0.0.1:6379? Just want to make sure so I can reproduce the issue. Thanks for reporting!

[2called-chaos]

@kbaum Exactly. We don't have a local redis server, we use sentinels. There is a local one (sentinel) but it runs on :26379

[kbaum]

Thanks @2called-chaos. Was able to reproduce and put together a quick fix on this branch:

https://github.com/danmayer/coverband/compare/early_report_error

Let me know if that works.

[danmayer]

good call if you all try that out we can get it merged in and cut a release

[danmayer]

thanks @kbaum

[2called-chaos]

That works like a charm (with config/coverband.rb).

I personally don't care that much but throwing the idea in the room. Does coverband queue reports when unconfigured or connection failure? If not it either way didn't report some early stuff I suppose but I can't quite tell if runtime_coverage! actually works if unconfigured as I don't plan on wiping our current coverage :)

But I guess easy for you to evaluate since you know the code a bit better.

Thank you guys no matter what! 👍

[kbaum]

Coverband does not do queue on report failures. Not sure if runtime/eager_load coverage would have been working in this case. If you look at your report and you see runtime coverage on class definitions or method definitions, you'll know that runtime vs eager load coverage was not working properly. Hope that helps!

[2called-chaos]

I think we broke something :<

I have to investigate further as to why but this change introduced a weird bug that reproducibly happens with the early_report_error branch (was that only this change?) and version 5.1.1

We use delayed_job with MySQL and when using said versions a huge number of jobs (supposedly those that do DB queries) fail with the following error (seemingly in random queries that work in the website and prod console)

Stack (reverse) until query (there is no coverband in stack):

ActiveRecord::StatementInvalid: Mysql2::Error::ConnectionError: Got packets out of order
mysql2-0.5.3/lib/mysql2/client.rb:131→ _query
mysql2-0.5.3/lib/mysql2/client.rb:131→ block in query
mysql2-0.5.3/lib/mysql2/client.rb:130→ handle_interrupt
mysql2-0.5.3/lib/mysql2/client.rb:130→ query
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:206→ block (2 levels) in execute
activesupport-6.1.3.2/lib/active_support/dependencies/interlock.rb:48→ block in permit_concurrent_loads
activesupport-6.1.3.2/lib/active_support/concurrency/share_lock.rb:187→ yield_shares
activesupport-6.1.3.2/lib/active_support/dependencies/interlock.rb:47→ permit_concurrent_loads
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:205→ block in execute
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract_adapter.rb:696→ block (2 levels) in log
activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26→ block (2 levels) in synchronize
activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25→ handle_interrupt
activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25→ block in synchronize
activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21→ handle_interrupt
activesupport-6.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21→ synchronize
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract_adapter.rb:695→ block in log
activesupport-6.1.3.2/lib/active_support/notifications/instrumenter.rb:24→ instrument
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract_adapter.rb:687→ log
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:204→ execute
activerecord-6.1.3.2/lib/active_record/connection_adapters/mysql/database_statements.rb:50→ execute
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:215→ execute_and_free
activerecord-6.1.3.2/lib/active_record/connection_adapters/mysql/database_statements.rb:55→ exec_query
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:532→ select
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:69→ select_all
activerecord-6.1.3.2/lib/active_record/connection_adapters/abstract/query_cache.rb:103→ select_all
activerecord-6.1.3.2/lib/active_record/connection_adapters/mysql/database_statements.rb:12→ select_all
activerecord-6.1.3.2/lib/active_record/querying.rb:47→ find_by_sql
activerecord-6.1.3.2/lib/active_record/statement_cache.rb:150→ execute
activerecord-6.1.3.2/lib/active_record/core.rb:377→ find_by
config/initializers/intercept_dead_mails.rb:6→ delivering_email

[kbaum]

Interesting. Looks so unrelated to the changes on that coverband branch.

https://github.com/danmayer/coverband/pull/422/files

Do you know what version of coverband you were previously on? Could do a diff against that.

[2called-chaos]

We pinned it to 5.1.0 which is what we used before and the problem goes away. It's really strange. I will try to recreate this in a basic app

[kbaum]

Ok sounds good. Thanks for the update!