cypress: Cypress unexpectedly and randomly hangs when running tests in CI

Current behavior:

We have tests running in Jenkins using docker and docker-compose for running micro-services. Many containers spin up and one is used for our app UI, but these are not the problem.

Since upgrading to Cypress 3.0.1, we’ve been noticing that random builds just stall out and never complete. As a result of this we’ve had to instate a 30minute timeout on Jenkins jobs. There are no errors visible in the console output so its hard to see what is happening. The exact same codebase, less some changes to upgrade to Cypress 3, worked on Cypress 2.1.0 perfectly fine up until we upgraded. Like this issue, it will run an random number of specs and stall. Everything runs fine using the headed mode, it seems to only affect headless mode.

Below is some log output from invoking Cypress with DEBUG=cypress:* ./node_modules/.bin/cypress run --env configFile=ci --reporter mocha-multi-reporters --reporter-options configFile=cypress/config/reporters.json

[... everything is great up until this point]

  Running: test_spec.js...                               (16 of 16) 
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:run about to run spec { spec: { name: 'test_spec.js', path: 'cypress/integration/test_spec.js', absolute: '/tests/cypress/integration/test_spec.js' }, headed: undefined, browserName: 'electron' }
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:video ffmpeg started
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:project launching browser electron spec /tests/cypress/integration/test_spec.js
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:project resetting project instance /tests
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:server Setting remoteAuth undefined
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:cors Parsed URL { port: '15901', tld: 'localhost', domain: '' }
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:server Setting remoteOrigin http://localhost:15901
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:server Setting remoteHostAndPort { port: '15901', tld: 'localhost', domain: '' }
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:server Setting remoteDocDomain localhost
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:server Getting remote state: { auth: undefined, props: { port: '15901', tld: 'localhost', domain: '' }, origin: 'http://localhost:15901', strategy: 'http', visiting: false, domainName: 'localhost', fileServer: null }
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:timers queuing timer id 2034 after 30000 ms
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:timers child received timer id 2034
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:project launching project in browser electron
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:browsers opening browser electron
Sat, 09 Jun 2018 00:08:04 GMT cypress:server making saved state from /root/.cache/Cypress/3.0.1/Cypress/resources/app/packages/server
Sat, 09 Jun 2018 00:08:04 GMT cypress:server for project path /tests
Sat, 09 Jun 2018 00:08:04 GMT cypress:server state path for project /tests
Sat, 09 Jun 2018 00:08:04 GMT cypress:server:appdata path: /root/.config/Cypress/cy/production/projects/tests-7304f32fd2c23aa2ad65c4f536e3c192/state.json
Sat, 09 Jun 2018 00:08:04 GMT cypress:server full state path /root/.config/Cypress/cy/production/projects/tests-7304f32fd2c23aa2ad65c4f536e3c192/state.json
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:file reading JSON file /root/.config/Cypress/cy/production/projects/tests-7304f32fd2c23aa2ad65c4f536e3c192/state.json
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:timers child sending timer id 1468
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:timers child sending timer id 1469
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:timers child sending timer id 1470
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:timers child sending timer id 1471
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:timers child sending timer id 1472
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:timers child sending timer id 1473
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:timers child sending timer id 1474
Sat, 09 Jun 2018 00:08:05 GMT cypress:server:timers child sending timer id 1475

[... repeats a few hundred timer ids then just stops]

Desired behavior:

All tests to run and output correct information regardless of fail or passing

Steps to reproduce:

It’s bizarre, I’m not quite sure how to reproduce it reliably as it seems completely random, and only happens about 30% of the time.

NOTE: I cannot recreate a reproducible test case with https://github.com/cypress-io/cypress-test-tiny as it just passes ever single run using Jenkins.

Versions

Cypress 3.0.1 + cypress/base:10 docker image Jenkins 2.89.3

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Reactions: 6
  • Comments: 20 (3 by maintainers)

Commits related to this issue

Most upvoted comments

@brandonb927 @kamituel @ikornienko We’ve investigated this - and we’re still unsure where this could be happening. We fixed the state stuff in 3.0.2 and we’ve added more debugging logs all around this area.

Currently we we cannot reproduce this locally or in CI, so we’ll release 3.0.3 with more debug logs. Once you guys upgrade please post your updated logs here so we can help pinpoint the exact area that it’s hanging.

We still see this issue happening to our builds with 3.0.2 release (same as for the author of this issue, it started to happen only after upgrading to 3.0.1), the debug output (with file paths being changed / obfuscated):

  Running: test.spec.js...                                                              (9 of 10) 
  cypress:server:run about to run spec { spec: { name: 'test.spec.js', relative: 'cypress/integration/test.spec.js', absolute: '/my-project/cypress/integration/test.spec.js' }, isHeadless: true, browserName: 'electron' } +31ms
  cypress:server:video capture started { command: 'ffmpeg -n 20 /home/circleci/.cache/Cypress/3.0.2/Cypress/resources/app/packages/server/node_modules/@ffmpeg-installer/linux-x64/ffmpeg -f image2pipe -use_wallclock_as_timestamps 1 -i pipe:0 -y -vcodec libx264 -preset ultrafast /my-project/cypress/videos/test.spec.js.mp4' } +13ms
  cypress:server:openproject resetting project state, preparing to launch browser +0ms
  cypress:server:project resetting project instance /my-project +1ms
  cypress:server:server Setting remoteAuth undefined +0ms
  cypress:server:cors Parsed URL { port: '8000', tld: 'localhost', domain: '' } +0ms
  cypress:server:server Setting remoteOrigin https://localhost:8000 +0ms
  cypress:server:server Setting remoteHostAndPort { port: '8000', tld: 'localhost', domain: '' } +0ms
  cypress:server:server Setting remoteDocDomain localhost +0ms
  cypress:server:server Getting remote state: { auth: undefined, props: { port: '8000', tld: 'localhost', domain: '' }, origin: 'https://localhost:8000', strategy: 'http', visiting: false, domainName: 'localhost', fileServer: null } +0ms
  cypress:server:timers queuing timer id 1307 after 30000 ms +1ms
  cypress:server:timers child received timer id 1307 +129ms
  cypress:server:openproject launching browser: electron, spec: cypress/integration/test.spec.js +2ms
  cypress:server:browsers opening browser electron +0ms
  cypress:server:saved_state noop saved state +0ms
  cypress:server:video capture stderr log { message: 'ffmpeg version N-45896-g19c3df0cd-static https://johnvansickle.com/ffmpeg/  Copyright (c) 2000-2018 the FFmpeg developers' } +1ms
  cypress:server:video capture stderr log { message: '  built with gcc 6.3.0 (Debian 6.3.0-18+deb9u1) 20170516' } +0ms
  cypress:server:video capture stderr log { message: '  configuration: --enable-gpl --enable-version3 --enable-static --disable-debug --disable-ffplay --disable-indev=sndio --disable-outdev=sndio --cc=gcc-6 --enable-fontconfig --enable-frei0r --enable-gnutls --enable-gray --enable-libaom --enable-libfribidi --enable-libass --enable-libvmaf --enable-libfreetype --enable-libmp3lame --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-librubberband --enable-libsoxr --enable-libspeex --enable-libvorbis --enable-libopus --enable-libtheora --enable-libvidstab --enable-libvo-amrwbenc --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzimg' } +0ms
  cypress:server:video capture stderr log { message: '  libavutil      56. 17.100 / 56. 17.100' } +0ms
  cypress:server:video capture stderr log { message: '  libavcodec     58. 19.100 / 58. 19.100' } +0ms
  cypress:server:video capture stderr log { message: '  libavformat    58. 13.100 / 58. 13.100' } +0ms
  cypress:server:video capture stderr log { message: '  libavdevice    58.  4.100 / 58.  4.100' } +1ms
  cypress:server:video capture stderr log { message: '  libavfilter     7. 20.100 /  7. 20.100' } +0ms
  cypress:server:video capture stderr log { message: '  libswscale      5.  2.100 /  5.  2.100' } +0ms
  cypress:server:video capture stderr log { message: '  libswresample   3.  2.100 /  3.  2.100' } +0ms
  cypress:server:video capture stderr log { message: '  libpostproc    55.  2.100 / 55.  2.100' } +0ms
  cypress:server:timers child sending timer id 578 +134ms
  cypress:server:timers child sending timer id 579 +18ms
  cypress:server:timers child sending timer id 580 +21ms
  cypress:server:timers child sending timer id 581 +5ms
  cypress:server:timers child sending timer id 582 +38ms
  cypress:server:timers child sending timer id 583 +1ms
  cypress:server:timers child sending timer id 584 +0ms
  cypress:server:timers child sending timer id 585 +2ms
  cypress:server:timers child sending timer id 585 +2ms
  cypress:server:timers child sending timer id 586 +9ms
  cypress:server:timers child sending timer id 1090 +42ms
  cypress:server:timers child sending timer id 587 +35ms
  cypress:server:timers child sending timer id 1091 +422ms
  cypress:server:timers child sending timer id 1099 +588ms
  cypress:server:timers child sending timer id 1100 +174ms
  cypress:server:timers child sending timer id 596 +95ms

[ this goes for 100-200 hundred times with different timer ids and ms, until eventually it starts to increment timer id ]

 cypress:server:timers child sending timer id 912 +5s
  cypress:server:timers child sending timer id 913 +37ms
  cypress:server:timers child sending timer id 914 +27ms
  cypress:server:timers child sending timer id 915 +0ms
  cypress:server:timers child sending timer id 916 +1ms

[ and then it increments timer id with various time in ms until the last line ]

  cypress:server:timers child sending timer id 1305 +5ms

And then it stops, and the build is killed by CircleCI with “Too long with no output (exceeded 10m0s)”. Same as for the author of this issue, it’s not obvious how to reproduce it, sometimes it hangs, sometimes it doesn’t.

@brian-mann @jennifer-shehane do you want to reopen this issue, or should it be a new one?

Released in 3.0.2.

FWIW, we’re having the same issue on Buildkite, with docker containers as well (cypress/base:8), and always on the 8th test file, even if the contents are empty.

Using 3.0.2, we have:

working test

  cypress:server:saved_state noop saved state +0ms
  cypress:server:timers queuing timer id 476 after 30000 ms +3ms
  cypress:server:timers child received timer id 476 +3ms
  cypress:server:browsers:electron launching browser window to url  ...

not working test

  cypress:server:openproject launching browser: electron, spec: cypress/integration/08_empty_test.js +1ms
  cypress:server:browsers opening browser electron +0ms
  cypress:server:saved_state noop saved state +0ms
  cypress:server:timers queuing timer id 546 after 30000 ms +3ms
  cypress:server:timers child received timer id 546 +4ms
  cypress:server:timers child sending timer id 395 +1s
  cypress:server:timers child sending timer id 396 +2ms
  cypress:server:timers child sending timer id 417 +2s
  cypress:server:timers child sending timer id 418 +38ms

I will also try and update logs with 3.0.3.

Running 3.1.0 on our CI for ~2 months, I’ve haven’t seen this issue reappear even once (whereas on 3.0 it’d be happening every day). So @rnb-web-dev, I’d suggest double checking if your issue is actually the same.

I’m still seeing the bug on 3.1.0