search

noseka1 / openshift-auto-upi

OpenShift Automated User-Provided Infrastructure
Apache License 2.0
98 stars 51 forks source link

unable to start mirror registry #12

Open jfblaine opened 4 years ago

jfblaine commented 4 years ago

Ran into the following error when attempting to use mirror registry:

TASK [mirror_registry : Enable container-mirror-registry on boot and start it] **** fatal: [helper]: FAILED! => {"changed": false, "msg": "Unable to start service container-mirror-registry: Job for container-mirror-registry.service failed because the control process exited with error code.\nSee \"systemctl status container-mirror-registry.service\" and \"journalctl -xe\" for details.\n"}

PLAY RECAP **** helper : ok=10 changed=0 unreachable=0 failed=1 skipped=6 rescued=0 ignored=0

[root@helper-host openshift-auto-upi]# systemctl status container-mirror-registry.service ● container-mirror-registry.service - Podman container-6e79cd4be0da3086a24806aa74851677040af5cbbc01b60cab5c9ff480a351e6.service Loaded: loaded (/etc/systemd/system/container-mirror-registry.service; enabled; vendor preset: disabled) Active: failed (Result: exit-code) since Fri 2020-07-17 09:18:52 EDT; 6s ago Docs: man:podman-generate-systemd(1) Process: 12371 ExecStart=/usr/bin/podman start 6e79cd4be0da3086a24806aa74851677040af5cbbc01b60cab5c9ff480a351e6 (code=exited, status=125) Main PID: 10694 (code=exited, status=0/SUCCESS)

Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: container-mirror-registry.service: Control process exited, code=exited status=125 Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: container-mirror-registry.service: Failed with result 'exit-code'. Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: Failed to start Podman container-6e79cd4be0da3086a24806aa74851677040af5cbbc01b60cab5c9ff480a351e6.service. Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: container-mirror-registry.service: Service RestartSec=100ms expired, scheduling restart. Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: container-mirror-registry.service: Scheduled restart job, restart counter is at 5. Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: Stopped Podman container-6e79cd4be0da3086a24806aa74851677040af5cbbc01b60cab5c9ff480a351e6.service. Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: container-mirror-registry.service: Start request repeated too quickly. Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: container-mirror-registry.service: Failed with result 'exit-code'. Jul 17 09:18:52 helper-host.autoupi.example.com systemd[1]: Failed to start Podman container-6e79cd4be0da3086a24806aa74851677040af5cbbc01b60cab5c9ff480a351e6.service.

jfblaine commented 4 years ago

With debug logs:

TASK [mirror_registry : Enable container-mirror-registry on boot and start it] **** task path: /root/gitstuff/openshift-auto-upi/roles/mirror_registry/tasks/mirror_create.yml:17 2673 1594992402.40801: sending task start callback 2673 1594992402.40807: entering _queue_task() for helper/service 2673 1594992402.40813: Creating lock for service 2673 1594992402.40969: worker is 1 (out of 1 available) 2673 1594992402.41025: exiting _queue_task() for helper/service 2673 1594992402.41105: done queuing things up, now waiting for results queue to drain 2673 1594992402.41114: waiting for pending results... 2955 1594992402.41350: running TaskExecutor() for helper/TASK: mirror_registry : Enable container-mirror-registry on boot and start it 2955 1594992402.41492: in run() - task 0050568a-9a66-f27c-56e2-000000000025 2955 1594992402.41554: calling self._execute() 2955 1594992402.42075: trying /usr/share/ansible/plugins/connection 2955 1594992402.42089: trying /usr/lib/python3.6/site-packages/ansible/plugins/connection 2955 1594992402.42184: Loading Connection 'local' from /usr/lib/python3.6/site-packages/ansible/plugins/connection/local.py (searched paths: /usr/lib/python3.6/site-packages/ansible/plugins/connection:/usr/share/ansible/plugins/connection) (found_in_cache=True, class_only=False) 2955 1594992402.42210: trying /usr/lib/python3.6/site-packages/ansible/plugins/shell 2955 1594992402.42234: Loading ShellModule 'sh' from /usr/lib/python3.6/site-packages/ansible/plugins/shell/sh.py (found_in_cache=True, class_only=False) 2955 1594992402.42252: Loading ShellModule 'sh' from /usr/lib/python3.6/site-packages/ansible/plugins/shell/sh.py (found_in_cache=True, class_only=False) 2955 1594992402.42268: trying /usr/share/ansible/plugins/become 2955 1594992402.42278: trying /usr/lib/python3.6/site-packages/ansible/plugins/become 2955 1594992402.42317: Loading BecomeModule 'sudo' from /usr/lib/python3.6/site-packages/ansible/plugins/become/sudo.py (searched paths: /usr/lib/python3.6/site-packages/ansible/plugins/become:/usr/share/ansible/plugins/become) (found_in_cache=True, class_only=False) 2955 1594992402.42464: Loading ActionModule 'service' from /usr/lib/python3.6/site-packages/ansible/plugins/action/service.py (searched paths: /usr/lib/python3.6/site-packages/ansible/plugins/action:/usr/lib/python3.6/site-packages/ansible/plugins/action/pycache:/usr/share/ansible/plugins/action) (found_in_cache=True, class_only=False) 2955 1594992402.42494: starting attempt loop 2955 1594992402.42500: running the handler 2955 1594992402.42570: Loading FilterModule 'core' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/core.py (found_in_cache=True, class_only=False) 2955 1594992402.42584: Loading FilterModule 'gcp_kms_filters' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/gcp_kms_filters.py (found_in_cache=True, class_only=False) 2955 1594992402.42595: Loading FilterModule 'ipaddr' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/ipaddr.py (found_in_cache=True, class_only=False) 2955 1594992402.42604: Loading FilterModule 'json_query' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/json_query.py (found_in_cache=True, class_only=False) 2955 1594992402.42613: Loading FilterModule 'k8s' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/k8s.py (found_in_cache=True, class_only=False) 2955 1594992402.42623: Loading FilterModule 'mathstuff' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/mathstuff.py (found_in_cache=True, class_only=False) 2955 1594992402.42632: Loading FilterModule 'network' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/network.py (found_in_cache=True, class_only=False) 2955 1594992402.42641: Loading FilterModule 'urls' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/urls.py (found_in_cache=True, class_only=False) 2955 1594992402.42649: Loading FilterModule 'urlsplit' from /usr/lib/python3.6/site-packages/ansible/plugins/filter/urlsplit.py (found_in_cache=True, class_only=False) 2955 1594992402.42718: Loading TestModule 'core' from /usr/lib/python3.6/site-packages/ansible/plugins/test/core.py (found_in_cache=True, class_only=False) 2955 1594992402.42727: Loading TestModule 'files' from /usr/lib/python3.6/site-packages/ansible/plugins/test/files.py (found_in_cache=True, class_only=False) 2955 1594992402.42735: Loading TestModule 'mathstuff' from /usr/lib/python3.6/site-packages/ansible/plugins/test/mathstuff.py (found_in_cache=True, class_only=False) Running systemd 2955 1594992402.43195: _low_level_execute_command(): starting 2955 1594992402.43210: _low_level_execute_command(): executing: /bin/sh -c 'echo ~root && sleep 0'

ESTABLISH LOCAL CONNECTION FOR USER: root 2955 1594992402.43231: in local.exec_command() EXEC /bin/sh -c 'echo ~root && sleep 0' 2955 1594992402.43245: opening command with Popen() 2955 1594992402.43733: done running command with Popen() 2955 1594992402.43753: getting output with communicate() 2955 1594992402.43959: done communicating 2955 1594992402.43968: done with local.exec_command() 2955 1594992402.43980: _low_level_execute_command() done: rc=0, stdout=/root , stderr= 2955 1594992402.44018: _low_level_execute_command(): starting 2955 1594992402.44032: _low_level_execute_command(): executing: /bin/sh -c '( umask 77 && mkdir -p "` echo /root/.ansible/tmp `"&& mkdir /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637 && echo ansible-tmp-1594992402.440076-2955-56461824364637="` echo /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637 `" ) && sleep 0' 2955 1594992402.44041: in local.exec_command() EXEC /bin/sh -c '( umask 77 && mkdir -p "` echo /root/.ansible/tmp `"&& mkdir /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637 && echo ansible-tmp-1594992402.440076-2955-56461824364637="` echo /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637 `" ) && sleep 0' 2955 1594992402.44058: opening command with Popen() 2955 1594992402.44463: done running command with Popen() 2955 1594992402.44485: getting output with communicate() 2955 1594992402.45021: done communicating 2955 1594992402.45028: done with local.exec_command() 2955 1594992402.45038: _low_level_execute_command() done: rc=0, stdout=ansible-tmp-1594992402.440076-2955-56461824364637=/root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637 , stderr= 2955 1594992402.45150: ANSIBALLZ: Using generic lock for systemd 2955 1594992402.45156: ANSIBALLZ: Acquiring lock 2955 1594992402.45165: ANSIBALLZ: Lock acquired: 139910541748544 2955 1594992402.45174: ANSIBALLZ: Creating module 2955 1594992402.91153: ANSIBALLZ: Writing module into payload 2955 1594992402.91402: ANSIBALLZ: Writing module 2955 1594992402.91436: ANSIBALLZ: Renaming module 2955 1594992402.91446: ANSIBALLZ: Done creating module Using module file /usr/lib/python3.6/site-packages/ansible/modules/system/systemd.py 2955 1594992402.91555: transferring module to remote /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/AnsiballZ_systemd.py PUT /root/.ansible/tmp/ansible-local-26733wkf1lhm/tmpebcb4b9h TO /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/AnsiballZ_systemd.py 2955 1594992402.91680: done transferring module to remote 2955 1594992402.91702: _low_level_execute_command(): starting 2955 1594992402.91712: _low_level_execute_command(): executing: /bin/sh -c 'chmod u+x /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/ /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/AnsiballZ_systemd.py && sleep 0' 2955 1594992402.91720: in local.exec_command() EXEC /bin/sh -c 'chmod u+x /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/ /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/AnsiballZ_systemd.py && sleep 0' 2955 1594992402.91731: opening command with Popen() 2955 1594992402.92226: done running command with Popen() 2955 1594992402.92246: getting output with communicate() 2955 1594992402.92477: done communicating 2955 1594992402.92484: done with local.exec_command() 2955 1594992402.92494: _low_level_execute_command() done: rc=0, stdout=, stderr= 2955 1594992402.92501: _low_level_execute_command(): starting 2955 1594992402.92525: _low_level_execute_command(): executing: /bin/sh -c '/usr/libexec/platform-python /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/AnsiballZ_systemd.py && sleep 0' 2955 1594992402.92534: in local.exec_command() EXEC /bin/sh -c '/usr/libexec/platform-python /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/AnsiballZ_systemd.py && sleep 0' 2955 1594992402.92548: opening command with Popen() 2955 1594992402.92958: done running command with Popen() 2955 1594992402.92983: getting output with communicate() 2955 1594992403.36807: done communicating 2955 1594992403.36820: done with local.exec_command() 2955 1594992403.36832: _low_level_execute_command() done: rc=1, stdout= {"msg": "Unable to start service container-mirror-registry: Job for container-mirror-registry.service failed because the control process exited with error code.\nSee \"systemctl status container-mirror-registry.service\" and \"journalctl -xe\" for details.\n", "failed": true, "invocation": {"module_args": {"name": "container-mirror-registry", "state": "started", "enabled": true, "daemon_reload": false, "daemon_reexec": false, "no_block": false, "force": null, "masked": null, "user": null, "scope": null}}} , stderr= 2955 1594992403.36893: done with _execute_module (systemd, {'name': 'container-mirror-registry', 'state': 'started', 'enabled': True, '_ansible_check_mode': False, '_ansible_no_log': False, '_ansible_debug': True, '_ansible_diff': False, '_ansible_verbosity': 4, '_ansible_version': '2.9.10', '_ansible_module_name': 'systemd', '_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': '/root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/', '_ansible_remote_tmp': '~/.ansible/tmp'}) 2955 1594992403.36919: _low_level_execute_command(): starting 2955 1594992403.36946: _low_level_execute_command(): executing: /bin/sh -c 'rm -f -r /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/ > /dev/null 2>&1 && sleep 0' 2955 1594992403.36957: in local.exec_command() EXEC /bin/sh -c 'rm -f -r /root/.ansible/tmp/ansible-tmp-1594992402.440076-2955-56461824364637/ > /dev/null 2>&1 && sleep 0' 2955 1594992403.36976: opening command with Popen() 2955 1594992403.38146: done running command with Popen() 2955 1594992403.38169: getting output with communicate() 2955 1594992403.38423: done communicating 2955 1594992403.38431: done with local.exec_command() 2955 1594992403.38440: _low_level_execute_command() done: rc=0, stdout=, stderr= 2955 1594992403.38454: handler run complete 2955 1594992403.38465: attempt loop complete, returning result 2955 1594992403.38482: _execute() done 2955 1594992403.38489: dumping result to json 2955 1594992403.38497: done dumping result, returning 2955 1594992403.38518: done running TaskExecutor() for helper/TASK: mirror_registry : Enable container-mirror-registry on boot and start it [0050568a-9a66-f27c-56e2-000000000025] 2955 1594992403.38539: sending task result for task 0050568a-9a66-f27c-56e2-000000000025 2955 1594992403.38607: done sending task result for task 0050568a-9a66-f27c-56e2-000000000025 2955 1594992403.38614: WORKER PROCESS EXITING 2673 1594992403.38961: marking helper as failed 2673 1594992403.38984: marking host helper failed, current state: HOST STATE: block=2, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=5, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=4, 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), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False 2673 1594992403.38995: ^ failed state is now: HOST STATE: block=2, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=5, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (HOST STATE: block=0, task=4, 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), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False 2673 1594992403.39002: getting the next task for host helper 2673 1594992403.39012: done getting next task for host helper 2673 1594992403.39017: ^ task is: None 2673 1594992403.39022: ^ state is: HOST STATE: block=2, 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 fatal: [helper]: FAILED! => { "changed": false, "invocation": { "module_args": { "daemon_reexec": false, "daemon_reload": false, "enabled": true, "force": null, "masked": null, "name": "container-mirror-registry", "no_block": false, "scope": null, "state": "started", "user": null } }, "msg": "Unable to start service container-mirror-registry: Job for container-mirror-registry.service failed because the control process exited with error code.\nSee \"systemctl status container-mirror-registry.service\" and \"journalctl -xe\" for details.\n" } 2673 1594992403.39095: no more pending results, returning what we have 2673 1594992403.39103: results queue empty 2673 1594992403.39109: checking for any_errors_fatal 2673 1594992403.39117: done checking for any_errors_fatal 2673 1594992403.39122: checking for max_fail_percentage 2673 1594992403.39127: done checking for max_fail_percentage 2673 1594992403.39132: checking to see if all hosts have failed and the running result is not ok 2673 1594992403.39137: done checking to see if all hosts have failed 2673 1594992403.39141: getting the remaining hosts for this loop 2673 1594992403.39147: done getting the remaining hosts for this loop 2673 1594992403.39157: building list of next tasks for hosts 2673 1594992403.39162: getting the next task for host helper 2673 1594992403.39170: done getting next task for host helper 2673 1594992403.39177: ^ task is: None 2673 1594992403.39182: ^ state is: HOST STATE: block=2, 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 2673 1594992403.39188: done building task lists 2673 1594992403.39192: counting tasks in each state of execution 2673 1594992403.39198: done counting tasks in each state of execution: num_setups: 0 num_tasks: 0 num_rescue: 0 num_always: 0 2673 1594992403.39203: all hosts are done, so returning None's for all hosts 2673 1594992403.39209: done queuing things up, now waiting for results queue to drain 2673 1594992403.39214: results queue empty 2673 1594992403.39218: checking for any_errors_fatal 2673 1594992403.39223: done checking for any_errors_fatal 2673 1594992403.39227: checking for max_fail_percentage 2673 1594992403.39231: done checking for max_fail_percentage 2673 1594992403.39236: checking to see if all hosts have failed and the running result is not ok 2673 1594992403.39240: done checking to see if all hosts have failed 2673 1594992403.39245: getting the next task for host helper 2673 1594992403.39253: done getting next task for host helper 2673 1594992403.39258: ^ task is: None 2673 1594992403.39264: ^ state is: HOST STATE: block=2, 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 2673 1594992403.39272: running handlers PLAY RECAP ************************************************************************************************************************************************************************************ helper : ok=10 changed=0 unreachable=0 failed=1 skipped=6 rescued=0 ignored=0 2673 1594992403.39457: RUNNING CLEANUP