ovb jobs fail with mistral InvalidActionException

[Martin André]

Since this morning all the ovb jobs fail with a mistral error in the overcloud_prep_images step:

2017-07-06 08:14:49 | [{u'result': u'Failed to run task [error=Failed to find action [action_name=baremetal_introspection.introspect], wf=tripleo.baremetal.v1._introspect, task=start_introspection]:\nTraceback (most recent call last):\n File "/usr/lib/python2.7/site-packages/mistral/engine/task_handler.py", line 58, in run_task\n task.run()\n File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper\n return f(*args, **kwargs)\n File "/usr/lib/python2.7/site-packages/mistral/engine/tasks.py", line 273, in run\n self._run_new()\n File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper\n return f(*args, **kwargs)\n File "/usr/lib/python2.7/site-packages/mistral/engine/tasks.py", line 297, in _run_new\n self._schedule_actions()\n File "/usr/lib/python2.7/site-packages/mistral/engine/tasks.py", line 358, in _schedule_actions\n action = self._build_action()\n File "/usr/lib/python2.7/site-packages/mistral/engine/tasks.py", line 416, in _build_action\n self.wf_spec.get_name()\n File "/usr/lib/python2.7/site-packages/mistral/engine/actions.py", line 567, in resolve_action_definition\n "Failed to find action [action_name=%s]" % action_spec_name\nInvalidActionException: Failed to find action [action_name=baremetal_introspection.introspect]\n'}, {u'result': u'Failed to run task [error=Failed to find action [action_name=baremetal_introspection.introspect], wf=tripleo.baremetal.v1._introspect, task=start_introspection]:\nTraceback (most recent call last):\n File "/usr/lib/python2.7/site-packages/mistral/engine/task_handler.py", line 58, in run_task\n task.run()\n File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper\n return f(*args, **kwargs)\n File "/usr/lib/python2.7/site-packages/mistral/engine/tasks.py", line 273, in run\n self._run_new()\n File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper\n return f(*args, **kwargs)\n File "/usr/lib/python2.7/site-packages/mistral/engine/tasks.py", line 297, in _run_new\n self._schedule_actions()\n File "/usr/lib/python2.7/site-packages/mistral/engine/tasks.py", line 358, in _schedule_actions\n action = self._build_action()\n File "/usr/lib/python2.7/site-packages/mistral/engine/tasks.py", line 416, in _build_action\n self.wf_spec.get_name()\n File "/usr/lib/python2.7/site-packages/mistral/engine/actions.py", line 567, in resolve_action_definition\n "Failed to find action [action_name=%s]" % action_spec_name\nInvalidActionException: Failed to find action [action_name=baremetal_introspection.introspect]\n'}]

http://logs.openstack.org/53/476153/12/check-tripleo/gate-tripleo-ci-centos-7-ovb-containers-oooq/cf7ffab/logs/undercloud/home/jenkins/overcloud_prep_images.log.txt.gz#_2017-07-06_08_14_49

[Martin André (mandre)]

It appears mistral fails to load ironic actions:

http://logs.openstack.org/53/476153/12/check-tripleo/gate-tripleo-ci-centos-7-ovb-ha-oooq/56903c3/logs/undercloud/var/log/mistral/mistral-db-manage.log.txt.gz#_2017-07-06_07_48_36_576

[Sagi (Sergey) Shnaidman (sshnaidm)]

Seems like ironic-inspector fails to start:
http://logs.openstack.org/53/476153/12/check-tripleo/gate-tripleo-ci-centos-7-ovb-ha-oooq/56903c3/logs/undercloud/var/log/messages.txt.gz#_Jul__6_07_59_02

Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: 2017-07-06 07:59:02.682 4694 INFO werkzeug [-] 192.168.24.1 - - [06/Jul/2017 07:59:02] "OPTIONS / HTTP/1.0" 200 -
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: Traceback (most recent call last):
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib64/python2.7/SocketServer.py", line 295, in _handle_request_noblock
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: self.process_request(request, client_address)
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib64/python2.7/SocketServer.py", line 321, in process_request
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: self.finish_request(request, client_address)
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib64/python2.7/SocketServer.py", line 334, in finish_request
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: self.RequestHandlerClass(request, client_address, self)
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib64/python2.7/SocketServer.py", line 651, in __init__
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: self.finish()
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib64/python2.7/SocketServer.py", line 710, in finish
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: self.wfile.close()
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib64/python2.7/socket.py", line 279, in close
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: self.flush()
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib64/python2.7/socket.py", line 303, in flush
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: self._sock.sendall(view[write_offset:write_offset+buffer_size])
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 390, in sendall
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: tail = self.send(data, flags)
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 384, in send
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: return self._send_loop(self.fd.send, data, flags)
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 371, in _send_loop
Jul 6 07:59:02 tripleo-centos-7-tripleo-test-cloud-rh...

[Sagi (Sergey) Shnaidman (sshnaidm)]

This may happen because of iptables(?):

http://logs.openstack.org/53/476153/12/check-tripleo/gate-tripleo-ci-centos-7-ovb-ha-oooq/56903c3/logs/undercloud/var/log/messages.txt.gz#_Jul__6_07_48_53

Jul 6 07:48:34 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: 2017-07-06 07:48:34.297 4694 DEBUG ironic_inspector.firewall [-] Ignoring failed iptables ('-D', 'INPUT', '-i', 'br-ctlplane', '-p', 'udp', '--dport', '67', '-j', 'ironic-inspector'): iptables v1.4.21: Couldn't load target `ironic-inspector':No such file or directory. . Try `iptables -h' or 'iptables --help' for more information.. _iptables /usr/lib/python2.7/site-packages/ironic_inspector/firewall.py:51

Jul 6 07:48:35 tripleo-centos-7-tripleo-test-cloud-rh1-9675551 ironic-inspector: 2017-07-06 07:48:35.262 4694 DEBUG ironic_inspector.firewall [-] Ignoring failed iptables ('-F', 'ironic-inspector'): iptables: No chain/target/match by that name.. _iptables /usr/lib/python2.7/site-packages/ironic_inspector/firewall.py:51

[Martin André (mandre)]

I don't know if it's really iptables, because iptables-save shows that the rule is there:

-A INPUT -i br-ctlplane -p udp -m udp --dport 67 -j ironic-inspector

http://logs.openstack.org/53/476153/12/check-tripleo/gate-tripleo-ci-centos-7-ovb-ha-oooq/56903c3/logs/undercloud/var/log/host_info.txt.gz

If I understand the logs correctly, ironic-inspectors deletes the chain and recreates it later. We can see the following calls to iptables to create the rule are ok.

[Emilien Macchi (emilienm)]

I'm trying https://review.openstack.org/#/c/481076/ first - I think we need a tripleo promotion to get https://review.openstack.org/#/c/481076/ working