[NETVIRT-288] OVS egress table (220) contains stale rules that send the packet to the wrong port Created: 22/Nov/16  Updated: 03/May/18  Resolved: 12/Dec/16

Status: Resolved
Project: netvirt
Component/s: General
Affects Version/s: Carbon
Fix Version/s: None

Type: Bug
Reporter: Tal Rosenzweig Assignee: Faseela K
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All

Attachments: File karaf.log.rar     File karaf.rar     Text File oldflows.txt    
Issue Links:
Duplicate
is duplicated by GENIUS-37 Incorrect output port for table 220 Resolved
is duplicated by NETVIRT-287 Table 220 - output ports action does... Resolved
External issue ID: 7220

 Description   

when we reload the vm (meaning it was created in the past but was removed),
it (the vm) didn't get replay from the dhcp due to old rules thus not getting ip.

you can look at the file attached below in table 220 there are conflicting rules one of them is old (you can see by the duration), both rules match on the reg "reg6=0x2200" but the action is different. because the old rule has higher priority the packet continue to the wrong port.

 Comments   
Comment by Tal Rosenzweig [ 22/Nov/16 ]

Attachment oldflows.txt has been added with description: flows rules on each table

Comment by Alon Kochba [ 22/Nov/16 ]

reducing severity pending explanation of OpenStack scenario done and what's not working.. I don't see the problem you mentioned in the attached flow dump

Comment by Tal Rosenzweig [ 22/Nov/16 ]

openstack scenario -
create vm, delete vm, recreate same vm, vm dosent get dhcp replay (no ip).

the problem -
if the vm has no ip it cannot connect to the net.
preventing full configuration for the vm thus the vm is stuck

Comment by Tal Rosenzweig [ 22/Nov/16 ]

Attachment karaf.rar has been added with description: Karaf log

Comment by Alon Kochba [ 22/Nov/16 ]

It seems that the old flow reg6=0x2200 wasn't deleted when the VM was deleted, and judging by the reg value and actions I believe this was a port without security enabled on it (resulting in priority=7).

Then a new port was assigned lport 0x2200, but this port has security enabled - so even though the new rules are inserted properly, the reg6=0x2200 flow now has priority=6, which is lower than the zombie flow.

This is the end result of the flows:
cookie=0x8000007, duration=83219.368s, table=220, n_packets=913, n_bytes=90732, priority=7,reg6=0x2200 actions=output:64
cookie=0x8000007, duration=11452.879s, table=220, n_packets=0, n_bytes=0, priority=7,reg6=0xe0002200 actions=output:145
cookie=0x6900000, duration=11452.879s, table=220, n_packets=0, n_bytes=0, priority=6,reg6=0x2200 actions=load:0xe0002200->NXM_NX_REG6[],write_metadata:0xe000220000000000/0xfffffffffffffffe,goto_table:251

Comment by Aswin Suryanarayanan [ 30/Nov/16 ]

@Alon,

As you stated it should be a port without port security and the flow deletion failed for it and thus having two conflicting flows. This needs to be fixed in the service handling the ouput flow may be in genius?

Comment by Faseela K [ 30/Nov/16 ]

Hi Tal,
Is it possible to check if table 220 flows are getting deleted upon deletion of VM?
Thanks,
Faseela

Comment by Tal Rosenzweig [ 30/Nov/16 ]

(In reply to Faseela K from comment #6)
> Hi Tal,
> Is it possible to check if table 220 flows are getting deleted upon
> deletion of VM?
> Thanks,
> Faseela

Hi Faseela,
usually the flow is deleted upon vm deletion,
but this specific time it seems the flow in table 220 wasn't.

Comment by Faseela K [ 01/Dec/16 ]

Hi Tal,
Is it possible to get the interface uuid for the problematic interface which output to port 251, or atleast the tap port name?

Comment by Alon Kochba [ 01/Dec/16 ]

unbindService() should be called on interface-config DCN.

Comment by Aswin Suryanarayanan [ 01/Dec/16 ]

@Alon,

Thhe unbind service in interface-config is for the issue we see in the CSIT. This is due to a different reason.

Comment by Alon Kochba [ 01/Dec/16 ]

(In reply to Aswin Suryanarayanan from comment #10)
> @Alon,
>
> Thhe unbind service in interface-config is for the issue we see in the
> CSIT. This is due to a different reason.

Ahh ok my bad, thanks, assigning to Faseela until we figure out more.

Comment by Faseela K [ 01/Dec/16 ]

Hi Tal,
I hope you are on the latest master code, but still to be sure, please see if you have a distribution where the below patch is merged :

https://git.opendaylight.org/gerrit/#/c/47674/2

From the karaf logs, I don't see the relevant logs for port 145, i see only delete calls, but no add calls for the corresponding problematic interface for table 220.

***remove 220 entry for output : port 64********
2016-11-22 09:57:12,344 | INFO | ool-49-thread-34 | FlowBasedServicesConfigListener | 350 - org.opendaylight.genius.interfacemanager-impl - 0.1.2.SNAPSHOT | Service Binding Entry removed for Interface: 24962fd1-c40e-4086-86a6-9e71c34e2978, Data: BoundServices{getServiceName=default.24962fd1-c40e-4086-86a6-9e71c34e2978, getServicePriority=7, getServiceType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.servicebinding.rev160406.ServiceTypeFlowBased, augmentations={interface org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.servicebinding.rev160406.StypeOpenflow=StypeOpenflow{getFlowCookie=134217735, getFlowPriority=7, getInstruction=[Instruction{getInstruction=ApplyActionsCase{getApplyActions=ApplyActions{getAction=[Action{getAction=OutputActionCase{getOutputAction=OutputAction{getMaxLength=0, getOutputNodeConnector=Uri [_value=64], augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}], augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}]}}}

****remove 220 entry for port 145***********

2016-11-22 16:16:43,297 | INFO | ool-49-thread-36 | FlowBasedServicesConfigListener | 350 - org.opendaylight.genius.interfacemanager-impl - 0.1.2.SNAPSHOT | Service Binding Entry removed for Interface: 9e42db80-4ba5-4f10-92ce-de92c14e8d13, Data: BoundServices{getServiceName=default.9e42db80-4ba5-4f10-92ce-de92c14e8d13, getServicePriority=7, getServiceType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.servicebinding.rev160406.ServiceTypeFlowBased, augmentations={interface org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.servicebinding.rev160406.StypeOpenflow=StypeOpenflow{getFlowCookie=134217735, getFlowPriority=7, getInstruction=[Instruction{getInstruction=ApplyActionsCase{getApplyActions=ApplyActions{getAction=[Action{getAction=OutputActionCase{getOutputAction=OutputAction{getMaxLength=0, getOutputNodeConnector=Uri [_value=145], augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}], augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}]}}}

Thanks,
Faseela

Comment by Tal Rosenzweig [ 01/Dec/16 ]

Attachment karaf.log.rar has been added with description: karaf.log.1

Comment by Tal Rosenzweig [ 01/Dec/16 ]

(In reply to Faseela K from comment #12)
> Hi Tal,
> I hope you are on the latest master code, but still to be sure, please see
> if you have a distribution where the below patch is merged :
>
> https://git.opendaylight.org/gerrit/#/c/47674/2
>
> From the karaf logs, I don't see the relevant logs for port 145, i see only
> delete calls, but no add calls for the corresponding problematic interface
> for table 220.
>
> ***remove 220 entry for output : port 64********
> 2016-11-22 09:57:12,344 | INFO | ool-49-thread-34 |
> FlowBasedServicesConfigListener | 350 -
> org.opendaylight.genius.interfacemanager-impl - 0.1.2.SNAPSHOT | Service
> Binding Entry removed for Interface: 24962fd1-c40e-4086-86a6-9e71c34e2978,
> Data:
> BoundServices{getServiceName=default.24962fd1-c40e-4086-86a6-9e71c34e2978,
> getServicePriority=7, getServiceType=class
> org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.
> servicebinding.rev160406.ServiceTypeFlowBased, augmentations={interface
> org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.
> servicebinding.rev160406.StypeOpenflow=StypeOpenflow{getFlowCookie=134217735,
> getFlowPriority=7,
> getInstruction=[Instruction{getInstruction=ApplyActionsCase{getApplyActions=A
> pplyActions{getAction=[Action{getAction=OutputActionCase{getOutputAction=Outp
> utAction{getMaxLength=0, getOutputNodeConnector=Uri [_value=64],
> augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}],
> augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}]}}}
>
> ****remove 220 entry for port 145***********
>
> 2016-11-22 16:16:43,297 | INFO | ool-49-thread-36 |
> FlowBasedServicesConfigListener | 350 -
> org.opendaylight.genius.interfacemanager-impl - 0.1.2.SNAPSHOT | Service
> Binding Entry removed for Interface: 9e42db80-4ba5-4f10-92ce-de92c14e8d13,
> Data:
> BoundServices{getServiceName=default.9e42db80-4ba5-4f10-92ce-de92c14e8d13,
> getServicePriority=7, getServiceType=class
> org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.
> servicebinding.rev160406.ServiceTypeFlowBased, augmentations={interface
> org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.
> servicebinding.rev160406.StypeOpenflow=StypeOpenflow{getFlowCookie=134217735,
> getFlowPriority=7,
> getInstruction=[Instruction{getInstruction=ApplyActionsCase{getApplyActions=A
> pplyActions{getAction=[Action{getAction=OutputActionCase{getOutputAction=Outp
> utAction{getMaxLength=0, getOutputNodeConnector=Uri [_value=145],
> augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}],
> augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}]}}}
>
>
> Thanks,
> Faseela

Hi Faseela,
i attached the log karaf.log.1 there you can see the Service Binding Entry created for Interface 145.

Comment by Faseela K [ 01/Dec/16 ]

Hi Tal,
could you please confirm if you are on the latest code?
If so could you please reproduce the issue with TRACE logs enabled for org.opendaylight.genius.interfacemanager and attach those logs?
Thanks,
Faseela

Comment by Alon Kochba [ 01/Dec/16 ]

Faseela, it seems this was with code from a few weeks back.
Tal, could you try to reproduce with latest code and turn on TRACE logs for the interfacemanager?

Thanks

Comment by Tomer Pearl [ 01/Dec/16 ]

(In reply to Faseela K from comment #12)
> Hi Tal,
> I hope you are on the latest master code, but still to be sure, please see
> if you have a distribution where the below patch is merged :
>
> https://git.opendaylight.org/gerrit/#/c/47674/2
>
> From the karaf logs, I don't see the relevant logs for port 145, i see only
> delete calls, but no add calls for the corresponding problematic interface
> for table 220.
>
> ***remove 220 entry for output : port 64********
> 2016-11-22 09:57:12,344 | INFO | ool-49-thread-34 |
> FlowBasedServicesConfigListener | 350 -
> org.opendaylight.genius.interfacemanager-impl - 0.1.2.SNAPSHOT | Service
> Binding Entry removed for Interface: 24962fd1-c40e-4086-86a6-9e71c34e2978,
> Data:
> BoundServices{getServiceName=default.24962fd1-c40e-4086-86a6-9e71c34e2978,
> getServicePriority=7, getServiceType=class
> org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.
> servicebinding.rev160406.ServiceTypeFlowBased, augmentations={interface
> org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.
> servicebinding.rev160406.StypeOpenflow=StypeOpenflow{getFlowCookie=134217735,
> getFlowPriority=7,
> getInstruction=[Instruction{getInstruction=ApplyActionsCase{getApplyActions=A
> pplyActions{getAction=[Action{getAction=OutputActionCase{getOutputAction=Outp
> utAction{getMaxLength=0, getOutputNodeConnector=Uri [_value=64],
> augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}],
> augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}]}}}
>
> ****remove 220 entry for port 145***********
>
> 2016-11-22 16:16:43,297 | INFO | ool-49-thread-36 |
> FlowBasedServicesConfigListener | 350 -
> org.opendaylight.genius.interfacemanager-impl - 0.1.2.SNAPSHOT | Service
> Binding Entry removed for Interface: 9e42db80-4ba5-4f10-92ce-de92c14e8d13,
> Data:
> BoundServices{getServiceName=default.9e42db80-4ba5-4f10-92ce-de92c14e8d13,
> getServicePriority=7, getServiceType=class
> org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.
> servicebinding.rev160406.ServiceTypeFlowBased, augmentations={interface
> org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.
> servicebinding.rev160406.StypeOpenflow=StypeOpenflow{getFlowCookie=134217735,
> getFlowPriority=7,
> getInstruction=[Instruction{getInstruction=ApplyActionsCase{getApplyActions=A
> pplyActions{getAction=[Action{getAction=OutputActionCase{getOutputAction=Outp
> utAction{getMaxLength=0, getOutputNodeConnector=Uri [_value=145],
> augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}],
> augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}]}}}
>
>
> Thanks,
> Faseela

Hi Faseela,

The missing port creation is in karaf.log.1
Copied the removal of port 64 and creation of port 145 for convenience.
This was supposed to remove the output:64 flow from table 220, right?

****remove 220 entry for port 64***********
2016-11-22 09:57:12,344 | INFO | ool-49-thread-34 | FlowBasedServicesConfigListener | 350 - org.opendaylight.genius.interfacemanager-impl - 0.1.2.SNAPSHOT | Service Binding Entry removed for Interface: 24962fd1-c40e-4086-86a6-9e71c34e2978, Data: BoundServices{getServiceName=default.24962fd1-c40e-4086-86a6-9e71c34e2978, getServicePriority=7, getServiceType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.servicebinding.rev160406.ServiceTypeFlowBased, augmentations={interface org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.servicebinding.rev160406.StypeOpenflow=StypeOpenflow{getFlowCookie=134217735, getFlowPriority=7, getInstruction=[Instruction{getInstruction=ApplyActionsCase{getApplyActions=ApplyActions{getAction=[Action{getAction=OutputActionCase{getOutputAction=OutputAction{getMaxLength=0, getOutputNodeConnector=Uri [_value=64], augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}], augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}]}}}

****create 220 entry for port 145***********
2016-11-22 12:03:54,661 | INFO | ool-49-thread-36 | FlowBasedServicesConfigListener | 350 - org.opendaylight.genius.interfacemanager-impl - 0.1.2.SNAPSHOT | Service Binding Entry created for Interface: 9e42db80-4ba5-4f10-92ce-de92c14e8d13, Data: BoundServices{getServiceName=default.9e42db80-4ba5-4f10-92ce-de92c14e8d13, getServicePriority=7, getServiceType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.servicebinding.rev160406.ServiceTypeFlowBased, augmentations={interface org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.servicebinding.rev160406.StypeOpenflow=StypeOpenflow{getFlowCookie=134217735, getFlowPriority=7, getInstruction=[Instruction{getInstruction=ApplyActionsCase{getApplyActions=ApplyActions{getAction=[Action{getAction=OutputActionCase{getOutputAction=OutputAction{getMaxLength=0, getOutputNodeConnector=Uri [_value=145], augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}], augmentations={}}, augmentations={}}, getOrder=0, augmentations={}}]}}}

Comment by Alon Kochba [ 04/Dec/16 ]

Resolved by Faseela here: https://git.opendaylight.org/gerrit/#/c/48922/

Generated at Wed Feb 07 20:21:11 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.