bahmutov / start-server-and-test

Starts server, waits for URL, then runs test command; when the tests end, shuts down server
MIT License
1.53k stars 92 forks source link

Times out in Github Action #287

Open BenHeath0 opened 3 years ago

BenHeath0 commented 3 years ago

Bug Report

I am running version 1.11.6. My server is nodejs, rendering server side EJS templates. I am using Nightwatch for tests. My scripts are: ci: start-server-and-test start http-get://localhost:8080 test:e2e start: node server.js "test:e2e": "nightwatch --env default --headless"

Running npm run ci works perfectly locally, but when I run in a Github Action pipeline it is timing out. As you can see, I am logging a confirmation that our express server is up and running. I am getting the following error.

> start-server-and-test start http-get://localhost:8080 test:e2e

1: starting server using command "npm run start"
and when url "[ 'http-get://localhost:8080' ]" is responding with HTTP status code 200
running tests using command "npm run test:e2e"

> project@1.0.0 start /home/runner/work/project/project
> node server.js

Express server listening on port 8080
Error: Timed out waiting for: http://localhost:8080
    at MergeMapSubscriber.project (/home/runner/work/project/project/node_modules/wait-on/lib/wait-on.js:130:25)
    at MergeMapSubscriber._tryNext (/home/runner/work/project/project/node_modules/rxjs/internal/operators/mergeMap.js:67:27)
    at MergeMapSubscriber._next (/home/runner/work/project/project/node_modules/rxjs/internal/operators/mergeMap.js:57:18)
    at MergeMapSubscriber.Subscriber.next (/home/runner/work/project/project/node_modules/rxjs/internal/Subscriber.js:66:18)
    at AsyncAction.dispatch [as work] (/home/runner/work/project/project/node_modules/rxjs/internal/observable/timer.js:31:16)
    at AsyncAction._execute (/home/runner/work/project/project/node_modules/rxjs/internal/scheduler/AsyncAction.js:71:18)
    at AsyncAction.execute (/home/runner/work/project/project/node_modules/rxjs/internal/scheduler/AsyncAction.js:59:26)
    at AsyncScheduler.flush (/home/runner/work/project/project/node_modules/rxjs/internal/scheduler/AsyncScheduler.js:52:32)
    at listOnTimeout (internal/timers.js:549:17)
    at processTimers (internal/timers.js:492:7)
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! tfiiu@1.0.0 ci: `start-server-and-test start http-get://localhost:8080 test:e2e`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the tfiiu@1.0.0 ci script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /home/runner/.npm/_logs/2020-11-20T16_38_11_687Z-debug.log
bahmutov commented 3 years ago

Can you enable https://github.com/bahmutov/start-server-and-test#debugging and paste the debug log during pinging the server?

BenHeath0 commented 3 years ago

Here is my log. Again though, this works perfectly fine locally.


 project@1.0.0 ci /home/runner/work/project/project
> start-server-and-test start http://localhost:8080 test:e2e

2020-11-20T17:33:47.352Z start-server-and-test parsing CLI arguments: [ 'start', 'http://localhost:8080', 'test:e2e' ]
2020-11-20T17:33:47.354Z start-server-and-test parsed args: { services: [ { start: 'npm run start', url: [Array] } ], test: 'npm run test:e2e' }
1: starting server using command "npm run start"
and when url "[ 'http://localhost:8080' ]" is responding with HTTP status code 200
running tests using command "npm run test:e2e"

2020-11-20T17:33:47.355Z start-server-and-test single service "npm run start" to run and test
2020-11-20T17:33:47.356Z start-server-and-test starting server with command "npm run start", verbose mode? true
2020-11-20T17:33:47.363Z start-server-and-test starting waitOn [ 'http://localhost:8080' ]
2020-11-20T17:33:47.364Z start-server-and-test wait-on options { resources: [ 'http://localhost:8080' ], interval: 2000, window: 1000, timeout: 300000, verbose: true, strictSSL: true, log: true }
waiting for 1 resources: http://localhost:8080
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: connect ECONNREFUSED 127.0.0.1:8080

> tfiiu@1.0.0 start /home/runner/work/TheFightIsInUs/TheFightIsInUs
> node server.js

true string false
Express server listening on port 8080
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
  HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500
making HTTP(S) head request to  url:http://localhost:8080 ...
Marsunpaisti commented 3 years ago

Im having a similar issue in Gitlab ci. Works locally but not in pipeline, even though server is definitely up its not getting past the check

bahmutov commented 3 years ago

From the debug log I see 500 server error, why would that happen?

making HTTP(S) head request to url:http://localhost:8080 ... HTTP(S) error for http://localhost:8080 Error: Request failed with status code 500

Sent from my iPhone

On Nov 22, 2020, at 10:40, Marsunpaisti notifications@github.com wrote:

 Im having a similar issue in Gitlab ci. Works locally but not in pipeline, even though server is definitely up its not getting past the check

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

Marsunpaisti commented 3 years ago

Im just getting this on repeat with debug output on... making HTTP(S) head request to url:http://localhost:8081/ ... HTTP(S) error for http://localhost:8081/ Error: connect ECONNREFUSED 127.0.0.1:8081

However localhost:8081 should be responding, just not doing it for the script for some reason

edward-morgan-avalara commented 3 years ago

Any movement on this? I'm having a similar issue with Gitlab pipeline:


2021-01-08T21:54:28.774Z start-server-and-test parsing CLI arguments: [ 'start', 'http-get://172.17.0.3:3000', 'cy:run' ]
2021-01-08T21:54:28.776Z start-server-and-test parsed args: { services: [ { start: 'npm run start', url: [Array] } ], test: 'npm run cy:run' }
1: starting server using command "npm run start"
and when url "[ 'http-get://172.17.0.3:3000' ]" is responding with HTTP status code 200
running tests using command "npm run cy:run"
2021-01-08T21:54:28.778Z start-server-and-test single service "npm run start" to run and test
2021-01-08T21:54:28.779Z start-server-and-test starting server with command "npm run start", verbose mode? true
2021-01-08T21:54:28.787Z start-server-and-test starting waitOn [ 'http-get://172.17.0.3:3000' ]
2021-01-08T21:54:28.787Z start-server-and-test wait-on options { resources: [ 'http-get://172.17.0.3:3000' ], interval: 2000, window: 1000, timeout: 300000, verbose: true, strictSSL: false, log: true }
waiting for 1 resources: http-get://172.17.0.3:3000
making HTTP(S) get request to  url:http://172.17.0.3:3000 ...
  HTTP(S) error for http://172.17.0.3:3000 Error: connect ECONNREFUSED 172.17.0.3:3000
> customer-portal-ui@0.1.0 start /builds/orl/customer-portal-ui
> react-scripts start
making HTTP(S) get request to  url:http://172.17.0.3:3000 ...
  HTTP(S) error for http://172.17.0.3:3000 Error: connect ECONNREFUSED 172.17.0.3:3000
making HTTP(S) get request to  url:http://172.17.0.3:3000 ...
  HTTP(S) error for http://172.17.0.3:3000 Error: connect ECONNREFUSED 172.17.0.3:3000
ℹ 「wds」: Project is running at http://172.17.0.3/
ℹ 「wds」: webpack output is served from 
ℹ 「wds」: Content not from webpack is served from /builds/orl/customer-portal-ui/public
ℹ 「wds」: 404s will fallback to /
Starting the development server...
making HTTP(S) get request to  url:http://172.17.0.3:3000 ...
making HTTP(S) get request to  url:http://172.17.0.3:3000 ...
making HTTP(S) get request to  url:http://172.17.0.3:3000 ...```
bahmutov commented 3 years ago

Honestly I have not seen this error in my repos, if anyone gets blocked by this and can debug it, I would be super happy

Sent from my iPhone

On Jan 8, 2021, at 17:13, edward-morgan-avalara notifications@github.com wrote:

 Any movement on this? I'm having a similar issue with Gitlab pipeline:

2021-01-08T21:54:28.774Z start-server-and-test parsing CLI arguments: [ 'start', 'http-get://172.17.0.3:3000', 'cy:run' ] 2021-01-08T21:54:28.776Z start-server-and-test parsed args: { services: [ { start: 'npm run start', url: [Array] } ], test: 'npm run cy:run' } 1: starting server using command "npm run start" and when url "[ 'http-get://172.17.0.3:3000' ]" is responding with HTTP status code 200 running tests using command "npm run cy:run" 2021-01-08T21:54:28.778Z start-server-and-test single service "npm run start" to run and test 2021-01-08T21:54:28.779Z start-server-and-test starting server with command "npm run start", verbose mode? true 2021-01-08T21:54:28.787Z start-server-and-test starting waitOn [ 'http-get://172.17.0.3:3000' ] 2021-01-08T21:54:28.787Z start-server-and-test wait-on options { resources: [ 'http-get://172.17.0.3:3000' ], interval: 2000, window: 1000, timeout: 300000, verbose: true, strictSSL: false, log: true } waiting for 1 resources: http-get://172.17.0.3:3000 making HTTP(S) get request to url:http://172.17.0.3:3000 ... HTTP(S) error for http://172.17.0.3:3000 Error: connect ECONNREFUSED 172.17.0.3:3000

customer-portal-ui@0.1.0 start /builds/orl/customer-portal-ui react-scripts start making HTTP(S) get request to url:http://172.17.0.3:3000 ... HTTP(S) error for http://172.17.0.3:3000 Error: connect ECONNREFUSED 172.17.0.3:3000 making HTTP(S) get request to url:http://172.17.0.3:3000 ... HTTP(S) error for http://172.17.0.3:3000 Error: connect ECONNREFUSED 172.17.0.3:3000 ℹ 「wds」: Project is running at http://172.17.0.3/ ℹ 「wds」: webpack output is served from ℹ 「wds」: Content not from webpack is served from /builds/orl/customer-portal-ui/public ℹ 「wds」: 404s will fallback to / Starting the development server... making HTTP(S) get request to url:http://172.17.0.3:3000 ... making HTTP(S) get request to url:http://172.17.0.3:3000 ... making HTTP(S) get request to url:http://172.17.0.3:3000 ...``` — You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

lleki commented 3 years ago

I am also getting same time out and ECONNREFUSED error on CI when trying run my Cypress tests on Github Action. It passes locally.

I found hack for it to pass on CI but I end up with two Cypresses running which is not good.

package.json scripts

    "start:ci": "next start -p 4000",
    "cy:run": "cypress run",
    "test:e2e:ci": "export NODE_ENV=test && start-server-and-test start:ci http://localhost:4000 cy:run",

first try I did workflow yml.

steps:
      - name: Checkout
        uses: actions/checkout@v2
.....
....
      # and run all Cypress tests
      - name: Cypress run
        uses: cypress-io/github-action@v2
        with:
          build: npm run build
          start: npm run test:e2e:ci

it worked but I ended up with two cypress tests running, the cypress/github-action default one + my script (npm run test:e2e:ci) So on second try I did workflow yml.

steps:
      - name: Checkout
        uses: actions/checkout@v2
.....
....
      # and run all Cypress tests
      - name: Cypress run
        uses: cypress-io/github-action@v2
        with:
          build: npm run build
          start: npm run start:ci 
          command: npm run test:e2e:ci 

the use of command was recommended by cypress/github-action to override THEIR cypress run with my own test command, which would fix my two cypress tests running. But this kept failing with the timeout/ ECONNREFUSED so I tried adding the start in front and finally the CI works except of course then npm run start is being called twice and there is a small error for Port in use 4000

If anyone has any pointers, please let me know, I've been on this for a few days now.

JosepSalvat commented 2 years ago

@lleki Did u solve it? I'm experiencing the same issue

lleki commented 2 years ago

@lleki Did u solve it? I'm experiencing the same issue

@JosepSalvat No, so What made it tricky was the script to use start-server-test module meant we had to include start-server in same line as cy:run and it ended up duplicating the cypress runs for us.

Turns out Cypress Github Action has a Custom Wait-On command and I used that instead of start-server.

alumni commented 2 years ago

If you have any kind of response (500 in this case), most likely the issue is coming from the server itself that behaves differently on CI.

There is also an upstream issue, btw: https://github.com/jeffbski/wait-on/issues/86.

You can also try replacing start-server-and-test start <url> test with concurrently + wait-on:

concurrently --kill-others \
  'start' \
  'wait-on --verbose <url> && test'
Leksat commented 1 year ago

In my case this started to happen both on GitHub CI and locally ~after a major update of axios~.

In my setup I was starting Drupal dev server on 127.0.0.1 with php -S 127.0.0.1:8888 .ht.router.php. Yet, I used localhost for testing: start-server-and-test start 8888 test.

Somehow, this worked well until the axios update. Then it broke:

making HTTP(S) head request to  url:http://localhost:8888 ...
  HTTP(S) error for http://localhost:8888 Error: connect ECONNREFUSED ::1:8888

To resolve it, I changed the server address from 127.0.0.1 to localhost (I start server with php -S localhost:8888 .ht.router.php). And now it works again 🎉

UPD: I'm not so sure that the axios update was the main cause.

UPD2: I think the reason was the update of nodejs from v16 to v18.

So the main conclusion: localhost and 127.0.0.1 aren't the same anymore. They are different addresses now.

abraham commented 1 year ago

After upgrade from Node v16 to v18 I ran into the same error with my Firebase Emulator server. I had to switch from localhost to 127.0.0.1.

start-server-and-test start:firebase http://127.0.0.1:5000/ test
raylyanway commented 1 year ago

Unfortunately, it doesn't work with CRA (create-react-app). To make it works, I had to downgrade to Node.js v16.19.0.

bahmutov commented 1 year ago

Can anyone provide a small public repo showing the problem?

abraham commented 1 year ago

Example repo: https://github.com/abraham/ssat ✅ on Node 16: https://github.com/abraham/ssat/actions/runs/4050710447/jobs/6968356428 🟥 on Node 18: https://github.com/abraham/ssat/actions/runs/4050710447/jobs/6968356507

tariqulislam commented 1 year ago

I had just solve this problem with pm2. in script section "cypress:headless": "cypress run", "e2e:headless": "pm2 start 'yarn start' --name next-js-app && yarn cypress:headless && pm2 kill"

raylyanway commented 1 year ago

Can anyone provide a small public repo showing the problem?

Create a new project using this: npx create-front-end-js-stub <name-of-your-project>

go to the project: cd <name-of-your-project> and run: npm run cy:dev

With Node.js v.16.19.0 Cypress will run, but with v.18.13.0 not.

sushil-truemark commented 1 year ago

In my case, I temporarily resolved this issue by downgrading node version to 16.xx from 18.xx.

MikeMcC399 commented 1 year ago

@sushil-truemark

I temporarily resolved this issue by downgrading node version to 16.xx from 18.xx.

Node.js 16 will enter end-of-life later this year, so it may be better to look for a solution which has a longer lifetime. You can find workarounds for the Cypress JavaScript github-action on

https://github.com/cypress-io/github-action#wait-on-with-nodejs-18

These are generic workarounds so they can also be used for start-server-and-test

It's also worth noting that the original issue from @BenjaminHeath96 is not related to the later issues caused by Node.js 18 and later.

vishwa3 commented 10 months ago

I am also facing the same issue, locally it works fine but stops working in Jenkins pipeline - fixed it using tcp:PORT

Also using Node version 18.17.0 locally as well as on pipeline and changing versions like Node 16 didn't help so maybe its not related to Node version

Logs -

[2023-10-20T23:22:48.372Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:22:48.372Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:22:50.308Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:22:50.308Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:22:52.248Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:22:52.513Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:22:54.451Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:22:54.451Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:22:56.430Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:22:56.430Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:22:58.396Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:22:58.396Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:23:00.384Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:23:00.384Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:23:02.354Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:23:02.354Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:23:04.291Z] making HTTP(S) head request to  url:http://127.0.0.1:3000/ ...

[2023-10-20T23:23:04.291Z]   HTTP(S) error for http://127.0.0.1:3000/ Error: Parse Error: Expected HTTP/

[2023-10-20T23:23:06.243Z] wait-on(1082) Timed out waiting for: http://127.0.0.1:3000/; exiting with error

[2023-10-20T23:23:06.243Z] 2023-10-20T23:23:05.719Z start-server-and-test error waiting for url [ 'http://127.0.0.1:3000/' ]

[2023-10-20T23:23:06.243Z] 2023-10-20T23:23:05.719Z start-server-and-test Timed out waiting for: http://127.0.0.1:3000/

[2023-10-20T23:23:06.243Z] 2023-10-20T23:23:05.721Z start-server-and-test getting child processes

[2023-10-20T23:23:06.243Z] 2023-10-20T23:23:05.744Z start-server-and-test stopping child processes

[2023-10-20T23:23:06.243Z] 2023-10-20T23:23:05.745Z start-server-and-test stopping server

[2023-10-20T23:23:06.243Z] 2023-10-20T23:23:05.747Z start-server-and-test getting child processes

[2023-10-20T23:23:06.243Z] Error: Timed out waiting for: http://127.0.0.1:3000/
gorankarlic commented 9 months ago

Fixed the same issue by changing the server hostname from localhost to 127.0.0.1; one possible cause is that localhost resolves to different IPs if IPv4 or IPv6 is used.

Curs3W4ll commented 2 months ago

I'm still having this issue (but with GitLab CI).

In the CI job output, it will time out, see output:

start-server-and-test 'vite preview --port 4173' http://localhost:4173/ 'cypress run --e2e'
1: starting server using command "vite preview --port 4173"
and when url "[ 'http://localhost:4173'/ ]" is responding with HTTP status code 200
running tests using command "cypress run --e2e"
[sentry-vite-plugin] Warning: No auth token provided. Will not create release. Please set the `authToken` option. You can find information on how to generate a Sentry auth token here: https://docs.sentry.io/api/auth/
[sentry-vite-plugin] Warning: No auth token provided. Will not upload source maps. Please set the `authToken` option. You can find information on how to generate a Sentry auth token here: https://docs.sentry.io/api/auth/
  ➜  Local:   http://localhost:4173/
  ➜  Network: use --host to expose
Error: Timed out waiting for: http://localhost:4173
    at /builds/epitech-it-2025/medali/medali-client-website/node_modules/wait-on/lib/wait-on.js:131:31
    at doInnerSub (/builds/epitech-it-2025/medali/medali-client-website/node_modules/rxjs/dist/cjs/internal/operators/mergeInternals.js:22:31)
    at outerNext (/builds/epitech-it-2025/medali/medali-client-website/node_modules/rxjs/dist/cjs/internal/operators/mergeInternals.js:17:70)
    at OperatorSubscriber._this._next (/builds/epitech-it-2025/medali/medali-client-website/node_modules/rxjs/dist/cjs/internal/operators/OperatorSubscriber.js:33:21)
    at Subscriber.next (/builds/epitech-it-2025/medali/medali-client-website/node_modules/rxjs/dist/cjs/internal/Subscriber.js:51:18)
    at AsyncAction.work (/builds/epitech-it-2025/medali/medali-client-website/node_modules/rxjs/dist/cjs/internal/observable/timer.js:28:28)
    at AsyncAction._execute (/builds/epitech-it-2025/medali/medali-client-website/node_modules/rxjs/dist/cjs/internal/scheduler/AsyncAction.js:79:18)
    at AsyncAction.execute (/builds/epitech-it-2025/medali/medali-client-website/node_modules/rxjs/dist/cjs/internal/scheduler/AsyncAction.js:[67](https://gitlab.com/epitech-it-2025/medali/medali-client-website/-/jobs/7203811528#L67):26)
    at AsyncScheduler.flush (/builds/epitech-it-2025/medali/medali-client-website/node_modules/rxjs/dist/cjs/internal/scheduler/AsyncScheduler.js:38:33)
    at listOnTimeout (node:internal/timers:573:17)
    at process.processTimers (node:internal/timers:514:7)

When I manually connect to the Docker container that run the CI job, and curl http://localhost:4173, it works as expected, returning HTTP 200.

I'm able to run debug steps if needed