geerlingguy / geerlingguy/ansible-for-devops
Issue with npm test in Zero-downtime multi-server deployment with NodeJS app
- Dominant language
- Python
- Stars
- 9.9k
- Forks
- 3.8k
- PR merge metrics
- No merged PRs in 30d
Description
## Issue
Error during execution of the **Run Node.js API app tests** Ansible task when provisioning VM in https://github.com/geerlingguy/ansible-for-devops/tree/master/deployments-rolling
Full log:
```shell
TASK [Run Node.js API app tests.] **********************************************
fatal: [192.168.56.2]: FAILED! => {"changed": true, "cmd": ["npm", "test"], "delta": "0:00:01.326310", "end": "2023-03-13 05:07:23.132796", "msg": "non-zero return code", "rc": 1, "start": "2023-03-13 05:07:21.806486", "stderr": "(node:4710) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.\n(Use `node --trace-deprecation ...` to show where the warning was created)", "stderr_lines": ["(node:4710) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.", "(Use `node --trace-deprecation ...` to show where the warning was created)"], "stdout": "\n> test\n> mocha test --exit\n\n\n\nrestify listening at http://[::]:8080\n Hello\n /hello/:name endpoint\n ✓ returns a welcome message based on the name\n\n Ping\n /ping/:server endpoint\n ✓ tells us when a server is reachable (129ms)\n\n Ping\n /ping/:server endpoint\n ✓ tells us when a server is unreachable\n\n 1) tells us when a server is unreachable\n\n 3 passing (187ms)\n 1 failing\n\n 1) Ping\n /ping/:server endpoint\n tells us when a server is unreachable:\n Uncaught Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client\n at new NodeError (node:internal/errors:387:5)\n at ServerResponse.setHeader (node:_http_outgoing:644:11)\n at ServerResponse.__send (node_modules/restify/lib/response.js:503:18)\n at ServerResponse.send (node_modules/restify/lib/response.js:316:21)\n at /opt/demo-nodejs-api/app.js:20:11\n at Socket. (node_modules/jjg-ping/lib/ping-system.js:105:21)\n at Socket.emit (node:events:513:28)\n at Socket.emit (node:domain:489:12)\n at addChunk (node:internal/streams/readable:315:12)\n at readableAddChunk (node:internal/streams/readable:289:9)\n at Socket.Readable.push (node:internal/streams/readable:228:10)\n at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)", "stdout_lines": ["", "> test", "> mocha test --exit", "", "", "", "restify listening at http://[::]:8080", " Hello", " /hello/:name endpoint", " ✓ returns a welcome message based on the name", "", " Ping", " /ping/:server endpoint", " ✓ tells us when a server is reachable (129ms)", "", " Ping", " /ping/:server endpoint", " ✓ tells us when a server is unreachable", "", " 1) tells us when a server is unreachable", "", " 3 passing (187ms)", " 1 failing", "", " 1) Ping", " /ping/:server endpoint", " tells us when a server is unreachable:", " Uncaught Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client", " at new NodeError (node:internal/errors:387:5)", " at ServerResponse.setHeader (node:_http_outgoing:644:11)", " at ServerResponse.__send (node_modules/restify/lib/response.js:503:18)", " at ServerResponse.send (node_modules/restify/lib/response.js:316:21)", " at /opt/demo-nodejs-api/app.js:20:11", " at Socket. (node_modules/jjg-ping/lib/ping-system.js:105:21)", " at Socket.emit (node:events:513:28)", " at Socket.emit (node:domain:489:12)", " at addChunk (node:internal/streams/readable:315:12)", " at readableAddChunk (node:internal/streams/readable:289:9)", " at Socket.Readable.push (node:internal/streams/readable:228:10)", " at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)"]}
fatal: [192.168.56.4]: FAILED! => {"changed": true, "cmd": ["npm", "test"], "delta": "0:00:01.293274", "end": "2023-03-13 05:07:23.731336", "msg": "non-zero return code", "rc": 1, "start": "2023-03-13 05:07:22.438062", "stderr": "(node:4692) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.\n(Use `node --trace-deprecation ...` to show where the warning was created)", "stderr_lines": ["(node:4692) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.", "(Use `node --trace-deprecation ...` to show where the warning was created)"], "stdout": "\n> test\n> mocha test --exit\n\n\n\nrestify listening at http://[::]:8080\n Hello\n /hello/:name endpoint\n ✓ returns a welcome message based on the name\n\n Ping\n /ping/:server endpoint\n ✓ tells us when a server is reachable (82ms)\n\n Ping\n /ping/:server endpoint\n ✓ tells us when a server is unreachable\n 1) tells us when a server is unreachable\n\n 3 passing (143ms)\n 1 failing\n\n 1) Ping\n /ping/:server endpoint\n tells us when a server is unreachable:\n Uncaught Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client\n at new NodeError (node:internal/errors:387:5)\n at ServerResponse.setHeader (node:_http_outgoing:644:11)\n at ServerResponse.__send (node_modules/restify/lib/response.js:503:18)\n at ServerResponse.send (node_modules/restify/lib/response.js:316:21)\n at /opt/demo-nodejs-api/app.js:20:11\n at Socket. (node_modules/jjg-ping/lib/ping-system.js:105:21)\n at Socket.emit (node:events:513:28)\n at Socket.emit (node:domain:489:12)\n at addChunk (node:internal/streams/readable:315:12)\n at readableAddChunk (node:internal/streams/readable:289:9)\n at Socket.Readable.push (node:internal/streams/readable:228:10)\n at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)", "stdout_lines": ["", "> test", "> mocha test --exit", "", "", "", "restify listening at http://[::]:8080", " Hello", " /hello/:name endpoint", " ✓ returns a welcome message based on the name", "", " Ping", " /ping/:server endpoint", " ✓ tells us when a server is reachable (82ms)", "", " Ping", " /ping/:server endpoint", " ✓ tells us when a server is unreachable", " 1) tells us when a server is unreachable", "", " 3 passing (143ms)", " 1 failing", "", " 1) Ping", " /ping/:server endpoint", " tells us when a server is unreachable:", " Uncaught Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client", " at new NodeError (node:internal/errors:387:5)", " at ServerResponse.setHeader (node:_http_outgoing:644:11)", " at ServerResponse.__send (node_modules/restify/lib/response.js:503:18)", " at ServerResponse.send (node_modules/restify/lib/response.js:316:21)", " at /opt/demo-nodejs-api/app.js:20:11", " at Socket. (node_modules/jjg-ping/lib/ping-system.js:105:21)", " at Socket.emit (node:events:513:28)", " at Socket.emit (node:domain:489:12)", " at addChunk (node:internal/streams/readable:315:12)", " at readableAddChunk (node:internal/streams/readable:289:9)", " at Socket.Readable.push (node:internal/streams/readable:228:10)", " at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)"]}
fatal: [192.168.56.5]: FAILED! => {"changed": true, "cmd": ["npm", "test"], "delta": "0:00:01.281178", "end": "2023-03-13 05:07:23.776612", "msg": "non-zero return code", "rc": 1, "start": "2023-03-13 05:07:22.495434", "stderr": "(node:4683) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.\n(Use `node --trace-deprecation ...` to show where the warning was created)", "stderr_lines": ["(node:4683) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.", "(Use `node --trace-deprecation ...` to show where the warning was created)"], "stdout": "\n> test\n> mocha test --exit\n\n\n\nrestify listening at http://[::]:8080\n Hello\n /hello/:name endpoint\n ✓ returns a welcome message based on the name\n\n Ping\n /ping/:server endpoint\n ✓ tells us when a server is reachable (83ms)\n\n Ping\n /ping/:server endpoint\n ✓ tells us when a server is unreachable\n\n 1) tells us when a server is unreachable\n\n 3 passing (143ms)\n 1 failing\n\n 1) Ping\n /ping/:server endpoint\n tells us when a server is unreachable:\n Uncaught Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client\n at new NodeError (node:internal/errors:387:5)\n at ServerResponse.setHeader (node:_http_outgoing:644:11)\n at ServerResponse.__send (node_modules/restify/lib/response.js:503:18)\n at ServerResponse.send (node_modules/restify/lib/response.js:316:21)\n at /opt/demo-nodejs-api/app.js:20:11\n at Socket. (node_modules/jjg-ping/lib/ping-system.js:105:21)\n at Socket.emit (node:events:513:28)\n at Socket.emit (node:domain:489:12)\n at addChunk (node:internal/streams/readable:315:12)\n at readableAddChunk (node:internal/streams/readable:289:9)\n at Socket.Readable.push (node:internal/streams/readable:228:10)\n at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)", "stdout_lines": ["", "> test", "> mocha test --exit", "", "", "", "restify listening at http://[::]:8080", " Hello", " /hello/:name endpoint", " ✓ returns a welcome message based on the name", "", " Ping", " /ping/:server endpoint", " ✓ tells us when a server is reachable (83ms)", "", " Ping", " /ping/:server endpoint", " ✓ tells us when a server is unreachable", "", " 1) tells us when a server is unreachable", "", " 3 passing (143ms)", " 1 failing", "", " 1) Ping", " /ping/:server endpoint", " tells us when a server is unreachable:", " Uncaught Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client", " at new NodeError (node:internal/errors:387:5)", " at ServerResponse.setHeader (node:_http_outgoing:644:11)", " at ServerResponse.__send (node_modules/restify/lib/response.js:503:18)", " at ServerResponse.send (node_modules/restify/lib/response.js:316:21)", " at /opt/demo-nodejs-api/app.js:20:11", " at Socket. (node_modules/jjg-ping/lib/ping-system.js:105:21)", " at Socket.emit (node:events:513:28)", " at Socket.emit (node:domain:489:12)", " at addChunk (node:internal/streams/readable:315:12)", " at readableAddChunk (node:internal/streams/readable:289:9)", " at Socket.Readable.push (node:internal/streams/readable:228:10)", " at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)"]}
fatal: [192.168.56.3]: FAILED! => {"changed": true, "cmd": ["npm", "test"], "delta": "0:00:01.303229", "end": "2023-03-13 05:07:23.569470", "msg": "non-zero return code", "rc": 1, "start": "2023-03-13 05:07:22.266241", "stderr": "(node:4693) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.\n(Use `node --trace-deprecation ...` to show where the warning was created)", "stderr_lines": ["(node:4693) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.", "(Use `node --trace-deprecation ...` to show where the warning was created)"], "stdout": "\n> test\n> mocha test --exit\n\n\n\nrestify listening at http://[::]:8080\n Hello\n /hello/:name endpoint\n ✓ returns a welcome message based on the name\n\n Ping\n /ping/:server endpoint\n ✓ tells us when a server is reachable (84ms)\n\n Ping\n /ping/:server endpoint\n ✓ tells us when a server is unreachable\n\n 1) tells us when a server is unreachable\n\n 3 passing (149ms)\n 1 failing\n\n 1) Ping\n /ping/:server endpoint\n tells us when a server is unreachable:\n Uncaught Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client\n at new NodeError (node:internal/errors:387:5)\n at ServerResponse.setHeader (node:_http_outgoing:644:11)\n at ServerResponse.__send (node_modules/restify/lib/response.js:503:18)\n at ServerResponse.send (node_modules/restify/lib/response.js:316:21)\n at /opt/demo-nodejs-api/app.js:20:11\n at Socket. (node_modules/jjg-ping/lib/ping-system.js:105:21)\n at Socket.emit (node:events:513:28)\n at Socket.emit (node:domain:489:12)\n at addChunk (node:internal/streams/readable:315:12)\n at readableAddChunk (node:internal/streams/readable:289:9)\n at Socket.Readable.push (node:internal/streams/readable:228:10)\n at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)", "stdout_lines": ["", "> test", "> mocha test --exit", "", "", "", "restify listening at http://[::]:8080", " Hello", " /hello/:name endpoint", " ✓ returns a welcome message based on the name", "", " Ping", " /ping/:server endpoint", " ✓ tells us when a server is reachable (84ms)", "", " Ping", " /ping/:server endpoint", " ✓ tells us when a server is unreachable", "", " 1) tells us when a server is unreachable", "", " 3 passing (149ms)", " 1 failing", "", " 1) Ping", " /ping/:server endpoint", " tells us when a server is unreachable:", " Uncaught Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client", " at new NodeError (node:internal/errors:387:5)", " at ServerResponse.setHeader (node:_http_outgoing:644:11)", " at ServerResponse.__send (node_modules/restify/lib/response.js:503:18)", " at ServerResponse.send (node_modules/restify/lib/response.js:316:21)", " at /opt/demo-nodejs-api/app.js:20:11", " at Socket. (node_modules/jjg-ping/lib/ping-system.js:105:21)", " at Socket.emit (node:events:513:28)", " at Socket.emit (node:domain:489:12)", " at addChunk (node:internal/streams/readable:315:12)", " at readableAddChunk (node:internal/streams/readable:289:9)", " at Socket.Readable.push (node:internal/streams/readable:228:10)", " at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)"]}
```
## Tested on
Vagrant 2.3.4
Ansible 2.14.2
Python 3.9.2
Contributor guide
No contributing guide indexed for this repository
Research direction
Start in deployments-rolling and inspect the Node.js API at /opt/demo-nodejs-api/app.js, especially line 20 referenced by the failure. Run npm test in the app to reproduce the failing Ping test and trace the repeated response. Done means the provisioning task completes successfully and the test suite no longer reports ERR_HTTP_HEADERS_SENT.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- ansible, node.js
- Domain
- backend, devops
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100