[ovirt-users] hosted engine install fails on useless DHCP lookup

Wed Feb 14 01:11:04 UTC 2018

Hello,

I'm seeing the hosted engine install fail on an Ansible playbook step. Log below. I tried looking at the file specified for retry, below (/usr/share/ovirt-hosted-engine-setup/ansible/bootstrap_local_vm.retry); it contains the word, 'localhost'. 

The log below didn't contain anything I could see that was actionable; given that it was an ansible error, I hunted down the config and enabled logging. On this run the error was different - the installer log was the same, but the reported error (from the installer changed). 

The first time, the installer said:

[ INFO  ] TASK [Wait for the host to become non operational]
[ ERROR ] fatal: [localhost]: FAILED! => {"ansible_facts": {"ovirt_hosts": []}, "attempts": 150, "changed": false}
[ ERROR ] Failed to execute stage 'Closing up': Failed executing ansible-playbook
[ INFO  ] Stage: Clean up

Second:

[ INFO  ] TASK [Get local vm ip]
[ ERROR ] fatal: [localhost]: FAILED! => {"attempts": 50, "changed": true, "cmd": "virsh -r net-dhcp-leases default | grep -i 00:16:3e:11:e7:bd | awk '{ print $5 }' | cut -f1 -d'/'", "delta": "0:00:00.093840", "end": "2018-02-13 16:53:08.658556", "rc": 0, "start": "2018-02-13 16:53:08.564716", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}
[ ERROR ] Failed to execute stage 'Closing up': Failed executing ansible-playbook
[ INFO  ] Stage: Clean up

 Ansible log below; as with that second snippet, it appears that it was trying to parse out a host name from virsh's list of DHCP leases, couldn't, and died. 

Which makes sense: I gave it a static IP, and unless I'm missing something, setup should not have been doing that. I verified that the answer file has the IP:

OVEHOSTED_VM/cloudinitVMStaticCIDR=str:10.181.26.150/24

Anyone see what is wrong here?

-j

hosted-engine --deploy log:

2018-02-13 16:20:32,138-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 TASK [Force host-deploy in offline mode]
2018-02-13 16:20:33,041-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 changed: [localhost]
2018-02-13 16:20:33,342-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 TASK [include_tasks]
2018-02-13 16:20:33,443-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 ok: [localhost]
2018-02-13 16:20:33,744-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 TASK [Obtain SSO token using username/password credentials]
2018-02-13 16:20:35,248-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 ok: [localhost]
2018-02-13 16:20:35,550-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 TASK [Add host]
2018-02-13 16:20:37,053-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 changed: [localhost]
2018-02-13 16:20:37,355-0800 INFO otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:100 TASK [Wait for the host to become non operational]
2018-02-13 16:27:48,895-0800 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:94 {u'_ansible_parsed': True, u'_ansible_no_log': False, u'changed': False, u'attempts': 150, u'invocation': {u'module_args': {u'pattern': u'name=ovirt-1.squaretrade.com', u'fetch_nested': False, u'nested_attributes': []}}, u'ansible_facts': {u'ovirt_hosts': []}}
2018-02-13 16:27:48,995-0800 ERROR otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:98 fatal: [localhost]: FAILED! => {"ansible_facts": {"ovirt_hosts": []}, "attempts": 150, "changed": false}
2018-02-13 16:27:49,297-0800 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:94 PLAY RECAP [localhost] : ok: 42 changed: 17 unreachable: 0 skipped: 2 failed: 1
2018-02-13 16:27:49,397-0800 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:94 PLAY RECAP [ovirt-engine-1.squaretrade.com] : ok: 15 changed: 8 unreachable: 0 skipped: 4 failed: 0
2018-02-13 16:27:49,498-0800 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils.run:180 ansible-playbook rc: 2
2018-02-13 16:27:49,498-0800 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils.run:187 ansible-playbook stdout:
2018-02-13 16:27:49,499-0800 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils.run:189  to retry, use: --limit @/usr/share/ovirt-hosted-engine-setup/ansible/bootstrap_local_vm.retry

2018-02-13 16:27:49,499-0800 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils.run:190 ansible-playbook stderr:
2018-02-13 16:27:49,500-0800 DEBUG otopi.context context._executeMethod:143 method exception
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/otopi/context.py", line 133, in _executeMethod
    method['method']()
  File "/usr/share/ovirt-hosted-engine-setup/scripts/../plugins/gr-he-ansiblesetup/core/misc.py", line 186, in _closeup
    r = ah.run()
  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_setup/ansible_utils.py", line 194, in run
    raise RuntimeError(_('Failed executing ansible-playbook'))
RuntimeError: Failed executing ansible-playbook
2018-02-13 16:27:49,512-0800 ERROR otopi.context context._executeMethod:152 Failed to execute stage 'Closing up': Failed executing ansible-playbook
2018-02-13 16:27:49,513-0800 DEBUG otopi.context context.dumpEnvironment:859 ENVIRONMENT DUMP - BEGIN

- - - - - -  

ansible log snip:

2018-02-13 16:52:47,548 ovirt-hosted-engine-setup-ansible ansible on_any args (<ansible.executor.task_result.TaskResult object at 0x7f00dc19f850>,) kwargs {}
2018-02-13 16:52:58,124 ovirt-hosted-engine-setup-ansible ansible on_any args (<ansible.executor.task_result.TaskResult object at 0x2a09310>,) kwargs {}
2018-02-13 16:53:08,954 ovirt-hosted-engine-setup-ansible var changed: host "localhost" var "local_vm_ip" type "<type 'dict'>" value: "{'stderr_lines': [], u'changed': True, u'end': u'2018-02-13 16:53:08.658556', u'stdout': u'', u'cmd': u"virsh -r net-dhcp-leases default | grep -i 00:16:3e:11:e7:bd | awk '{ print $5 }' | cut -f1 -d'/'", u'rc': 0, u'start': u'2018-02-13 16:53:08.564716', 'attempts': 50, u'stderr': u'', u'delta': u'0:00:00.093840', 'stdout_lines': [], 'failed': True}"