Bug 1270818

Summary: Two ironic-inspector processes are running on the undercloud, breaking the introspection
Product: [Community] RDO Reporter: Marius Cornea <mcornea>
Component: rdo-managerAssignee: Hugh Brock <hbrock>
Status: CLOSED WORKSFORME QA Contact: Shai Revivo <srevivo>
Severity: high Docs Contact:
Priority: unspecified    
Version: LibertyCC: dtantsur, goneri, jtrowbri, mburns, mcornea
Target Milestone: ---   
Target Release: Liberty   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-04-18 08:50:12 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
openstack-ironic-inspector log none

Description Marius Cornea 2015-10-12 12:54:07 UTC 
Description of problem:
openstack baremetal introspection bulk status reports 'Unexpected exception in background introspection thread ' for one of the nodes

Version-Release number of selected component (if applicable):
python-ironicclient-0.8.2-dev1.el7.centos.noarch
openstack-ironic-api-4.2.1-dev5.el7.centos.noarch
openstack-ironic-conductor-4.2.1-dev5.el7.centos.noarch
openstack-ironic-common-4.2.1-dev5.el7.centos.noarch
openstack-ironic-inspector-2.2.2-dev1.el7.centos.noarch
python-ironic-inspector-client-1.2.1-dev3.el7.centos.noarch


How reproducible:
100%

Steps to Reproduce:
1. Follow the docs at https://repos.fedorapeople.org/repos/openstack-m/rdo-manager-docs/liberty/
2. Register 8 nodes:
openstack baremetal import --json instackenv.json
3. openstack baremetal configure boot
4. openstack baremetal introspection bulk start 

Actual results:
Introspection completed with errors. When running 'openstack baremetal introspection bulk status' one of the nodes shows 'Unexpected exception in background introspection thread' in the Error column.

Expected results:
Introspections completes ok for all the nodes.

Additional info:
Even though the introspection reports errors, the discovered properties are there for the node. 

[stack@instack ~]$ openstack baremetal introspection bulk status | grep 1f3f4aa1-783e-4053-8c6a-f0cd88ac312d
| 1f3f4aa1-783e-4053-8c6a-f0cd88ac312d | True     | Unexpected exception in background introspection thread |

[stack@instack ~]$ ironic node-show 1f3f4aa1-783e-4053-8c6a-f0cd88ac312d | grep -A1 properties
| properties             | {u'memory_mb': u'8192', u'cpu_arch': u'x86_64', u'local_gb': u'40',   |
|                        | u'cpus': u'4', u'capabilities': u'boot_option:local'}                 |
Comment 1 Dmitry Tantsur 2015-10-19 09:03:51 UTC 
Hi! Please provide logs for ironic-inspector:

 sudo journalctl -u openstack-ironic-inspector
Comment 2 Marius Cornea 2015-10-19 10:33:09 UTC 
Created attachment 1084328 [details]
openstack-ironic-inspector log

Attached. Thanks!
Comment 3 Dmitry Tantsur 2015-10-19 11:38:22 UTC 
Related logs:

ironic-inspector : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ironic-inspector-rootwrap /etc/ironic-inspector/rootwrap.conf iptables -w -E ironic-inspector_temp ironic-inspector
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.firewall [-] iptables ('-E', 'ironic-inspector_temp', 'ironic-inspector') failed:
iptables: No chain/target/match by that name.
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect [-] Unexpected exception in background introspection thread
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect Traceback (most recent call last):
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect   File "/usr/lib/python2.7/site-packages/ironic_inspector/introspect.py", line 106, in _handle_exceptions
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect     _background_introspect(ironic, node_info)
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect   File "/usr/lib/python2.7/site-packages/ironic_inspector/introspect.py", line 127, in _background_introspect
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect     firewall.update_filters(ironic)
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect   File "/usr/lib/python2.7/site-packages/ironic_inspector/firewall.py", line 149, in update_filters
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect     _iptables('-E', NEW_CHAIN, CHAIN)
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect   File "/usr/lib/python2.7/site-packages/ironic_inspector/firewall.py", line 42, in _iptables
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect     subprocess.check_output(cmd, **kwargs)
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect   File "/usr/lib64/python2.7/subprocess.py", line 575, in check_output
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect     raise CalledProcessError(retcode, cmd, output=output)
2015-10-19 10:25:52.051 16410 ERROR ironic_inspector.introspect CalledProcessError: Command '('sudo', 'ironic-inspector-rootwrap', '/etc/ironic-inspector/rootwrap.conf', 'iptables', '-w', '-E', 'ironic-inspector_temp', 'ironic-inspector')' returned non-zero exit status 1
Comment 4 Dmitry Tantsur 2015-10-19 11:45:21 UTC 
One more thing: how reproduceable is this problem?
Comment 5 Marius Cornea 2015-10-19 12:07:43 UTC 
It only shows up when I register more nodes, last time I registered 15 for example, with 6 it didn't show up.

python-eventlet-0.17.4-1.el7.noarch
Comment 6 Dmitry Tantsur 2015-10-19 13:53:38 UTC 
Hi! When looking into the log we've noticed something weird: it looks like there's several PID's in log. Could you please check that you don't have several instances of inspector running? Namely, PID's 16338 and 16410
Comment 7 Marius Cornea 2015-10-19 21:22:27 UTC 
I don't have that environment available anymore but checking another environment I can see 2 inspector processes:

stack@instack:~>>> ps axu | grep ironic-inspector | grep -v grep
ironic-+ 16293  1.2  0.3 331856 51556 ?        Ss   11:47   6:54 /usr/bin/python2 /usr/bin/ironic-inspector --config-file /etc/ironic-inspector/inspector.conf
nobody   16320  0.0  0.0  15496   404 ?        S    11:47   0:00 /sbin/dnsmasq --conf-file=/etc/ironic-inspector/dnsmasq.conf
ironic-+ 16365  1.0  0.3 338216 55912 ?        S    11:47   6:00 /usr/bin/python2 /usr/bin/ironic-inspector --config-file /etc/ironic-inspector/inspector.conf
Comment 8 Dmitry Tantsur 2015-10-20 08:01:43 UTC 
Hmmm, this is not supposed to work, probably puppet folks should take a look.
Comment 11 Dmitry Tantsur 2016-04-18 08:50:12 UTC 
I haven't seen this or complaints about this for a long time already, so I assume it's fixed now. Please reopen if you can reproduce with the latest code.