Timing failures in system tests

[jywarren]

We're seeing intermittent test failures due to Capybara not waiting long enough; now:

ERROR["test_posting_from_the_editor", #<Minitest::Reporters::Suite:0x0000564375476be8 @name="PostTest">, 42.33207633999996]
 test_posting_from_the_editor#PostTest (42.33s)
Capybara::ElementNotFound:         Capybara::ElementNotFound: Unable to find field "Title" that is not disabled
            test/system/post_test.rb:20:in `block in <class:PostTest>'

We can individually set a wait parameter but maybe better to set it system wide...

PRs that are stuck:

• remove authlogic startup from system test #5654
• System test for drag to upload image in comment form #5655
• Start to pinning in notes grids (work in progress) #5681
• Try system testing image upload in comments #5526 (this takes 1137.86s to build... system tests are only 20s)
  • 24m: screenshots test: https://travis-ci.org/publiclab/plots2/builds/528581066
• Take screenshots during system tests, upload to Google Cloud storage, and append to Dangerbot output #5320

Here are some of the builds:

• 13m: First build with system tests, 182 seconds for tests (3m): https://travis-ci.org/publiclab/plots2/builds/523776601
• 17m: this was the first additional system test to clock in at over 17m, (405.59s for tests or 6.7m): https://travis-ci.org/publiclab/plots2/builds/527521182

[jywarren]

I've set Capybara.default_max_wait_time = 8 in #5526, but we're still seeing intermittent failures. We could set it to 12 or 15 or 20, but this would start to really make looooooong Travis runs. This one was already 18 min 3 sec: https://travis-ci.org/publiclab/plots2/builds/530045458

[jywarren]

https://stackoverflow.com/questions/36732120/capybara-rspec-test-takes-a-long-time-to-execute-why says that 3rd party javascript loading can take a lot of time, though I don't know why.

apparently we can turn on debug mode in capybara-webkit (maybe selenium? dunno) and see the output to see what's taking so long.

this wasn't too helpful: https://stackoverflow.com/questions/37005387/poltergeist-capybara-view-testing-taking-long-time-when-running-all-test-in-spec

These folks found it required adding time as well: https://stackoverflow.com/questions/28464090/poltergeist-capybara-test-unable-to-find-css-intermittently?rq=1 ?

[jywarren]

Noting re: Sebastian's idea on the build taking too long; when i see 1137s to do docker build, i see:

dpkg: error processing package google-chrome-stable (--install):
 dependency problems - leaving unconfigured
Processing triggers for mime-support (3.60) ...
Errors were encountered while processing:
 google-chrome-stable

[jywarren]

So: after connecting with @icarito on this, our best theory right now is that actually the slowdown in overall test run is from installation of google-chrome-stable, not from actually running the system tests.

However, we are also seeing system test failures which seem timing related.

HYPOTHESIS: Potentially, whatever is causing google-chrome-stable to take so long to install is slowing down processing in the Travis test container overall, and causing the many system tests to blow past their timeout limits. Are we, perhaps, trying to run too much in the Travis container? Might we be up against some kind of memory limit?

[jywarren]

@alaxalves with your experience in Docker, would you be able to offer any insights here? Noting that @icarito has been working the overall test run speed in #5730

Thanks, all, this is becoming a bit urgent as many PRs are failing due to these issues! Many thanks for your work on this. Also mentioning @publiclab/plots2-reviewers @publiclab/soc to just make people aware that we're encountering these issues.

[alaxalves]

@alaxalves with your experience in Docker, would you be able to offer any insights here? Noting that @icarito has been working the overall test run speed in #5730

Thanks, all, this is becoming a bit urgent as many PRs are failing due to these issues! Many thanks for your work on this. Also mentioning @publiclab/plots2-reviewers @publiclab/soc to just make people aware that we're encountering these issues.

@jywarren What I have suggested in publiclab/mapknitter#605 improves our build time, since everything is run in parallel. Regarding the variable Capybara.default_max_wait_time, during a Rails 5 upgrade in Noosfero we have switched our driver from Firefox to Chrome, and we have set this variable to 60. Check it out: https://gitlab.com/noosfero/noosfero/blob/master/features/support/selenium.rb#L32

[jywarren]

Whoa, 60 seconds? Well, we can try this, but formerly I thought this had been causing the really long build times. Now that we are thinking it could actually be an issue with installing google-chrome-stable, maybe this is reasonable?

[jywarren]

OK, trying Capybara.default_max_wait_time = 60 in #5681 -- hold on to your seats!

[jywarren]

Hmm. It seems to have had a positive effect since i'm seeing more tests pass - like #5748, but some don't, like #5654

[alaxalves]

Whoa, 60 seconds? Well, we can try this, but formerly I thought this had been causing the really long build times. Now that we are thinking it could actually be an issue with installing google-chrome-stable, maybe this is reasonable?

Installing google-chrome-stable definitely is a big cause to the long builds duration. Those random failing tests might also be related to this:

@jywarren I could work on this if you want, but I'd freeze my work on Mapknitter for a while. What do you say?

[jywarren]

Well, it's your call -- we'd love your help on this, but if you feel it'd compromise your other work, I totally understand! But I'm fine with it if you are ok spending a little time on this? Thank you, in any case!

…

On Mon, May 20, 2019 at 8:22 PM Álax de Carvalho Alves < ***@***.***> wrote: Whoa, 60 seconds? Well, we can try this, but formerly I thought this had been causing the really long build times. Now that we are thinking it could actually be an issue with installing google-chrome-stable, maybe this is reasonable? Installing google-chrome-stable definitely is a big cause to the long builds duration. Those random failing tests might also be related to this: [image: image] <https://user-images.githubusercontent.com/19597045/58059863-28dc5900-7b45-11e9-8803-c7f40c4e3be5.png> @jywarren <https://github.com/jywarren> I could work on this if you want, but I'd freeze my work on Mapknitter for a while. What do you say? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#5683?email_source=notifications&email_token=AAAF6J6H7SUPW7TDXV3OX3DPWM6B5A5CNFSM4HLOMGOKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODV2M7OA#issuecomment-494194616>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAAF6J4RNGNTTKNB6MT3GU3PWM6B5ANCNFSM4HLOMGOA> .

[alaxalves]

Well, it's your call -- we'd love your help on this, but if you feel it'd compromise your other work, I totally understand! But I'm fine with it if you are ok spending a little time on this? Thank you, in any case!
…
On Mon, May 20, 2019 at 8:22 PM Álax de Carvalho Alves < @.***> wrote: Whoa, 60 seconds? Well, we can try this, but formerly I thought this had been causing the really long build times. Now that we are thinking it could actually be an issue with installing google-chrome-stable, maybe this is reasonable? Installing google-chrome-stable definitely is a big cause to the long builds duration. Those random failing tests might also be related to this: [image: image] https://user-images.githubusercontent.com/19597045/58059863-28dc5900-7b45-11e9-8803-c7f40c4e3be5.png @jywarren https://github.com/jywarren I could work on this if you want, but I'd freeze my work on Mapknitter for a while. What do you say? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#5683?email_source=notifications&email_token=AAAF6J6H7SUPW7TDXV3OX3DPWM6B5A5CNFSM4HLOMGOKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODV2M7OA#issuecomment-494194616>, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAF6J4RNGNTTKNB6MT3GU3PWM6B5ANCNFSM4HLOMGOA .

@jywarren This week I'll take a look a this, I'd like get this train rolling and start some DevOps improvements in here too. No problemo. 😄 💪

[jywarren]

I believe this is solved. I'm no longer seeing it happening! We can re-open if it happens again. Thanks!!!

[jywarren]

I'm going to re-open because I am seeing intermittent system test failures, like this:

The error is: https://travis-ci.org/publiclab/plots2/jobs/540748689#L3885

 FAIL["test_viewing_the_dashboard", #<Minitest::Reporters::Suite:0x00007fa5e78de4f8 @name="DashboardTest">, 150.24667566600004]
 test_viewing_the_dashboard#DashboardTest (150.25s)
        expected to find visible css ".row.header > h1" with text "Dashboard" but there were no matches. Also found "Community research", which matched the selector but not all filters. 
        test/system/dashboard_test.rb:19:in `block in <class:DashboardTest>'

Now, this means we're not logged in, but it's not reliably reproducible. So, I think it's likely that it's a timing/timeout issue!

For example, in the very next build it passed.

[jywarren]

These two PRs are reliably (4+ restarts) not passing their system tests:

#5824 + #5825

[alaxalves]

@jywarren Apparently #5825 is failing because there's a end missing somewhere.

[jywarren]

Oof! Thanks @alaxalves! 🎊 i had assumed I hadn't touched any system test code and was so used to system tests not working... but my changes are to one of the only features we actually have system tests for, so this is a perfect use case for system tests! 🎉

[jywarren]

OMG and the other is also a true system test failure! Wow, closing again. It's so pleasant to have ones tests fail due to real bugs! 😆