Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

CI: "Timed out waiting for last boot time check (timeout=600)" in staging-test-with-rebase #5401

Closed
eloquence opened this issue Jul 23, 2020 · 10 comments
Closed

CI: "Timed out waiting for last boot time check (timeout=600)" in staging-test-with-rebase #5401

eloquence opened this issue Jul 23, 2020 · 10 comments
Labels
CI-specific bug

Comments

@eloquence
Copy link
Member

eloquence commented Jul 23, 2020 •
edited
Loading

Example: https://app.circleci.com/pipelines/github/freedomofpress/securedrop/604/workflows/c35e8063-7544-4920-8c75-fef439e5cd42/jobs/42713

Similar: #4901

Output excerpt:

    TASK [Reboot if required due to security updates.] *****************************
    changed: [app-staging]
    fatal: [mon-staging]: FAILED! => {"changed": false, "elapsed": 666, "msg": "Timed out waiting
    for last boot time check (timeout=600)", "rebooted": true}
@eloquence eloquence mentioned this issue Jul 23, 2020
Closed
@eloquence eloquence changed the title CI: converge, scp error in staging-test-with-rebase CI: "Timed out waiting for last boot time check (timeout=600)" in staging-test-with-rebase Jul 23, 2020
@eloquence
Copy link
Member Author

eloquence commented Jul 23, 2020 •
edited
Loading

@conorsch wants to poke at this during the 7/23-8/5 sprint (4 hour timebox). We may still want to move the job to nightly for develop (#5336), but that won't do us much good if it keeps flaking out like this.

@eloquence eloquence mentioned this issue Jul 23, 2020
Merged
2 tasks
@zenmonkeykstop
Copy link
Contributor

Ansible 2.10 will have a new reboot parameter to set a custom command to check for last reboot, which might help. It looks like the current default, cat /proc/sys/kernel/random/boot_id, causes trouble for some folk running Ansible against containers. But that pushes any fix to mid/late August.

https://docs.ansible.com/ansible/devel/modules/reboot_module.html for more...

@eloquence
Copy link
Member Author

eloquence commented Aug 6, 2020 •
edited
Loading

@zenmonkeykstop has offered to do continued time-boxed investigation on this during the 8/6-8/20 sprint (4 hours) to get closer to understanding the root cause of this issue.

@emkll emkll mentioned this issue Aug 13, 2020
Merged
3 tasks
@gonzalo-bulnes
Copy link
Contributor

gonzalo-bulnes commented Aug 16, 2020 •
edited
Loading

Note: the reboot module docs are in latest (Ansible 2.9?), but the devel link is broken:
https://docs.ansible.com/ansible/latest/modules/reboot_module.html

@eloquence
Copy link
Member Author

Still biting us a fair bit. If nobody beats him to it, @zenmonkeykstop has committed to further investigating late in the 8/20-9/2 sprint.

@zenmonkeykstop
Copy link
Contributor

Looks like docs mentioned above moved to: https://docs.ansible.com/ansible/devel/collections/ansible/builtin/reboot_module.html

@kushaldas
Copy link
Contributor

kushaldas commented Sep 16, 2020 •
edited
Loading

Happening a lot of time in my system for both xenial and focal staging.

    TASK [Reboot if required due to security updates.] *****************************
    fatal: [mon-staging]: FAILED! => {"changed": false, "elapsed": 665, "msg": "Timed out waiting for last boot time check (timeout=600)", "rebooted": true}
    fatal: [app-staging]: FAILED! => {"changed": false, "elapsed": 665, "msg": "Timed out waiting for last boot time check (timeout=600)", "rebooted": true}

@zenmonkeykstop
Copy link
Contributor

zenmonkeykstop commented Sep 16, 2020 •
edited
Loading

Managed to get a CI run with debugging turned on where app-staging failed to reboot. Relevant log snippet below:

    12552 1600266843.15008:  ^ task is: TASK: Reboot if required due to security updates.
     12552 1600266843.15015:  ^ state is: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600266843.15019: getting the next task for host mon-staging
     12552 1600266843.15025: done getting next task for host mon-staging
     12552 1600266843.15028:  ^ task is: TASK: Reboot if required due to security updates.
     12552 1600266843.15033:  ^ state is: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600266843.15037: done building task lists
     12552 1600266843.15041: counting tasks in each state of execution
     12552 1600266843.15047: done counting tasks in each state of execution:
    	num_setups: 0
    	num_tasks: 2
    	num_rescue: 0
    	num_always: 0
     12552 1600266843.15050: advancing hosts in ITERATING_TASKS
     12552 1600266843.15054: starting to advance hosts
     12552 1600266843.15057: getting the next task for host app-staging
     12552 1600266843.15062: done getting next task for host app-staging
     12552 1600266843.15064:  ^ task is: TASK: Reboot if required due to security updates.
     12552 1600266843.15068:  ^ state is: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600266843.15074: getting the next task for host mon-staging
     12552 1600266843.15082: done getting next task for host mon-staging
     12552 1600266843.15087:  ^ task is: TASK: Reboot if required due to security updates.
     12552 1600266843.15092:  ^ state is: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600266843.15096: done advancing hosts to next task
     12552 1600266843.15111: Loading ActionModule 'reboot' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action/reboot.py (searched paths: /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action/__pycache__:/home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action) (found_in_cache=True, class_only=True)
     12552 1600266843.15118: getting variables
     12552 1600266843.15121: in VariableManager get_vars()
     12552 1600266843.15147: Calling all_inventory to load vars for app-staging
     12552 1600266843.15155: Calling groups_inventory to load vars for app-staging
     12552 1600266843.15163: Calling all_plugins_inventory to load vars for app-staging
     12552 1600266843.15205: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.15231: Calling all_plugins_play to load vars for app-staging
     12552 1600266843.15260: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.15279: Loading data from /home/sdci/securedrop-source/install_files/ansible-base/group_vars/all/securedrop
     12552 1600266843.15288: Calling groups_plugins_inventory to load vars for app-staging
     12552 1600266843.15315: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.15352: Calling groups_plugins_play to load vars for app-staging
     12552 1600266843.15381: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.15405: Loading data from /home/sdci/securedrop-source/install_files/ansible-base/group_vars/securedrop_application_server.yml
     12552 1600266843.15420: Loading data from /home/sdci/securedrop-source/install_files/ansible-base/group_vars/staging.yml
     12552 1600266843.15456: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.15499: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.16098: done with get_vars()
     12552 1600266843.16121: done getting variables
     12552 1600266843.16133: sending task start callback, copying the task so we can template it temporarily
     12552 1600266843.16139: done copying, going to template now
     12552 1600266843.16144: done templating
     12552 1600266843.16148: here goes the callback...
     12552 1600266843.16158: sending task start callback
     12552 1600266843.16164: entering _queue_task() for app-staging/reboot
     12552 1600266843.16676: worker is 1 (out of 2 available)
     12552 1600266843.16743: exiting _queue_task() for app-staging/reboot
     12552 1600266843.16941: Loading ActionModule 'reboot' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action/reboot.py (searched paths: /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action/__pycache__:/home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action) (found_in_cache=True, class_only=True)
     14936 1600266843.16944: running TaskExecutor() for app-staging/TASK: Reboot if required due to security updates.
     12552 1600266843.16958: getting variables
     12552 1600266843.16970: in VariableManager get_vars()
     12552 1600266843.17077: Calling all_inventory to load vars for mon-staging
     12552 1600266843.17104: Calling groups_inventory to load vars for mon-staging
     12552 1600266843.17115: Calling all_plugins_inventory to load vars for mon-staging
     12552 1600266843.17193: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.17235: Calling all_plugins_play to load vars for mon-staging
     12552 1600266843.17266: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     14936 1600266843.17054: in run() - task 4201ac12-000a-7afe-25dc-0000000009af
     12552 1600266843.17297: Loading data from /home/sdci/securedrop-source/install_files/ansible-base/group_vars/all/securedrop
     12552 1600266843.17313: Calling groups_plugins_inventory to load vars for mon-staging
     12552 1600266843.17343: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     14936 1600266843.17373: calling self._execute()
     12552 1600266843.17381: Calling groups_plugins_play to load vars for mon-staging
     12552 1600266843.17408: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.17435: Loading data from /home/sdci/securedrop-source/install_files/ansible-base/group_vars/securedrop_monitor_server.yml
     12552 1600266843.17456: Loading data from /home/sdci/securedrop-source/install_files/ansible-base/group_vars/staging.yml
     12552 1600266843.17497: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     12552 1600266843.17539: Loading VarsModule 'host_group_vars' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
     14936 1600266843.17749: Loading FilterModule 'core' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/core.py (found_in_cache=True, class_only=False)
     14936 1600266843.17763: Loading FilterModule 'gcp_kms_filters' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/gcp_kms_filters.py (found_in_cache=True, class_only=False)
     14936 1600266843.17771: Loading FilterModule 'ipaddr' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/ipaddr.py (found_in_cache=True, class_only=False)
     14936 1600266843.17782: Loading FilterModule 'json_query' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/json_query.py (found_in_cache=True, class_only=False)
     14936 1600266843.17790: Loading FilterModule 'k8s' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/k8s.py (found_in_cache=True, class_only=False)
     14936 1600266843.17797: Loading FilterModule 'mathstuff' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/mathstuff.py (found_in_cache=True, class_only=False)
     14936 1600266843.17804: Loading FilterModule 'molecule_core' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/molecule/provisioner/ansible/plugins/filters/molecule_core.py (found_in_cache=True, class_only=False)
     14936 1600266843.17811: Loading FilterModule 'network' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/network.py (found_in_cache=True, class_only=False)
     14936 1600266843.17817: Loading FilterModule 'urls' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/urls.py (found_in_cache=True, class_only=False)
     14936 1600266843.17823: Loading FilterModule 'urlsplit' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/urlsplit.py (found_in_cache=True, class_only=False)
     14936 1600266843.17918: Loading TestModule 'core' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/test/core.py (found_in_cache=True, class_only=False)
     14936 1600266843.17929: Loading TestModule 'files' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/test/files.py (found_in_cache=True, class_only=False)
     14936 1600266843.17937: Loading TestModule 'mathstuff' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/test/mathstuff.py (found_in_cache=True, class_only=False)
     14936 1600266843.18602: trying /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/connection
     14936 1600266843.18680: Loading Connection 'ssh' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/connection/ssh.py (found_in_cache=True, class_only=False)
     14936 1600266843.18705: trying /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/shell
     14936 1600266843.18729: Loading ShellModule 'sh' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/shell/sh.py (found_in_cache=True, class_only=False)
     14936 1600266843.18745: Loading ShellModule 'sh' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/shell/sh.py (found_in_cache=True, class_only=False)
     12552 1600266843.18744: done with get_vars()
     14936 1600266843.18764: trying /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/become
     12552 1600266843.18770: done getting variables
     12552 1600266843.18789: entering _queue_task() for mon-staging/reboot
     14936 1600266843.18808: Loading BecomeModule 'sudo' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/become/sudo.py (found_in_cache=True, class_only=False)
     14936 1600266843.19080: Loading ActionModule 'reboot' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action/reboot.py (searched paths: /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action/__pycache__:/home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action) (found_in_cache=True, class_only=False)
     14936 1600266843.19102: starting attempt loop
     14936 1600266843.19107: running the handler
     14936 1600266843.19123: reboot: running setup module to get distribution
     14936 1600266843.19226: ANSIBALLZ: using cached module: /home/sdci/.ansible/tmp/ansible-local-125524nz_9g87/ansiballz_cache/setup-ZIP_DEFLATED
     14936 1600266843.19394: _low_level_execute_command(): starting
     14936 1600266843.19407: _low_level_execute_command(): using become for this command
     12552 1600266843.19371: worker is 2 (out of 2 available)
     12552 1600266843.19443: exiting _queue_task() for mon-staging/reboot
     14936 1600266843.19477: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-gsvaudtnpebzctmsctpqdmfwhdfgtgiy ; LC_ALL=C /usr/bin/python3'"'"' && sleep 0'
     12552 1600266843.19596: done queuing things up, now waiting for results queue to drain
     12552 1600266843.19608: waiting for pending results...
     14937 1600266843.19961: running TaskExecutor() for mon-staging/TASK: Reboot if required due to security updates.
     14937 1600266843.20082: in run() - task 4201ac12-000a-7afe-25dc-0000000009af
     14937 1600266843.20183: calling self._execute()
     14936 1600266843.20190: Initial state: awaiting_escalation: BECOME-SUCCESS-gsvaudtnpebzctmsctpqdmfwhdfgtgiy
     14937 1600266843.20737: Loading FilterModule 'core' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/core.py (found_in_cache=True, class_only=False)
     14937 1600266843.20755: Loading FilterModule 'gcp_kms_filters' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/gcp_kms_filters.py (found_in_cache=True, class_only=False)
     14937 1600266843.20767: Loading FilterModule 'ipaddr' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/ipaddr.py (found_in_cache=True, class_only=False)
     14937 1600266843.20781: Loading FilterModule 'json_query' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/json_query.py (found_in_cache=True, class_only=False)
     14937 1600266843.20793: Loading FilterModule 'k8s' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/k8s.py (found_in_cache=True, class_only=False)
     14937 1600266843.20802: Loading FilterModule 'mathstuff' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/mathstuff.py (found_in_cache=True, class_only=False)
     14937 1600266843.20811: Loading FilterModule 'molecule_core' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/molecule/provisioner/ansible/plugins/filters/molecule_core.py (found_in_cache=True, class_only=False)
     14937 1600266843.20820: Loading FilterModule 'network' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/network.py (found_in_cache=True, class_only=False)
     14937 1600266843.20828: Loading FilterModule 'urls' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/urls.py (found_in_cache=True, class_only=False)
     14937 1600266843.20834: Loading FilterModule 'urlsplit' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/filter/urlsplit.py (found_in_cache=True, class_only=False)
     14937 1600266843.20941: Loading TestModule 'core' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/test/core.py (found_in_cache=True, class_only=False)
     14937 1600266843.20951: Loading TestModule 'files' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/test/files.py (found_in_cache=True, class_only=False)
     14937 1600266843.20959: Loading TestModule 'mathstuff' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/test/mathstuff.py (found_in_cache=True, class_only=False)
     14937 1600266843.21937: trying /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/connection
     14937 1600266843.22025: Loading Connection 'ssh' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/connection/ssh.py (found_in_cache=True, class_only=False)
     14937 1600266843.22054: trying /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/shell
     14937 1600266843.22081: Loading ShellModule 'sh' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/shell/sh.py (found_in_cache=True, class_only=False)
     14937 1600266843.22100: Loading ShellModule 'sh' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/shell/sh.py (found_in_cache=True, class_only=False)
     14937 1600266843.22121: trying /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/become
     14937 1600266843.22169: Loading BecomeModule 'sudo' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/become/sudo.py (found_in_cache=True, class_only=False)
     14937 1600266843.22505: Loading ActionModule 'reboot' from /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action/reboot.py (searched paths: /home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action/__pycache__:/home/sdci/securedrop-source/.venv/lib/python3.7/site-packages/ansible/plugins/action) (found_in_cache=True, class_only=False)
     14937 1600266843.22530: starting attempt loop
     14937 1600266843.22537: running the handler
     14937 1600266843.22553: reboot: running setup module to get distribution
     14937 1600266843.22677: ANSIBALLZ: using cached module: /home/sdci/.ansible/tmp/ansible-local-125524nz_9g87/ansiballz_cache/setup-ZIP_DEFLATED
     14937 1600266843.22872: _low_level_execute_command(): starting
     14937 1600266843.22907: _low_level_execute_command(): using become for this command
     14937 1600266843.22938: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-fyaidxsewknuklkrqrpvqeyfheifoxmm ; LC_ALL=C /usr/bin/python3'"'"' && sleep 0'
     14937 1600266843.23615: Initial state: awaiting_escalation: BECOME-SUCCESS-fyaidxsewknuklkrqrpvqeyfheifoxmm
     14936 1600266843.26579: stdout chunk (state=1):
    >>>BECOME-SUCCESS-gsvaudtnpebzctmsctpqdmfwhdfgtgiy
    <<<
     14936 1600266843.26605: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-gsvaudtnpebzctmsctpqdmfwhdfgtgiy'
     14936 1600266843.26615: Sending initial data
     14936 1600266843.26771: Sent initial data (255100 bytes)
     14937 1600266843.33517: stdout chunk (state=1):
    >>>BECOME-SUCCESS-fyaidxsewknuklkrqrpvqeyfheifoxmm
    <<<
     14937 1600266843.33538: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-fyaidxsewknuklkrqrpvqeyfheifoxmm'
     14937 1600266843.33546: Sending initial data
     14937 1600266843.33729: Sent initial data (255100 bytes)
     14937 1600266844.21379: stdout chunk (state=3):
    >>>
    {"invocation": {"module_args": {"gather_subset": ["min"], "filter": "*", "fact_path": "/etc/ansible/facts.d", "gather_timeout": 10}}, "ansible_facts": {"ansible_distribution_file_parsed": true, "ansible_python": {"version_info": [3, 5, 2, "final", 0], "version": {"micro": 2, "major": 3, "serial": 0, "releaselevel": "final", "minor": 5}, "type": "cpython", "executable": "/usr/bin/python3", "has_sslcontext": true}, "ansible_domain": "", "ansible_selinux": {"status": "Missing selinux Python library"}, "ansible_distribution": "Ubuntu", "ansible_dns": {"nameservers": ["192.168.121.1", "8.8.8.8", "8.8.4.4"]}, "ansible_fqdn": "mon-staging", "gather_subset": ["min"], "ansible_userspace_bits": "64", "ansible_date_time": {"day": "16", "iso8601": "2020-09-16T14:34:04Z", "weeknumber": "37", "tz_offset": "+0000", "minute": "34", "weekday": "Wednesday", "weekday_number": "3", "iso8601_micro": "2020-09-16T14:34:04.034555Z", "tz": "UTC", "hour": "14", "iso8601_basic_short": "20200916T143404", "epoch": "1600266844", "date": "2020-09-16", "month": "09", "time": "14:34:04", "year": "2020", "second": "04", "iso8601_basic": "20200916T143404034317"}, "ansible_fips": false, "ansible_user_uid": 0, "ansible_system_capabilities": ["cap_chown", "cap_dac_override", "cap_dac_read_search", "cap_fowner", "cap_fsetid", "cap_kill", "cap_setgid", "cap_setuid", "cap_setpcap", "cap_linux_immutable", "cap_net_bind_service", "cap_net_broadcast", "cap_net_admin", "cap_net_raw", "cap_ipc_lock", "cap_ipc_owner", "cap_sys_module", "cap_sys_rawio", "cap_sys_chroot", "cap_sys_ptrace", "cap_sys_pacct", "cap_sys_admin", "cap_sys_boot", "cap_sys_nice", "cap_sys_resource", "cap_sys_time", "cap_sys_tty_config", "cap_mknod", "cap_lease", "cap_audit_write", "cap_audit_control", "cap_setfcap", "cap_mac_override", "cap_mac_admin", "cap_syslog", "cap_wake_alarm", "cap_block_suspend", "37+ep"], "ansible_ssh_host_key_ed25519_public": "AAAAC3NzaC1lZDI1NTE5AAAAICnmmJiqb/yAhr5dNTZWxtAO2OZnjN6vNJMM29F42w3G", "ansible_os_family": "Debian", "ansible_ssh_host_key_rsa_public": "AAAAB3NzaC1yc2EAAAADAQABAAABAQC9yFeYuz/06diKtNkBaOM26oYMbDY4V06qgAFbkQIabZrmP3X3UBGu7EChxx2eR1KMh1y7f8hoh7esab+hwA80utZZsQmO8ceqo8f3NkbrCkhquRPO4xkX+1hqubsGtkI/K4FcQQoRrEG3le2r/wCqMR/3246hxwosrAZNdH9ExkbwcQzsmoVAigS/gzLaYwFDpAVAxDtTNSGPg8h82NITZ6wleNhJuIXaEknDX+GH5zPMTWJz2UGJT1xnndCuBaPtk2NYdmasJNa/+UrMWZkfo7UmUa9GQHPlq1LWtQ5F3gxgkdPZR6yZEkJbqXHGCDZAzmEfJw/wTubS42wCzT1j", "ansible_service_mgr": "systemd", "ansible_system_capabilities_enforced": "True", "ansible_cmdline": {"biosdevname": "0", "noefi": true, "BOOT_IMAGE": "/vmlinuz-4.14.188-grsec-securedrop", "net.ifnames": "0", "mds": "full,nosmt", "root": "/dev/mapper/vagrant--vg-root", "ro": true}, "ansible_machine_id": "ab7cf0db9091cbe26f095eb15ec69eef", "ansible_userspace_architecture": "x86_64", "ansible_distribution_release": "xenial", "ansible_effective_user_id": 0, "ansible_nodename": "mon-staging", "ansible_user_gecos": "root", "ansible_selinux_python_present": false, "ansible_machine": "x86_64", "ansible_ssh_host_key_dsa_public": "AAAAB3NzaC1kc3MAAACBAORP9bfEqbLWedoQvb5PcuAnwyR7Y224PqeVok2bflDhgs9qKYLsnLzJcCB4RKobsFA8qzQbSzEwgBZNv1uixU8ZVka+WEtLdLqBDENDQr49atYyFYnmtCoc1MQafGuUm7PN3iA+CSkpmLYWRPQyYSn8q050MWVEN/gQf6CgBhUdAAAAFQD+4+XvWYECioDGfLCRphxjZaWNxwAAAIBDXxPcqZh+Oj2a0jiIVuglqz3xKqnWC6XC/yl2OyXbQ1eloJlOfHX0OBHtlPDRJgupCCr9fqUwM822913S+YXK0jYLCZHJcomuRDFXuAzqmsEX5J04WrCbK5u389EWUmIXe9saHsEab10g7mjG1WgaXNy8MLU4pqFr9zV8Cio51QAAAIBhU3RBNXJykF/JIlcFzSueLFfhIiRfA3ozdXI3ku7Y9GH1z5TEY4ocMh+hkFh8iBxX691B5PSRHj3AkYQFyvDpUOEWIGxbmfMYXC3mat8gs9jKLIciAtJVQQrGvKu6Keup23+TZNTKU7veGYWLUQgO5T6llY94Vvv4ETc07RRvSA==", "ansible_system": "Linux", "ansible_proc_cmdline": {"biosdevname": "0", "noefi": true, "BOOT_IMAGE": "/vmlinuz-4.14.188-grsec-securedrop", "net.ifnames": "0", "mds": "full,nosmt", "root": "/dev/mapper/vagrant--vg-root", "ro": true}, "ansible_lsb": {"codename": "xenial", "major_release": "16", "description": "Ubuntu 16.04.7 LTS", "release": "16.04", "id": "Ubuntu"}, "ansible_real_group_id": 0, "ansible_user_dir": "/root", "ansible_apparmor": {"status": "enabled"}, "ansible_python_version": "3.5.2", "ansible_kernel_version": "#1 SMP Thu Jul 9 21:45:42 UTC 2020", "ansible_distribution_version": "16.04", "ansible_architecture": "x86_64", "ansible_distribution_major_version": "16", "module_setup": true, "ansible_local": {}, "ansible_real_user_id": 0, "ansible_user_id": "root", "ansible_ssh_host_key_ecdsa_public": "AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBMspV2GkiUtib9dXpiRalaI9JuTeQ+Wv83y8gbNg+lSqtrOHc9nh6gj5rbFsGpHjjjZ5cw7mFfZGuB1FduS+Km0=", "ansible_distribution_file_path": "/etc/os-release", "ansible_user_shell": "/bin/bash", "ansible_distribution_file_variety": "Debian", "ansible_pkg_mgr": "apt", "ansible_user_gid": 0, "ansible_env": {"SUDO_USER": "vagrant", "PATH": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "SHELL": "/bin/bash", "LANGUAGE": "en_US:", "LC_ALL": "C", "SUDO_GID": "1000", "SUDO_COMMAND": "/bin/sh -c echo BECOME-SUCCESS-fyaidxsewknuklkrqrpvqeyfheifoxmm ; LC_ALL=C /usr/bin/python3", "PWD": "/home/vagrant", "HOME": "/root", "USERNAME": "root", "LOGNAME": "root", "MAIL": "/var/mail/root", "LANG": "en_US.UTF-8", "USER": "root", "TERM": "unknown", "SUDO_UID": "1000"}, "ansible_hostname": "mon-staging", "ansible_kernel": "4.14.188-grsec-securedrop", "ansible_effective_group_id": 0}}
    <<<
     14937 1600266844.28082: stderr chunk (state=3):
    >>><<<
     14937 1600266844.28099: stdout chunk (state=3):
    >>><<<
     14937 1600266844.28138: _low_level_execute_command() done: rc=0, stdout=
    {"invocation": {"module_args": {"gather_subset": ["min"], "filter": "*", "fact_path": "/etc/ansible/facts.d", "gather_timeout": 10}}, "ansible_facts": {"ansible_distribution_file_parsed": true, "ansible_python": {"version_info": [3, 5, 2, "final", 0], "version": {"micro": 2, "major": 3, "serial": 0, "releaselevel": "final", "minor": 5}, "type": "cpython", "executable": "/usr/bin/python3", "has_sslcontext": true}, "ansible_domain": "", "ansible_selinux": {"status": "Missing selinux Python library"}, "ansible_distribution": "Ubuntu", "ansible_dns": {"nameservers": ["192.168.121.1", "8.8.8.8", "8.8.4.4"]}, "ansible_fqdn": "mon-staging", "gather_subset": ["min"], "ansible_userspace_bits": "64", "ansible_date_time": {"day": "16", "iso8601": "2020-09-16T14:34:04Z", "weeknumber": "37", "tz_offset": "+0000", "minute": "34", "weekday": "Wednesday", "weekday_number": "3", "iso8601_micro": "2020-09-16T14:34:04.034555Z", "tz": "UTC", "hour": "14", "iso8601_basic_short": "20200916T143404", "epoch": "1600266844", "date": "2020-09-16", "month": "09", "time": "14:34:04", "year": "2020", "second": "04", "iso8601_basic": "20200916T143404034317"}, "ansible_fips": false, "ansible_user_uid": 0, "ansible_system_capabilities": ["cap_chown", "cap_dac_override", "cap_dac_read_search", "cap_fowner", "cap_fsetid", "cap_kill", "cap_setgid", "cap_setuid", "cap_setpcap", "cap_linux_immutable", "cap_net_bind_service", "cap_net_broadcast", "cap_net_admin", "cap_net_raw", "cap_ipc_lock", "cap_ipc_owner", "cap_sys_module", "cap_sys_rawio", "cap_sys_chroot", "cap_sys_ptrace", "cap_sys_pacct", "cap_sys_admin", "cap_sys_boot", "cap_sys_nice", "cap_sys_resource", "cap_sys_time", "cap_sys_tty_config", "cap_mknod", "cap_lease", "cap_audit_write", "cap_audit_control", "cap_setfcap", "cap_mac_override", "cap_mac_admin", "cap_syslog", "cap_wake_alarm", "cap_block_suspend", "37+ep"], "ansible_ssh_host_key_ed25519_public": "AAAAC3NzaC1lZDI1NTE5AAAAICnmmJiqb/yAhr5dNTZWxtAO2OZnjN6vNJMM29F42w3G", "ansible_os_family": "Debian", "ansible_ssh_host_key_rsa_public": "AAAAB3NzaC1yc2EAAAADAQABAAABAQC9yFeYuz/06diKtNkBaOM26oYMbDY4V06qgAFbkQIabZrmP3X3UBGu7EChxx2eR1KMh1y7f8hoh7esab+hwA80utZZsQmO8ceqo8f3NkbrCkhquRPO4xkX+1hqubsGtkI/K4FcQQoRrEG3le2r/wCqMR/3246hxwosrAZNdH9ExkbwcQzsmoVAigS/gzLaYwFDpAVAxDtTNSGPg8h82NITZ6wleNhJuIXaEknDX+GH5zPMTWJz2UGJT1xnndCuBaPtk2NYdmasJNa/+UrMWZkfo7UmUa9GQHPlq1LWtQ5F3gxgkdPZR6yZEkJbqXHGCDZAzmEfJw/wTubS42wCzT1j", "ansible_service_mgr": "systemd", "ansible_system_capabilities_enforced": "True", "ansible_cmdline": {"biosdevname": "0", "noefi": true, "BOOT_IMAGE": "/vmlinuz-4.14.188-grsec-securedrop", "net.ifnames": "0", "mds": "full,nosmt", "root": "/dev/mapper/vagrant--vg-root", "ro": true}, "ansible_machine_id": "ab7cf0db9091cbe26f095eb15ec69eef", "ansible_userspace_architecture": "x86_64", "ansible_distribution_release": "xenial", "ansible_effective_user_id": 0, "ansible_nodename": "mon-staging", "ansible_user_gecos": "root", "ansible_selinux_python_present": false, "ansible_machine": "x86_64", "ansible_ssh_host_key_dsa_public": "AAAAB3NzaC1kc3MAAACBAORP9bfEqbLWedoQvb5PcuAnwyR7Y224PqeVok2bflDhgs9qKYLsnLzJcCB4RKobsFA8qzQbSzEwgBZNv1uixU8ZVka+WEtLdLqBDENDQr49atYyFYnmtCoc1MQafGuUm7PN3iA+CSkpmLYWRPQyYSn8q050MWVEN/gQf6CgBhUdAAAAFQD+4+XvWYECioDGfLCRphxjZaWNxwAAAIBDXxPcqZh+Oj2a0jiIVuglqz3xKqnWC6XC/yl2OyXbQ1eloJlOfHX0OBHtlPDRJgupCCr9fqUwM822913S+YXK0jYLCZHJcomuRDFXuAzqmsEX5J04WrCbK5u389EWUmIXe9saHsEab10g7mjG1WgaXNy8MLU4pqFr9zV8Cio51QAAAIBhU3RBNXJykF/JIlcFzSueLFfhIiRfA3ozdXI3ku7Y9GH1z5TEY4ocMh+hkFh8iBxX691B5PSRHj3AkYQFyvDpUOEWIGxbmfMYXC3mat8gs9jKLIciAtJVQQrGvKu6Keup23+TZNTKU7veGYWLUQgO5T6llY94Vvv4ETc07RRvSA==", "ansible_system": "Linux", "ansible_proc_cmdline": {"biosdevname": "0", "noefi": true, "BOOT_IMAGE": "/vmlinuz-4.14.188-grsec-securedrop", "net.ifnames": "0", "mds": "full,nosmt", "root": "/dev/mapper/vagrant--vg-root", "ro": true}, "ansible_lsb": {"codename": "xenial", "major_release": "16", "description": "Ubuntu 16.04.7 LTS", "release": "16.04", "id": "Ubuntu"}, "ansible_real_group_id": 0, "ansible_user_dir": "/root", "ansible_apparmor": {"status": "enabled"}, "ansible_python_version": "3.5.2", "ansible_kernel_version": "#1 SMP Thu Jul 9 21:45:42 UTC 2020", "ansible_distribution_version": "16.04", "ansible_architecture": "x86_64", "ansible_distribution_major_version": "16", "module_setup": true, "ansible_local": {}, "ansible_real_user_id": 0, "ansible_user_id": "root", "ansible_ssh_host_key_ecdsa_public": "AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBMspV2GkiUtib9dXpiRalaI9JuTeQ+Wv83y8gbNg+lSqtrOHc9nh6gj5rbFsGpHjjjZ5cw7mFfZGuB1FduS+Km0=", "ansible_distribution_file_path": "/etc/os-release", "ansible_user_shell": "/bin/bash", "ansible_distribution_file_variety": "Debian", "ansible_pkg_mgr": "apt", "ansible_user_gid": 0, "ansible_env": {"SUDO_USER": "vagrant", "PATH": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "SHELL": "/bin/bash", "LANGUAGE": "en_US:", "LC_ALL": "C", "SUDO_GID": "1000", "SUDO_COMMAND": "/bin/sh -c echo BECOME-SUCCESS-fyaidxsewknuklkrqrpvqeyfheifoxmm ; LC_ALL=C /usr/bin/python3", "PWD": "/home/vagrant", "HOME": "/root", "USERNAME": "root", "LOGNAME": "root", "MAIL": "/var/mail/root", "LANG": "en_US.UTF-8", "USER": "root", "TERM": "unknown", "SUDO_UID": "1000"}, "ansible_hostname": "mon-staging", "ansible_kernel": "4.14.188-grsec-securedrop", "ansible_effective_group_id": 0}}
    , stderr=
     14937 1600266844.28312: done with _execute_module (setup, {'gather_subset': 'min', '_ansible_check_mode': False, '_ansible_no_log': False, '_ansible_debug': True, '_ansible_diff': False, '_ansible_verbosity': 0, '_ansible_version': '2.9.7', '_ansible_module_name': 'setup', '_ansible_syslog_facility': 'LOG_USER', '_ansible_selinux_special_fs': ['fuse', 'nfs', 'vboxsf', 'ramfs', '9p', 'vfat'], '_ansible_string_conversion_action': 'warn', '_ansible_socket': None, '_ansible_shell_executable': '/bin/sh', '_ansible_keep_remote_files': False, '_ansible_tmpdir': None, '_ansible_remote_tmp': '~/.ansible/tmp'})
     14937 1600266844.28330: reboot: distribution: {'name': 'ubuntu', 'version': '16', 'family': 'debian'}
     14937 1600266844.28342: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14937 1600266844.28347: _low_level_execute_command(): starting
     14937 1600266844.28356: _low_level_execute_command(): using become for this command
     14937 1600266844.28385: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-xrvomycnegctgxmmjgbaomzdboeyzvam ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14937 1600266844.29307: Initial state: awaiting_escalation: BECOME-SUCCESS-xrvomycnegctgxmmjgbaomzdboeyzvam
     14936 1600266844.33578: stdout chunk (state=3):
    >>>
    {"invocation": {"module_args": {"gather_subset": ["min"], "gather_timeout": 10, "fact_path": "/etc/ansible/facts.d", "filter": "*"}}, "ansible_facts": {"ansible_os_family": "Debian", "ansible_distribution": "Ubuntu", "ansible_user_gid": 0, "ansible_effective_user_id": 0, "ansible_date_time": {"time": "14:34:04", "weekday_number": "3", "tz": "UTC", "hour": "14", "second": "04", "day": "16", "iso8601": "2020-09-16T14:34:04Z", "weekday": "Wednesday", "month": "09", "iso8601_basic_short": "20200916T143404", "iso8601_basic": "20200916T143404140334", "year": "2020", "tz_offset": "+0000", "epoch": "1600266844", "minute": "34", "weeknumber": "37", "iso8601_micro": "2020-09-16T14:34:04.140645Z", "date": "2020-09-16"}, "ansible_ssh_host_key_ecdsa_public": "AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBMspV2GkiUtib9dXpiRalaI9JuTeQ+Wv83y8gbNg+lSqtrOHc9nh6gj5rbFsGpHjjjZ5cw7mFfZGuB1FduS+Km0=", "ansible_machine": "x86_64", "ansible_user_uid": 0, "ansible_selinux": {"status": "Missing selinux Python library"}, "ansible_real_group_id": 0, "ansible_pkg_mgr": "apt", "ansible_distribution_release": "xenial", "ansible_userspace_architecture": "x86_64", "ansible_system_capabilities_enforced": "True", "ansible_kernel_version": "#1 SMP Thu Jul 9 21:45:42 UTC 2020", "ansible_local": {"tor_app": {"source_location": "http://frt7rqs6i4o2y3go.onion", "hidserv_token": "KzPZLhYd3+W6XUMXF7olth", "journalist_location": "http://ahhu4rwtndpvgwh7.onion"}}, "ansible_python_version": "3.5.2", "ansible_env": {"LANG": "en_US.UTF-8", "HOME": "/root", "USERNAME": "root", "TERM": "unknown", "LANGUAGE": "en_US:", "LOGNAME": "root", "SUDO_COMMAND": "/bin/sh -c echo BECOME-SUCCESS-gsvaudtnpebzctmsctpqdmfwhdfgtgiy ; LC_ALL=C /usr/bin/python3", "SUDO_UID": "1000", "SUDO_USER": "vagrant", "SUDO_GID": "1000", "PWD": "/home/vagrant", "USER": "root", "SHELL": "/bin/bash", "PATH": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "LC_ALL": "C", "MAIL": "/var/mail/root"}, "ansible_distribution_version": "16.04", "ansible_machine_id": "ab7cf0db9091cbe26f095eb15ec69eef", "ansible_system_capabilities": ["cap_chown", "cap_dac_override", "cap_dac_read_search", "cap_fowner", "cap_fsetid", "cap_kill", "cap_setgid", "cap_setuid", "cap_setpcap", "cap_linux_immutable", "cap_net_bind_service", "cap_net_broadcast", "cap_net_admin", "cap_net_raw", "cap_ipc_lock", "cap_ipc_owner", "cap_sys_module", "cap_sys_rawio", "cap_sys_chroot", "cap_sys_ptrace", "cap_sys_pacct", "cap_sys_admin", "cap_sys_boot", "cap_sys_nice", "cap_sys_resource", "cap_sys_time", "cap_sys_tty_config", "cap_mknod", "cap_lease", "cap_audit_write", "cap_audit_control", "cap_setfcap", "cap_mac_override", "cap_mac_admin", "cap_syslog", "cap_wake_alarm", "cap_block_suspend", "37+ep"], "ansible_nodename": "app-staging", "ansible_python": {"executable": "/usr/bin/python3", "type": "cpython", "version_info": [3, 5, 2, "final", 0], "has_sslcontext": true, "version": {"micro": 2, "minor": 5, "releaselevel": "final", "major": 3, "serial": 0}}, "ansible_ssh_host_key_ed25519_public": "AAAAC3NzaC1lZDI1NTE5AAAAICnmmJiqb/yAhr5dNTZWxtAO2OZnjN6vNJMM29F42w3G", "ansible_distribution_file_path": "/etc/os-release", "ansible_fqdn": "app-staging", "ansible_selinux_python_present": false, "ansible_effective_group_id": 0, "ansible_architecture": "x86_64", "ansible_user_dir": "/root", "ansible_kernel": "4.14.188-grsec-securedrop", "ansible_fips": false, "gather_subset": ["min"], "ansible_apparmor": {"status": "enabled"}, "ansible_real_user_id": 0, "ansible_distribution_file_variety": "Debian", "ansible_dns": {"nameservers": ["192.168.121.1", "8.8.8.8", "8.8.4.4"]}, "ansible_ssh_host_key_rsa_public": "AAAAB3NzaC1yc2EAAAADAQABAAABAQC9yFeYuz/06diKtNkBaOM26oYMbDY4V06qgAFbkQIabZrmP3X3UBGu7EChxx2eR1KMh1y7f8hoh7esab+hwA80utZZsQmO8ceqo8f3NkbrCkhquRPO4xkX+1hqubsGtkI/K4FcQQoRrEG3le2r/wCqMR/3246hxwosrAZNdH9ExkbwcQzsmoVAigS/gzLaYwFDpAVAxDtTNSGPg8h82NITZ6wleNhJuIXaEknDX+GH5zPMTWJz2UGJT1xnndCuBaPtk2NYdmasJNa/+UrMWZkfo7UmUa9GQHPlq1LWtQ5F3gxgkdPZR6yZEkJbqXHGCDZAzmEfJw/wTubS42wCzT1j", "ansible_ssh_host_key_dsa_public": "AAAAB3NzaC1kc3MAAACBAORP9bfEqbLWedoQvb5PcuAnwyR7Y224PqeVok2bflDhgs9qKYLsnLzJcCB4RKobsFA8qzQbSzEwgBZNv1uixU8ZVka+WEtLdLqBDENDQr49atYyFYnmtCoc1MQafGuUm7PN3iA+CSkpmLYWRPQyYSn8q050MWVEN/gQf6CgBhUdAAAAFQD+4+XvWYECioDGfLCRphxjZaWNxwAAAIBDXxPcqZh+Oj2a0jiIVuglqz3xKqnWC6XC/yl2OyXbQ1eloJlOfHX0OBHtlPDRJgupCCr9fqUwM822913S+YXK0jYLCZHJcomuRDFXuAzqmsEX5J04WrCbK5u389EWUmIXe9saHsEab10g7mjG1WgaXNy8MLU4pqFr9zV8Cio51QAAAIBhU3RBNXJykF/JIlcFzSueLFfhIiRfA3ozdXI3ku7Y9GH1z5TEY4ocMh+hkFh8iBxX691B5PSRHj3AkYQFyvDpUOEWIGxbmfMYXC3mat8gs9jKLIciAtJVQQrGvKu6Keup23+TZNTKU7veGYWLUQgO5T6llY94Vvv4ETc07RRvSA==", "ansible_service_mgr": "systemd", "ansible_proc_cmdline": {"net.ifnames": "0", "mds": "full,nosmt", "ro": true, "root": "/dev/mapper/vagrant--vg-root", "BOOT_IMAGE": "/vmlinuz-4.14.188-grsec-securedrop", "noefi": true, "biosdevname": "0"}, "ansible_user_gecos": "root", "module_setup": true, "ansible_userspace_bits": "64", "ansible_hostname": "app-staging", "ansible_distribution_major_version": "16", "ansible_distribution_file_parsed": true, "ansible_user_shell": "/bin/bash", "ansible_system": "Linux", "ansible_cmdline": {"net.ifnames": "0", "mds": "full,nosmt", "ro": true, "root": "/dev/mapper/vagrant--vg-root", "BOOT_IMAGE": "/vmlinuz-4.14.188-grsec-securedrop", "noefi": true, "biosdevname": "0"}, "ansible_domain": "", "ansible_lsb": {"description": "Ubuntu 16.04.7 LTS", "id": "Ubuntu", "major_release": "16", "codename": "xenial", "release": "16.04"}, "ansible_user_id": "root"}}
    <<<
     14937 1600266844.35980: stdout chunk (state=1):
    >>>BECOME-SUCCESS-xrvomycnegctgxmmjgbaomzdboeyzvam<<<
     14937 1600266844.36002: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-xrvomycnegctgxmmjgbaomzdboeyzvam'
     14937 1600266844.36083: stdout chunk (state=3):
    >>>
    <<<
     14937 1600266844.37047: stdout chunk (state=3):
    >>>3eb8fc4d-49bd-4dd5-a890-df41cb517e8e<<<
     14937 1600266844.37183: stdout chunk (state=3):
    >>>
    <<<
     14936 1600266844.39175: stderr chunk (state=3):
    >>><<<
     14936 1600266844.39194: stdout chunk (state=3):
    >>><<<
     14936 1600266844.39235: _low_level_execute_command() done: rc=0, stdout=
    {"invocation": {"module_args": {"gather_subset": ["min"], "gather_timeout": 10, "fact_path": "/etc/ansible/facts.d", "filter": "*"}}, "ansible_facts": {"ansible_os_family": "Debian", "ansible_distribution": "Ubuntu", "ansible_user_gid": 0, "ansible_effective_user_id": 0, "ansible_date_time": {"time": "14:34:04", "weekday_number": "3", "tz": "UTC", "hour": "14", "second": "04", "day": "16", "iso8601": "2020-09-16T14:34:04Z", "weekday": "Wednesday", "month": "09", "iso8601_basic_short": "20200916T143404", "iso8601_basic": "20200916T143404140334", "year": "2020", "tz_offset": "+0000", "epoch": "1600266844", "minute": "34", "weeknumber": "37", "iso8601_micro": "2020-09-16T14:34:04.140645Z", "date": "2020-09-16"}, "ansible_ssh_host_key_ecdsa_public": "AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBMspV2GkiUtib9dXpiRalaI9JuTeQ+Wv83y8gbNg+lSqtrOHc9nh6gj5rbFsGpHjjjZ5cw7mFfZGuB1FduS+Km0=", "ansible_machine": "x86_64", "ansible_user_uid": 0, "ansible_selinux": {"status": "Missing selinux Python library"}, "ansible_real_group_id": 0, "ansible_pkg_mgr": "apt", "ansible_distribution_release": "xenial", "ansible_userspace_architecture": "x86_64", "ansible_system_capabilities_enforced": "True", "ansible_kernel_version": "#1 SMP Thu Jul 9 21:45:42 UTC 2020", "ansible_local": {"tor_app": {"source_location": "http://frt7rqs6i4o2y3go.onion", "hidserv_token": "KzPZLhYd3+W6XUMXF7olth", "journalist_location": "http://ahhu4rwtndpvgwh7.onion"}}, "ansible_python_version": "3.5.2", "ansible_env": {"LANG": "en_US.UTF-8", "HOME": "/root", "USERNAME": "root", "TERM": "unknown", "LANGUAGE": "en_US:", "LOGNAME": "root", "SUDO_COMMAND": "/bin/sh -c echo BECOME-SUCCESS-gsvaudtnpebzctmsctpqdmfwhdfgtgiy ; LC_ALL=C /usr/bin/python3", "SUDO_UID": "1000", "SUDO_USER": "vagrant", "SUDO_GID": "1000", "PWD": "/home/vagrant", "USER": "root", "SHELL": "/bin/bash", "PATH": "/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "LC_ALL": "C", "MAIL": "/var/mail/root"}, "ansible_distribution_version": "16.04", "ansible_machine_id": "ab7cf0db9091cbe26f095eb15ec69eef", "ansible_system_capabilities": ["cap_chown", "cap_dac_override", "cap_dac_read_search", "cap_fowner", "cap_fsetid", "cap_kill", "cap_setgid", "cap_setuid", "cap_setpcap", "cap_linux_immutable", "cap_net_bind_service", "cap_net_broadcast", "cap_net_admin", "cap_net_raw", "cap_ipc_lock", "cap_ipc_owner", "cap_sys_module", "cap_sys_rawio", "cap_sys_chroot", "cap_sys_ptrace", "cap_sys_pacct", "cap_sys_admin", "cap_sys_boot", "cap_sys_nice", "cap_sys_resource", "cap_sys_time", "cap_sys_tty_config", "cap_mknod", "cap_lease", "cap_audit_write", "cap_audit_control", "cap_setfcap", "cap_mac_override", "cap_mac_admin", "cap_syslog", "cap_wake_alarm", "cap_block_suspend", "37+ep"], "ansible_nodename": "app-staging", "ansible_python": {"executable": "/usr/bin/python3", "type": "cpython", "version_info": [3, 5, 2, "final", 0], "has_sslcontext": true, "version": {"micro": 2, "minor": 5, "releaselevel": "final", "major": 3, "serial": 0}}, "ansible_ssh_host_key_ed25519_public": "AAAAC3NzaC1lZDI1NTE5AAAAICnmmJiqb/yAhr5dNTZWxtAO2OZnjN6vNJMM29F42w3G", "ansible_distribution_file_path": "/etc/os-release", "ansible_fqdn": "app-staging", "ansible_selinux_python_present": false, "ansible_effective_group_id": 0, "ansible_architecture": "x86_64", "ansible_user_dir": "/root", "ansible_kernel": "4.14.188-grsec-securedrop", "ansible_fips": false, "gather_subset": ["min"], "ansible_apparmor": {"status": "enabled"}, "ansible_real_user_id": 0, "ansible_distribution_file_variety": "Debian", "ansible_dns": {"nameservers": ["192.168.121.1", "8.8.8.8", "8.8.4.4"]}, "ansible_ssh_host_key_rsa_public": "AAAAB3NzaC1yc2EAAAADAQABAAABAQC9yFeYuz/06diKtNkBaOM26oYMbDY4V06qgAFbkQIabZrmP3X3UBGu7EChxx2eR1KMh1y7f8hoh7esab+hwA80utZZsQmO8ceqo8f3NkbrCkhquRPO4xkX+1hqubsGtkI/K4FcQQoRrEG3le2r/wCqMR/3246hxwosrAZNdH9ExkbwcQzsmoVAigS/gzLaYwFDpAVAxDtTNSGPg8h82NITZ6wleNhJuIXaEknDX+GH5zPMTWJz2UGJT1xnndCuBaPtk2NYdmasJNa/+UrMWZkfo7UmUa9GQHPlq1LWtQ5F3gxgkdPZR6yZEkJbqXHGCDZAzmEfJw/wTubS42wCzT1j", "ansible_ssh_host_key_dsa_public": "AAAAB3NzaC1kc3MAAACBAORP9bfEqbLWedoQvb5PcuAnwyR7Y224PqeVok2bflDhgs9qKYLsnLzJcCB4RKobsFA8qzQbSzEwgBZNv1uixU8ZVka+WEtLdLqBDENDQr49atYyFYnmtCoc1MQafGuUm7PN3iA+CSkpmLYWRPQyYSn8q050MWVEN/gQf6CgBhUdAAAAFQD+4+XvWYECioDGfLCRphxjZaWNxwAAAIBDXxPcqZh+Oj2a0jiIVuglqz3xKqnWC6XC/yl2OyXbQ1eloJlOfHX0OBHtlPDRJgupCCr9fqUwM822913S+YXK0jYLCZHJcomuRDFXuAzqmsEX5J04WrCbK5u389EWUmIXe9saHsEab10g7mjG1WgaXNy8MLU4pqFr9zV8Cio51QAAAIBhU3RBNXJykF/JIlcFzSueLFfhIiRfA3ozdXI3ku7Y9GH1z5TEY4ocMh+hkFh8iBxX691B5PSRHj3AkYQFyvDpUOEWIGxbmfMYXC3mat8gs9jKLIciAtJVQQrGvKu6Keup23+TZNTKU7veGYWLUQgO5T6llY94Vvv4ETc07RRvSA==", "ansible_service_mgr": "systemd", "ansible_proc_cmdline": {"net.ifnames": "0", "mds": "full,nosmt", "ro": true, "root": "/dev/mapper/vagrant--vg-root", "BOOT_IMAGE": "/vmlinuz-4.14.188-grsec-securedrop", "noefi": true, "biosdevname": "0"}, "ansible_user_gecos": "root", "module_setup": true, "ansible_userspace_bits": "64", "ansible_hostname": "app-staging", "ansible_distribution_major_version": "16", "ansible_distribution_file_parsed": true, "ansible_user_shell": "/bin/bash", "ansible_system": "Linux", "ansible_cmdline": {"net.ifnames": "0", "mds": "full,nosmt", "ro": true, "root": "/dev/mapper/vagrant--vg-root", "BOOT_IMAGE": "/vmlinuz-4.14.188-grsec-securedrop", "noefi": true, "biosdevname": "0"}, "ansible_domain": "", "ansible_lsb": {"description": "Ubuntu 16.04.7 LTS", "id": "Ubuntu", "major_release": "16", "codename": "xenial", "release": "16.04"}, "ansible_user_id": "root"}}
    , stderr=
     14936 1600266844.39343: done with _execute_module (setup, {'gather_subset': 'min', '_ansible_check_mode': False, '_ansible_no_log': False, '_ansible_debug': True, '_ansible_diff': False, '_ansible_verbosity': 0, '_ansible_version': '2.9.7', '_ansible_module_name': 'setup', '_ansible_syslog_facility': 'LOG_USER', '_ansible_selinux_special_fs': ['fuse', 'nfs', 'vboxsf', 'ramfs', '9p', 'vfat'], '_ansible_string_conversion_action': 'warn', '_ansible_socket': None, '_ansible_shell_executable': '/bin/sh', '_ansible_keep_remote_files': False, '_ansible_tmpdir': None, '_ansible_remote_tmp': '~/.ansible/tmp'})
     14936 1600266844.39356: reboot: distribution: {'name': 'ubuntu', 'version': '16', 'family': 'debian'}
     14936 1600266844.39361: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600266844.39364: _low_level_execute_command(): starting
     14936 1600266844.39371: _low_level_execute_command(): using become for this command
     14936 1600266844.39399: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-tihdytkmbqzvhufxrwmgvsnyfmyspxcm ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14937 1600266844.39646: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.190 closed.
    <<<
     14937 1600266844.39707: stderr chunk (state=3):
    >>><<<
     14937 1600266844.39718: stdout chunk (state=3):
    >>><<<
     14937 1600266844.39758: _low_level_execute_command() done: rc=0, stdout=
    3eb8fc4d-49bd-4dd5-a890-df41cb517e8e
    , stderr=Shared connection to 192.168.121.190 closed.
     14937 1600266844.39771: reboot: last boot time: 3eb8fc4d-49bd-4dd5-a890-df41cb517e8e
     14937 1600266844.39800: reboot: connect_timeout connection option has not been set
     14937 1600266844.39821: reboot: running find module looking in ['/sbin', '/usr/sbin', '/usr/local/sbin'] to get path for "shutdown"
     14937 1600266844.39935: ANSIBALLZ: using cached module: /home/sdci/.ansible/tmp/ansible-local-125524nz_9g87/ansiballz_cache/find-ZIP_DEFLATED
     14937 1600266844.40055: _low_level_execute_command(): starting
     14937 1600266844.40085: _low_level_execute_command(): using become for this command
     14937 1600266844.40124: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-grimyqeeuzhfhqsedljyzzxlqajehqym ; LC_ALL=C /usr/bin/python3'"'"' && sleep 0'
     14936 1600266844.40411: Initial state: awaiting_escalation: BECOME-SUCCESS-tihdytkmbqzvhufxrwmgvsnyfmyspxcm
     14937 1600266844.40730: Initial state: awaiting_escalation: BECOME-SUCCESS-grimyqeeuzhfhqsedljyzzxlqajehqym
     14936 1600266844.47182: stdout chunk (state=1):
    >>>BECOME-SUCCESS-tihdytkmbqzvhufxrwmgvsnyfmyspxcm
    <<<
     14936 1600266844.47205: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-tihdytkmbqzvhufxrwmgvsnyfmyspxcm'
     14937 1600266844.47584: stdout chunk (state=1):
    >>>BECOME-SUCCESS-grimyqeeuzhfhqsedljyzzxlqajehqym
    <<<
     14937 1600266844.47606: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-grimyqeeuzhfhqsedljyzzxlqajehqym'
     14937 1600266844.47614: Sending initial data
     14937 1600266844.47696: Sent initial data (108607 bytes)
     14936 1600266844.48032: stdout chunk (state=3):
    >>>311b651d-0bfb-4979-aa0d-9cf153eb331c
    <<<
     14936 1600266844.49780: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.59 closed.
    <<<
     14936 1600266844.49894: stderr chunk (state=3):
    >>><<<
     14936 1600266844.49912: stdout chunk (state=3):
    >>><<<
     14936 1600266844.49952: _low_level_execute_command() done: rc=0, stdout=311b651d-0bfb-4979-aa0d-9cf153eb331c
    , stderr=Shared connection to 192.168.121.59 closed.
     14936 1600266844.49967: reboot: last boot time: 311b651d-0bfb-4979-aa0d-9cf153eb331c
     14936 1600266844.49997: reboot: connect_timeout connection option has not been set
     14936 1600266844.50016: reboot: running find module looking in ['/sbin', '/usr/sbin', '/usr/local/sbin'] to get path for "shutdown"
     14936 1600266844.50137: ANSIBALLZ: using cached module: /home/sdci/.ansible/tmp/ansible-local-125524nz_9g87/ansiballz_cache/find-ZIP_DEFLATED
     14936 1600266844.50233: _low_level_execute_command(): starting
     14936 1600266844.50243: _low_level_execute_command(): using become for this command
     14936 1600266844.50264: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-xlfmegmijtcjlmwwhxcdnfztgubdecfc ; LC_ALL=C /usr/bin/python3'"'"' && sleep 0'
     14936 1600266844.51071: Initial state: awaiting_escalation: BECOME-SUCCESS-xlfmegmijtcjlmwwhxcdnfztgubdecfc
     14936 1600266844.57186: stdout chunk (state=1):
    >>>BECOME-SUCCESS-xlfmegmijtcjlmwwhxcdnfztgubdecfc
    <<<
     14936 1600266844.57210: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-xlfmegmijtcjlmwwhxcdnfztgubdecfc'
     14936 1600266844.57218: Sending initial data
     14936 1600266844.57339: Sent initial data (108607 bytes)
     14936 1600266844.87626: stdout chunk (state=3):
    >>>
    {"matched": 1, "msg": "", "changed": false, "examined": 441, "files": [{"pw_name": "root", "wusr": true, "issock": false, "isgid": false, "ischr": false, "rusr": true, "uid": 0, "dev": 64512, "isdir": false, "islnk": true, "nlink": 1, "wgrp": true, "woth": true, "mode": "0777", "size": 14, "rgrp": true, "gr_name": "root", "isblk": false, "isreg": false, "atime": 1600266190.222152, "ctime": 1600265904.4161353, "path": "/sbin/shutdown", "xusr": true, "mtime": 1599211871.0, "xgrp": true, "isfifo": false, "roth": true, "isuid": false, "inode": 2490471, "xoth": true, "gid": 0}], "invocation": {"module_args": {"size": null, "use_regex": false, "recurse": false, "age_stamp": "mtime", "file_type": "any", "paths": ["/sbin", "/usr/sbin", "/usr/local/sbin"], "excludes": null, "age": null, "contains": null, "follow": false, "get_checksum": false, "hidden": false, "depth": null, "patterns": ["shutdown"]}}}
    <<<
     14936 1600266844.92619: stderr chunk (state=3):
    >>><<<
     14936 1600266844.92638: stdout chunk (state=3):
    >>><<<
     14936 1600266844.92686: _low_level_execute_command() done: rc=0, stdout=
    {"matched": 1, "msg": "", "changed": false, "examined": 441, "files": [{"pw_name": "root", "wusr": true, "issock": false, "isgid": false, "ischr": false, "rusr": true, "uid": 0, "dev": 64512, "isdir": false, "islnk": true, "nlink": 1, "wgrp": true, "woth": true, "mode": "0777", "size": 14, "rgrp": true, "gr_name": "root", "isblk": false, "isreg": false, "atime": 1600266190.222152, "ctime": 1600265904.4161353, "path": "/sbin/shutdown", "xusr": true, "mtime": 1599211871.0, "xgrp": true, "isfifo": false, "roth": true, "isuid": false, "inode": 2490471, "xoth": true, "gid": 0}], "invocation": {"module_args": {"size": null, "use_regex": false, "recurse": false, "age_stamp": "mtime", "file_type": "any", "paths": ["/sbin", "/usr/sbin", "/usr/local/sbin"], "excludes": null, "age": null, "contains": null, "follow": false, "get_checksum": false, "hidden": false, "depth": null, "patterns": ["shutdown"]}}}
    , stderr=
     14936 1600266844.92803: done with _execute_module (find, {'paths': ['/sbin', '/usr/sbin', '/usr/local/sbin'], 'patterns': ['shutdown'], 'file_type': 'any', '_ansible_check_mode': False, '_ansible_no_log': False, '_ansible_debug': True, '_ansible_diff': False, '_ansible_verbosity': 0, '_ansible_version': '2.9.7', '_ansible_module_name': 'find', '_ansible_syslog_facility': 'LOG_USER', '_ansible_selinux_special_fs': ['fuse', 'nfs', 'vboxsf', 'ramfs', '9p', 'vfat'], '_ansible_string_conversion_action': 'warn', '_ansible_socket': None, '_ansible_shell_executable': '/bin/sh', '_ansible_keep_remote_files': False, '_ansible_tmpdir': None, '_ansible_remote_tmp': '~/.ansible/tmp'})
     14936 1600266844.92834: reboot: rebooting server with command '/sbin/shutdown -r 0 "Reboot initiated by Ansible"'
     14936 1600266844.92841: _low_level_execute_command(): starting
     14936 1600266844.92853: _low_level_execute_command(): using become for this command
     14936 1600266844.92884: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-wwrxhjzuwsgmhfkppytnudscyfnsbjne ; /sbin/shutdown -r 0 "Reboot initiated by Ansible"'"'"' && sleep 0'
     14936 1600266844.93564: Initial state: awaiting_escalation: BECOME-SUCCESS-wwrxhjzuwsgmhfkppytnudscyfnsbjne
     14937 1600266844.97542: stdout chunk (state=3):
    >>>
    {"examined": 435, "msg": "", "invocation": {"module_args": {"size": null, "excludes": null, "age_stamp": "mtime", "follow": false, "paths": ["/sbin", "/usr/sbin", "/usr/local/sbin"], "use_regex": false, "age": null, "patterns": ["shutdown"], "get_checksum": false, "depth": null, "hidden": false, "recurse": false, "contains": null, "file_type": "any"}}, "changed": false, "files": [{"size": 14, "islnk": true, "path": "/sbin/shutdown", "ischr": false, "gr_name": "root", "uid": 0, "nlink": 1, "pw_name": "root", "isreg": false, "rusr": true, "isblk": false, "atime": 1600266190.261901, "woth": true, "gid": 0, "isgid": false, "inode": 2490471, "isfifo": false, "isdir": false, "wusr": true, "ctime": 1600265904.1023552, "xusr": true, "issock": false, "xoth": true, "wgrp": true, "dev": 64512, "isuid": false, "roth": true, "rgrp": true, "mode": "0777", "mtime": 1599211871.0, "xgrp": true}], "matched": 1}
    <<<
     14936 1600266845.00300: stdout chunk (state=1):
    >>>BECOME-SUCCESS-wwrxhjzuwsgmhfkppytnudscyfnsbjne
    <<<
     14936 1600266845.00321: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-wwrxhjzuwsgmhfkppytnudscyfnsbjne'
     14937 1600266845.02837: stderr chunk (state=3):
    >>><<<
     14937 1600266845.02852: stdout chunk (state=3):
    >>><<<
     14937 1600266845.02891: _low_level_execute_command() done: rc=0, stdout=
    {"examined": 435, "msg": "", "invocation": {"module_args": {"size": null, "excludes": null, "age_stamp": "mtime", "follow": false, "paths": ["/sbin", "/usr/sbin", "/usr/local/sbin"], "use_regex": false, "age": null, "patterns": ["shutdown"], "get_checksum": false, "depth": null, "hidden": false, "recurse": false, "contains": null, "file_type": "any"}}, "changed": false, "files": [{"size": 14, "islnk": true, "path": "/sbin/shutdown", "ischr": false, "gr_name": "root", "uid": 0, "nlink": 1, "pw_name": "root", "isreg": false, "rusr": true, "isblk": false, "atime": 1600266190.261901, "woth": true, "gid": 0, "isgid": false, "inode": 2490471, "isfifo": false, "isdir": false, "wusr": true, "ctime": 1600265904.1023552, "xusr": true, "issock": false, "xoth": true, "wgrp": true, "dev": 64512, "isuid": false, "roth": true, "rgrp": true, "mode": "0777", "mtime": 1599211871.0, "xgrp": true}], "matched": 1}
    , stderr=
     14937 1600266845.02995: done with _execute_module (find, {'paths': ['/sbin', '/usr/sbin', '/usr/local/sbin'], 'patterns': ['shutdown'], 'file_type': 'any', '_ansible_check_mode': False, '_ansible_no_log': False, '_ansible_debug': True, '_ansible_diff': False, '_ansible_verbosity': 0, '_ansible_version': '2.9.7', '_ansible_module_name': 'find', '_ansible_syslog_facility': 'LOG_USER', '_ansible_selinux_special_fs': ['fuse', 'nfs', 'vboxsf', 'ramfs', '9p', 'vfat'], '_ansible_string_conversion_action': 'warn', '_ansible_socket': None, '_ansible_shell_executable': '/bin/sh', '_ansible_keep_remote_files': False, '_ansible_tmpdir': None, '_ansible_remote_tmp': '~/.ansible/tmp'})
     14937 1600266845.03022: reboot: rebooting server with command '/sbin/shutdown -r 0 "Reboot initiated by Ansible"'
     14937 1600266845.03028: _low_level_execute_command(): starting
     14937 1600266845.03037: _low_level_execute_command(): using become for this command
     14937 1600266845.03061: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-oigarwhvtteahvdlqboictlbnrerxfrj ; /sbin/shutdown -r 0 "Reboot initiated by Ansible"'"'"' && sleep 0'
     14937 1600266845.03786: Initial state: awaiting_escalation: BECOME-SUCCESS-oigarwhvtteahvdlqboictlbnrerxfrj
     14936 1600266845.04738: stdout chunk (state=3):
    >>>Shutdown scheduled for Wed 2020-09-16 14:34:05 UTC, use 'shutdown -c' to cancel.
    <<<
     14937 1600266845.12831: stdout chunk (state=1):
    >>>BECOME-SUCCESS-oigarwhvtteahvdlqboictlbnrerxfrj<<<
     14937 1600266845.12854: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-oigarwhvtteahvdlqboictlbnrerxfrj'
     14937 1600266845.12921: stdout chunk (state=3):
    >>>
    <<<
     14937 1600266845.15980: stdout chunk (state=3):
    >>>Shutdown scheduled for Wed 2020-09-16 14:34:05 UTC, use 'shutdown -c' to cancel.<<<
     14937 1600266845.16399: stdout chunk (state=3):
    >>>
    <<<
     14937 1600266845.20264: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.190 closed.
    <<<
     14937 1600266845.20375: stderr chunk (state=3):
    >>><<<
     14937 1600266845.20396: stdout chunk (state=3):
    >>><<<
     14937 1600266845.20444: _low_level_execute_command() done: rc=0, stdout=
    Shutdown scheduled for Wed 2020-09-16 14:34:05 UTC, use 'shutdown -c' to cancel.
    , stderr=Shared connection to 192.168.121.190 closed.
     14937 1600266845.20478: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14937 1600266845.20486: _low_level_execute_command(): starting
     14937 1600266845.20497: _low_level_execute_command(): using become for this command
     14937 1600266845.20526: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-xhuxraxtdeijuugvkgxhuuygbvufzcbi ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14936 1600266845.20855: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.59 closed.
    <<<
     14936 1600266845.20869: stdout chunk (state=3):
    >>><<<
     14936 1600266845.20883: stderr chunk (state=3):
    >>><<<
     14936 1600266845.20918: reboot: AnsibleConnectionFailure caught and handled: Failed to connect to the host via ssh: Shared connection to 192.168.121.59 closed.
     14936 1600266845.20938: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600266845.20941: _low_level_execute_command(): starting
     14936 1600266845.20949: _low_level_execute_command(): using become for this command
     14936 1600266845.20969: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-gbdnnhjohwhdlixrwboagyijshsbrpta ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14937 1600266845.21490: Initial state: awaiting_escalation: BECOME-SUCCESS-xhuxraxtdeijuugvkgxhuuygbvufzcbi
     14936 1600266845.21642: Initial state: awaiting_escalation: BECOME-SUCCESS-gbdnnhjohwhdlixrwboagyijshsbrpta
     14937 1600266845.51165: stderr chunk (state=1):
    >>>Shared connection to 192.168.121.190 closed.
    <<<
     14937 1600266845.51385: stderr chunk (state=1):
    >>><<<
     14937 1600266845.51399: stdout chunk (state=1):
    >>><<<
     14937 1600266845.51575: reboot: last boot time check fail 'Failed to connect to the host via ssh: Shared connection to 192.168.121.190 closed.', retrying in 1.606 seconds...
     14936 1600266846.44508: stderr chunk (state=1):
    >>>Warning: Permanently added '192.168.121.59' (ECDSA) to the list of known hosts.
    <<<
     14937 1600266847.12375: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14937 1600266847.12393: _low_level_execute_command(): starting
     14937 1600266847.12405: _low_level_execute_command(): using become for this command
     14937 1600266847.12428: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-vldangbaibnlpihxhfmbnaohomjatblr ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14937 1600266847.13207: Initial state: awaiting_escalation: BECOME-SUCCESS-vldangbaibnlpihxhfmbnaohomjatblr
     14936 1600266847.14736: stdout chunk (state=1):
    >>>BECOME-SUCCESS-gbdnnhjohwhdlixrwboagyijshsbrpta<<<
     14936 1600266847.14758: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-gbdnnhjohwhdlixrwboagyijshsbrpta'
     14936 1600266847.14910: stdout chunk (state=3):
    >>>
    <<<
     14936 1600266847.16942: stdout chunk (state=3):
    >>>311b651d-0bfb-4979-aa0d-9cf153eb331c<<<
     14936 1600266847.18363: stdout chunk (state=3):
    >>>
    <<<
     14936 1600266847.23610: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.59 closed.
    <<<
     14936 1600266847.23718: stderr chunk (state=3):
    >>><<<
     14936 1600266847.23731: stdout chunk (state=3):
    >>><<<
     14936 1600266847.23781: _low_level_execute_command() done: rc=0, stdout=
    311b651d-0bfb-4979-aa0d-9cf153eb331c
    , stderr=Warning: Permanently added '192.168.121.59' (ECDSA) to the list of known hosts.
    Shared connection to 192.168.121.59 closed.
     14936 1600266847.23795: reboot: last boot time: 311b651d-0bfb-4979-aa0d-9cf153eb331c
     14936 1600266847.23813: reboot: last boot time check fail 'boot time has not changed', retrying in 1.466 seconds...
     14936 1600266848.70457: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600266848.70470: _low_level_execute_command(): starting
     14936 1600266848.70483: _low_level_execute_command(): using become for this command
     14936 1600266848.70511: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-wkfyeevlulnozbfcgvjsafithivnufrx ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14936 1600266848.71016: Initial state: awaiting_escalation: BECOME-SUCCESS-wkfyeevlulnozbfcgvjsafithivnufrx
     14936 1600266848.76284: stdout chunk (state=1):
    >>>BECOME-SUCCESS-wkfyeevlulnozbfcgvjsafithivnufrx
    <<<
     14936 1600266848.76309: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-wkfyeevlulnozbfcgvjsafithivnufrx'
     14936 1600266848.76822: stdout chunk (state=3):
    >>>311b651d-0bfb-4979-aa0d-9cf153eb331c<<<
     14936 1600266848.76888: stdout chunk (state=3):
    >>>
    <<<
     14936 1600266848.79153: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.59 closed.
    <<<
     14936 1600266848.79223: stderr chunk (state=3):
    >>><<<
     14936 1600266848.79232: stdout chunk (state=3):
    >>><<<
     14936 1600266848.79263: _low_level_execute_command() done: rc=0, stdout=311b651d-0bfb-4979-aa0d-9cf153eb331c
    , stderr=Shared connection to 192.168.121.59 closed.
     14936 1600266848.79276: reboot: last boot time: 311b651d-0bfb-4979-aa0d-9cf153eb331c
     14936 1600266848.79291: reboot: last boot time check fail 'boot time has not changed', retrying in 2.953 seconds...
     14936 1600266851.74905: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600266851.74921: _low_level_execute_command(): starting
     14936 1600266851.74932: _low_level_execute_command(): using become for this command
     14936 1600266851.74958: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-pbpqaswyevnttcebmwcffwuxnnindsab ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14936 1600266851.75701: Initial state: awaiting_escalation: BECOME-SUCCESS-pbpqaswyevnttcebmwcffwuxnnindsab
     14936 1600266851.82688: stdout chunk (state=1):
    >>>BECOME-SUCCESS-pbpqaswyevnttcebmwcffwuxnnindsab
    <<<
     14936 1600266851.82711: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-pbpqaswyevnttcebmwcffwuxnnindsab'
     14936 1600266851.83601: stdout chunk (state=3):
    >>>311b651d-0bfb-4979-aa0d-9cf153eb331c
    <<<
     14936 1600266851.86252: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.59 closed.
    <<<
     14936 1600266851.86270: stdout chunk (state=3):
    >>><<<
     14936 1600266851.86287: stderr chunk (state=3):
    >>><<<
     14936 1600266851.86318: _low_level_execute_command() done: rc=0, stdout=311b651d-0bfb-4979-aa0d-9cf153eb331c
    , stderr=Shared connection to 192.168.121.59 closed.
     14936 1600266851.86334: reboot: last boot time: 311b651d-0bfb-4979-aa0d-9cf153eb331c
     14936 1600266851.86349: reboot: last boot time check fail 'boot time has not changed', retrying in 4.592 seconds...
     14936 1600266856.46033: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600266856.46050: _low_level_execute_command(): starting
     14936 1600266856.46063: _low_level_execute_command(): using become for this command
     14936 1600266856.46091: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-gpiofzlnxxaeomlhnkyfnepmxbziozsu ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14936 1600266856.46881: Initial state: awaiting_escalation: BECOME-SUCCESS-gpiofzlnxxaeomlhnkyfnepmxbziozsu
     14937 1600266878.69220: stderr chunk (state=1):
    >>>ssh: connect to host 192.168.121.190 port 22: Connection timed out
    <<<
     14937 1600266878.69326: stderr chunk (state=1):
    >>><<<
     14937 1600266878.69336: stdout chunk (state=1):
    >>><<<
     14937 1600266878.69514: reboot: last boot time check fail 'Failed to connect to the host via ssh: ssh: connect to host 192.168.121.190 port 22: Connection timed out', retrying in 2.54 seconds...
     14937 1600266881.23563: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14937 1600266881.23584: _low_level_execute_command(): starting
     14937 1600266881.23596: _low_level_execute_command(): using become for this command
     14937 1600266881.23620: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-ynimwkdxmetmzwcirpajtcklktcpvvvq ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14937 1600266881.24299: Initial state: awaiting_escalation: BECOME-SUCCESS-ynimwkdxmetmzwcirpajtcklktcpvvvq
     14937 1600266885.35227: stderr chunk (state=1):
    >>>ssh: connect to host 192.168.121.190 port 22: No route to host
    <<<
     14937 1600266885.35328: stderr chunk (state=1):
    >>><<<
     14937 1600266885.35338: stdout chunk (state=1):
    >>><<<
     14937 1600266885.35557: reboot: last boot time check fail 'Failed to connect to the host via ssh: ssh: connect to host 192.168.121.190 port 22: No route to host', retrying in 4.448 seconds...
     14937 1600266889.80833: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14937 1600266889.80850: _low_level_execute_command(): starting
     14937 1600266889.80859: _low_level_execute_command(): using become for this command
     14937 1600266889.80877: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-rligkzzgvnnmnbayvupbkwlmoirruttl ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14937 1600266889.81539: Initial state: awaiting_escalation: BECOME-SUCCESS-rligkzzgvnnmnbayvupbkwlmoirruttl
     14937 1600266897.21052: stderr chunk (state=1):
    >>>Warning: Permanently added '192.168.121.190' (ECDSA) to the list of known hosts.
    <<<
     14937 1600266897.54300: stdout chunk (state=1):
    >>>BECOME-SUCCESS-rligkzzgvnnmnbayvupbkwlmoirruttl
    <<<
     14937 1600266897.54316: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-rligkzzgvnnmnbayvupbkwlmoirruttl'
     14937 1600266897.55191: stdout chunk (state=3):
    >>>48997805-0df9-46df-8da7-605df11337b8
    <<<
     14937 1600266897.58289: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.190 closed.
    <<<
     14937 1600266897.58383: stderr chunk (state=3):
    >>><<<
     14937 1600266897.58396: stdout chunk (state=3):
    >>><<<
     14937 1600266897.58430: _low_level_execute_command() done: rc=0, stdout=48997805-0df9-46df-8da7-605df11337b8
    , stderr=Warning: Permanently added '192.168.121.190' (ECDSA) to the list of known hosts.
    Shared connection to 192.168.121.190 closed.
     14937 1600266897.58439: reboot: last boot time: 48997805-0df9-46df-8da7-605df11337b8
     14937 1600266897.58445: reboot: last boot time check success
     14937 1600266897.58473: reboot: attempting post-reboot test command 'whoami'
     14937 1600266897.58478: _low_level_execute_command(): starting
     14937 1600266897.58486: _low_level_execute_command(): using become for this command
     14937 1600266897.58519: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-wowsyxqqvthsfaatvwuzvxgrrzbwtygb ; whoami'"'"' && sleep 0'
     14937 1600266897.59272: Initial state: awaiting_escalation: BECOME-SUCCESS-wowsyxqqvthsfaatvwuzvxgrrzbwtygb
     14937 1600266897.67415: stdout chunk (state=1):
    >>>BECOME-SUCCESS-wowsyxqqvthsfaatvwuzvxgrrzbwtygb<<<
     14937 1600266897.67437: become_success: (source=stdout, state=awaiting_escalation): 'BECOME-SUCCESS-wowsyxqqvthsfaatvwuzvxgrrzbwtygb'
     14937 1600266897.67543: stdout chunk (state=3):
    >>>
    <<<
     14937 1600266897.69692: stdout chunk (state=3):
    >>>root
    <<<
     14937 1600266897.72341: stderr chunk (state=3):
    >>>Shared connection to 192.168.121.190 closed.
    <<<
     14937 1600266897.72359: stdout chunk (state=3):
    >>><<<
     14937 1600266897.72375: stderr chunk (state=3):
    >>><<<
     14937 1600266897.72407: _low_level_execute_command() done: rc=0, stdout=
    root
    , stderr=Shared connection to 192.168.121.190 closed.
     14937 1600266897.72421: reboot: post-reboot test command success
     14937 1600266897.72439: handler run complete
     14937 1600266897.72452: attempt loop complete, returning result
     14937 1600266897.72489: _execute() done
     14937 1600266897.72496: dumping result to json
     14937 1600266897.72503: done dumping result, returning
     14937 1600266897.72533: done running TaskExecutor() for mon-staging/TASK: Reboot if required due to security updates. [4201ac12-000a-7afe-25dc-0000000009af]
     14937 1600266897.72580: sending task result for task 4201ac12-000a-7afe-25dc-0000000009af
     14937 1600266897.73091: done sending task result for task 4201ac12-000a-7afe-25dc-0000000009af
     14937 1600266897.73165: WORKER PROCESS EXITING
    
    TASK [Reboot if required due to security updates.] *****************************
    changed: [mon-staging]
     14936 1600266978.57031: reboot: last boot time check fail 'Timeout (122s) waiting for privilege escalation prompt: ', retrying in 8.786 seconds...
     14936 1600266987.36588: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600266987.36599: _low_level_execute_command(): starting
     14936 1600266987.36609: _low_level_execute_command(): using become for this command
     14936 1600266987.36660: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-hnkwxjxdtevlrlugkshgczvsmfwvoptk ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14936 1600266987.37203: Initial state: awaiting_escalation: BECOME-SUCCESS-hnkwxjxdtevlrlugkshgczvsmfwvoptk
     14936 1600267109.46295: reboot: last boot time check fail 'Timeout (122s) waiting for privilege escalation prompt: ', retrying in 12.01 seconds...
     14936 1600267121.48844: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600267121.48857: _low_level_execute_command(): starting
     14936 1600267121.48866: _low_level_execute_command(): using become for this command
     14936 1600267121.48897: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-ebklmxsrdxhqjcdeyvuydljyzsbvqfsy ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14936 1600267121.49432: Initial state: awaiting_escalation: BECOME-SUCCESS-ebklmxsrdxhqjcdeyvuydljyzsbvqfsy
     14936 1600267243.51290: reboot: last boot time check fail 'Timeout (122s) waiting for privilege escalation prompt: ', retrying in 12.45 seconds...
     14936 1600267255.97506: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600267255.97518: _low_level_execute_command(): starting
     14936 1600267255.97531: _low_level_execute_command(): using become for this command
     14936 1600267255.97571: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-xmcdqhazrmzjqpzsatrnxjphusvdnqim ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14936 1600267255.98128: Initial state: awaiting_escalation: BECOME-SUCCESS-xmcdqhazrmzjqpzsatrnxjphusvdnqim
     14936 1600267377.98668: reboot: last boot time check fail 'Timeout (122s) waiting for privilege escalation prompt: ', retrying in 12.82 seconds...
     14936 1600267390.81521: reboot: getting boot time with command: 'cat /proc/sys/kernel/random/boot_id'
     14936 1600267390.81534: _low_level_execute_command(): starting
     14936 1600267390.81546: _low_level_execute_command(): using become for this command
     14936 1600267390.81575: _low_level_execute_command(): executing: /bin/sh -c 'sudo -H -S -n  -u root /bin/sh -c '"'"'echo BECOME-SUCCESS-lwmztoygogfodrhfbaorqveilysrviii ; cat /proc/sys/kernel/random/boot_id'"'"' && sleep 0'
     14936 1600267390.82217: Initial state: awaiting_escalation: BECOME-SUCCESS-lwmztoygogfodrhfbaorqveilysrviii
     14936 1600267512.90861: reboot: last boot time check fail 'Timeout (122s) waiting for privilege escalation prompt: ', retrying in 12.05 seconds...
     14936 1600267524.95789: handler run complete
     14936 1600267524.95816: attempt loop complete, returning result
     14936 1600267524.95846: _execute() done
     14936 1600267524.95850: dumping result to json
     14936 1600267524.95854: done dumping result, returning
     14936 1600267524.95880: done running TaskExecutor() for app-staging/TASK: Reboot if required due to security updates. [4201ac12-000a-7afe-25dc-0000000009af]
     14936 1600267524.95906: sending task result for task 4201ac12-000a-7afe-25dc-0000000009af
     14936 1600267524.95974: done sending task result for task 4201ac12-000a-7afe-25dc-0000000009af
     14936 1600267524.95984: WORKER PROCESS EXITING
     12552 1600267524.96166: marking app-staging as failed
     12552 1600267524.96198: marking host app-staging failed, current state: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600267524.96210: ^ failed state is now: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=1, rescue=0, always=0, run_state=ITERATING_COMPLETE, fail_state=FAILED_TASKS, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600267524.96216: getting the next task for host app-staging
     12552 1600267524.96224: done getting next task for host app-staging
     12552 1600267524.96228:  ^ task is: None
     12552 1600267524.96232:  ^ state is: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_COMPLETE, fail_state=FAILED_TASKS, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
    fatal: [app-staging]: FAILED! => {"changed": false, "elapsed": 679, "msg": "Timed out waiting for last boot time check (timeout=600)", "rebooted": true}
     12552 1600267524.96395: no more pending results, returning what we have
     12552 1600267524.96404: results queue empty
     12552 1600267524.96408: checking for any_errors_fatal
     12552 1600267524.96419: getting the next task for host app-staging
     12552 1600267524.96425: done getting next task for host app-staging
     12552 1600267524.96428:  ^ task is: None
     12552 1600267524.96432:  ^ state is: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_COMPLETE, fail_state=FAILED_TASKS, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600267524.96436: getting the next task for host mon-staging
     12552 1600267524.96442: done getting next task for host mon-staging
     12552 1600267524.96448:  ^ task is: TASK: Gracefully halt Qubes staging VM
     12552 1600267524.96452:  ^ state is: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600267524.96456: done checking for any_errors_fatal
     12552 1600267524.96458: checking for max_fail_percentage
     12552 1600267524.96464: marking host mon-staging failed, current state: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
     12552 1600267524.96469: ^ failed state is now: HOST STATE: block=2, task=2, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=1, rescue=0, always=0, run_state=ITERATING_COMPLETE, fail_state=FAILED_TASKS, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
    
    NO MORE HOSTS LEFT *************************************************************
     12552 1600267524.96479: (2 failed / 2 total )> 0.0 max fail
     12552 1600267524.96483: done checking for max_fail_percentage
     12552 1600267524.96486: checking to see if all hosts have failed and the running result is not ok
     12552 1600267524.96488: ^ not ok, so returning result now
    
    NO MORE HOSTS LEFT *************************************************************
    
    PLAY RECAP *********************************************************************

It doesn't look like app-staging ever becomes accessible, as the calls to check the boot_id just time out, as opposed to not getting an updated value. Full log is here.

@zenmonkeykstop zenmonkeykstop mentioned this issue Sep 16, 2020
Merged
3 tasks
@emkll emkll mentioned this issue Sep 28, 2020
Closed
22 tasks
@eloquence
Copy link
Member Author

@zenmonkeykstop's changes in #5504 have reduced the number of test flakes significantly. 🎉 Given other commitments, we're not allocating time to further investigation during the 10/1-10/15 sprint, but will revisit again in future (that could include moving this to nightly, once we have sufficient confidence in the results).

@eloquence
Copy link
Member Author

I've inspected recent runs of this workflow, and while it's still flaky, I've not seen recent recurrences of this specific issue, so closing.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
CI-specific bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@eloquence @kushaldas @gonzalo-bulnes @zenmonkeykstop