Bug 1691044
| Summary: | Adding ports to VM trunk takes too long with OVN neutron backend | |||
|---|---|---|---|---|
| Product: | Red Hat OpenStack | Reporter: | Jon Uriarte <juriarte> | |
| Component: | python-networking-ovn | Assignee: | Lucas Alvares Gomes <lmartins> | |
| Status: | CLOSED ERRATA | QA Contact: | Jon Uriarte <juriarte> | |
| Severity: | urgent | Docs Contact: | ||
| Priority: | urgent | |||
| Version: | 13.0 (Queens) | CC: | apevec, dalvarez, ealcaniz, lhh, lmartins, majopela, mjozefcz, rbost, scohen, skaplons, twilson, ushkalim | |
| Target Milestone: | z8 | Keywords: | Triaged, ZStream | |
| Target Release: | 13.0 (Queens) | |||
| Hardware: | Unspecified | |||
| OS: | Unspecified | |||
| Whiteboard: | ||||
| Fixed In Version: | python-networking-ovn-4.0.3-8.el7ost | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | ||
| Clone Of: | ||||
| : | 1724557 (view as bug list) | Environment: | ||
| Last Closed: | 2019-09-03 16:53:02 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: | ||||
| Bug Depends On: | ||||
| Bug Blocks: | 1724557 | |||
|
Description
Jon Uriarte
2019-03-20 17:36:15 UTC
I see a bunch of these messages: 2019-03-21 12:01:04.077 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.079 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.081 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.083 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.084 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.086 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.088 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.090 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.092 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.094 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 2019-03-21 12:01:04.096 35 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement [req-ad4b7334-17d5-4bde-90c1-fb5d141af326 c13e0cc8325b47d99780b07e32c1c29e 240611d0d1c84092a8105e7e9f7ec85c - default default] Attributes excluded by policy engine: [u'binding:profile', u'binding:vif_details', u'binding:vif_type', u'binding:host_id'] _exclude_attributes_by_policy /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256 Which I believe is the reason of the slowness. The binding details come from this: https://github.com/openstack/networking-ovn/blob/6.0.0.0b1/networking_ovn/ml2/trunk_driver.py#L53 I was able to reproduce this issue on devstack with ml2/ovn with steps like: 1. Create trunk parent port openstack port create --network private trunk-port 2. Create trunk openstack network trunk create --parent-port a103ed20-ea9c-46b6-a89d-4441b6d4fb72 trunk 3. Create trunked net neutron net-create trunked-net neutron subnet-create trunked-net 192.168.100.0/24 4. Create subports: openstack port create --network trunked-net subport1 openstack port create --network trunked-net subport2 openstack port create --network trunked-net subport3 openstack port create --network trunked-net subport4 openstack port create --network trunked-net subport5 4. Add subports to trunk: openstack network trunk set --subport port=b41659ba-2444-4a34-96b3-9bcd7ec89296,segmentation-type=vlan,segmentation-id=101 --subport port=a70f1dc9-8fe7-481e-9608-d3d51cdc1eac,segmentation-type=vlan,segmentation-id=102 --subport port=2b7dc21f-18ee-42ea-854c-01e4654b7f0c,segmentation-type=vlan,segmentation-id=103 --subport port=8d1e3151-992c-48d4-85ec-618449189423,segmentation-type=vlan,segmentation-id=104 --subport port=91d4d286-81d8-4101-a3c2-359e0c800a7e,segmentation-type=vlan,segmentation-id=105 9da4ef0f-72bf-4031-8c4f-5d3b739b8e5b 5. Spawm vm connected to this trunk's parent port: nova boot --image cirros-0.3.4-i386-disk --flavor m1.micro --nic port-id=a103ed20-ea9c-46b6-a89d-4441b6d4fb72 vm-trunks After that watch status of subports, it took a lot of time to switch all of them to ACTIVE. When I did the same steps on devstack with ml2/ovs it was much faster. Some update with what I did and what I found today. I used simple script to reproduce the issue: http://pastebin.test.redhat.com/742759 with this script I got results like: $ bash test_trunks.sh +------------+------------------------------------------------+ | Property | Value | +------------+------------------------------------------------+ | ip_address | 10.0.0.31,fdd5:442b:9728:0:f816:3eff:fef8:f8ac | | mac_addr | fa:16:3e:f8:f8:ac | | net_id | 120fe645-30f8-478a-9446-b357550acb3a | | port_id | adf3ee81-2ab1-478f-abfd-6024991af9b0 | | port_state | DOWN | | tag | - | +------------+------------------------------------------------+ Number of active ports: 0 .... Number of active ports: 0 .... Number of active ports: 1 .... Number of active ports: 1 .... Number of active ports: 2 .... Number of active ports: 2 .... Number of active ports: 2 .... Number of active ports: 3 .... Number of active ports: 3 .... Number of active ports: 4 .... Number of active ports: 4 .... Number of active ports: 4 .... Number of active ports: 4 .... Number of active ports: 5 .... Transition of ports to ACTIVE took 99.169112739 seconds So it took almost 100 seconds to turn all subports to active after trunk port was connected to instance. I was debugging this issue and I found that it takes about 20 seconds for each subport in set_port_status_up: Mar 22 16:44:13 devstack-ovn-ubuntu-controller neutron-server[12800]: INFO networking_ovn.ml2.mech_driver [None req-93d6d785-05ee-42a4-b909-206eb9bfd983 None None] OVN reports status up for port: 824dd0b0-5e31-4b44-9718-b4e1c8dc9af5 (id of subport-3) Mar 22 16:44:37 devstack-ovn-ubuntu-controller neutron-server[12800]: INFO networking_ovn.ml2.mech_driver [None req-93d6d785-05ee-42a4-b909-206eb9bfd983 None None] OVN reports status up for port: f0ebaacd-22ce-454c-a8ac-8dc1dc408f62 (id of subport-5) Mar 22 16:44:53 devstack-ovn-ubuntu-controller neutron-server[12800]: INFO networking_ovn.ml2.mech_driver [None req-93d6d785-05ee-42a4-b909-206eb9bfd983 None None] OVN reports status up for port: 07c7396b-5c64-4ada-a992-fd6fca1d130a (id of subport-4) Mar 22 16:45:10 devstack-ovn-ubuntu-controller neutron-server[12800]: INFO networking_ovn.ml2.mech_driver [None req-93d6d785-05ee-42a4-b909-206eb9bfd983 None None] OVN reports status up for port: e5406129-114a-414b-b923-869864e45fd9 (id of subport-2) Mar 22 16:45:26 devstack-ovn-ubuntu-controller neutron-server[12800]: INFO networking_ovn.ml2.mech_driver [None req-93d6d785-05ee-42a4-b909-206eb9bfd983 None None] OVN reports status up for port: adf3ee81-2ab1-478f-abfd-6024991af9b0 (id of trunk port) Mar 22 16:45:31 devstack-ovn-ubuntu-controller neutron-server[12800]: INFO networking_ovn.ml2.mech_driver [None req-93d6d785-05ee-42a4-b909-206eb9bfd983 None None] OVN reports status up for port: e80b876f-ee81-484a-b645-4ea616bc4ef9 (id of subport-1) So, next I wanted to found out where we are loosing time in this set_port_status_up method. So I added some "dummy" logging (patch like http://pastebin.test.redhat.com/742768) to check where it spends most of the time. It looks that we lost most of the time in _update_subport_host_if_needed() method, and inside this method vast majority of time is spend in self._plugin.update_port() - in overall it is around 10 seconds there for each subport. Second bottleneck is in provisioning_blocks.provisioning_complete() method, it's around 5 seconds. Both those methods are not from networking-ovn but from core neutron code. For now I don't know yet how to improve it. First thing which comes to my mind is to call set_port_status_up in parallel but I don't know networking-ovn mech driver well thus I have no idea what other problems it may cause and why it isn't done like that for now. Lucas' working on this BZ and a general optimization mechanism in the context of this design document: https://docs.openstack.org/networking-ovn/latest/contributor/design/distributed_ovsdb_events.html Verified on python-networking-ovn-4.0.3-10.el7ost.noarch Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2019:2629 |