[ovs-discuss] MAC learning table does not always update

Ben Pfaff blp at nicira.com
Fri Mar 6 05:53:55 UTC 2015


On Thu, Mar 05, 2015 at 10:42:12PM -0600, Cheng Jin wrote:
> Attached please find the log file. Thanks for your time and help.

Thanks.  I'm adding back the mailing list to continue the discussion.

Consider 00:00:00:00:00:02 in bridge s1 (it would be a lot easier to
read the log if there were only one bridge, by the way).  We initially
see this getting learned on port s1-eth1 (in_port(2)) when a packet
arrives for it.  OVS forwards the packet and sets up a kernel cache
entry:

    2015-03-06T03:01:06.923Z|00019|dpif(handler671)|DBG|system at ovs-system: miss upcall:
    dp_hash(0),recirc_id(0),skb_priority(0),in_port(2),skb_mark(0),eth(src=00:00:00:00:00:02,dst=00:00:00:00:00:01),eth_type(0x8100),vlan(vid=100,pcp=0),encap(eth_type(0x0806),arp(sip=10.0.0.2,tip=10.0.0.1,op=2,sha=00:00:00:00:00:02,tha=00:00:00:00:00:01))
    arp,metadata=0,in_port=0,dl_vlan=100,dl_vlan_pcp=0,dl_src=00:00:00:00:00:02,dl_dst=00:00:00:00:00:01,arp_spa=10.0.0.2,arp_tpa=10.0.0.1,arp_op=2,arp_sha=00:00:00:00:00:02,arp_tha=00:00:00:00:00:01
    2015-03-06T03:01:06.923Z|00020|ofproto_dpif_xlate(handler671)|DBG|bridge s1: learned that 00:00:00:00:00:02 is on port s1-eth1 in VLAN 100
    2015-03-06T03:01:06.923Z|00021|dpif(handler671)|DBG|system at ovs-system: put[create] dp_hash(0/0),recirc_id(0),skb_priority(0),in_port(2),skb_mark(0/0),eth(src=00:00:00:00:00:02,dst=00:00:00:00:00:01),eth_type(0x8100),vlan(vid=100,pcp=0),encap(eth_type(0x0806),arp(sip=10.0.0.2/0.0.0.0,tip=10.0.0.1/0.0.0.0,op=2/0,sha=00:00:00:00:00:02/00:00:00:00:00:00,tha=00:00:00:00:00:01/00:00:00:00:00:00)), actions:pop_vlan,4
    2015-03-06T03:01:06.923Z|00022|dpif(handler671)|DBG|system at ovs-system: execute pop_vlan,4 on packet arp,metadata=0,in_port=0,dl_vlan=100,dl_vlan_pcp=0,dl_src=00:00:00:00:00:02,dl_dst=00:00:00:00:00:01,arp_spa=10.0.0.2,arp_tpa=10.0.0.1,arp_op=2,arp_sha=00:00:00:00:00:02,arp_tha=00:00:00:00:00:01

A few seconds later, a packet with the same source arrives on s1-eth2
(in_port(3)).  OVS learns the new port for the MAC and again forwards
the packet and sets up a kernel cache entry:

    2015-03-06T03:01:11.367Z|00036|dpif(handler671)|DBG|system at ovs-system: miss upcall:
    dp_hash(0),recirc_id(0),skb_priority(0),in_port(3),skb_mark(0),eth(src=00:00:00:00:00:02,dst=00:00:00:00:00:01),eth_type(0x8100),vlan(vid=100,pcp=0),encap()
    metadata=0,in_port=0,dl_vlan=100,dl_vlan_pcp=0,dl_src=00:00:00:00:00:02,dl_dst=00:00:00:00:00:01,dl_type=0x05ff
    2015-03-06T03:01:11.367Z|00037|dpif(handler671)|DBG|system at ovs-system: get_stats success
    2015-03-06T03:01:11.367Z|00038|ofproto_dpif_xlate(handler671)|DBG|bridge s1: learned that 00:00:00:00:00:02 is on port s1-eth2 in VLAN 100
    2015-03-06T03:01:11.368Z|00039|dpif(handler671)|DBG|system at ovs-system: put[create] dp_hash(0/0),recirc_id(0),skb_priority(0),in_port(3),skb_mark(0/0),eth(src=00:00:00:00:00:02,dst=00:00:00:00:00:01),eth_type(0x8100),vlan(vid=100,pcp=0),encap(), actions:pop_vlan,4
    2015-03-06T03:01:11.368Z|00040|dpif(handler671)|DBG|system at ovs-system: execute pop_vlan,4 on packet metadata=0,in_port=0,dl_vlan=100,dl_vlan_pcp=0,dl_src=00:00:00:00:00:02,dl_dst=00:00:00:00:00:01,dl_type=0x05ff
    2015-03-06T03:01:11.368Z|04443|dpif|DBG|system at ovs-system: execute 10 on packet metadata=0,in_port=0,dl_vlan=100,dl_vlan_pcp=0,dl_src=00:00:00:00:00:02,dl_dst=00:00:00:00:00:01,dl_type=0x05ff

This is when things get murky.  About 79 ms later, another 5 packets
arrive with the same MAC arrives on the original port, s1-eth1 (you can
tell the time and the count from "idle" and packets" below).  The kernel
cache entry for that flow is still there, so userspace only notices the
next time it checks the kernel cache statistics.  At that point, it
re-learns the old address:

    2015-03-06T03:01:11.871Z|00201|dpif(revalidator670)|DBG|system at ovs-system: flow_dump dp_hash(0/0),recirc_id(0),skb_priority(0),in_port(3),skb_mark(0/0),eth(src=00:00:00:00:00:02,dst=00:00:00:00:00:01),eth_type(0x8100),vlan(vid=100,pcp=0),encap(), packets:0, bytes:0, used:never, actions:pop_vlan,4
    2015-03-06T03:01:11.872Z|00202|dpif(revalidator670)|DBG|system at ovs-system: flow_dump dp_hash(0/0),recirc_id(0),skb_priority(0),in_port(2),skb_mark(0/0),eth(src=00:00:00:00:00:02,dst=00:00:00:00:00:01),eth_type(0x8100),vlan(vid=100,pcp=0),encap(eth_type(0x0800),ipv4(src=10.0.0.2/0.0.0.0,dst=10.0.0.1/0.0.0.0,proto=1/0,tos=0/0,ttl=64/0,frag=no/0xff),icmp(type=0/0,code=0/0)), packets:5, bytes:490, used:0.421s, actions:pop_vlan,4
    2015-03-06T03:01:11.872Z|00203|ofproto_dpif_xlate(revalidator670)|DBG|bridge s1: learned that 00:00:00:00:00:02 is on port s1-eth1 in VLAN 100

Similarly, there's another packet on s1-eth2 a bit later and that port
is relearned:

    2015-03-06T03:01:12.377Z|00222|dpif(revalidator670)|DBG|system at ovs-system: flow_dump dp_hash(0/0),recirc_id(0),skb_priority(0),in_port(3),skb_mark(0/0),eth(src=00:00:00:00:00:02,dst=00:00:00:00:00:01),eth_type(0x8100),vlan(vid=100,pcp=0),encap(), packets:1, bytes:42, used:0.005s, actions:pop_vlan,4
    2015-03-06T03:01:12.377Z|00223|ofproto_dpif_xlate(revalidator670)|DBG|bridge s1: learned that 00:00:00:00:00:02 is on port s1-eth2 in VLAN 100

and so on

In other words, I see that MAC bouncing back and forth because there's
continuing traffic for it arriving on both ports.  There is some
hysteresis to the bouncing because it only gets processed when OVS looks
at kernel statistics.

If this isn't the MAC that you're having trouble with (in that log) then
can you be specific about which MAC and bridge you're looking at?



More information about the discuss mailing list