Displayed update timestamps vary by 1 second for the exact same update
Hi all, If I do several consecutive "show route" queries, the timestamp keeps changing back and forth, by about a second. Example: 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:27] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i] I notice (via public route servers) that Quagga and FRRouting seem to do the same thing. Example: Last update: Thu Nov 25 18:20:31 2021 Last update: Thu Nov 25 18:20:30 2021 Last update: Thu Nov 25 18:20:30 2021 Last update: Thu Nov 25 18:20:31 2021 Does Bird do this in order emulate some convention (like perhaps something Cisco has done for decades), or is there some other reason it's displaying an inconsistent timestamp? I have a script that compares the md5 of the current output with the previous minute to decide whether to log the routing table, but because of this quirk the md5 changes almost every time... So, is this a bug, or feature? :) And is there some other reliable way to determine that Bird's routing table has changed? Thanks.
Hello! This is probably due to BIRD updating the "current real time" once per IO cycle which is in idle case once per 3 seconds. This may change in future versions, anyway I wouldn't trust the time as an indicator of route change at all. The most reliable way is to write your own protocol inside BIRD <^-^> and get the updates from the source directly. Anyway, it takes some work. (We plan to make this method simple, hopefully in near future.) Another quite reliable way is to export the routes to kernel and then run 'ip monitor' or 'route monitor' command to read them. This anyway drops some attributes. Or you can use the script to compare the MD5 of "show route all" outputs, yet you should probably s/\d\d:\d\d:\d\d/<TIME>/ (or something like that). The output is also done by walking over a hash table which may rehash sometimes and change the overall order of prefixes. Anyway, rehashing happens only when a route is changed (no sudden rehashes out of nothing). Maria On 11/25/21 9:51 PM, bird21@sensation.net.au wrote:
Hi all,
If I do several consecutive "show route" queries, the timestamp keeps changing back and forth, by about a second. Example:
0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:27] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i]
I notice (via public route servers) that Quagga and FRRouting seem to do the same thing. Example:
Last update: Thu Nov 25 18:20:31 2021 Last update: Thu Nov 25 18:20:30 2021 Last update: Thu Nov 25 18:20:30 2021 Last update: Thu Nov 25 18:20:31 2021
Does Bird do this in order emulate some convention (like perhaps something Cisco has done for decades), or is there some other reason it's displaying an inconsistent timestamp?
I have a script that compares the md5 of the current output with the previous minute to decide whether to log the routing table, but because of this quirk the md5 changes almost every time...
So, is this a bug, or feature? :) And is there some other reliable way to determine that Bird's routing table has changed?
Thanks.
On Fri, Nov 26, 2021 at 07:51:21AM +1100, bird21@sensation.net.au wrote:
Hi all,
If I do several consecutive "show route" queries, the timestamp keeps changing back and forth, by about a second. Example:
0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:27] * (100) [AS2764i] 0.0.0.0/0 via x.x.x.x on em2.100 [aapt 05:20:28] * (100) [AS2764i]
I notice (via public route servers) that Quagga and FRRouting seem to do the same thing. Example:
Last update: Thu Nov 25 18:20:31 2021 Last update: Thu Nov 25 18:20:30 2021 Last update: Thu Nov 25 18:20:30 2021 Last update: Thu Nov 25 18:20:31 2021
Does Bird do this in order emulate some convention (like perhaps something Cisco has done for decades), or is there some other reason it's displaying an inconsistent timestamp?
Hi The reason is that the timestamp is stored in monotonic time and is recomputed to wall-clock time during printing, and all these computations are done with precision of seconds, so the difference between monotonic time and wall-clock time is sometimes rounded down, sometimes up. In BIRD 2.0, time computations use microsecond precision (while printed values are rounded to milliseconds), so these rounding effects are much less visible.
I have a script that compares the md5 of the current output with the previous minute to decide whether to log the routing table, but because of this quirk the md5 changes almost every time...
You could use sed expression to remove the timestamp. We use something similar in our testing setup to normalize output to canonical format to see whether we get the same result as expected. -- Elen sila lumenn' omentielvo Ondrej 'Santiago' Zajicek (email: santiago@crfreenet.org) OpenPGP encrypted e-mails preferred (KeyID 0x11DEADC3, wwwkeys.pgp.net) "To err is human -- to blame it on a computer is even more so."
participants (3)
-
bird21＠sensation.net.au -
Maria Matejka -
Ondrej Zajicek