100% CPU on bonded link with link monitoring

kemeris2 · Sat Dec 07, 2013 1:04 am

I have two CCR routers interconnected with active-backup bonded (sfp, ether3) interface with ARP link monitoring.
While pinging between routers, when I unplug sfp cable, link switches to eth3, ping OK, but after one minute CPU on both routers starts to increase. After another minute or so, CPU is 100% on both routers.
When I plug sfp cable back CPU instantly returns to normal load.

Router1:

ros code

/interface bonding
add arp-ip-targets=10.0.0.2 comment="Trunk to CCR2" link-monitoring=arp \
    mode=active-backup name=sfp1-bond primary=sfp1 slaves=eth3,sfp1

Router2:

ros code

/interface bonding
add arp-ip-targets=10.0.0.1 comment="Trunk to CCR1" link-monitoring=arp \
    mode=active-backup name=sfp1-bond primary=sfp1 slaves=eth3,sfp1

MII link monitoring does not work at all. Link does not switch to slave when active link is unplugged.

Any ideas what could be wrong?

jaykay2342 · Sat Dec 07, 2013 6:31 pm

have you used the "profil" tool to investigate what is eating all the cpu cycles?

kemeris2 · Sat Dec 07, 2013 11:37 pm

have you used the "profil" tool to investigate what is eating all the cpu cycles?

Yes, 100% load under management profile. Tried packet sniffer on primary bond interface, but could not detect any loops.
Look like this happens only on link switch. If I unplug non running ether3 slave interface everything ok.

I just noticed my "br-vlan20" bridge l2mtu=1590 while other bridges 65535, could it be a problem?
I think l2mtu=1590 because WiFi router connected to ether5.

Here is my router1 config:

ros code

/interface bonding
add arp-ip-targets=10.0.0.2 comment="Trunk to CCR2" link-monitoring=arp mode=\
    active-backup name=sfp1-bond primary=sfp1 slaves=eth3,sfp1
add link-monitoring=none mode=active-backup name=sfp2-bond primary=eth4 slaves=\
    sfp2,eth4
/interface vlan
add interface=sfp1-bond name=vlan10 vlan-id=10
add interface=sfp1-bond name=vlan20 vlan-id=20
add interface=sfp1-bond name=vlan30 vlan-id=30
/interface bridge
add name=br-vlan10
add l2mtu=1590 name=br-vlan20
add name=br-vlan30
/interface bridge port
add bridge=br-vlan30 interface=vlan30 path-cost=2
add bridge=br-vlan20 interface=eth5 path-cost=4
add bridge=br-vlan10 interface=vlan10 path-cost=2
add bridge=br-vlan10 interface=eth8 path-cost=4
add bridge=br-vlan10 interface=eth7 path-cost=4
add bridge=br-vlan20 interface=eth6 path-cost=4
add bridge=br-vlan20 interface=vlan20 path-cost=2
add bridge=br-vlan30 interface=sfp2-bond path-cost=2
/ip address
add address=10.0.0.1/27 interface=br-vlan10 network=10.0.0.0
add address=10.1.0.1/27 interface=br-vlan20 network=10.1.0.0
add address=10.2.0.1/29 interface=br-vlan30 network=10.2.0.0

kemeris2 · Sun Dec 08, 2013 4:07 pm

When CPU reach 2% load my sfp1-bond link goes down and up constantly.
Still cant find what is causing this

Ignore wrong date in logs, this is another problem I have with CCR (constant reset every two days or so).

Jan/01/2002 03:51:37 route,debug,event Update
Jan/01/2002 03:51:37 route,debug,event     interface=vlan20
Jan/01/2002 03:51:37 route,debug,event Link up
Jan/01/2002 03:51:37 route,debug,event     interface=vlan30
Jan/01/2002 03:51:37 route,debug,event Update
Jan/01/2002 03:51:37 route,debug,event     interface=vlan30
Jan/01/2002 03:51:37 route,debug,calc End calculation
Jan/01/2002 03:51:37 radvd,debug skip Router Advertisement sending on sfp1-bond: no prefixes to send
Jan/01/2002 03:51:37 radvd,debug skip Router Advertisement sending on vlan10: no prefixes to send
Jan/01/2002 03:51:37 radvd,debug skip Router Advertisement sending on vlan30: no prefixes to send
Jan/01/2002 03:51:37 radvd,debug skip Router Advertisement sending on vlan20: no prefixes to send
Jan/01/2002 03:51:55 radvd,debug skip Router Advertisement sending on eth5: no prefixes to send
Jan/01/2002 03:52:41 interface,info sfp1-bond link down
Jan/01/2002 03:52:41 route,debug,event Interface change
Jan/01/2002 03:52:41 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:41 route,debug,event     status=UP
Jan/01/2002 03:52:41 route,debug,event     mtu=1500
Jan/01/2002 03:52:41 route,debug,event Interface change
Jan/01/2002 03:52:41 route,debug,event     interface=vlan10
Jan/01/2002 03:52:41 route,debug,event     status=UP
Jan/01/2002 03:52:41 route,debug,event     mtu=1500
Jan/01/2002 03:52:41 route,debug,event Interface change
Jan/01/2002 03:52:41 route,debug,event     interface=vlan20
Jan/01/2002 03:52:41 route,debug,event     status=UP
Jan/01/2002 03:52:41 route,debug,event     mtu=1500
Jan/01/2002 03:52:41 route,debug,event Interface change
Jan/01/2002 03:52:41 route,debug,event     interface=vlan30
Jan/01/2002 03:52:41 route,debug,event     status=UP
Jan/01/2002 03:52:41 route,debug,event     mtu=1500
Jan/01/2002 03:52:41 interface,info sfp1-bond link up
Jan/01/2002 03:52:41 route,debug,calc Begin calculation
Jan/01/2002 03:52:41 route,debug,event Link down
Jan/01/2002 03:52:41 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:41 route,debug,event Update
Jan/01/2002 03:52:41 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:41 route,debug,event Link down
Jan/01/2002 03:52:41 route,debug,event     interface=vlan10
Jan/01/2002 03:52:41 route,debug,event Update
Jan/01/2002 03:52:41 route,debug,event     interface=vlan10
Jan/01/2002 03:52:41 route,debug,event Link down
Jan/01/2002 03:52:41 route,debug,event     interface=vlan20
Jan/01/2002 03:52:41 route,debug,event Update
Jan/01/2002 03:52:41 route,debug,event     interface=vlan20
Jan/01/2002 03:52:41 route,debug,event Link down
Jan/01/2002 03:52:41 route,debug,event     interface=vlan30
Jan/01/2002 03:52:41 route,debug,event Update
Jan/01/2002 03:52:41 route,debug,event     interface=vlan30
Jan/01/2002 03:52:41 route,debug,calc End calculation
Jan/01/2002 03:52:44 route,debug,event Interface change
Jan/01/2002 03:52:44 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:44 route,debug,event     status=UP,RUNNING
Jan/01/2002 03:52:44 route,debug,event     mtu=1500
Jan/01/2002 03:52:44 route,debug,event Interface change
Jan/01/2002 03:52:44 route,debug,event     interface=vlan10
Jan/01/2002 03:52:44 route,debug,event     status=UP,RUNNING
Jan/01/2002 03:52:44 route,debug,event     mtu=1500
Jan/01/2002 03:52:44 route,debug,event Interface change
Jan/01/2002 03:52:44 route,debug,event     interface=vlan20
Jan/01/2002 03:52:44 route,debug,event     status=UP,RUNNING
Jan/01/2002 03:52:44 route,debug,event     mtu=1500
Jan/01/2002 03:52:44 route,debug,event Interface change
Jan/01/2002 03:52:44 route,debug,event     interface=vlan30
Jan/01/2002 03:52:44 route,debug,event     status=UP,RUNNING
Jan/01/2002 03:52:44 route,debug,event     mtu=1500
Jan/01/2002 03:52:44 route,debug,calc Begin calculation
Jan/01/2002 03:52:44 route,debug,event Link up
Jan/01/2002 03:52:44 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:44 route,debug,event Update
Jan/01/2002 03:52:44 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:44 route,debug,event Link up
Jan/01/2002 03:52:44 route,debug,event     interface=vlan10
Jan/01/2002 03:52:44 route,debug,event Update
Jan/01/2002 03:52:44 route,debug,event     interface=vlan10
Jan/01/2002 03:52:44 route,debug,event Link up
Jan/01/2002 03:52:44 route,debug,event     interface=vlan20
Jan/01/2002 03:52:44 route,debug,event Update
Jan/01/2002 03:52:44 route,debug,event     interface=vlan20
Jan/01/2002 03:52:44 route,debug,event Link up
Jan/01/2002 03:52:44 route,debug,event     interface=vlan30
Jan/01/2002 03:52:44 route,debug,event Update
Jan/01/2002 03:52:44 route,debug,event     interface=vlan30
Jan/01/2002 03:52:44 route,debug,calc End calculation
Jan/01/2002 03:52:44 radvd,debug skip Router Advertisement sending on sfp1-bond: no prefixes to send
Jan/01/2002 03:52:44 radvd,debug skip Router Advertisement sending on vlan10: no prefixes to send
Jan/01/2002 03:52:44 radvd,debug skip Router Advertisement sending on vlan30: no prefixes to send
Jan/01/2002 03:52:44 radvd,debug skip Router Advertisement sending on vlan20: no prefixes to send
Jan/01/2002 03:52:59 interface,info sfp1-bond link down
Jan/01/2002 03:52:59 route,debug,event Interface change
Jan/01/2002 03:52:59 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:59 route,debug,event     status=UP
Jan/01/2002 03:52:59 route,debug,event     mtu=1500
Jan/01/2002 03:52:59 route,debug,event Interface change
Jan/01/2002 03:52:59 route,debug,event     interface=vlan10
Jan/01/2002 03:52:59 route,debug,event     status=UP
Jan/01/2002 03:52:59 route,debug,event     mtu=1500
Jan/01/2002 03:52:59 route,debug,event Interface change
Jan/01/2002 03:52:59 route,debug,event     interface=vlan20
Jan/01/2002 03:52:59 route,debug,event     status=UP
Jan/01/2002 03:52:59 route,debug,event     mtu=1500
Jan/01/2002 03:52:59 route,debug,event Interface change
Jan/01/2002 03:52:59 route,debug,event     interface=vlan30
Jan/01/2002 03:52:59 route,debug,event     status=UP
Jan/01/2002 03:52:59 route,debug,event     mtu=1500
Jan/01/2002 03:52:59 route,debug,calc Begin calculation
Jan/01/2002 03:52:59 route,debug,event Link down
Jan/01/2002 03:52:59 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:59 route,debug,event Update
Jan/01/2002 03:52:59 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:52:59 route,debug,event Link down
Jan/01/2002 03:52:59 route,debug,event     interface=vlan10
Jan/01/2002 03:52:59 route,debug,event Update
Jan/01/2002 03:52:59 route,debug,event     interface=vlan10
Jan/01/2002 03:52:59 route,debug,event Link down
Jan/01/2002 03:52:59 route,debug,event     interface=vlan20
Jan/01/2002 03:52:59 route,debug,event Update
Jan/01/2002 03:52:59 route,debug,event     interface=vlan20
Jan/01/2002 03:52:59 route,debug,event Link down
Jan/01/2002 03:52:59 route,debug,event     interface=vlan30
Jan/01/2002 03:52:59 route,debug,event Update
Jan/01/2002 03:52:59 route,debug,event     interface=vlan30
Jan/01/2002 03:52:59 route,debug,calc End calculation
Jan/01/2002 03:52:59 interface,info sfp1-bond link up
Jan/01/2002 03:53:02 route,debug,event Interface change
Jan/01/2002 03:53:02 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:53:02 route,debug,event     status=UP,RUNNING
Jan/01/2002 03:53:02 route,debug,event     mtu=1500
Jan/01/2002 03:53:02 route,debug,event Interface change
Jan/01/2002 03:53:02 route,debug,event     interface=vlan10
Jan/01/2002 03:53:02 route,debug,event     status=UP,RUNNING
Jan/01/2002 03:53:02 route,debug,event     mtu=1500
Jan/01/2002 03:53:02 route,debug,event Interface change
Jan/01/2002 03:53:02 route,debug,event     interface=vlan20
Jan/01/2002 03:53:02 route,debug,event     status=UP,RUNNING
Jan/01/2002 03:53:02 route,debug,event     mtu=1500
Jan/01/2002 03:53:02 route,debug,event Interface change
Jan/01/2002 03:53:02 route,debug,event     interface=vlan30
Jan/01/2002 03:53:02 route,debug,event     status=UP,RUNNING
Jan/01/2002 03:53:02 route,debug,event     mtu=1500
Jan/01/2002 03:53:02 route,debug,calc Begin calculation
Jan/01/2002 03:53:02 route,debug,event Link up
Jan/01/2002 03:53:02 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:53:02 route,debug,event Update
Jan/01/2002 03:53:02 route,debug,event     interface=sfp1-bond
Jan/01/2002 03:53:02 route,debug,event Link up
Jan/01/2002 03:53:02 route,debug,event     interface=vlan10
Jan/01/2002 03:53:02 route,debug,event Update
Jan/01/2002 03:53:02 route,debug,event     interface=vlan10
Jan/01/2002 03:53:02 route,debug,event Link up
Jan/01/2002 03:53:02 route,debug,event     interface=vlan20
Jan/01/2002 03:53:02 route,debug,event Update
Jan/01/2002 03:53:02 route,debug,event     interface=vlan20
Jan/01/2002 03:53:02 route,debug,event Link up
Jan/01/2002 03:53:02 route,debug,event     interface=vlan30
Jan/01/2002 03:53:02 route,debug,event Update
Jan/01/2002 03:53:02 route,debug,event     interface=vlan30
Jan/01/2002 03:53:02 route,debug,calc End calculation
Jan/01/2002 03:53:02 radvd,debug skip Router Advertisement sending on sfp1-bond: no prefixes to send
Jan/01/2002 03:53:02 radvd,debug skip Router Advertisement sending on vlan10: no prefixes to send
Jan/01/2002 03:53:02 radvd,debug skip Router Advertisement sending on vlan30: no prefixes to send
Jan/01/2002 03:53:02 radvd,debug skip Router Advertisement sending on vlan20: no prefixes to send