XenAPI: With ovs polling mode, Neutron gets the error of oslo_rootwrap.wrapper.FilterMatchNotExecutable

[Jianghua Wang]

When enabled polling mode for XenAPI, the neutron q-domua always get the error of oslo_rootwrap.wrapper.FilterMatchNotExecutable. See the following log.

With ovs polling mode, ovs will report data to neutron once any ovs DB update. So there is chance to report partialy data for vifs before ovs DB synced-up with xapi. so it will invoke xe command to get iface-id. But xe is not in the allowed command list. So it will raise errors.

https://github.com/openstack/neutron/blob/master/neutron/agent/common/ovs_lib.py#L418

2016-12-12 09:59:31.449 32172 DEBUG neutron.agent.linux.async_process [-] Output received from [ovsdb-client monitor tcp:192.168.33.2:6640 Interface name,ofport,external_ids --format=json]: {"data":[["2d32873e-2b35-47ba-90b3-81c953fd8193","old",null,["set",[]],null],["","new","vif16.0",1,["map",[["attached-mac","fa:16:3e:c9:46:63"],["xs-network-uuid","75ba394a-ed6a-549e-d608-9ad43461c462"],["xs-vif-uuid","f72ce34c-f1cb-f54c-3132-bfd97fabef37"],["xs-vm-uuid","c91f272e-a710-2c00-818d-df05953f34d9"]]]]],"headings":["row","action","name","ofport","external_ids"]} _read_stdout /opt/stack/new/neutron/neutron/agent/linux/async_process.py:238
2016-12-12 09:59:31.469 32172 DEBUG neutron.agent.linux.async_process [-] Output received from [ovsdb-client monitor tcp:192.168.33.2:6640 Interface name,ofport,external_ids --format=json]: {"data":[["2d32873e-2b35-47ba-90b3-81c953fd8193","old",null,null,["map",[["attached-mac","fa:16:3e:c9:46:63"],["xs-network-uuid","75ba394a-ed6a-549e-d608-9ad43461c462"],["xs-vif-uuid","f72ce34c-f1cb-f54c-3132-bfd97fabef37"],["xs-vm-uuid","c91f272e-a710-2c00-818d-df05953f34d9"]]]],["","new","vif16.0",1,["map",[["attached-mac","fa:16:3e:c9:46:63"],["iface-id","81329e07-4df2-4239-a2c6-1cba950741a4"],["iface-status","active"],["vm-id","c91f272e-a710-2c00-818d-df05953f34d9"],["xs-network-uuid","75ba394a-ed6a-549e-d608-9ad43461c462"],["xs-vif-uuid","f72ce34c-f1cb-f54c-3132-bfd97fabef37"],["xs-vm-uuid","c91f272e-a710-2c00-818d-df05953f34d9"]]]]],"headings":["row","action","name","ofport","external_ids"]} _read_stdout /opt/stack/new/neutron/neutron/agent/linux/async_process.py:238
2016-12-12 09:59:31.469 32172 DEBUG neutron.agent.ovsdb.native.vlog [-] [POLLIN] on fd 7 __log_wakeup /usr/local/lib/python2.7/dist-packages/ovs/poller.py:202
2016-12-12 09:59:31.511 32172 DEBUG neutron.agent.ovsdb.native.vlog [-] [POLLIN] on fd 7 __log_wakeup /usr/local/lib/python2.7/dist-packages/ovs/poller.py:202
2016-12-12 09:59:31.711 32172 DEBUG neutron.agent.ovsdb.native.vlog [-] [POLLIN] on fd 7 __log_wakeup /usr/local/lib/python2.7/dist-packages/ovs/poller.py:202
2016-12-12 09:59:32.346 32172 DEBUG neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-ba252219-a9c6-4354-9981-3cfeff7ca54f - -] Agent rpc_loop - iteration:251 started rpc_loop /opt/stack/new/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py:1943
2016-12-12 09:59:32.351 32172 DEBUG neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [req-ba252219-a9c6-4354-9981-3cfeff7ca54f - -] ofctl request version=0x4,msg_type=0x12,msg_len=0x38,xid=0x9a58c035,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) result [OFPFlowStatsReply(body=[OFPFlowStats(byte_count=0,cookie=9912536195431297602L,duration_nsec=712000000,duration_sec=504,flags=0,hard_timeout=0,idle_timeout=0,instructions=[],length=56,match=OFPMatch(oxm_fields={}),packet_count=0,priority=0,table_id=23)],flags=0,type=1)] _send_msg /opt/stack/new/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py:93
2016-12-12 09:59:32.353 32172 DEBUG neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-ba252219-a9c6-4354-9981-3cfeff7ca54f - -] Agent rpc_loop - iteration:251 - starting polling. Elapsed:0.007 rpc_loop /opt/stack/new/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py:1994
2016-12-12 09:59:32.354 32172 DEBUG neutron.agent.linux.utils [req-ba252219-a9c6-4354-9981-3cfeff7ca54f - -] Running command: ['/usr/local/bin/neutron-rootwrap-xen-dom0', '/etc/neutron/rootwrap.conf', 'xe', 'vif-param-get', 'param-name=other-config', 'param-key=nicira-iface-id', 'uuid=f72ce34c-f1cb-f54c-3132-bfd97fabef37'] create_process /opt/stack/new/neutron/neutron/agent/linux/utils.py:92
2016-12-12 09:59:33.564 32172 ERROR neutron.agent.linux.utils [req-ba252219-a9c6-4354-9981-3cfeff7ca54f - -] Exit code: 1; Stdin: ; Stdout: ; Stderr: Traceback (most recent call last):
  File "/usr/local/bin/neutron-rootwrap-xen-dom0", line 6, in <module>
    exec(compile(open(__file__).read(), __file__, 'exec'))
  File "/opt/stack/new/neutron/bin/neutron-rootwrap-xen-dom0", line 151, in <module>
    main()
  File "/opt/stack/new/neutron/bin/neutron-rootwrap-xen-dom0", line 138, in main
    filter_command(exec_name, config['filters_path'], user_args, config['exec_dirs'])
  File "/opt/stack/new/neutron/bin/neutron-rootwrap-xen-dom0", line 106, in filter_command
    filters, user_args, exec_dirs=exec_dirs)
  File "/usr/local/lib/python2.7/dist-packages/oslo_rootwrap/wrapper.py", line 176, in match_filter
    raise FilterMatchNotExecutable(match=first_not_executable_filter)
oslo_rootwrap.wrapper.FilterMatchNotExecutable

2016-12-12 09:59:33.567 32172 ERROR neutron.agent.common.ovs_lib [req-ba252219-a9c6-4354-9981-3cfeff7ca54f - -] Unable to execute ['xe', 'vif-param-get', 'param-name=other-config', 'param-key=nicira-iface-id', u'uuid=f72ce34c-f1cb-f54c-3132-bfd97fabef37']. Exception: Exit code: 1; Stdin: ; Stdout: ; Stderr: Traceback (most recent call last):
  File "/usr/local/bin/neutron-rootwrap-xen-dom0", line 6, in <module>
    exec(compile(open(__file__).read(), __file__, 'exec'))
  File "/opt/stack/new/neutron/bin/neutron-rootwrap-xen-dom0", line 151, in <module>
    main()
  File "/opt/stack/new/neutron/bin/neutron-rootwrap-xen-dom0", line 138, in main
    filter_command(exec_name, config['filters_path'], user_args, config['exec_dirs'])
  File "/opt/stack/new/neutron/bin/neutron-rootwrap-xen-dom0", line 106, in filter_command
    filters, user_args, exec_dirs=exec_dirs)
  File "/usr/local/lib/python2.7/dist-packages/oslo_rootwrap/wrapper.py", line 176, in match_filter
    raise FilterMatchNotExecutable(match=first_not_executable_filter)
oslo_rootwrap.wrapper.FilterMatchNotExecutable

[Ihar Hrachyshka (ihar-hrachyshka)]

The 'xe' filter is present in etc/neutron/rootwrap.d/openvswitch-plugin.filters. Is this filters file installed in your setup? If so, is 'xe' binary present in PATH?

[huan (huan-xie)]

@Ihar, seems it didn't use that filter, but besides that I think it should not call https://github.com/openstack/neutron/blob/master/neutron/agent/common/ovs_lib.py#L452 as the above line should match as we already set the external-ids, I found we use https://github.com/openstack/nova/blob/master/nova/virt/xenapi/vif.py#L545 to create ovs port and its related params in external-ids, but we separate this to several command, I will check this part first and then checking why the filter didn't take affect

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/447415

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/447415
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=3d58ce44d41fd38af862007ad79dd4dae826b9c0
Submitter: Jenkins
Branch: master

commit 3d58ce44d41fd38af862007ad79dd4dae826b9c0
Author: Huan Xie <email address hidden>
Date: Mon Mar 20 01:34:12 2017 -0700

    Deal with port commonly when hypervisor is XenServer

    When neutron is deployed with hypervisor is XenServer, current
    implementation will grab port's iface-id via xapi, but this isn't
    the proper way:
    Port's iface-id is already set when creating VM or hot plugging
    VIFs in nova project, so there is no need to grab it via xapi

    Change-Id: Ie07527cc89ac81ff1e3519db66925cee482f77a4
    Closes-Bug: #1649747

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 11.0.0.0b1 development milestone.