<div dir="ltr"><div dir="ltr">On Tue, Mar 3, 2020 at 2:37 PM Ondrej Zajicek <<a href="mailto:santiago@crfreenet.org">santiago@crfreenet.org</a>> wrote:<br></div><div class="gmail_quote"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">On Mon, Mar 02, 2020 at 05:35:01PM +0000, Neil Jerram wrote:<br>
> On Sat, Feb 29, 2020 at 1:05 PM Neil Jerram <<a href="mailto:neil@tigera.io" target="_blank">neil@tigera.io</a>> wrote:<br>
> <br>
> > I am struggling to understand and ideally eliminate an unwanted flap (i.e.<br>
> > delete and re-add) of an IPv6 route on node M, when a neighbouring node R<br>
> > restarts, and R is configured to advertise that IPv6 route statically. [...]<br>
> ><br>
> <br>
> FYI I have just tried the same test again with DBG(...) statements compiled<br>
> in, in the hope that that might reveal strange timing in the static<br>
> protocol processing. Unfortunately I don't think it revealed anything<br>
> suspicious. There is a line with<br>
<br>
Hi<br>
<br>
I would guess that the issue is more in node M than in node R. The fact<br>
that it happens only for IPv6 can be explained by implementation of<br>
Kernel protocol, which uses replace operation for IPv4 (since 2.0.5), but<br>
only remove/add for IPv6. Technically, the kernel protocol should detect<br>
that the new route is the same as old one and avoid pushing it to the<br>
kernel, but perhaps for some reason it pushes it anyway and causes the<br>
flap.<br>
<br>
To debug this isse, it would be useful to enable 'debug { events, routes<br>
}' on BGP and Kernel on node M. One could see if there are any withdraws,<br>
or just updates.<br></blockquote><div><br></div><div>Thanks Ondrej. Here is a case where node R was killed (-9) at 15:50:03 and restarted at 15:50:08. Node M saw this route flap at 15:50:11:</div><div><br></div><div>[2020-03-04T15:50:11.257106] Deleted fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 via 2001:20::2 dev eth0 proto bird metric 1024 pref medium<br>[2020-03-04T15:50:11.257459] fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 via 2001:20::2 dev eth0 proto bird metric 1024 pref medium<br></div><div><br></div><div>Here is the node M log with "debug all", for both v4 and v6, from when R restarted until the route flap:</div><div><br></div><div>2020-03-04T15:50:09.246741514Z KRT: Scanning routing table<br>2020-03-04T15:50:09.246805309Z BGP: connect_timeout<br>2020-03-04T15:50:09.246820405Z BGP: Closing connection<br>2020-03-04T15:50:09.246830788Z BGP: Connecting<br>2020-03-04T15:50:09.246843075Z bird: Mesh_172_17_0_2: Connecting to 172.17.0.2 from local address 172.17.0.3<br>2020-03-04T15:50:09.246852834Z KRT: Got 2001:20::/64, type=1, oif=36, table=254, prid=2, proto=kernel1<br>2020-03-04T15:50:09.246861952Z KRT: Got fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122, type=1, oif=36, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:09.246871442Z KRT: Got fd00:10:244:0:586d:4461:e980:a280/128, type=1, oif=6, table=254, prid=3, proto=kernel1<br>2020-03-04T15:50:09.246879832Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.246889555Z KRT: Got fd00:10:244:0:586d:4461:e980:a280/122, type=6, oif=1, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:09.246898969Z KRT: Got fd00:10:244:0:58fd:b191:5c13:9cc0/122, type=1, oif=36, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:09.246908792Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.24691778Z KRT: Got fe80::/64, type=1, oif=36, table=254, prid=2, proto=kernel1<br>2020-03-04T15:50:09.246927197Z KRT: Ignoring route - strange class/scope<br>2020-03-04T15:50:09.246935966Z KRT: Got fe80::/64, type=1, oif=6, table=254, prid=2, proto=kernel1<br>2020-03-04T15:50:09.246944298Z KRT: Ignoring route - strange class/scope<br>2020-03-04T15:50:09.247009224Z KRT: Got ::1/128, type=2, oif=1, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.247065042Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247088778Z KRT: Got 2001:20::/128, type=4, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.247115256Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247131555Z KRT: Got 2001:20::1/128, type=2, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.247145697Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247159089Z KRT: Got fd00:10:96::ac35/128, type=2, oif=3, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.24717877Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247192816Z KRT: Got fe80::/128, type=4, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.247206392Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247219343Z KRT: Got fe80::/128, type=4, oif=6, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.247262729Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247279256Z KRT: Got fe80::42:acff:fe11:3/128, type=2, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.247294287Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247307585Z KRT: Got fe80::ecee:eeff:feee:eeee/128, type=2, oif=6, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.247322176Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247335799Z KRT: Got ff00::/8, type=1, oif=36, table=255, prid=3, proto=(none)<br>2020-03-04T15:50:09.247349484Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.24736411Z KRT: Got ff00::/8, type=1, oif=2, table=255, prid=3, proto=(none)<br>2020-03-04T15:50:09.247378221Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247391919Z KRT: Got ff00::/8, type=1, oif=6, table=255, prid=3, proto=(none)<br>2020-03-04T15:50:09.247405262Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.247417972Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.247439521Z KRT: Pruning table master<br>2020-03-04T15:50:09.247455481Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.247554245Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.247607455Z KRT: Pruning inherited routes<br>2020-03-04T15:50:09.247630001Z fd00:10:244:0:586d:4461:e980:a280/128: uptodate (metric=1024)<br>2020-03-04T15:50:09.24764445Z KRT: Scanning interfaces<br>2020-03-04T15:50:09.247654547Z bird6: device1: Scanning interfaces<br>2020-03-04T15:50:09.247664209Z BGP: Waiting for connect success<br>2020-03-04T15:50:09.247672821Z KRT: Scanning routing table<br>2020-03-04T15:50:09.247735015Z KIF: IF1(lo) goes up (mtu=65536,flg=10049)<br>2020-03-04T15:50:09.247758005Z KRT: Got <a href="http://0.0.0.0/0">0.0.0.0/0</a>, type=1, oif=36, table=254, prid=3, proto=kernel1<br>2020-03-04T15:50:09.247773084Z KIF: IF2(tunl0) goes up (mtu=1440,flg=100c1)<br>2020-03-04T15:50:09.247786978Z KRT: Got <a href="http://172.17.0.0/16">172.17.0.0/16</a>, type=1, oif=36, table=254, prid=2, proto=kernel1<br>2020-03-04T15:50:09.247800431Z KIF: IF3(kube-ipvs0) goes up (mtu=1500,flg=82)<br>2020-03-04T15:50:09.247813312Z KRT: Got <a href="http://192.168.82.0/26">192.168.82.0/26</a>, type=1, oif=2, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:09.24783563Z KIF: IF6(cali8cac6bddbc7) goes up (mtu=1440,flg=11043)<br>2020-03-04T15:50:09.247851668Z KIF: IF36(eth0) goes up (mtu=1500,flg=11043)<br>2020-03-04T15:50:09.247866271Z KRT: Got <a href="http://192.168.110.128/26">192.168.110.128/26</a>, type=1, oif=2, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:09.247877588Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.247887009Z KRT: Got <a href="http://192.168.162.128/26">192.168.162.128/26</a>, type=6, oif=-1, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:09.247897047Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.247909529Z KRT: Got <a href="http://192.168.162.129/32">192.168.162.129/32</a>, type=1, oif=6, table=254, prid=3, proto=kernel1<br>2020-03-04T15:50:09.247922738Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.247936079Z KRT: Got <a href="http://192.168.195.192/26">192.168.195.192/26</a>, type=1, oif=2, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:09.247950491Z KRT: Got <a href="http://192.168.195.194/32">192.168.195.194/32</a>, type=1, oif=2, table=254, prid=0, proto=kernel1<br>2020-03-04T15:50:09.247965204Z KRT: Ignoring route - proto unspec<br>2020-03-04T15:50:09.247981588Z KRT: Got <a href="http://10.96.0.1/32">10.96.0.1/32</a>, type=2, oif=3, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.247996158Z KIF: IF1(lo): added IPA ::1, flg 80000, net ::1/128, brd ::1, opp ::<br>2020-03-04T15:50:09.248010666Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248023519Z KRT: Got <a href="http://10.96.0.10/32">10.96.0.10/32</a>, type=2, oif=3, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248031562Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248078034Z KIF: IF3(kube-ipvs0): added IPA fd00:10:96::ac35, flg 80000, net fd00:10:96::ac35/128, brd fd00:10:96::ac35, opp ::<br>2020-03-04T15:50:09.248096436Z KRT: Got <a href="http://10.96.139.174/32">10.96.139.174/32</a>, type=2, oif=3, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.24811125Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248126598Z KRT: Got <a href="http://127.0.0.0/32">127.0.0.0/32</a>, type=3, oif=1, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248141107Z KIF: IF6(cali8cac6bddbc7): added IPA fe80::ecee:eeff:feee:eeee, flg 0, net fe80::/64, brd fe80::ffff:ffff:ffff:ffff, opp ::<br>2020-03-04T15:50:09.248161213Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248175116Z KRT: Got <a href="http://127.0.0.0/8">127.0.0.0/8</a>, type=2, oif=1, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248188541Z KIF: IF36(eth0): added IPA 2001:20::1, flg 0, net 2001:20::/64, brd 2001:20::ffff:ffff:ffff:ffff, opp ::<br>2020-03-04T15:50:09.248201047Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248211099Z KRT: Got <a href="http://127.0.0.1/32">127.0.0.1/32</a>, type=2, oif=1, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248221199Z KIF: IF36(eth0): added IPA fe80::42:acff:fe11:3, flg 0, net fe80::/64, brd fe80::ffff:ffff:ffff:ffff, opp ::<br>2020-03-04T15:50:09.24823302Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248246842Z KRT: Got <a href="http://127.255.255.255/32">127.255.255.255/32</a>, type=3, oif=1, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248259358Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248273776Z KRT: Got <a href="http://172.17.0.0/32">172.17.0.0/32</a>, type=3, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248286895Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248299546Z KRT: Got <a href="http://172.17.0.3/32">172.17.0.3/32</a>, type=2, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248314329Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248326176Z KRT: Got <a href="http://172.17.255.255/32">172.17.255.255/32</a>, type=3, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248340421Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248353604Z KRT: Got <a href="http://192.168.162.128/32">192.168.162.128/32</a>, type=2, oif=2, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248396709Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248410649Z KRT: Got <a href="http://192.168.162.128/32">192.168.162.128/32</a>, type=3, oif=2, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:09.248424182Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:09.248432641Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.248444232Z KRT: Pruning table master<br>2020-03-04T15:50:09.248455103Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.248467991Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.248481917Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.248495733Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:09.248507692Z KRT: Pruning inherited routes<br>2020-03-04T15:50:09.248520821Z <a href="http://0.0.0.0/0">0.0.0.0/0</a>: uptodate (metric=0)<br>2020-03-04T15:50:09.248533995Z <a href="http://192.168.162.129/32">192.168.162.129/32</a>: uptodate (metric=0)<br>2020-03-04T15:50:09.248548157Z KRT: Scanning interfaces<br>2020-03-04T15:50:09.248562678Z bird: device1: Scanning interfaces<br>2020-03-04T15:50:09.248634912Z KIF: IF1(lo) goes up (mtu=65536,flg=10049)<br>2020-03-04T15:50:09.248654262Z KIF: IF2(tunl0) goes up (mtu=1440,flg=100c1)<br>2020-03-04T15:50:09.248667478Z KIF: IF3(kube-ipvs0) goes up (mtu=1500,flg=82)<br>2020-03-04T15:50:09.248679741Z KIF: IF6(cali8cac6bddbc7) goes up (mtu=1440,flg=11043)<br>2020-03-04T15:50:09.24869377Z KIF: IF36(eth0) goes up (mtu=1500,flg=11043)<br>2020-03-04T15:50:09.248707404Z KIF: IF1(lo): added IPA 127.0.0.1, flg 0, net <a href="http://127.0.0.0/8">127.0.0.0/8</a>, brd 127.255.255.255, opp 0.0.0.0<br>2020-03-04T15:50:09.248721777Z KIF: IF2(tunl0): added IPA 192.168.162.128, flg 80000, net <a href="http://192.168.162.128/32">192.168.162.128/32</a>, brd 192.168.162.128, opp 0.0.0.0<br>2020-03-04T15:50:09.24875919Z KIF: IF3(kube-ipvs0): added IPA 10.96.0.10, flg 80000, net <a href="http://10.96.0.10/32">10.96.0.10/32</a>, brd 10.96.0.10, opp 0.0.0.0<br>2020-03-04T15:50:09.248774578Z KIF: IF3(kube-ipvs0): added IPA 10.96.0.1, flg 80000, net <a href="http://10.96.0.1/32">10.96.0.1/32</a>, brd 10.96.0.1, opp 0.0.0.0<br>2020-03-04T15:50:09.248787796Z KIF: IF3(kube-ipvs0): added IPA 10.96.139.174, flg 80000, net <a href="http://10.96.139.174/32">10.96.139.174/32</a>, brd 10.96.139.174, opp 0.0.0.0<br>2020-03-04T15:50:09.248801387Z KIF: IF36(eth0): added IPA 172.17.0.3, flg 0, net <a href="http://172.17.0.0/16">172.17.0.0/16</a>, brd 172.17.255.255, opp 0.0.0.0<br>2020-03-04T15:50:09.248813862Z bird: Mesh_172_17_0_2: Connected<br>2020-03-04T15:50:09.248826279Z BGP: Sending open<br>2020-03-04T15:50:09.248838704Z BGP: Scheduling packet type 1<br>2020-03-04T15:50:09.248853116Z BGP: kicking TX<br>2020-03-04T15:50:09.248867125Z bird: Mesh_172_17_0_2: Sending OPEN(ver=4,as=64512,hold=240,id=ac110003)<br>2020-03-04T15:50:09.248917898Z BGP: RX hook: Got 63 bytes<br>2020-03-04T15:50:09.248934749Z BGP: Got packet 01 (63 bytes)<br>2020-03-04T15:50:09.248950737Z bird: Mesh_172_17_0_2: Got OPEN(as=64512,hold=240,id=ac110002)<br>2020-03-04T15:50:09.248966303Z BGP: Hold timer set to 240, keepalive to 80, AS to 64512, ID to ac110002, AS4 session to 1<br>2020-03-04T15:50:09.248980707Z BGP: Scheduling packet type 4<br>2020-03-04T15:50:09.248994608Z BGP: kicking TX<br>2020-03-04T15:50:09.249010838Z bird: Mesh_172_17_0_2: Sending KEEPALIVE<br>2020-03-04T15:50:09.249025237Z BGP: RX hook: Got 19 bytes<br>2020-03-04T15:50:09.249041602Z BGP: Got packet 04 (19 bytes)<br>2020-03-04T15:50:09.249055904Z bird: Mesh_172_17_0_2: Got KEEPALIVE<br>2020-03-04T15:50:09.249070942Z bird: Mesh_172_17_0_2: BGP session established<br>2020-03-04T15:50:09.249086311Z BGP: UP!!!<br>2020-03-04T15:50:09.249101679Z Mesh_172_17_0_2 reporting state transition HAPPY/START -> */UP<br>2020-03-04T15:50:09.249115749Z Mesh_172_17_0_2: Scheduling meal<br>2020-03-04T15:50:09.249129837Z bird: Mesh_172_17_0_2: State changed to feed<br>2020-03-04T15:50:09.249144331Z Feeding protocol Mesh_172_17_0_2<br>2020-03-04T15:50:09.249158675Z Feeding protocol Mesh_172_17_0_2 continued<br>2020-03-04T15:50:09.249173112Z Announcing routes to new protocol Mesh_172_17_0_2<br>2020-03-04T15:50:09.249188304Z Running filter `calico_export_to_bgp_peers'...done (3)<br>2020-03-04T15:50:09.249203949Z bird: Mesh_172_17_0_2 < filtered out <a href="http://0.0.0.0/0">0.0.0.0/0</a> via 172.17.0.1 on eth0<br>2020-03-04T15:50:09.249218774Z bird: Mesh_172_17_0_2 < rejected by protocol <a href="http://192.168.110.128/26">192.168.110.128/26</a> via 172.17.0.2 on eth0<br>2020-03-04T15:50:09.24923382Z bird: Mesh_172_17_0_2 < rejected by protocol <a href="http://192.168.82.0/26">192.168.82.0/26</a> via 172.17.0.5 on eth0<br>2020-03-04T15:50:09.249247862Z bird: Mesh_172_17_0_2 < rejected by protocol <a href="http://192.168.195.192/26">192.168.195.192/26</a> via 172.17.0.4 on eth0<br>2020-03-04T15:50:09.249262073Z Running filter `calico_export_to_bgp_peers'...done (2)<br>2020-03-04T15:50:09.249276515Z bird: Mesh_172_17_0_2 < added <a href="http://192.168.162.128/26">192.168.162.128/26</a> blackhole<br>2020-03-04T15:50:09.249290957Z BGP: Got route <a href="http://192.168.162.128/26">192.168.162.128/26</a> up<br>2020-03-04T15:50:09.249306466Z Creating bucket.<br>2020-03-04T15:50:09.249320685Z BGP: Scheduling packet type 2<br>2020-03-04T15:50:09.249334842Z Running filter `calico_export_to_bgp_peers'...done (3)<br>2020-03-04T15:50:09.24934932Z bird: Mesh_172_17_0_2 < filtered out <a href="http://192.168.162.128/32">192.168.162.128/32</a> dev tunl0<br>2020-03-04T15:50:09.249364445Z Running filter `calico_export_to_bgp_peers'...done (3)<br>2020-03-04T15:50:09.24937825Z bird: Mesh_172_17_0_2 < filtered out <a href="http://192.168.162.129/32">192.168.162.129/32</a> dev cali8cac6bddbc7<br>2020-03-04T15:50:09.249391382Z Running filter `calico_export_to_bgp_peers'...done (3)<br>2020-03-04T15:50:09.24940507Z bird: Mesh_172_17_0_2 < filtered out <a href="http://172.17.0.0/16">172.17.0.0/16</a> dev eth0<br>2020-03-04T15:50:09.249418815Z Feeding protocol Mesh_172_17_0_2 finished<br>2020-03-04T15:50:09.249447337Z bird: Mesh_172_17_0_2: State changed to up<br>2020-03-04T15:50:09.249461645Z BGP: Scheduling packet type 2<br>2020-03-04T15:50:09.249475753Z BGP: kicking TX<br>2020-03-04T15:50:09.249490907Z Processing bucket 0000555557021ba0<br>2020-03-04T15:50:09.249505903Z Attribute 01 (1 bytes, flags 40)<br>2020-03-04T15:50:09.249520285Z Attribute 02 (0 bytes, flags 40)<br>2020-03-04T15:50:09.249534754Z Attribute 03 (4 bytes, flags 40)<br>2020-03-04T15:50:09.249549382Z Attribute 05 (4 bytes, flags 40)<br>2020-03-04T15:50:09.249563745Z Dequeued route <a href="http://192.168.162.128/26">192.168.162.128/26</a><br>2020-03-04T15:50:09.249578227Z bird: Mesh_172_17_0_2: Sending UPDATE<br>2020-03-04T15:50:09.249592887Z Deleting empty bucket 0000555557021ba0<br>2020-03-04T15:50:09.24960707Z bird: Mesh_172_17_0_2: Sending END-OF-RIB<br>2020-03-04T15:50:10.250941727Z BGP: Incoming connection from 2001:20::2 port 53505<br>2020-03-04T15:50:10.25100382Z bird6: Mesh_2001_20__2: Incoming connection from 2001:20::2 (port 53505) accepted<br>2020-03-04T15:50:10.251028737Z BGP: Sending open<br>2020-03-04T15:50:10.251044532Z BGP: Scheduling packet type 1<br>2020-03-04T15:50:10.251059599Z BGP: kicking TX<br>2020-03-04T15:50:10.251071469Z bird6: Mesh_2001_20__2: Sending OPEN(ver=4,as=64512,hold=240,id=ac110003)<br>2020-03-04T15:50:10.252332027Z BGP: RX hook: Got 63 bytes<br>2020-03-04T15:50:10.25237946Z BGP: Got packet 01 (63 bytes)<br>2020-03-04T15:50:10.252399422Z bird6: Mesh_2001_20__2: Got OPEN(as=64512,hold=240,id=ac110002)<br>2020-03-04T15:50:10.252415598Z BGP: Hold timer set to 240, keepalive to 80, AS to 64512, ID to ac110002, AS4 session to 1<br>2020-03-04T15:50:10.252439287Z BGP: Scheduling packet type 4<br>2020-03-04T15:50:10.252453834Z BGP: kicking TX<br>2020-03-04T15:50:10.252464763Z bird6: Mesh_2001_20__2: Sending KEEPALIVE<br>2020-03-04T15:50:10.253102292Z BGP: RX hook: Got 19 bytes<br>2020-03-04T15:50:10.253132439Z BGP: Got packet 04 (19 bytes)<br>2020-03-04T15:50:10.253148868Z bird6: Mesh_2001_20__2: Got KEEPALIVE<br>2020-03-04T15:50:10.253170356Z bird6: Mesh_2001_20__2: BGP session established<br>2020-03-04T15:50:10.253190165Z BGP: UP!!!<br>2020-03-04T15:50:10.253205073Z Mesh_2001_20__2 reporting state transition HAPPY/START -> */UP<br>2020-03-04T15:50:10.25322086Z Mesh_2001_20__2: Scheduling meal<br>2020-03-04T15:50:10.253235671Z bird6: Mesh_2001_20__2: State changed to feed<br>2020-03-04T15:50:10.253249294Z Feeding protocol Mesh_2001_20__2<br>2020-03-04T15:50:10.253258967Z Feeding protocol Mesh_2001_20__2 continued<br>2020-03-04T15:50:10.253266931Z Announcing routes to new protocol Mesh_2001_20__2<br>2020-03-04T15:50:10.253276208Z Running filter `calico_export_to_bgp_peers'...done (2)<br>2020-03-04T15:50:10.253290268Z bird6: Mesh_2001_20__2 < added fd00:10:244:0:586d:4461:e980:a280/122 blackhole<br>2020-03-04T15:50:10.253301947Z BGP: Got route fd00:10:244:0:586d:4461:e980:a280/122 up<br>2020-03-04T15:50:10.253313259Z Creating bucket.<br>2020-03-04T15:50:10.253327684Z BGP: Scheduling packet type 2<br>2020-03-04T15:50:10.253341534Z Running filter `calico_export_to_bgp_peers'...done (3)<br>2020-03-04T15:50:10.253350322Z bird6: Mesh_2001_20__2 < filtered out fd00:10:244:0:586d:4461:e980:a280/128 dev cali8cac6bddbc7<br>2020-03-04T15:50:10.253364301Z Running filter `calico_export_to_bgp_peers'...done (3)<br>2020-03-04T15:50:10.253372521Z bird6: Mesh_2001_20__2 < filtered out 2001:20::/64 dev eth0<br>2020-03-04T15:50:10.2533812Z bird6: Mesh_2001_20__2 < rejected by protocol fd00:10:244:0:58fd:b191:5c13:9cc0/122 via 2001:20::3 on eth0<br>2020-03-04T15:50:10.253390384Z bird6: Mesh_2001_20__2 < rejected by protocol fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 via 2001:20::2 on eth0<br>2020-03-04T15:50:10.253399959Z Feeding protocol Mesh_2001_20__2 finished<br>2020-03-04T15:50:10.253432938Z bird6: Mesh_2001_20__2: State changed to up<br>2020-03-04T15:50:10.253444309Z BGP: Scheduling packet type 2<br>2020-03-04T15:50:10.253452592Z BGP: kicking TX<br>2020-03-04T15:50:10.253460975Z Processing bucket 0000555555dfe420<br>2020-03-04T15:50:10.25346923Z Attribute 01 (1 bytes, flags 40)<br>2020-03-04T15:50:10.25347761Z Attribute 02 (0 bytes, flags 40)<br>2020-03-04T15:50:10.253487113Z Attribute 05 (4 bytes, flags 40)<br>2020-03-04T15:50:10.25350068Z Dequeued route fd00:10:244:0:586d:4461:e980:a280/122<br>2020-03-04T15:50:10.253514208Z Attribute 0e (42 bytes, flags 80)<br>2020-03-04T15:50:10.253522744Z bird6: Mesh_2001_20__2: Sending UPDATE<br>2020-03-04T15:50:10.253530604Z Deleting empty bucket 0000555555dfe420<br>2020-03-04T15:50:10.253538422Z bird6: Mesh_2001_20__2: Sending END-OF-RIB<br>2020-03-04T15:50:11.253764583Z KRT: Scanning interfaces<br>2020-03-04T15:50:11.25383745Z bird6: device1: Scanning interfaces<br>2020-03-04T15:50:11.253887546Z KIF: IF1(lo) goes up (mtu=65536,flg=10049)<br>2020-03-04T15:50:11.253902966Z KIF: IF2(tunl0) goes up (mtu=1440,flg=100c1)<br>2020-03-04T15:50:11.253916537Z KIF: IF3(kube-ipvs0) goes up (mtu=1500,flg=82)<br>2020-03-04T15:50:11.253931398Z KIF: IF6(cali8cac6bddbc7) goes up (mtu=1440,flg=11043)<br>2020-03-04T15:50:11.253943237Z KIF: IF36(eth0) goes up (mtu=1500,flg=11043)<br>2020-03-04T15:50:11.253974158Z KIF: IF1(lo): added IPA ::1, flg 80000, net ::1/128, brd ::1, opp ::<br>2020-03-04T15:50:11.254024015Z KIF: IF3(kube-ipvs0): added IPA fd00:10:96::ac35, flg 80000, net fd00:10:96::ac35/128, brd fd00:10:96::ac35, opp ::<br>2020-03-04T15:50:11.254047398Z KIF: IF6(cali8cac6bddbc7): added IPA fe80::ecee:eeff:feee:eeee, flg 0, net fe80::/64, brd fe80::ffff:ffff:ffff:ffff, opp ::<br>2020-03-04T15:50:11.254063128Z KIF: IF36(eth0): added IPA 2001:20::1, flg 0, net 2001:20::/64, brd 2001:20::ffff:ffff:ffff:ffff, opp ::<br>2020-03-04T15:50:11.254078935Z KIF: IF36(eth0): added IPA fe80::42:acff:fe11:3, flg 0, net fe80::/64, brd fe80::ffff:ffff:ffff:ffff, opp ::<br>2020-03-04T15:50:11.254092728Z KRT: Scanning routing table<br>2020-03-04T15:50:11.25413487Z KRT: Got 2001:20::/64, type=1, oif=36, table=254, prid=2, proto=kernel1<br>2020-03-04T15:50:11.25415363Z KRT: Got fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122, type=1, oif=36, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:11.254164119Z KRT: Got fd00:10:244:0:586d:4461:e980:a280/128, type=1, oif=6, table=254, prid=3, proto=kernel1<br>2020-03-04T15:50:11.254175746Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:11.254188796Z KRT: Got fd00:10:244:0:586d:4461:e980:a280/122, type=6, oif=1, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:11.254283224Z KRT: Got fd00:10:244:0:58fd:b191:5c13:9cc0/122, type=1, oif=36, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:11.254318016Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:11.254335065Z KRT: Got fe80::/64, type=1, oif=36, table=254, prid=2, proto=kernel1<br>2020-03-04T15:50:11.254350178Z KRT: Ignoring route - strange class/scope<br>2020-03-04T15:50:11.254472086Z KRT: Got fe80::/64, type=1, oif=6, table=254, prid=2, proto=kernel1<br>2020-03-04T15:50:11.254500919Z KRT: Ignoring route - strange class/scope<br>2020-03-04T15:50:11.254512685Z KRT: Got ::1/128, type=2, oif=1, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:11.254521732Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254530077Z KRT: Got 2001:20::/128, type=4, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:11.254538211Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254546883Z KRT: Got 2001:20::1/128, type=2, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:11.254555491Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254563599Z KRT: Got fd00:10:96::ac35/128, type=2, oif=3, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:11.254600998Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254615195Z KRT: Got fe80::/128, type=4, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:11.254624445Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254635211Z KRT: Got fe80::/128, type=4, oif=6, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:11.254646553Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254659762Z KRT: Got fe80::42:acff:fe11:3/128, type=2, oif=36, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:11.254670086Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254683633Z KRT: Got fe80::ecee:eeff:feee:eeee/128, type=2, oif=6, table=255, prid=2, proto=(none)<br>2020-03-04T15:50:11.254697735Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254710567Z KRT: Got ff00::/8, type=1, oif=36, table=255, prid=3, proto=(none)<br>2020-03-04T15:50:11.254719301Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254727431Z KRT: Got ff00::/8, type=1, oif=2, table=255, prid=3, proto=(none)<br>2020-03-04T15:50:11.254736273Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.25474529Z KRT: Got ff00::/8, type=1, oif=6, table=255, prid=3, proto=(none)<br>2020-03-04T15:50:11.254754378Z KRT: Ignoring route - unknown table 255<br>2020-03-04T15:50:11.254763132Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:11.254776483Z KRT: Pruning table master<br>2020-03-04T15:50:11.254790207Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:11.254799595Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:11.254831733Z KRT: Pruning inherited routes<br>2020-03-04T15:50:11.254842769Z fd00:10:244:0:586d:4461:e980:a280/128: uptodate (metric=1024)<br>2020-03-04T15:50:11.256894131Z BGP: RX hook: Got 111 bytes<br>2020-03-04T15:50:11.256979051Z BGP: Got packet 02 (82 bytes)<br>2020-03-04T15:50:11.257024509Z bird6: Mesh_2001_20__2: Got UPDATE<br>2020-03-04T15:50:11.257040575Z Sizes: withdrawn=0, attrs=59, NLRI=0<br>2020-03-04T15:50:11.257054067Z BGP: Parsing attributes<br>2020-03-04T15:50:11.257068745Z Attr 01 40 1<br>2020-03-04T15:50:11.257083598Z Attr 02 40 0<br>2020-03-04T15:50:11.25709827Z Attr 05 40 4<br>2020-03-04T15:50:11.257113016Z Attr 0e 80 42<br>2020-03-04T15:50:11.257128231Z NLRI AF=2 sub=1 len=39<br>2020-03-04T15:50:11.257189797Z Add fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122<br>2020-03-04T15:50:11.257207985Z bird6: Mesh_2001_20__2 > added fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 via 2001:20::2 on eth0<br>2020-03-04T15:50:11.257223847Z bird6: Mesh_2001_20__8 < rejected by protocol fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 via 2001:20::2 on eth0<br>2020-03-04T15:50:11.257239326Z bird6: Mesh_2001_20__3 < rejected by protocol fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 via 2001:20::2 on eth0<br>2020-03-04T15:50:11.257256297Z bird6: Mesh_2001_20__2 < rejected by protocol fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 via 2001:20::2 on eth0<br>2020-03-04T15:50:11.257270473Z BGP: Got packet 02 (29 bytes)<br>2020-03-04T15:50:11.257285672Z bird6: Mesh_2001_20__2: Got UPDATE<br>2020-03-04T15:50:11.257300413Z Sizes: withdrawn=0, attrs=6, NLRI=0<br>2020-03-04T15:50:11.257316312Z BGP: Parsing attributes<br>2020-03-04T15:50:11.257330382Z Attr 0f 80 3<br>2020-03-04T15:50:11.257345353Z bird6: Mesh_2001_20__2: Got END-OF-RIB<br>2020-03-04T15:50:11.257360035Z bird6: Mesh_2001_20__2: Neighbor graceful restart done<br>2020-03-04T15:50:11.257375484Z Pruning route table master<br>2020-03-04T15:50:11.257390138Z bird6: Mesh_2001_20__2 > removed [replaced] fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 via 2001:20::2 on eth0<br>2020-03-04T15:50:11.257405096Z BGP: Got route fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 down<br>2020-03-04T15:50:11.257443755Z BGP: Scheduling packet type 2<br>2020-03-04T15:50:11.257459135Z BGP: Got route fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122 down<br>2020-03-04T15:50:11.257474149Z BGP: Scheduling packet type 2<br>2020-03-04T15:50:11.257489172Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:11.257503396Z Running filter `calico_kernel_programming'...done (2)<br>2020-03-04T15:50:11.257521838Z nl_send_route(fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122,op=0)<br>2020-03-04T15:50:11.257555033Z nl_send_route(fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122,op=0)<br>2020-03-04T15:50:11.257571646Z nl_send_route(fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122,op=600)<br>2020-03-04T15:50:11.257587015Z BGP: kicking TX<br>2020-03-04T15:50:11.257600455Z Withdrawn routes:<br>2020-03-04T15:50:11.257614953Z Dequeued route fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122<br>2020-03-04T15:50:11.257902007Z Attribute 0f (24 bytes, flags 80)<br>2020-03-04T15:50:11.257997418Z bird6: Mesh_2001_20__8: Sending UPDATE<br>2020-03-04T15:50:11.258026482Z BGP: kicking TX<br>2020-03-04T15:50:11.258042446Z Withdrawn routes:<br>2020-03-04T15:50:11.258060895Z Dequeued route fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122<br>2020-03-04T15:50:11.258074666Z Attribute 0f (24 bytes, flags 80)<br>2020-03-04T15:50:11.258088857Z bird6: Mesh_2001_20__3: Sending UPDATE<br>2020-03-04T15:50:11.258138862Z KRT: Received async route notification (25)<br>2020-03-04T15:50:11.258163062Z KRT: Got fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122, type=1, oif=36, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:11.258179983Z KRT: Ignoring route - echo<br>2020-03-04T15:50:11.258195125Z BGP: RX hook: Got 50 bytes<br>2020-03-04T15:50:11.258209426Z BGP: Got packet 02 (50 bytes)<br>2020-03-04T15:50:11.258223518Z bird6: Mesh_2001_20__3: Got UPDATE<br>2020-03-04T15:50:11.258236264Z Sizes: withdrawn=0, attrs=27, NLRI=0<br>2020-03-04T15:50:11.258249812Z BGP: Parsing attributes<br>2020-03-04T15:50:11.258263316Z Attr 0f 80 24<br>2020-03-04T15:50:11.258279266Z NLRI AF=2 sub=1 len=21<br>2020-03-04T15:50:11.258293723Z Withdraw fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122<br>2020-03-04T15:50:11.258308432Z KRT: Received async route notification (24)<br>2020-03-04T15:50:11.258323263Z KRT: Got fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122, type=1, oif=36, table=254, prid=12, proto=kernel1<br>2020-03-04T15:50:11.258339029Z KRT: Ignoring route - echo<br>2020-03-04T15:50:11.642617031Z KRT: Scanning interfaces<br></div><div><br></div><div>The BGP protocol for node R on node M is Mesh_2001_20__2. I will work on understanding this myself, but probably you will be able to see the key points here more readily than me!</div><div><br></div><div>Best wishes,</div><div> Neil</div><div><br></div></div></div>