Bug Report - BIRD 3.3.2 — `Assertion '!new || rte_is_valid(new)' failed at nest/rt-table.c:1562`
Hi, # BIRD 3.3.2 — `Assertion '!new || rte_is_valid(new)' failed at nest/rt-table.c:1562` Apparent race between `rt_next_hop_update_net()` and `channel_notify_optimal_req()`. Addresses, ASNs and hostnames below are replaced with documentation ranges (RFC 5398, RFC 3849). Pointer values, offsets and line numbers are verbatim. ## Summary BIRD 3.3.2 aborts on an internal assertion roughly every 20–40 seconds on two independent route servers once recursive next-hop resolution is active and the table is under churn. ``` Assertion '!new || rte_is_valid(new)' failed at nest/rt-table.c:1562 ``` **84 and 81 aborts** in about 40 minutes. The two machines are separate VMs on separate hypervisors, same configuration shape, same peers. They began aborting **three seconds apart**, which pointed at a data/timing trigger arriving over BGP rather than anything host-local. The backtrace shows the assertion firing in the main loop while a worker thread is suspended mid-update inside `rt_next_hop_update_net()`. ## Environment ``` BIRD 3.3.2 (Debian package bird3 3.3.2-cznic.1~trixie, amd64) OS Debian GNU/Linux 13 (trixie) Kernel 6.12.107+deb13-cloud-amd64 Role IX-style route server ``` Ruled out: 16 GB RAM, ~1 GB in use, BIRD RSS 538–564 MB at abort. No kernel OOM records, `dmesg` clean. Configuration parses (`birdc configure check` → OK). ## Backtrace Symbolised with `bird3-dbgsym` 3.3.2-cznic.1~trixie. **Thread 1 — main loop, the abort:** ``` #3 bug (msg=msg@entry=0x... "Assertion '%s' failed at %s:%d") at sysdep/unix/log.c:446 #4 channel_notify_optimal_req (c=c@entry=0x562028c3a000, req=req@entry=0x562028c3a128) at nest/rt-table.c:1562 new = <optimized out> old = <optimized out> trte = <optimized out> u = 0x7f8308f4f2b0 #5 channel_notify_optimal (_channel=0x562028c3a000) at nest/rt-table.c:1591 c = 0x562028c3a000 #6 ev_run_list_limited (l=0x... <global_work_list>, limit=7, limit@entry=10) at lib/event.c:336 #7 io_loop () at sysdep/unix/io.c:2642 #8 main (argc=<optimized out>, argv=<optimized out>) at sysdep/unix/main.c:1114 ``` **Thread 2 — next-hop update worker, suspended mid-update:** ``` #5 birdloop_yield () at sysdep/unix/io-loop.c:2372 #6 synchronize_rcu () at ./lib/rcu.h:96 #7 rt_next_hop_update_net (tab=<optimized out>, ni=<optimized out>, n=<optimized out>) at nest/rt-table.c:4747 #8 rt_next_hop_update (_tab=<optimized out>) at nest/rt-table.c:4951 #9 ev_run_list_limited (l=l@entry=0x..., limit=4294967294, limit@entry=4294967295) at lib/event.c:336 #10 birdloop_run (_loop=0x...) at sysdep/unix/io-loop.c:2114 #11 ev_run_list_limited (...) at lib/event.c:336 #12 bird_thread_main (arg=0x...) at sysdep/unix/io-loop.c:1034 ``` **Thread 3 — idle in `poll()`**, `bird_thread_main` at `sysdep/unix/io-loop.c:1094`. ## What this looks like Thread 2 is inside `rt_next_hop_update_net()` and has yielded in `synchronize_rcu()` → `birdloop_yield()`, so the network it is updating is part-way through modification. Thread 1, in the main loop, runs `channel_notify_optimal()` for a channel and `channel_notify_optimal_req()` asserts that the route it has been handed is valid. We have not read the source to confirm the exact window, and the relevant locals are optimised out, so this is offered as where to look rather than as a diagnosis. ## Reproduction Consistent and quick once the conditions are present: 1. Route server with ~1.07M IPv4 and ~250k IPv6 in `master4`/`master6`, learned over two multihop eBGP sessions from edge routers. 2. Eight multihop eBGP customer sessions sourced from a loopback, whose next hops require **recursive resolution** against the local table. 3. A default route installed such that those next hops actually resolve. 4. Churn — a session flap, or `systemctl restart bird` to reload the full table. The abort then occurs within seconds to a couple of minutes, repeatedly. Log immediately before one abort, showing recursive resolution in bulk: ``` Next hop address 2001:db8:0:2::211 resolvable through recursive route for 2001:db8::/32 Next hop address 2001:db8:1000:700::11 resolvable through recursive route for 2001:db8::/32 Next hop address 2001:db8:1::1 resolvable through recursive route for 2001:db8:1::/48 Next hop address 2001:db8:1::1 resolvable through recursive route for 2001:db8:1::/48 Next hop address 2001:db8:1::2 resolvable through recursive route for 2001:db8:1::/48 Next hop address 2001:db8:1::2 resolvable through recursive route for 2001:db8:1::/48 Assertion '!new || rte_is_valid(new)' failed at nest/rt-table.c:1562 ``` Before another: ``` edge_a.ipv4: table prune after refresh end: rr 4096 set 5 valid 5 pruning 5 pruned 5 fabric_b: Connecting to 2001:db8:100:b00b::3 from local address 2001:db8:1000:701::1 fabric_b: Connection lost (Connection refused) fabric_b: Connect delayed by 5 seconds device1: Scanning interfaces Assertion '!new || rte_is_valid(new)' failed at nest/rt-table.c:1562 ``` ## The workaround, which also isolates the trigger Changing **one line** — the static default used as the recursive resolution target — is the difference between a stable process and one aborting every 20–40 seconds. Same box, same table, same peers. ``` # aborts, 84 times in ~40 minutes protocol static resolver6 { ipv6; route ::/0 via fe80::1%eth0; } protocol static resolver4 { ipv4; route 0.0.0.0/0 via "eth0"; } # stable, 30+ minutes and counting protocol static resolver6 { ipv6; route ::/0 blackhole; } protocol static resolver4 { ipv4; route 0.0.0.0/0 blackhole; } ``` With `blackhole` the default still exists in the table and is still exported to peers, but nothing resolves recursively through it — so `rt_next_hop_update_*` has no hostentries to process and Thread 2's code path is never entered. This was verified as a controlled test rather than assumed: the change was applied to **one** of the two route servers while the other was left alone. The changed box stopped aborting immediately (restart counter frozen, uptime growing past 30 minutes); the untouched box continued aborting every 20–40 seconds until the same change was applied to it. Re-applying the gateway form to the second box reproduced the abort on demand and produced the core above. ## Configuration shape ``` Protocols 12 BGP, 5 Static, 2 Pipe, 2 Kernel, 1 RPKI, 1 BFD, 1 Device Tables master4, master6, t_cust4, t_cust6, rpki4, rpki6, aspa1 Pipes master4 <=> t_cust4, master6 <=> t_cust6 Kernel export none, learn off (BIRD installs nothing in the FIB) RPKI RTR session with roa4, roa6 and aspa channels ``` BGP: two multihop eBGP to edge routers carrying a full table, two single-hop eBGP to switches, eight multihop eBGP customer sessions sourced from a loopback with recursive next-hop resolution. Import filters call `roa_check()` and `aspa_check_downstream()` / `aspa_check_upstream()`. ## Impact Both route servers of a redundant pair abort on the same input at the same time, and `Restart=on-abort` restarts each in a loop. Every restart drops all BGP sessions; the edge routers then re-push a full table, which does not complete before the next abort. Customer sessions cannot stay established. The redundancy provides no protection because both machines fail identically. ## Core dumps etc The compressed core (57–105 MB per dump) https://www.filemail.com/d/bpysuryqkeusczh Best regards Lars Strandos
participants (1)
-
Lars Strandos