ansible-for-devops
ansible-for-devops copied to clipboard
geerlingguy
Issue with npm test in Zero-downtime multi-server deployment with NodeJS app
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:
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.<anonymous> (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.<anonymous> (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.<anonymous> (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.<anonymous> (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.<anonymous> (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.<anonymous> (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.<anonymous> (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.<anonymous> (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
I'm having the exact same issue. In the first run with vagrant up only 1 server had an error and the 3 other had 'changed' state, I ran vagrant destroy and ran vagrant up again and got 2 servers with errors and 2 which are fine.
If I re-run with ansible-playbook -i inventory playbooks/deploy.yml I get the following error:
TASK [Ensure Node.js API app is present.] ************************************************************************************************************************************************************************
fatal: [192.168.56.4]: FAILED! => {"ansible_facts": {"discovered_interpreter_python": "/usr/bin/python3"}, "before": "2a73724af5095247eef42ac84480b7bb0663b203", "changed": false, "msg": "Local modifications exist in the destination: /opt/demo-nodejs-api (force=no)."}
fatal: [192.168.56.3]: FAILED! => {"ansible_facts": {"discovered_interpreter_python": "/usr/bin/python3"}, "before": "2a73724af5095247eef42ac84480b7bb0663b203", "changed": false, "msg": "Local modifications exist in the destination: /opt/demo-nodejs-api (force=no)."}
fatal: [192.168.56.5]: FAILED! => {"ansible_facts": {"discovered_interpreter_python": "/usr/bin/python3"}, "before": "2a73724af5095247eef42ac84480b7bb0663b203", "changed": false, "msg": "Local modifications exist in the destination: /opt/demo-nodejs-api (force=no)."}
fatal: [192.168.56.2]: FAILED! => {"ansible_facts": {"discovered_interpreter_python": "/usr/bin/python3"}, "before": "2a73724af5095247eef42ac84480b7bb0663b203", "changed": false, "msg": "Local modifications exist in the destination: /opt/demo-nodejs-api (force=no)."}
I hope anyone can help us.
I have added 'force: yes' to git section of 'name: Ensure Node.js API app is present.' and it solved the issue. Simply had to run command 3 times 😅
it should look like this:
- name: Ensure Node.js API app is present.
git:
repo: "{{ app_repository }}"
version: "{{ app_version }}"
dest: "{{ app_directory }}"
accept_hostkey: true
force: yes
register: app_updated
notify: restart forever apps
