Bug: CI vulnerable to flaking when Github's servers are under high load

[FireLemons]

Impacted Users

• contributing developers

Environment

Github Continuous Integration(CI)

Problem

When github's free CI servers are under heavy load, a race condition between the page loading and checking the database causes tests to flake. This is caused by a system test inputting data into a form then immediately checking the database without waiting for the form to finish submitting.

For every database check in the system files, make sure it's preceded by a capybara matcher with automatic waiting or replace the database check with a check for something to appear on the page.

Common matchers with built in waiting are have_selector, have_css, have_content, have_button ,have_field, and have_link.

How to Replicate

It's difficult to replicate. To replicate it consistently you have to slow down how fast the page loads in your test browser.

Example failure output

Example 1:

Failures:

  1) case_contacts/edit is successful with mileage reimbursement on
     Failure/Error: expect(case_contact.contact_made).to be true

       expected true
            got false

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_contacts_edit_is_successful_with_mileage_reimbursement_on_616.png


     # ./spec/system/case_contacts/edit_spec.rb:146:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  2) case_contacts/edit when admin admin successfully edits case contact with mileage reimbursement
     Failure/Error: expect(case_contact.contact_made).to be true

       expected true
            got false

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_contacts_edit_when_admin_admin_successfully_edits_case_contact_with_mileage_reimbursement_195.png


     # ./spec/system/case_contacts/edit_spec.rb:53:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  3) case_court_reports/index as a supervisor when searching for cases selects the correct case
     Failure/Error: expect(page).to have_css(".select2-selection__rendered", text: casa_case.case_number)
       expected to find visible css ".select2-selection__rendered" with text "CINA-442" but there were no matches. Also found "Search by volunteer name or case number", which matched the selector but not all filters. 

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_court_reports_index_as_a_supervisor_when_searching_for_cases_selects_the_correct_case_433.png


     # ./spec/system/case_court_reports/index_spec.rb:217:in `block (4 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  4) case_contacts/new when 'Create Another' is checked when multiple cases selected redirects to the new CaseContact form with the same cases selected
     Failure/Error:
       expect {
         click_on "Submit"
       }.to change(CaseContact.active, :count).by(2)

       expected `CaseContact::ActiveRecord_Relation#count` to have changed by 2, but was changed by 0

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_contacts_new_when_create_another_is_checked_when_multiple_cases_selected_redirects_to_the_new_case_contact_form_with_the_same_cases_selected_53.png


     # ./spec/system/case_contacts/new_spec.rb:451:in `block (4 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  5) CaseContact AdditionalExpenses Form can remove an expense
     Failure/Error:
           expect {
             click_on "Add Another Expense"
             fill_expense_fields 1.50, "1st meal"
             click_on "Add Another Expense"
             fill_expense_fields 2.50, "2nd meal"
             click_on "Add Another Expense"
             fill_expense_fields 2.00, "3rd meal"
       
             within "#contact-form-expenses" do
               click_on "Delete", match: :first

       expected `CaseContact::ActiveRecord_Relation#count` to have changed by 1, but was changed by 0

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_contact_additional_expenses_form_can_remove_an_expense_8[76](https://github.com/rubyforgood/casa/actions/runs/13801704303/job/39005142586#step:9:77).png


     # ./spec/system/case_contacts/additional_expenses_spec.rb:68:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  6) followups/resolve changes status of followup to resolved
     Failure/Error: expect(case_contact.followups.first.resolved?).to be_truthy

       expected: truthy value
            got: false

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_followups_resolve_changes_status_of_followup_to_resolved_436.png


     # ./spec/system/case_contacts/followups/resolve_spec.rb:21:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  7) CaseContact form ContactTopicAnswers and notes when casa org has no contact topics displays a field for contact.notes
     Failure/Error: expect { click_on "Submit" }.to change(CaseContact.active, :count).by(1)
       expected `CaseContact::ActiveRecord_Relation#count` to have changed by 1, but was changed by 0

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_contact_form_contact_topic_answers_and_notes_when_casa_org_has_no_contact_topics_displays_a_field_for_contact_notes_965.png


     # ./spec/system/case_contacts/contact_topic_answers_spec.rb:125:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

Finished in 7 minutes 3 seconds (files took 9.[94](https://github.com/rubyforgood/casa/actions/runs/13801704303/job/39005142586#step:9:95) seconds to load)
3076 examples, 7 failures, 7 pending

Failed examples:

rspec ./spec/system/case_contacts/edit_spec.rb:130 # case_contacts/edit is successful with mileage reimbursement on
rspec ./spec/system/case_contacts/edit_spec.rb:38 # case_contacts/edit when admin admin successfully edits case contact with mileage reimbursement
rspec ./spec/system/case_court_reports/index_spec.rb:210 # case_court_reports/index as a supervisor when searching for cases selects the correct case
rspec ./spec/system/case_contacts/new_spec.rb:439 # case_contacts/new when 'Create Another' is checked when multiple cases selected redirects to the new CaseContact form with the same cases selected
rspec ./spec/system/case_contacts/additional_expenses_spec.rb:61 # CaseContact AdditionalExpenses Form can remove an expense
rspec ./spec/system/case_contacts/followups/resolve_spec.rb:14 # followups/resolve changes status of followup to resolved
rspec ./spec/system/case_contacts/contact_topic_answers_spec.rb:117 # CaseContact form ContactTopicAnswers and notes when casa org has no contact topics displays a field for contact.notes

Example 2:

1) case_contacts/new notes/contact topic answsers section when org has no contact topics allows entering contact notes
     Failure/Error:
       expect {
         click_on "Submit"
       }.to change(CaseContact.active, :count).by(1)

       expected `CaseContact::ActiveRecord_Relation#count` to have changed by 1, but was changed by 0

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_contacts_new_notes_contact_topic_answsers_section_when_org_has_no_contact_topics_allows_entering_contact_notes_524.png


     # ./spec/system/case_contacts/new_spec.rb:189:in `block (4 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  2) case_contacts/edit is successful with mileage reimbursement on
     Failure/Error: expect(case_contact.contact_made).to be true

       expected true
            got false

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_contacts_edit_is_successful_with_mileage_reimbursement_on_303.png


     # ./spec/system/case_contacts/edit_spec.rb:146:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  3) notifications/index FollowupResolvedNotifier when volunteer changes its name lists notifications showing it's current name
     Failure/Error: fill_in "Display name", with: created_by_name

     Capybara::ElementNotFound:
       Unable to find field "Display name" that is not disabled

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_notifications_index_followup_resolved_notifier_when_volunteer_changes_its_name_lists_notifications_showing_it_s_current_name_386.png


     # ./spec/system/notifications/index_spec.rb:37:in `block (4 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

  4) case_court_reports/index as a supervisor when searching for cases selects the correct case
     Failure/Error: expect(page).to have_css(".select2-selection__rendered", text: casa_case.case_number)
       expected to find visible css ".select2-selection__rendered" with text "CINA-2161" but there were no matches. Also found "Search by volunteer name or case number", which matched the selector but not all filters. 

     [Screenshot Image]: /home/runner/work/casa/casa/tmp/screenshots/failures_r_spec_example_groups_case_court_reports_index_as_a_supervisor_when_searching_for_cases_selects_the_correct_case_630.png


     # ./spec/system/case_court_reports/index_spec.rb:217:in `block (4 levels) in <top (required)>'
     # ./spec/rails_helper.rb:132:in `block (2 levels) in <top (required)>'
     # ./spec/rails_helper.rb:117:in `block (3 levels) in <top (required)>'
     # ./spec/rails_helper.rb:116:in `block (2 levels) in <top (required)>'

Finished in 6 minutes 42 seconds (files took 9.46 seconds to load)
30[76](https://github.com/rubyforgood/casa/actions/runs/13898502303/job/38884459475#step:9:77) examples, 4 failures, 7 pending

Failed examples:

rspec ./spec/system/case_contacts/new_spec.rb:181 # case_contacts/new notes/contact topic answsers section when org has no contact topics allows entering contact notes
rspec ./spec/system/case_contacts/edit_spec.rb:130 # case_contacts/edit is successful with mileage reimbursement on
rspec ./spec/system/notifications/index_spec.rb:35 # notifications/index FollowupResolvedNotifier when volunteer changes its name lists notifications showing it's current name
rspec ./spec/system/case_court_reports/index_spec.rb:210 # case_court_reports/index as a supervisor when searching for cases selects the correct case

Questions? Join Slack!

We highly recommend that you join us in slack #casa channel to ask questions quickly. And discord for office hours (currently Tuesday 5-7pm Pacific), stakeholder news, and upcoming new issues.

[compwron]

I wonder why it's so flaky

[FireLemons]

@compwron can you record here what you tried already? also things we can rule out

[FireLemons]

It's not the failure from earlier where the browser runs out of memory and crashes. When that happened, every system test after the crash would fail(usually > 20).

[FireLemons]

From: @elasticspoon

The basic issue in common with the failures is a pattern like:

• perform action on page
• assert some database state

The issue is that the tests are often faster than the server, thus, the check it the action worked happens before the action finished. Ex:

• click submit to create case contact
• controller gets the request and starts working
• check that count of contacts went up => fails controller not done yet
• controller finishes

Thus, we can use capybara waits to fix this. Basically we want to check that the front end shows the action finished (we see an alert) then check the database state.

• perform action on page
• check for front end flash message (capybara will wait on these)
• assert some database state