[L2] stop processing ports twice in ovs-agent

[LIU Yulong]

When port installed to the agent, it will be processed in rpc_loop X as "added". In next X + 1 rpc_loop, it will be processed again as "updated". This is unnecessary. And it can highly probably increase the processing time of new "added" ports in this X+1 loop.

We have do something for the first rpc_loop 0 during agent restart, the ports will not be processed again. But for the running loop, we should re-examine such double processing mechanism or bug.

[Sapna Jadhav (sapana45)]

Hi, I have debugged this logs while launching a VM.
Observing below logs, where it is updating port again,

Oct 02 18:15:12 dev-Standard-PC-i440FX-PIIX-1996 neutron-openvswitch-agent[8964]: DEBUG neutron.agent.resource_cache [None req-334dbab3-cd48-4bfb-ac7a-ab641101fc8d service neutron] Resource Port 5df7ecb2-875e-4fbf-b452-e5ef89b755f1 updated (revision_number 4->5). Old fields: {'device_owner': u'', 'binding': PortBinding(host='',port_id=5df7ecb2-875e-4fbf-b452-e5ef89b755f1,profile={},status='ACTIVE',vif_details=None,vif_type='unbound',vnic_type='normal')} New fields: {'device_owner': u'compute:nova', 'binding': PortBinding(host='dev-Standard-PC-i440FX-PIIX-1996',port_id=5df7ecb2-875e-4fbf-b452-e5ef89b755f1,profile={},status='ACTIVE',vif_details=None,vif_type='unbound',vnic_type='normal')} {{(pid=8964) record_resource_update /opt/stack/neutron/neutron/agent/resource_cache.py:185}}

Oct 02 18:15:13 dev-Standard-PC-i440FX-PIIX-1996 neutron-openvswitch-agent[8964]: DEBUG neutron.agent.resource_cache [None req-334dbab3-cd48-4bfb-ac7a-ab641101fc8d service neutron] Resource Port 5df7ecb2-875e-4fbf-b452-e5ef89b755f1 updated (revision_number 5->6). Old fields: {'binding': PortBinding(host='dev-Standard-PC-i440FX-PIIX-1996',port_id=5df7ecb2-875e-4fbf-b452-e5ef89b755f1,profile={},status='ACTIVE',vif_details=None,vif_type='unbound',vnic_type='normal'), 'binding_levels': []} New fields: {'binding': PortBinding(host='dev-Standard-PC-i440FX-PIIX-1996',port_id=5df7ecb2-875e-4fbf-b452-e5ef89b755f1,profile={},status='ACTIVE',vif_details={"port_filter": true, "datapath_type": "system", "ovs_hybrid_plug": true},vif_type='ovs',vnic_type='normal'), 'binding_levels': [PortBindingLevel(driver='openvswitch',host='dev-Standard-PC-i440FX-PIIX-1996',level=0,port_id=5df7ecb2-875e-4fbf-b452-e5ef89b755f1,segment=NetworkSegment(0032ea77-5df5-437f-86f7-6e31db95cc52))]} {{(pid=8964) record_resource_update /opt/stack/neutron/neutron/agent/resource_cache.py:185}}

So, in these bug are we talking about these logs only?

[Sapna Jadhav (sapana45)]

And I am looking logs at journalctl -fu <email address hidden> as I am using devstack for this.

[Sapna Jadhav (sapana45)]

@LIU Yulong: Could you please check these logs, I just have ensure if I am following this right.

[Miguel Lavalle (minsel)]

Hi Sapna,

You are looking at the correct log. Let me give you a few pointers:

1) You can add the 'a' option (journalctl -afu <email address hidden>) and that will allow to see the log in color in real time.

2) Often, it is better to remove the 'f' option (journalctl -u <email address hidden>). In this way you are not "following" the log in real time. You start looking at the beginning of the log and you can move up and down the file with vim like commands. You can move up and down with you keyboard arrows. You can search for something with '/'. You can go to the latest record in the log with 'G'. And so on.

3) Have you watched this presentation: https://www.openstack.org/videos/summits/vancouver-2015/neutron-l2-and-l3-agents-how-they-work-and-how-kilo-improves-them? It is a bit old but still describes pretty well the overall working of the L2 agent. You can download the slides here: https://www.slideshare.net/RossellaSblendido/l2-and-l3-agent-restructure

4) Look at any patch in Gerrit, for example https://review.opendev.org/#/c/681200. Under the "Zuul check" section, click on 'neutron-tempest-plugin-scenario-openvswitch' (you could click on any other of the jobs, I'm choosing this as an example), which is the job that performs test for OVS. You will land here: https://zuul.opendev.org/t/openstack/build/3e50fa5807824100833e97c151033a64. Scroll down until you find 'log_url' and click on the url in that line (https://657640e1b74d2ccd83c5-2f55ac5fe50f14ffb2563f318bf721a9.ssl.cf5.rackcdn.com/681200/3/check/neutron-tempest-plugin-scenario-openvswitch/3e50fa5/). There you will notice that you can click on ' testr_results.html.gz' and see the lists of tests performed. You can also click on 'controller' and then on 'logs' and you will land here: https://657640e1b74d2ccd83c5-2f55ac5fe50f14ffb2563f318bf721a9.ssl.cf5.rackcdn.com/681200/3/check/neutron-tempest-plugin-scenario-openvswitch/3e50fa5/controller/logs/. Scroll down and you will find 'screen-q-agt.txt.gz'. Click on it and you will see the log file (https://657640e1b74d2ccd83c5-2f55ac5fe50f14ffb2563f318bf721a9.ssl.cf5.rackcdn.com/681200/3/check/neutron-tempest-plugin-scenario-openvswitch/3e50fa5/controller/logs/screen-q-agt.txt.gz) of the OVS agent where you can see what the OVS agent did as a result of all the tests executed in this job. You can download the log if you want and look at it with 'less' for example.

5) As the presentation in point 3 indicates, the OVS agent (and all the Neutron agents for that matter) have a big loop (method rpc_loop in the case of the OVS agent) that iterates checking if there is some work to do or a signal to respond to. The OVS agent big loop is here: https://github.com/openstack/neutron/blob/88683b76aeefde5a051d9349fac20fedebcea987/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py#L2346.

6) rpc_loop checks here https://github.com/openstack/neutron/blob/88683b76aeefde5a051d9349fac20fedebcea987/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py#L2383 if any ports were added, updated or removed from the integration bridge and if that's the case, it processes them by triggering this chain of calls:

https://github.com/openst...

[Sapna Jadhav (sapana45)]

@Miguel Lavalle, thank you so much for this comment. this is very very helpful information for me. I will add my comment shortly again regarding fix.

[Sapna Jadhav (sapana45)]

@Miguel Lavalle, Can we follow this kind of approch like setting some flag after port gets added, and then skipping port update in next x+1 loop if it is just now added(I mean after instance creation)?
I have seen this aproch in below issues. But I have no idea if this will affect on any other functionality.

I was referring this,
https://review.opendev.org/#/c/638644/7
https://review.opendev.org/#/c/638643/1

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/693484

[OpenStack Infra (hudson-openstack)]

Change abandoned by LIU Yulong (<email address hidden>) on branch: master
Review: https://review.opendev.org/693484