diff --git a/labsim/wan-failover-evidence/README.md b/labsim/wan-failover-evidence/README.md new file mode 100644 index 0000000..da6f20b --- /dev/null +++ b/labsim/wan-failover-evidence/README.md @@ -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 20–26s | +| `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. diff --git a/labsim/wan-failover-evidence/T0-baseline/state.txt b/labsim/wan-failover-evidence/T0-baseline/state.txt index 41b1b32..40ee123 100644 --- a/labsim/wan-failover-evidence/T0-baseline/state.txt +++ b/labsim/wan-failover-evidence/T0-baseline/state.txt @@ -1,27 +1,31 @@ -=== 2026-09-06T00:06:00+01:00 === +=== 2026-09-06T00:27:16+01:00 === --- AC sessions --- 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 --- 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 18:06:24 apitest vrrp-wan[3007095]: MASTER: dialling pppoe0 -Sep 05 18:08:15 apitest vrrp-wan[3010461]: not MASTER: hanging up pppoe0 -Sep 05 18:08:16 apitest vrrp-wan[3010622]: not MASTER but bond0.53 enabled -> releasing -Sep 05 18:08:40 apitest vrrp-wan[3012085]: bond0.53 disable commit took 24s -Sep 05 18:11:42 apitest vrrp-wan[3016900]: MASTER: dialling pppoe0 -Sep 05 18:11:42 apitest vrrp-wan[3017050]: MASTER with bond0.53 disabled -> enabling -Sep 05 18:11:46 apitest vrrp-wan[3017685]: bond0.53 enable commit took 4s +Sep 05 23:07:43 apitest vrrp-wan[22667]: MASTER: dialling pppoe0 +Sep 05 23:08:14 apitest vrrp-wan[24120]: MASTER: dialling pppoe0 +-- Boot c5f23399239b468c8c8b752a4305c515 -- +Sep 05 23:13:04 apitest vrrp-wan[6261]: MASTER: dialling pppoe0 +Sep 05 23:13:04 apitest vrrp-wan[6413]: MASTER with bond0.53 disabled -> enabling +Sep 05 23:13:08 apitest vrrp-wan[7122]: bond0.53 enable commit took 4s +-- Boot 46727d256db344d6ad4b37c142272071 -- +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 --- -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 -pppoe0 UNKNOWN 198.51.100.123 peer 198.51.100.1/32 -default nhid 93 dev pppoe0 proto static metric 20 -Sep 05 22:54:48 vyos vrrp-wan[193770]: MASTER: dialling pppoe0 -Sep 05 22:55:18 vyos vrrp-wan[194885]: MASTER: dialling pppoe0 -Sep 05 22:55:49 vyos vrrp-wan[195925]: MASTER: dialling pppoe0 -Sep 05 22:56:19 vyos vrrp-wan[196724]: DIAL FLAP: >=6 attempts in 600s -- holding off 900s -Sep 05 22:57:24 vyos vrrp-wan[199011]: MASTER with bond0.53 disabled -> enabling -Sep 05 22:57:28 vyos vrrp-wan[199711]: 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 -Sep 05 23:02:41 vyos vrrp-wan[206596]: MASTER: dialling pppoe0 +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.131 peer 198.51.100.1/32 +default nhid 57 dev pppoe0 proto static metric 20 +Sep 05 23:10:44 vyos vrrp-wan[221212]: MASTER with bond0.53 disabled -> enabling +Sep 05 23:10:48 vyos vrrp-wan[221995]: bond0.53 enable commit took 4s +-- Boot 1f635fc6900c4661b3ac6d016d63d293 -- +Sep 05 23:16:10 vyos vrrp-wan[7037]: MASTER: dialling pppoe0 +Sep 05 23:16:11 vyos vrrp-wan[7190]: MASTER with bond0.53 disabled -> enabling +Sep 05 23:16:15 vyos vrrp-wan[7979]: bond0.53 enable commit took 4s +-- Boot c0e38585d7354ad6ab018800c7f3f6be -- +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