geerlingguy / geerlingguy/ansible-for-devops

Issue with npm test in Zero-downtime multi-server deployment with NodeJS app

Open
#536 2 comments 0 reactions 0 assignees View on GitHub
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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.