On Sat, Feb 29, 2020 at 1:05 PM Neil Jerram <n...@tigera.io> wrote:
> I am struggling to understand and ideally eliminate an unwanted flap (i.e.
> delete and re-add) of an IPv6 route on node M, when a neighbouring node R
> restarts, and R is configured to advertise that IPv6 route statically. [...]
>
FYI I have just tried the same test again with DBG(...) statements compiled
in, in the hope that that might reveal strange timing in the static
protocol processing. Unfortunately I don't think it revealed anything
suspicious. There is a line with
static_add(fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122,2)
almost immediately after BIRD6 start-up, and 2 seconds before the "Graceful
restart done" log. So it doesn't look - for example - like the static
processing is being deferred until after "Graceful restart done". Possibly
interesting that I do not see any "Installing static route" line, but maybe
that is because that route was present in the kernel and so has already
been copied into the BIRD6 core by the kernel protocol.
The complete log is below, in case it reveals more clues to someone else!
As in the previous run, the unwanted route flap was observed on the other
node just after the BGP session reached state Up. (I think
at 16:59:44.795, but have unfortunately lost the exact output now.)
Best wishes,
Neil
Merged (sorry) logs for BIRD and BIRD6:
2020-03-02T16:59:41.58460202Z Parsing configuration file
`/etc/calico/confd/config/bird.cfg'
2020-03-02T16:59:41.584628001Z Parsing configuration file
`/etc/calico/confd/config/bird6.cfg'
2020-03-02T16:59:41.585771719Z bird6: device1: Initializingbird:
2020-03-02T16:59:41.585818652Z bird6: direct1: Initializing
2020-03-02T16:59:41.58584128Z bird: direct1: Initializingbird6:
2020-03-02T16:59:41.585935985Z bird: Mesh_172_17_0_5: Initializingbird6:
2020-03-02T16:59:41.585981801Z bird: Mesh_172_17_0_3: Initializingbird6:
2020-03-02T16:59:41.586024543Z bird: done
2020-03-02T16:59:41.586130702Z bird6: Protocol start
2020-03-02T16:59:41.586193279Z bird: device1: Starting
2020-03-02T16:59:41.58709367Z bird6: IFA change notification (1) for
tunl0:192.168.110.128
2020-03-02T16:59:41.587183626Z bird6: device1: State changed to feeddevice1
reporting state transition HUNGRY/DOWN -> */UP
2020-03-02T16:59:41.587332806Z bird: device1: Connected to table
masterstatic_add(fd00:10:244:0:1cc0:b1ac:ad47:e7c0/122,2)
2020-03-02T16:59:41.587408514Z bird: device1: State changed to feed
2020-03-02T16:59:41.587664691Z bird6: direct1: Starting
2020-03-02T16:59:41.587740399Z bird6: Kicking kernel1 up
2020-03-02T16:59:41.587822811Z bird6: direct1: State changed to feed
2020-03-02T16:59:41.587859128Z bird6: Mesh_2001_20__8: Starting
2020-03-02T16:59:41.587985681Z bird: bird6: direct1:
StartingMesh_2001_20__8: State changed to start
2020-03-02T16:59:41.588075077Z bird6: bird: Mesh_2001_20__1:
Startingdirect1: Connected to table master
2020-03-02T16:59:41.58826728Z bird: Mesh_2001_20__1 reporting state
transition HUNGRY/DOWN -> */START
2020-03-02T16:59:41.588285997Z direct1: State changed to feedbird6:
2020-03-02T16:59:41.588345781Z bird: Mesh_172_17_0_5: StartingKicking
Mesh_2001_20__3 up
2020-03-02T16:59:41.588385171Z bird6: Mesh_2001_20__3: StartingBGP: Startup.
2020-03-02T16:59:41.588520104Z bird: bird6: Mesh_172_17_0_5: State changed
to startMesh_2001_20__3: State changed to start
2020-03-02T16:59:41.588601958Z bird: Mesh_172_17_0_3: Startingbird6:
2020-03-02T16:59:41.588650567Z bird6: Started
2020-03-02T16:59:41.588713145Z bird: Mesh_172_17_0_3: State changed to start
2020-03-02T16:59:41.588776561Z bird: Announcing routes to new protocol
device1
2020-03-02T16:59:41.588838859Z bird6: olock: 0000555556bb6b20 acquired
immediately
2020-03-02T16:59:41.58892183Z bird: Announcing interfaces to new protocol
static1
2020-03-02T16:59:41.588999773Z bird: Graceful restart startedFeeding
protocol static1 finished
2020-03-02T16:59:41.589046985Z bird: Announcing interfaces to new protocol
direct1
2020-03-02T16:59:41.589203429Z bird6: direct1: State changed to up
2020-03-02T16:59:41.589266566Z bird: BGP: Got lock
2020-03-02T16:59:41.589579174Z bird: direct1: State changed to up
2020-03-02T16:59:41.774914181Z bird6: Mesh_2001_20__8: Connected to table
master
2020-03-02T16:59:41.774983464Z bird6: Mesh_2001_20__8: State changed to wait
2020-03-02T16:59:42.372436086Z bird: Mesh_172_17_0_3: Connected to table
master
2020-03-02T16:59:42.372457597Z bird: Mesh_172_17_0_3: State changed to wait
2020-03-02T16:59:42.776392912Z bird6: Mesh_2001_20__3: Connected to table
master
2020-03-02T16:59:42.776416378Z bird6: Mesh_2001_20__3: State changed to wait
2020-03-02T16:59:43.081266214Z bird: Mesh_172_17_0_5: Connected to table
master
2020-03-02T16:59:43.081286329Z bird: Mesh_172_17_0_5: State changed to wait
2020-03-02T16:59:43.19352288Z bird: Mesh_172_17_0_4: Connected to table
master
2020-03-02T16:59:43.193545788Z bird: Mesh_172_17_0_4: State changed to wait
2020-03-02T16:59:43.19394472Z bird: Graceful restart done
2020-03-02T16:59:43.194007298Z bird: Mesh_172_17_0_5: State changed to feed
2020-03-02T16:59:43.194044733Z bird: Mesh_172_17_0_3: State changed to feed
2020-03-02T16:59:43.194076301Z bird: Mesh_172_17_0_4: State changed to feed
2020-03-02T16:59:43.778698281Z bird6: Mesh_2001_20__1: Connected to table
master
2020-03-02T16:59:43.778712249Z bird6: Mesh_2001_20__1: State changed to wait
2020-03-02T16:59:43.779284946Z bird6: Graceful restart done
2020-03-02T16:59:43.779327688Z bird6: Mesh_2001_20__8: State changed to feed
2020-03-02T16:59:43.779351993Z bird6: Mesh_2001_20__1: State changed to feed
2020-03-02T16:59:43.779383282Z bird6: Mesh_2001_20__3: State changed to feed
2020-03-02T16:59:44.195069776Z bird: Mesh_172_17_0_5: State changed to up
2020-03-02T16:59:44.195572352Z bird: Mesh_172_17_0_3: State changed to up
2020-03-02T16:59:44.196010954Z bird: Mesh_172_17_0_4: State changed to up
2020-03-02T16:59:44.780565328Z bird6: Mesh_2001_20__8: State changed to up
2020-03-02T16:59:44.78083687Z bird6: Mesh_2001_20__1: State changed to up
2020-03-02T16:59:44.781566569Z bird6: Mesh_2001_20__3: State changed to up
