github-action: Action timing out as of a few days ago

I see some others having similar issues as of a few days ago but despite having upgraded to v2.3.9 of this plugin we’re still seeing a timeout:

Starting the development server...

http://localhost:3000 timed out
Error: Timeout awaiting 'request' for 1000ms

Any ideas?

Full logs:

Run cypress-io/github-action@v2.3.9
Received 83886080 of 173170025 (48.4%), 80.0 MBs/sec
Received 146800640 of 173170025 (84.8%), 70.0 MBs/sec
Received 168975721 of 173170025 (97.6%), 53.7 MBs/sec
Received 168975721 of 173170025 (97.6%), 40.3 MBs/sec
Received 168975721 of 173170025 (97.6%), 32.2 MBs/sec
Received 168975721 of 173170025 (97.6%), 26.8 MBs/sec
Received 168975721 of 173170025 (97.6%), 23.0 MBs/sec
Received 168975721 of 173170025 (97.6%), 20.1 MBs/sec
Received 173170025 of 173170025 (100.0%), 18.1 MBs/sec
Cache Size: ~165 MB (173170025 B)
/bin/tar --use-compress-program zstd -d -xf /home/runner/work/_temp/395f82d7-f931-4439-a531-26fcc49358d3/cache.tzst -P -C /home/runner/work/frontwork/frontwork
/usr/bin/yarn --frozen-lockfile
yarn install v1.22.5
[1/4] Resolving packages...
[2/4] Fetching packages...
info fsevents@2.2.1: The platform "linux" is incompatible with this module.
info "fsevents@2.2.1" is an optional dependency and failed compatibility check. Excluding it from installation.
info fsevents@1.2.13: The platform "linux" is incompatible with this module.
info "fsevents@1.2.13" is an optional dependency and failed compatibility check. Excluding it from installation.
info fsevents@2.1.3: The platform "linux" is incompatible with this module.
info "fsevents@2.1.3" is an optional dependency and failed compatibility check. Excluding it from installation.
[3/4] Linking dependencies...
warning " > @testing-library/user-event@12.2.2" has unmet peer dependency "@testing-library/dom@>=7.21.4".
warning " > react-image-annotation@0.9.10" has unmet peer dependency "prop-types@^15.6.0".
warning "@storybook/react > @babel/preset-react@7.12.5" has unmet peer dependency "@babel/core@^7.0.0-0".
warning "@storybook/addon-essentials > @storybook/addon-docs > @babel/plugin-transform-react-jsx@7.12.5" has unmet peer dependency "@babel/core@^7.0.0-0".
warning " > styled-components@5.2.1" has unmet peer dependency "react-is@>= 16.8.0".
warning " > @graphql-codegen/typescript-react-apollo@2.0.7" has unmet peer dependency "graphql-tag@^2.0.0".
warning " > @storybook/addon-essentials@6.0.28" has unmet peer dependency "babel-loader@^8.0.0".
warning " > @storybook/addon-essentials@6.0.28" has unmet peer dependency "react-is@^16.8.0".
warning "@storybook/addon-essentials > @storybook/addon-docs@6.0.28" has unmet peer dependency "@babel/core@^7.0.0-0".
warning "@storybook/addon-essentials > @storybook/addon-docs@6.0.28" has unmet peer dependency "babel-loader@^8.0.0".
warning "@storybook/addon-essentials > @storybook/addon-docs@6.0.28" has unmet peer dependency "react-is@^16.8.0".
warning "@storybook/react > @storybook/core@6.0.28" has unmet peer dependency "@babel/core@*".
warning "@storybook/addon-essentials > @storybook/addon-docs > @storybook/core > @babel/plugin-proposal-export-default-from@7.12.1" has unmet peer dependency "@babel/core@^7.0.0-0".
warning "@storybook/addon-essentials > @storybook/addon-docs > @storybook/core > @babel/register@7.12.1" has unmet peer dependency "@babel/core@^7.0.0-0".
warning "@storybook/addon-essentials > @storybook/addon-docs > @storybook/core > @babel/plugin-proposal-export-default-from > @babel/plugin-syntax-export-default-from@7.12.1" has unmet peer dependency "@babel/core@^7.0.0-0".
warning " > @storybook/preset-create-react-app@3.1.5" has unmet peer dependency "@babel/core@*".
warning " > @storybook/preset-create-react-app@3.1.5" has unmet peer dependency "@storybook/node-logger@*".
warning " > @storybook/react@6.0.28" has unmet peer dependency "@babel/core@^7.0.1".
warning "@storybook/react > @babel/preset-flow@7.12.1" has unmet peer dependency "@babel/core@^7.0.0-0".
warning " > storybook-react-router@1.0.8" has unmet peer dependency "@storybook/addon-actions@^4.0.0||^5.0.0||5.2.0-beta.13".
warning " > storybook-react-router@1.0.8" has unmet peer dependency "react-router@^4.0.0||^5.0.0".
[4/4] Building fresh packages...
Done in 46.55s.
/opt/hostedtoolcache/node/12.19.0/x64/bin/npx cypress cache list
┌─────────┬──────────────┐
│ version │ last used    │
├─────────┼──────────────┤
│ 5.6.0   │ a minute ago │
└─────────┴──────────────┘
/opt/hostedtoolcache/node/12.19.0/x64/bin/npx cypress verify

25l[19:17:37]  Verifying Cypress can run /home/runner/.cache/Cypress/5.6.0/Cypress [started]
[19:17:40]  Verifying Cypress can run /home/runner/.cache/Cypress/5.6.0/Cypress [completed]
25h25h::debug::saving NPM modules
/bin/tar --posix --use-compress-program zstd -T0 -cf cache.tzst -P -C /home/runner/work/frontwork/frontwork --files-from manifest.txt
Cache saved successfully
/bin/tar --posix --use-compress-program zstd -T0 -cf cache.tzst -P -C /home/runner/work/frontwork/frontwork --files-from manifest.txt
Cache saved successfully
start server with command "yarn start"
current working directory "/home/runner/work/frontwork/frontwork/client"
waiting on "http://localhost:3000" with timeout of 30 seconds
/usr/bin/yarn start
yarn run v1.22.5
$ npm run watch:css && cross-env EXTEND_ESLINT=true react-app-rewired start
npm WARN lifecycle The node binary used for scripts is /tmp/yarn--1605467898479-0.33537419860463835/node but npm is using /opt/hostedtoolcache/node/12.19.0/x64/bin/node itself. Use the `--scripts-prepend-node-path` option to include the path for the node binary npm was executed with.

> frontwork@0.1.0 watch:css /home/runner/work/frontwork/frontwork/client
> postcss src/tailwind.css -o src/main.css

ℹ ｢wds｣: Project is running at http://10.1.0.4
ℹ ｢wds｣: webpack output is served from 
ℹ ｢wds｣: Content not from webpack is served from /home/runner/work/frontwork/frontwork/client/public
ℹ ｢wds｣: 404s will fallback to /
Starting the development server...

http://localhost:3000 timed out
Error: Timeout awaiting 'request' for 1000ms

About this issue

  • Original URL
  • State: closed
  • Created 4 years ago
  • Reactions: 6
  • Comments: 30 (11 by maintainers)

Most upvoted comments

I don’t think it has been resolved. I’m going back to 2.3.8 again 🤷‍♂️

image

+2
elie222 on Nov 22, 2020

That might be it @jrparish - I have added a test with server that takes 5 seconds and it used to fail, now it is passing in https://github.com/cypress-io/github-action/pull/245

+1
bahmutov on Nov 20, 2020

Ok. Here’s the debug log to compare between working and non-working versions:

v2.3.8 (working) 
##[debug]parsed command: bundle exec rails server -e test -p 5017
##[debug]found command "/opt/hostedtoolcache/Ruby/2.6.6/x64/bin/bundle"
##[debug]with arguments exec rails server -e test -p 5017
##[debug]running "/opt/hostedtoolcache/Ruby/2.6.6/x64/bin/bundle" exec rails server -e test -p 5017 in /home/runner/work/my/project/spec
##[debug]without waiting for the promise to resolve
waiting on "http://localhost:5017" with timeout of 120 seconds
/opt/hostedtoolcache/Ruby/2.6.6/x64/bin/bundle exec rails server -e test -p 5017
##[debug]18ms GET localhost:5017 ECONNREFUSED
##[debug]1022ms GET localhost:5017 ECONNREFUSED
##[debug]2027ms GET localhost:5017 ECONNREFUSED
##[debug]3029ms GET localhost:5017 ECONNREFUSED
##[debug]4032ms GET localhost:5017 ECONNREFUSED
=> Booting Puma
=> Rails 5.2.4.3 application starting in test 
=> Run `rails server -h` for more startup options
##[debug]5034ms GET localhost:5017 ECONNREFUSED
##[debug]6037ms GET localhost:5017 ECONNREFUSED
##[debug]7038ms GET localhost:5017 ECONNREFUSED
##[debug]8040ms GET localhost:5017 ECONNREFUSED
##[debug]9043ms GET localhost:5017 ECONNREFUSED
##[debug]10045ms GET localhost:5017 ECONNREFUSED
##[debug]11048ms GET localhost:5017 ECONNREFUSED
Puma starting in single mode...
* Version 3.12.6 (ruby 2.6.6-p146), codename: Llamas in Pajamas
* Min threads: 5, max threads: 5
* Environment: test
* Listening on tcp://0.0.0.0:5017
Use Ctrl-C to stop
[Webpacker] Browserslist: caniuse-lite is outdated. Please run:
npx browserslist@latest --update-db

##[debug]Running Cypress tests using NPM module API
##[debug]requiring cypress dependency, cwd is /home/runner/work/my/project
##[debug]working directory /home/runner/work/my/project/spec
##[debug]resolved cypress /home/runner/work/my/project/node_modules/cypress/index.js
##[debug]Cypress options {"headless":true,"record":false,"parallel":false,"quiet":false,"configFile":"cypress.json","browser":"chrome"}
It looks like this is your first time using Cypress: 4.12.0

25l[09:12:53]  Verifying Cypress can run /home/runner/.cache/Cypress/4.12.0/Cypress [started]
[09:12:58]  Verifying Cypress can run /home/runner/.cache/Cypress/4.12.0/Cypress [completed]
25h
Opening Cypress...
v2 (not working) 
Run cypress-io/github-action@v2
##[debug]working directory /home/runner/work/my/project/spec
##[debug]using custom Cypress cache folder "/home/runner/.cache/Cypress"
Skipping install because install parameter is false
##[debug]Separated start commands bundle exec rails server -e test -p 5017
start server "bundle exec rails server -e test -p 5017 with command "bundle exec rails server -e test -p 5017"
current working directory "/home/runner/work/my/project/spec"
##[debug]parsed command: bundle exec rails server -e test -p 5017
waiting on "http://localhost:5017" with timeout of 120 seconds
##[debug]Waiting for urls http://localhost:5017
##[debug]Waiting for url http://localhost:5017
##[debug]19ms undefined undefined ECONNREFUSED
##[debug]found command "/opt/hostedtoolcache/Ruby/2.6.6/x64/bin/bundle"
##[debug]with arguments exec rails server -e test -p 5017
##[debug]running "/opt/hostedtoolcache/Ruby/2.6.6/x64/bin/bundle" exec rails server -e test -p 5017 in /home/runner/work/my/project/spec
##[debug]without waiting for the promise to resolve
/opt/hostedtoolcache/Ruby/2.6.6/x64/bin/bundle exec rails server -e test -p 5017
##[debug]1022ms undefined undefined ECONNREFUSED
##[debug]2025ms undefined undefined ECONNREFUSED
##[debug]3027ms undefined undefined ECONNREFUSED
##[debug]4029ms undefined undefined ECONNREFUSED
=> Booting Puma
=> Rails 5.2.4.3 application starting in test 
=> Run `rails server -h` for more startup options
##[debug]5031ms undefined undefined ECONNREFUSED
##[debug]6033ms undefined undefined ECONNREFUSED
##[debug]7034ms undefined undefined ECONNREFUSED
##[debug]8037ms undefined undefined ECONNREFUSED
##[debug]9039ms undefined undefined ECONNREFUSED
##[debug]10041ms undefined undefined ECONNREFUSED
Puma starting in single mode...
* Version 3.12.6 (ruby 2.6.6-p146), codename: Llamas in Pajamas
* Min threads: 5, max threads: 5
* Environment: test
* Listening on tcp://0.0.0.0:5017
Use Ctrl-C to stop
##[debug]12549ms undefined undefined ETIMEDOUT
##[debug]14554ms undefined undefined ETIMEDOUT
##[debug]16557ms undefined undefined ETIMEDOUT
##[debug]18560ms undefined undefined ETIMEDOUT
##[debug]20563ms undefined undefined ETIMEDOUT
##[debug]22566ms undefined undefined ETIMEDOUT
##[debug]24568ms undefined undefined ETIMEDOUT
##[debug]26572ms undefined undefined ETIMEDOUT
##[debug]28576ms undefined undefined ETIMEDOUT
##[debug]30580ms undefined undefined ETIMEDOUT
##[debug]32584ms undefined undefined ETIMEDOUT
##[debug]34588ms undefined undefined ETIMEDOUT
##[debug]36590ms undefined undefined ETIMEDOUT
##[debug]38592ms undefined undefined ETIMEDOUT
##[debug]40595ms undefined undefined ETIMEDOUT
##[debug]42599ms undefined undefined ETIMEDOUT
##[debug]44601ms undefined undefined ETIMEDOUT
##[debug]46604ms undefined undefined ETIMEDOUT
##[debug]48608ms undefined undefined ETIMEDOUT
##[debug]50613ms undefined undefined ETIMEDOUT
##[debug]52616ms undefined undefined ETIMEDOUT
##[debug]54619ms undefined undefined ETIMEDOUT
##[debug]56622ms undefined undefined ETIMEDOUT
##[debug]58624ms undefined undefined ETIMEDOUT
##[debug]60627ms undefined undefined ETIMEDOUT
##[debug]62629ms undefined undefined ETIMEDOUT
##[debug]64632ms undefined undefined ETIMEDOUT
##[debug]66636ms undefined undefined ETIMEDOUT
##[debug]68639ms undefined undefined ETIMEDOUT
##[debug]70642ms undefined undefined ETIMEDOUT
##[debug]72648ms undefined undefined ETIMEDOUT
##[debug]74652ms undefined undefined ETIMEDOUT
##[debug]76656ms undefined undefined ETIMEDOUT
##[debug]78661ms undefined undefined ETIMEDOUT
##[debug]80664ms undefined undefined ETIMEDOUT
##[debug]82670ms undefined undefined ETIMEDOUT
##[debug]84672ms undefined undefined ETIMEDOUT
##[debug]86678ms undefined undefined ETIMEDOUT
##[debug]88680ms undefined undefined ETIMEDOUT
##[debug]90683ms undefined undefined ETIMEDOUT
##[debug]92686ms undefined undefined ETIMEDOUT
##[debug]94688ms undefined undefined ETIMEDOUT
##[debug]96691ms undefined undefined ETIMEDOUT
##[debug]98696ms undefined undefined ETIMEDOUT
##[debug]100700ms undefined undefined ETIMEDOUT
##[debug]102703ms undefined undefined ETIMEDOUT
##[debug]104705ms undefined undefined ETIMEDOUT
##[debug]106708ms undefined undefined ETIMEDOUT
##[debug]108711ms undefined undefined ETIMEDOUT
##[debug]110715ms undefined undefined ETIMEDOUT
##[debug]112718ms undefined undefined ETIMEDOUT
##[debug]114722ms undefined undefined ETIMEDOUT
##[debug]116726ms undefined undefined ETIMEDOUT
##[debug]118730ms undefined undefined ETIMEDOUT
http://localhost:5017 timed out
##[debug]120734ms undefined undefined ETIMEDOUT
##[debug]Timeout awaiting 'request' for 1000ms
##[debug]RequestError: Timeout awaiting 'request' for 1000ms
##[debug]    at ClientRequest.<anonymous> (/home/runner/work/_actions/cypress-io/github-action/v2/dist/index.js:3542:65)
##[debug]    at Object.onceWrapper (events.js:300:26)
##[debug]    at ClientRequest.emit (events.js:215:7)
##[debug]    at ClientRequest.origin.emit (/home/runner/work/_actions/cypress-io/github-action/v2/dist/index.js:59917:20)
##[debug]    at Socket.socketErrorListener (_http_client.js:406:9)
##[debug]    at Socket.emit (events.js:210:5)
##[debug]    at emitErrorNT (internal/streams/destroy.js:92:8)
##[debug]    at emitErrorAndCloseNT (internal/streams/destroy.js:60:3)
##[debug]    at processTicksAndRejections (internal/process/task_queues.js:80:21)
##[debug]    at Timeout.timeoutHandler [as _onTimeout] (/home/runner/work/_actions/cypress-io/github-action/v2/dist/index.js:77879:25)
##[debug]    at listOnTimeout (internal/timers.js:533:17)
##[debug]    at processTimers (internal/timers.js:475:7)
Error: Timeout awaiting 'request' for 1000ms
##[debug]Node Action run completed with exit code 1
##[debug]Finishing: Cypress.io

From what I understand from the log, my Rails server has already started after 10 seconds but somehow the newest wait-on implementation is giving ETIMEDOUT and waited for 120 seconds as configured in wait-on-timeout.

This is the config, if it’s helpful:

- name: Cypress.io
  uses: cypress-io/github-action@v2
  with:
    install: false
    start: bundle exec rails server -e test -p 5017
    working-directory: spec
    wait-on: 'http://localhost:5017'
    wait-on-timeout: 120
    browser: chrome
    headless: true
+1
yoonwaiyan on Nov 19, 2020

@barisbora 's suggestion worked for me too. I believe the new changes related to wait-on is the problem, I’ll try to get the debug log or an example.

+1
yoonwaiyan on Nov 18, 2020

When I switch back to @v2.3.8 problem gone!

+1
barisbora on Nov 18, 2020
Read more comments on GitHub
← github-action: Action stuck at Warning: vkCreateInstance: Found no drivers!
github-action: Chrome parallel-group-params-mismatch error →