Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Intermittent test failures in travis #897

Open
viroulep opened this issue Sep 15, 2016 · 7 comments

Comments

Projects
None yet
3 participants

@viroulep viroulep added the test-bug label Sep 15, 2016

@jfly jfly changed the title Test(s?) failing (randomly?) in travis Intermittent test failures in travis Sep 30, 2016

@viroulep

This comment has been minimized.

Copy link
Member Author

commented Jun 27, 2018

One more:
https://travis-ci.org/thewca/worldcubeassociation.org/builds/397319235#L3913

I won't restart the build to keep the log.

jfly added a commit to jfly/worldcubeassociation.org that referenced this issue Jun 27, 2018

Sort competitions by date before generating notifications for them.
Sometimes our tests expect the notifications in a different order than
our code actually produces them, and this results in flaky tests. This
fixes the most recent intermittent test failure on thewca#897.
@jfly

This comment has been minimized.

Copy link
Member

commented Jun 27, 2018

Thanks, @viroulep! I am able to reproduce this reliably by running rspec with the same seed that travis used.

jfly added a commit that referenced this issue Jun 27, 2018

Sort competitions by date before generating notifications for them.
Sometimes our tests expect the notifications in a different order than
our code actually produces them, and this results in flaky tests. This
fixes the most recent intermittent test failure on #897.

LinusFresz added a commit to LinusFresz/worldcubeassociation.org that referenced this issue Jul 6, 2018

Sort competitions by date before generating notifications for them.
Sometimes our tests expect the notifications in a different order than
our code actually produces them, and this results in flaky tests. This
fixes the most recent intermittent test failure on thewca#897.
@viroulep

This comment has been minimized.

Copy link
Member Author

commented Aug 29, 2018

I've seen the following happen several times recently:

Failures:
  1) Competition events management unconfirmed competition change round attributes change cutoff to best of 2 in 2 minutes
     Failure/Error: first(:button, "save your changes!", visible: true).click
     
     Capybara::ExpectationNotMet:
       expected to find button "save your changes!" at least 1 time but there were no matches
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.6.0/lib/capybara/node/finders.rb:253:in `block in all'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.6.0/lib/capybara/node/base.rb:83:in `synchronize'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.6.0/lib/capybara/node/finders.rb:251:in `all'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.6.0/lib/capybara/node/finders.rb:279:in `first'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.6.0/lib/capybara/session.rb:736:in `block (2 levels) in <class:Session>'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.6.0/lib/capybara/dsl.rb:51:in `block (2 levels) in <module:DSL>'
     # ./spec/features/competition_manage_schedule_spec.rb:49:in `save'
     # ./spec/features/competition_events_spec.rb:94:in `block (4 levels) in <top (required)>'

Currently restarting the build works fine, but it would be good to try to reproduce it reliably and see what causes it :s

@ronaldmansveld

This comment has been minimized.

Copy link
Member

commented Oct 11, 2018

If it is reproducable with the same seed, than it seems like it's an issue where some tests are not isolated. (The seed is used to determine the random order in which the tests are ran).

This also explains why restarting the build will (most of the time) 'solve' the problem, as the tests are ran in a different order because a different seed is generated.

@viroulep

This comment has been minimized.

Copy link
Member Author

commented Oct 16, 2018

Got another one just now, with a randomly-generated email being too long:

Partial trace with seed
  1) media GET #index filter by region filters by country
     Failure/Error: let!(:medium) { FactoryBot.create(:competition_medium, :pending, competition: competition, text: "i am pending") }
 ActiveRecord::ValueTooLong:
   Mysql2::Error: Data too long for column 'submitterEmail' at row 1: INSERT INTO `CompetitionsMedia` (`competitionId`, `type`, `text`, `uri`, `submitterName`, `submitterComment`, `submitterEmail`, `timestampSubmitted`, `status`) VALUES ('FooComp3262015', 'article', 'i am pending', 'https://www.example.com/article-42', 'Jamey Lueilwitz', 'This is a comment', 'aureliocruickshank@runolfsdottirwilliamson.info', '2018-10-14 17:14:30', 'pending')
 # /home/travis/.bundle/ruby/2.5.0/gems/mysql2-0.5.2/lib/mysql2/client.rb:131:in `_query'
 # /home/travis/.bundle/ruby/2.5.0/gems/mysql2-0.5.2/lib/mysql2/client.rb:131:in `block in query'
 # /home/travis/.bundle/ruby/2.5.0/gems/mysql2-0.5.2/lib/mysql2/client.rb:130:in `handle_interrupt'
 # /home/travis/.bundle/ruby/2.5.0/gems/mysql2-0.5.2/lib/mysql2/client.rb:130:in `query'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:187:in `block (2 levels) in execute'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:186:in `block in execute'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract_adapter.rb:579:in `block (2 levels) in log'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract_adapter.rb:578:in `block in log'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract_adapter.rb:569:in `log'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:185:in `execute'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/mysql/database_statements.rb:28:in `execute'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:196:in `execute_and_free'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/mysql/database_statements.rb:33:in `exec_query'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract/database_statements.rb:117:in `exec_insert'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract/database_statements.rb:149:in `insert'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract/query_cache.rb:21:in `insert'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/persistence.rb:187:in `_insert_record'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/persistence.rb:733:in `_create_record'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/counter_cache.rb:184:in `_create_record'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/locking/optimistic.rb:70:in `_create_record'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/attribute_methods/dirty.rb:137:in `_create_record'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/callbacks.rb:346:in `block in _create_record'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/callbacks.rb:132:in `run_callbacks'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/callbacks.rb:816:in `_run_create_callbacks'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/callbacks.rb:346:in `_create_record'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/timestamp.rb:102:in `_create_record'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/persistence.rb:704:in `create_or_update'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/callbacks.rb:342:in `block in create_or_update'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/callbacks.rb:132:in `run_callbacks'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/callbacks.rb:816:in `_run_save_callbacks'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/callbacks.rb:342:in `create_or_update'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/persistence.rb:308:in `save!'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/validations.rb:52:in `save!'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/transactions.rb:315:in `block in save!'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract/database_statements.rb:254:in `block in transaction'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract/transaction.rb:239:in `block in within_new_transaction'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract/transaction.rb:236:in `within_new_transaction'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/connection_adapters/abstract/database_statements.rb:254:in `transaction'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/transactions.rb:212:in `transaction'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/transactions.rb:385:in `with_transaction_returning_status'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/transactions.rb:315:in `save!'
 # /home/travis/.bundle/ruby/2.5.0/gems/activerecord-5.2.1/lib/active_record/suppressor.rb:48:in `save!'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/configuration.rb:18:in `block in initialize'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/evaluation.rb:18:in `create'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/strategy/create.rb:12:in `block in result'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/strategy/create.rb:9:in `tap'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/strategy/create.rb:9:in `result'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/factory.rb:43:in `run'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/factory_runner.rb:29:in `block in run'
 # /home/travis/.bundle/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/notifications.rb:170:in `instrument'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/factory_runner.rb:28:in `run'
 # /home/travis/.bundle/ruby/2.5.0/gems/factory_bot-4.11.1/lib/factory_bot/strategy_syntax_method_registrar.rb:20:in `block in define_singular_strategy_method'
 # ./spec/requests/media_spec.rb:62:in `block (2 levels) in <top (required)>'
 # ------------------
 # --- Caused by: ---
 # Mysql2::Error:
 #   Data too long for column 'submitterEmail' at row 1
 #   /home/travis/.bundle/ruby/2.5.0/gems/mysql2-0.5.2/lib/mysql2/client.rb:131:in `_query'

Finished in 3 minutes 48.4 seconds (files took 14.09 seconds to load)
1921 examples, 1 failure
Failed examples:
rspec ./spec/requests/media_spec.rb:126 # media GET #index filter by region filters by country
Randomized with seed 23441

@jfly

This comment has been minimized.

Copy link
Member

commented Oct 16, 2018

The seed is used to determine the random order in which the tests are ran

Not just this, actually! We also have many other places where we intentionally randomize test data, in particular using the Faker gem. As @viroulep just pointed out, sometimes the randomly generated emails are larger than some of our database columns can handle (I think the right fix there would be to do a database migration and expand the problematic column).

@jfly

This comment has been minimized.

Copy link
Member

commented Jan 21, 2019

Another one I've seen a few times: https://travis-ci.org/thewca/worldcubeassociation.org/builds/482552084#L4508-L4534

Failures:
  1) Competition management when signed in as delegate clone competition
     Failure/Error: click_button "Create Competition"
     
     Capybara::Poltergeist::JavascriptError:
       One or more errors were raised in the Javascript code on the page. If you don't care about these errors, you can ignore them by setting js_errors: false in your Poltergeist configuration (see documentation for details).
     
       Unhandled promise rejection Error: Could not load "places_impl".
       Unhandled promise rejection Error: Could not load "places_impl".
           at http://127.0.0.1:40092/packs-test/application-eed742276b84c1925c4d.js:1
     # /home/travis/.bundle/ruby/2.5.0/gems/poltergeist-1.18.1/lib/capybara/poltergeist/browser.rb:396:in `command'
     # /home/travis/.bundle/ruby/2.5.0/gems/poltergeist-1.18.1/lib/capybara/poltergeist/browser.rb:208:in `click'
     # /home/travis/.bundle/ruby/2.5.0/gems/poltergeist-1.18.1/lib/capybara/poltergeist/node.rb:19:in `command'
     # /home/travis/.bundle/ruby/2.5.0/gems/poltergeist-1.18.1/lib/capybara/poltergeist/node.rb:143:in `click'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.12.0/lib/capybara/node/element.rb:158:in `block in click'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.12.0/lib/capybara/node/base.rb:83:in `synchronize'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.12.0/lib/capybara/node/element.rb:158:in `click'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.12.0/lib/capybara/node/actions.rb:57:in `click_button'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.12.0/lib/capybara/session.rb:732:in `block (2 levels) in <class:Session>'
     # /home/travis/.bundle/ruby/2.5.0/gems/capybara-3.12.0/lib/capybara/dsl.rb:51:in `block (2 levels) in <module:DSL>'
     # ./spec/features/competition_management_spec.rb:138:in `block (3 levels) in <top (required)>'
Finished in 3 minutes 53.1 seconds (files took 8.08 seconds to load)
2038 examples, 1 failure
Failed examples:
rspec ./spec/features/competition_management_spec.rb:132 # Competition management when signed in as delegate clone competition
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.