labsim: record the failover numbers and how they were nearly wrong
Some checks failed
CI/CD / lint (push) Failing after 9s
CI/CD / test (push) Failing after 9s
CI/CD / typecheck (push) Failing after 25s
CI/CD / build (push) Has been skipped
CI/CD / publish-rpm (push) Has been skipped
CI/CD / publish-deb (push) Has been skipped

The three T4 measurements (replace 26s, deny 148s, disable 21s), why deny is
the only one that sizes GRACE, and why 148s is a floor rather than a worst
case -- idle VMs, and an AC that shares an OVS bridge so `virsh destroy` lets
it see the peer vanish in a way a real BRAS never would.

Also writes down the broken setter that made the previous numbers fiction, so
the next person to touch the matrix knows to check the policy actually landed.
This commit is contained in:
Michal
2026-09-06 00:27:38 +01:00
parent 6987b324f1
commit 97efb5abb2
2 changed files with 108 additions and 21 deletions

View File

@@ -0,0 +1,83 @@
# WAN failover evidence
Captured by `labsim/labsim-pppoe-ha-test.sh`. Each directory holds the state of
both routers and the access concentrator at the end of one test.
## The number that sizes GRACE
`T4` destroys the master with `virsh destroy` — no LCP Terminate, no PADT, the
router simply ceases — and times how long until the survivor holds a PPPoE
session. Run across every policy VyOS can express, because Vodafone's is
unknown:
| `session-control` | takeover | |
|---|---|---|
| `replace` | 26s | accel-ppp default; the new auth kills the old session |
| **`deny`** | **148s** | the AC refuses the survivor until its own dead-peer timer frees the dead session |
| `disable` | 21s | no single-session enforcement at all |
`deny` is the only one that matters for sizing, and `GRACE=300` in
`migration/vrrp-wan.conf` comes from it. Session polling during that run caught
the mechanism directly: the destroyed router's session stayed in the AC's table
while the survivor's dial attempts appeared and were rejected — twice — before
one finally took.
**Treat 148s as a floor, not a worst case.** These are idle 2-vCPU VMs, and the
AC shares an OVS bridge with the routers, so `virsh destroy` removes the port
and accel-ppp sees the peer physically vanish. A real BRAS reached over DSL
never learns our router died; it waits out its own timers, which are longer and
not ours to know.
## How these numbers were nearly wrong
Until 2026-09-06 the matrix set the policy with:
```sh
isp "vbash -c 'source /opt/vyatta/etc/functions/script-template; configure; \
set service pppoe-server session-control $mode; commit; save; exit'"
```
That form never starts a config session. `commit` fails with
`Invalid command: [commit]` on stderr, which `isp()` discards — so all three
iterations ran against the accel-ppp default while printing the mode they were
supposedly testing. `show configuration commands | grep session-control` on the
ISP VM came back empty after a full run. The matrix reported `deny` at 25s; the
real figure is 148s, and `GRACE` was sized against the fiction.
`isp_session_control()` now drives it from a real script file, reads the value
back, and skips the iteration rather than measure the wrong policy. A harness
that reports coverage it does not have is worse than one that reports a failure.
## The other tests
| | what it proves |
|---|---|
| `T0-baseline` | exactly one session, held by the VIP holder |
| `T3-clean-failover` | `force-fault` moves `pppoe0` in 2026s |
| `T5-tengig-down` | 10 gig down → route falls to `pppoe0`, LAN back in 5s |
| `T8-lease-expiry` | the guard hangs up a stale lease within ~5s |
| `T11-no-peers-file` | a blessed box with no peers file does not restart-loop |
| `T12-holdoff-keeps-session` | a 900s flap hold-off does **not** tear down a live session |
`T12` exists because it did. `ppp_dial()` checked the hold-off and returned
before renewing `/run/vrrp-wan/may-dial`; that lease is what `vrrp-wan-guard`
expires, so tripping the damper stopped the renewal and the guard hung up
`pppoe0` on the master ~80s later:
```
DIAL FLAP: >=6 attempts in 600s -- holding off 900s
GUARD: lease stale (81s > 75s) -- hanging up pppoe0
```
A damper meant to suppress repeated *dials* was destroying an established
session instead.
## Reading `check_invariant`
The invariant that matters is **at most one of our routers holds `pppoe0`**.
The AC's session count is only a proxy for it, and only while the AC enforces
single-session — under `disable` it does not, so a destroyed router's session
lingers and the count reads 2 with exactly one live router dialled. That is
reported as a `WARN`, not a failure. It is not silenced, because an orphaned
session still occupies the single slot at a real ISP: it is exactly what made
`deny` take 148s.

View File

@@ -1,27 +1,31 @@
=== 2026-09-06T00:06:00+01:00 === === 2026-09-06T00:27:16+01:00 ===
--- AC sessions --- --- AC sessions ---
ifname | username | ip | ip6 | ip6-dp | calling-sid | rate-limit | state | uptime | rx-bytes | tx-bytes ifname | username | ip | ip6 | ip6-dp | calling-sid | rate-limit | state | uptime | rx-bytes | tx-bytes
--------+----------+----------------+-----+--------+-------------------+------------+--------+----------+----------+---------- --------+----------+----------------+-----+--------+-------------------+------------+--------+----------+----------+----------
ppp0 | simdsl | 198.51.100.123 | | | 52:54:00:4e:0b:56 | | active | 00:03:19 | 438 B | 204 B ppp1 | simdsl | 198.51.100.131 | | | 52:54:00:4e:0b:56 | | active | 00:04:24 | 1.1 KiB | 204 B
--- 172.31.1.252 --- --- 172.31.1.252 ---
vip=172.31.1.1 holds_vip=no wan_disabled=yes wan_up=no ppp_up=no ppp_active=no may_dial=no lease_age=- dropin=yes role=backup vip=172.31.1.1 holds_vip=no wan_disabled=yes wan_up=no ppp_up=no ppp_active=no may_dial=no lease_age=- dropin=yes role=backup
Sep 05 18:05:53 apitest vrrp-wan[3005490]: MASTER: dialling pppoe0 Sep 05 23:07:43 apitest vrrp-wan[22667]: MASTER: dialling pppoe0
Sep 05 18:06:24 apitest vrrp-wan[3007095]: MASTER: dialling pppoe0 Sep 05 23:08:14 apitest vrrp-wan[24120]: MASTER: dialling pppoe0
Sep 05 18:08:15 apitest vrrp-wan[3010461]: not MASTER: hanging up pppoe0 -- Boot c5f23399239b468c8c8b752a4305c515 --
Sep 05 18:08:16 apitest vrrp-wan[3010622]: not MASTER but bond0.53 enabled -> releasing Sep 05 23:13:04 apitest vrrp-wan[6261]: MASTER: dialling pppoe0
Sep 05 18:08:40 apitest vrrp-wan[3012085]: bond0.53 disable commit took 24s Sep 05 23:13:04 apitest vrrp-wan[6413]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:11:42 apitest vrrp-wan[3016900]: MASTER: dialling pppoe0 Sep 05 23:13:08 apitest vrrp-wan[7122]: bond0.53 enable commit took 4s
Sep 05 18:11:42 apitest vrrp-wan[3017050]: MASTER with bond0.53 disabled -> enabling -- Boot 46727d256db344d6ad4b37c142272071 --
Sep 05 18:11:46 apitest vrrp-wan[3017685]: bond0.53 enable commit took 4s Sep 05 23:18:31 apitest vrrp-wan[6258]: MASTER: dialling pppoe0
Sep 05 23:18:31 apitest vrrp-wan[6411]: MASTER with bond0.53 disabled -> enabling
Sep 05 23:18:36 apitest vrrp-wan[7038]: bond0.53 enable commit took 5s
--- 172.31.1.253 --- --- 172.31.1.253 ---
vip=172.31.1.1 holds_vip=yes wan_disabled=no wan_up=yes ppp_up=yes ppp_active=yes may_dial=yes lease_age=10 dropin=yes role=master vip=172.31.1.1 holds_vip=yes wan_disabled=no wan_up=yes ppp_up=yes ppp_active=yes may_dial=yes lease_age=19 dropin=yes role=master
pppoe0 UNKNOWN 198.51.100.123 peer 198.51.100.1/32 pppoe0 UNKNOWN 198.51.100.131 peer 198.51.100.1/32
default nhid 93 dev pppoe0 proto static metric 20 default nhid 57 dev pppoe0 proto static metric 20
Sep 05 22:54:48 vyos vrrp-wan[193770]: MASTER: dialling pppoe0 Sep 05 23:10:44 vyos vrrp-wan[221212]: MASTER with bond0.53 disabled -> enabling
Sep 05 22:55:18 vyos vrrp-wan[194885]: MASTER: dialling pppoe0 Sep 05 23:10:48 vyos vrrp-wan[221995]: bond0.53 enable commit took 4s
Sep 05 22:55:49 vyos vrrp-wan[195925]: MASTER: dialling pppoe0 -- Boot 1f635fc6900c4661b3ac6d016d63d293 --
Sep 05 22:56:19 vyos vrrp-wan[196724]: DIAL FLAP: >=6 attempts in 600s -- holding off 900s Sep 05 23:16:10 vyos vrrp-wan[7037]: MASTER: dialling pppoe0
Sep 05 22:57:24 vyos vrrp-wan[199011]: MASTER with bond0.53 disabled -> enabling Sep 05 23:16:11 vyos vrrp-wan[7190]: MASTER with bond0.53 disabled -> enabling
Sep 05 22:57:28 vyos vrrp-wan[199711]: bond0.53 enable commit took 4s Sep 05 23:16:15 vyos vrrp-wan[7979]: bond0.53 enable commit took 4s
Sep 05 22:57:40 vyos vrrp-wan[199948]: GUARD: lease stale (81s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0 -- Boot c0e38585d7354ad6ab018800c7f3f6be --
Sep 05 23:02:41 vyos vrrp-wan[206596]: MASTER: dialling pppoe0 Sep 05 23:22:54 vyos vrrp-wan[5970]: MASTER: dialling pppoe0
Sep 05 23:22:54 vyos vrrp-wan[6126]: MASTER with bond0.53 disabled -> enabling
Sep 05 23:22:59 vyos vrrp-wan[6915]: bond0.53 enable commit took 5s