michal/lab
1
0
Fork 0
Code Issues Pull Requests 3 Actions Packages Projects Releases Wiki Activity

PPPOE-HA: record the two failure modes found by running the thing
Some checks failed
CI/CD / lint (push) Failing after 8s
Details
CI/CD / test (push) Failing after 8s
Details
CI/CD / typecheck (push) Failing after 25s
Details
CI/CD / build (push) Has been skipped
Details
CI/CD / publish-rpm (push) Has been skipped
Details
CI/CD / publish-deb (push) Has been skipped
Details

Browse Source 
Both were invisible to inspection and only appeared under the hard matrix:
the flap damper tearing down an established session via the lease it stopped
renewing, and a missing peers file being completely silent. The second has a
production edge worth spelling out -- an unsaved commit reverts on reboot and
takes pppoe0 with it, leaving a standby that can never take over while
looking perfectly healthy.
This commit is contained in:
Michal
2026-09-06 00:11:32 +01:00
parent b659e0d47e
commit 4d47b609a2
9 changed files with 192 additions and 124 deletions
Download Patch File Download Diff File Expand all files Collapse all files

5
labsim/labsim-pppoe-ha-test.sh
View File

@@ -106,7 +106,10 @@ preflight() {
fail "$h has no /etc/ppp/peers/pppoe0 -- it cannot dial; re-commit the pppoe subtree"
rc=1
fi
if ! r "$h" 'show configuration commands' 2>/dev/null | grep -q 'interfaces pppoe pppoe0 source-interface'; then
# The op-mode WRAPPER, not a bare `show`: over non-interactive ssh the
# bare form is not on PATH, so this silently matched nothing and failed
# both routers that were in fact configured correctly.
if ! r "$h" '/opt/vyatta/bin/vyatta-op-cmd-wrapper show configuration commands' 2>/dev/null | grep -q 'interfaces pppoe pppoe0 source-interface'; then
fail "$h has no pppoe0 in config (unsaved commit lost on reboot?)"
rc=1
fi

40
labsim/wan-failover-evidence/T0-baseline/state.txt
View File

@@ -1,27 +1,27 @@
=== 2026-09-05T19:07:59+01:00 ===
=== 2026-09-06T00:06:00+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.117 | | | 52:54:00:e5:95:a2 | | active | 00:01:31 | 1.0 KiB | 792 B
ppp0 | simdsl | 198.51.100.123 | | | 52:54:00:4e:0b:56 | | active | 00:03:19 | 438 B | 204 B
--- 172.31.1.252 ---
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=0 dropin=yes role=master
pppoe0 UNKNOWN 198.51.100.117 peer 198.51.100.1/32
default via 203.0.113.1 dev bond0.53 proto failover metric 1
Sep 05 18:01:26 apitest vrrp-wan[2994197]: not MASTER but bond0.53 enabled -> releasing
Sep 05 18:01:30 apitest vrrp-wan[2995085]: bond0.53 disable commit took 4s
Sep 05 18:03:25 apitest vrrp-wan[3000708]: MASTER: dialling pppoe0
Sep 05 18:03:25 apitest vrrp-wan[3000872]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:03:29 apitest vrrp-wan[3001568]: bond0.53 enable commit took 4s
Sep 05 18:05:43 apitest vrrp-wan[3005097]: GUARD: lease stale (204s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
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
--- 172.31.1.253 ---
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 17:57:52 vyos vrrp-wan[2797572]: not MASTER but bond0.53 enabled -> releasing
Sep 05 17:58:16 vyos vrrp-wan[2798935]: bond0.53 disable commit took 24s
Sep 05 18:01:03 vyos vrrp-wan[2802338]: MASTER: dialling pppoe0
Sep 05 18:01:03 vyos vrrp-wan[2802489]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:01:07 vyos vrrp-wan[2803365]: bond0.53 enable commit took 4s
Sep 05 18:03:02 vyos vrrp-wan[2808661]: not MASTER: hanging up pppoe0
Sep 05 18:03:02 vyos vrrp-wan[2808822]: not MASTER but bond0.53 enabled -> releasing
Sep 05 18:03:26 vyos vrrp-wan[2810178]: bond0.53 disable commit took 24s
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

43
labsim/wan-failover-evidence/T11-no-peers-file/state.txt
View File

@@ -1,25 +1,26 @@
=== 2026-09-05T19:10:28+01:00 ===
=== 2026-09-06T00:08:14+01:00 ===
--- AC sessions ---
ifname | username | ip | ip6 | ip6-dp | calling-sid | rate-limit | state | uptime | rx-bytes | tx-bytes
--------+----------+----+-----+--------+-------------+------------+-------+--------+----------+----------
--------+----------+----+-----+--------+-------------------+------------+-------+----------+----------+----------
| | | | | 52:54:00:e5:95:a2 | | start | 00:00:00 | 0 B | 0 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:03:25 apitest vrrp-wan[3000872]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:03:29 apitest vrrp-wan[3001568]: bond0.53 enable commit took 4s
Sep 05 18:05:43 apitest vrrp-wan[3005097]: GUARD: lease stale (204s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
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
vip=172.31.1.1 holds_vip=yes wan_disabled=no wan_up=no ppp_up=no ppp_active=yes may_dial=yes lease_age=1 dropin=yes role=master
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
-- Boot 7cb878bdb4c74380ae7869ffd0dad9eb --
Sep 05 23:06:18 apitest vrrp-wan[18533]: MASTER: dialling pppoe0
Sep 05 23:06:18 apitest vrrp-wan[18704]: MASTER with bond0.53 disabled -> enabling
Sep 05 23:06:22 apitest vrrp-wan[19398]: bond0.53 enable commit took 4s
Sep 05 23:07:35 apitest vrrp-wan[22111]: GUARD: lease stale (206s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
Sep 05 23:07:43 apitest vrrp-wan[22667]: MASTER: dialling pppoe0
Sep 05 23:08:14 apitest vrrp-wan[24120]: MASTER: dialling pppoe0
--- 172.31.1.253 ---
vip=172.31.1.1 holds_vip=yes wan_disabled=no wan_up=yes ppp_up=no ppp_active=yes may_dial=yes lease_age=0 dropin=yes role=master
default via 203.0.113.1 dev bond0.53 proto failover metric 1
Sep 05 18:03:02 vyos vrrp-wan[2808822]: not MASTER but bond0.53 enabled -> releasing
Sep 05 18:03:26 vyos vrrp-wan[2810178]: bond0.53 disable commit took 24s
Sep 05 18:07:53 vyos vrrp-wan[2815869]: MASTER: dialling pppoe0
Sep 05 18:07:53 vyos vrrp-wan[2816022]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:07:57 vyos vrrp-wan[2816731]: bond0.53 enable commit took 4s
Sep 05 18:09:10 vyos vrrp-wan[2819736]: GUARD: lease stale (204s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
Sep 05 18:09:34 vyos vrrp-wan[2820820]: MASTER: dialling pppoe0
Sep 05 18:10:04 vyos vrrp-wan[2821942]: MASTER: dialling pppoe0
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 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
Sep 05 23:06:17 vyos vrrp-wan[213698]: not MASTER: hanging up pppoe0
Sep 05 23:06:18 vyos vrrp-wan[213859]: not MASTER but bond0.53 enabled -> releasing
Sep 05 23:06:23 vyos vrrp-wan[214503]: bond0.53 disable commit took 5s

28
labsim/wan-failover-evidence/T12-holdoff-keeps-session/state.txt Normal file
View File

@@ -0,0 +1,28 @@
=== 2026-09-06T00:10:11+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.126 | | | 52:54:00:e5:95:a2 | | active | 00:01:57 | 514 B | 204 B
--- 172.31.1.252 ---
vip=172.31.1.1 holds_vip=yes wan_disabled=no wan_up=no ppp_up=yes ppp_active=yes may_dial=yes lease_age=23 dropin=yes role=master
pppoe0 UNKNOWN 198.51.100.126 peer 198.51.100.1/32
default nhid 78 dev pppoe0 proto static metric 20
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
-- Boot 7cb878bdb4c74380ae7869ffd0dad9eb --
Sep 05 23:06:18 apitest vrrp-wan[18533]: MASTER: dialling pppoe0
Sep 05 23:06:18 apitest vrrp-wan[18704]: MASTER with bond0.53 disabled -> enabling
Sep 05 23:06:22 apitest vrrp-wan[19398]: bond0.53 enable commit took 4s
Sep 05 23:07:35 apitest vrrp-wan[22111]: GUARD: lease stale (206s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
Sep 05 23:07:43 apitest vrrp-wan[22667]: MASTER: dialling pppoe0
Sep 05 23:08:14 apitest vrrp-wan[24120]: MASTER: dialling pppoe0
--- 172.31.1.253 ---
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 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
Sep 05 23:06:17 vyos vrrp-wan[213698]: not MASTER: hanging up pppoe0
Sep 05 23:06:18 vyos vrrp-wan[213859]: not MASTER but bond0.53 enabled -> releasing
Sep 05 23:06:23 vyos vrrp-wan[214503]: bond0.53 disable commit took 5s

42
labsim/wan-failover-evidence/T3-clean-failover/state.txt
View File

@@ -1,28 +1,28 @@
=== 2026-09-05T19:08:34+01:00 ===
=== 2026-09-06T00:06:31+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.118 | | | 52:54:00:4e:0b:56 | | active | 00:00:15 | 590 B | 280 B
ppp0 | simdsl | 198.51.100.124 | | | 52:54:00:e5:95:a2 | | active | 00:00:13 | 514 B | 204 B
--- 172.31.1.252 ---
vip=172.31.1.1 holds_vip=no wan_disabled=no wan_up=yes ppp_up=no ppp_active=no may_dial=no lease_age=- dropin=yes role=backup
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=3 dropin=yes role=master
pppoe0 UNKNOWN 198.51.100.124 peer 198.51.100.1/32
default via 203.0.113.1 dev bond0.53 proto failover metric 1
Sep 05 18:03:25 apitest vrrp-wan[3000708]: MASTER: dialling pppoe0
Sep 05 18:03:25 apitest vrrp-wan[3000872]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:03:29 apitest vrrp-wan[3001568]: bond0.53 enable commit took 4s
Sep 05 18:05:43 apitest vrrp-wan[3005097]: GUARD: lease stale (204s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
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
-- Boot 7cb878bdb4c74380ae7869ffd0dad9eb --
Sep 05 23:06:18 apitest vrrp-wan[18533]: MASTER: dialling pppoe0
Sep 05 23:06:18 apitest vrrp-wan[18704]: MASTER with bond0.53 disabled -> enabling
Sep 05 23:06:22 apitest vrrp-wan[19398]: bond0.53 enable commit took 4s
--- 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=13 dropin=yes role=master
pppoe0 UNKNOWN 198.51.100.118 peer 198.51.100.1/32
default via 203.0.113.1 dev bond0.53 proto failover metric 1
Sep 05 18:01:03 vyos vrrp-wan[2802489]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:01:07 vyos vrrp-wan[2803365]: bond0.53 enable commit took 4s
Sep 05 18:03:02 vyos vrrp-wan[2808661]: not MASTER: hanging up pppoe0
Sep 05 18:03:02 vyos vrrp-wan[2808822]: not MASTER but bond0.53 enabled -> releasing
Sep 05 18:03:26 vyos vrrp-wan[2810178]: bond0.53 disable commit took 24s
Sep 05 18:07:53 vyos vrrp-wan[2815869]: MASTER: dialling pppoe0
Sep 05 18:07:53 vyos vrrp-wan[2816022]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:07:57 vyos vrrp-wan[2816731]: bond0.53 enable commit took 4s
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 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
Sep 05 23:06:17 vyos vrrp-wan[213698]: not MASTER: hanging up pppoe0
Sep 05 23:06:18 vyos vrrp-wan[213859]: not MASTER but bond0.53 enabled -> releasing
Sep 05 23:06:23 vyos vrrp-wan[214503]: bond0.53 disable commit took 5s

35
labsim/wan-failover-evidence/T4-hard-failover-replace/state.txt
View File

@@ -1,17 +1,18 @@
=== hard failover, session-control=replace, 2026-09-05T19:20:56+01:00 ===
master labsim-vyos2 (172.31.1.253) destroyed with virsh destroy -- no PADT sent.
-- survivor took over and dialled --
172.31.1.252 holds_vip=yes wan_up=yes ppp_up=yes ppp_active=yes may_dial=yes role=master
-- AC: exactly one session throughout, from the survivor's MAC --
ppp0 simdsl 198.51.100.121 calling-sid 52:54:00:e5:95:a2 active 00:07:01
-- returning router did NOT dial on boot (the gate) --
ConditionResult=no ActiveState=inactive NRestarts=0 pppoe0 absent may_dial=no
AC session count after its return: 1
-- caveat --
A VM restart recreates its taps, leaving the OVS bond holding stale members
(lacp dead, VLAN 1 unreachable). Re-bonded via ovs_bond_router; the harness
now does this automatically after virsh start.
=== 2026-09-06T00:11:13+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.127 | | | 52:54:00:4e:0b:56 | | active | 00:00:30 | 514 B | 204 B
--- 172.31.1.252 ---
--- 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.127 peer 198.51.100.1/32
default nhid 110 dev pppoe0 proto static metric 20
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
Sep 05 23:06:17 vyos vrrp-wan[213698]: not MASTER: hanging up pppoe0
Sep 05 23:06:18 vyos vrrp-wan[213859]: not MASTER but bond0.53 enabled -> releasing
Sep 05 23:06:23 vyos vrrp-wan[214503]: bond0.53 disable commit took 5s
Sep 05 23:10:43 vyos vrrp-wan[221064]: MASTER: dialling pppoe0
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

41
labsim/wan-failover-evidence/T5-tengig-down/state.txt
View File

@@ -1,27 +1,28 @@
=== 2026-09-05T19:09:05+01:00 ===
=== 2026-09-06T00:07:02+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.118 | | | 52:54:00:4e:0b:56 | | active | 00:00:46 | 758 B | 448 B
ppp0 | simdsl | 198.51.100.124 | | | 52:54:00:e5:95:a2 | | active | 00:00:44 | 682 B | 372 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:03:25 apitest vrrp-wan[3000872]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:03:29 apitest vrrp-wan[3001568]: bond0.53 enable commit took 4s
Sep 05 18:05:43 apitest vrrp-wan[3005097]: GUARD: lease stale (204s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
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
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=3 dropin=yes role=master
pppoe0 UNKNOWN 198.51.100.124 peer 198.51.100.1/32
default nhid 67 dev pppoe0 proto static metric 20
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
-- Boot 7cb878bdb4c74380ae7869ffd0dad9eb --
Sep 05 23:06:18 apitest vrrp-wan[18533]: MASTER: dialling pppoe0
Sep 05 23:06:18 apitest vrrp-wan[18704]: MASTER with bond0.53 disabled -> enabling
Sep 05 23:06:22 apitest vrrp-wan[19398]: bond0.53 enable commit took 4s
--- 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.118 peer 198.51.100.1/32
default nhid 483 dev pppoe0 proto static metric 20
Sep 05 18:01:03 vyos vrrp-wan[2802489]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:01:07 vyos vrrp-wan[2803365]: bond0.53 enable commit took 4s
Sep 05 18:03:02 vyos vrrp-wan[2808661]: not MASTER: hanging up pppoe0
Sep 05 18:03:02 vyos vrrp-wan[2808822]: not MASTER but bond0.53 enabled -> releasing
Sep 05 18:03:26 vyos vrrp-wan[2810178]: bond0.53 disable commit took 24s
Sep 05 18:07:53 vyos vrrp-wan[2815869]: MASTER: dialling pppoe0
Sep 05 18:07:53 vyos vrrp-wan[2816022]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:07:57 vyos vrrp-wan[2816731]: bond0.53 enable commit took 4s
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 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
Sep 05 23:06:17 vyos vrrp-wan[213698]: not MASTER: hanging up pppoe0
Sep 05 23:06:18 vyos vrrp-wan[213859]: not MASTER but bond0.53 enabled -> releasing
Sep 05 23:06:23 vyos vrrp-wan[214503]: bond0.53 disable commit took 5s

43
labsim/wan-failover-evidence/T8-lease-expiry/state.txt
View File

@@ -1,25 +1,26 @@
=== 2026-09-05T19:09:47+01:00 ===
=== 2026-09-06T00:07:44+01:00 ===
--- AC sessions ---
ifname | username | ip | ip6 | ip6-dp | calling-sid | rate-limit | state | uptime | rx-bytes | tx-bytes
--------+----------+----+-----+--------+-------------+------------+-------+--------+----------+----------
--------+----------+----+-----+--------+-------------------+------------+-------+----------+----------+----------
| | | | | 52:54:00:e5:95:a2 | | start | 00:00:00 | 0 B | 0 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:03:25 apitest vrrp-wan[3000872]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:03:29 apitest vrrp-wan[3001568]: bond0.53 enable commit took 4s
Sep 05 18:05:43 apitest vrrp-wan[3005097]: GUARD: lease stale (204s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
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
vip=172.31.1.1 holds_vip=yes wan_disabled=no wan_up=no ppp_up=no ppp_active=yes may_dial=yes lease_age=2 dropin=yes role=master
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
-- Boot 7cb878bdb4c74380ae7869ffd0dad9eb --
Sep 05 23:06:18 apitest vrrp-wan[18533]: MASTER: dialling pppoe0
Sep 05 23:06:18 apitest vrrp-wan[18704]: MASTER with bond0.53 disabled -> enabling
Sep 05 23:06:22 apitest vrrp-wan[19398]: bond0.53 enable commit took 4s
Sep 05 23:07:35 apitest vrrp-wan[22111]: GUARD: lease stale (206s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
Sep 05 23:07:43 apitest vrrp-wan[22667]: MASTER: dialling pppoe0
--- 172.31.1.253 ---
vip=172.31.1.1 holds_vip=yes wan_disabled=no wan_up=yes ppp_up=no ppp_active=no may_dial=no lease_age=- dropin=yes role=master
default via 203.0.113.1 dev bond0.53 proto failover metric 1
Sep 05 18:01:07 vyos vrrp-wan[2803365]: bond0.53 enable commit took 4s
Sep 05 18:03:02 vyos vrrp-wan[2808661]: not MASTER: hanging up pppoe0
Sep 05 18:03:02 vyos vrrp-wan[2808822]: not MASTER but bond0.53 enabled -> releasing
Sep 05 18:03:26 vyos vrrp-wan[2810178]: bond0.53 disable commit took 24s
Sep 05 18:07:53 vyos vrrp-wan[2815869]: MASTER: dialling pppoe0
Sep 05 18:07:53 vyos vrrp-wan[2816022]: MASTER with bond0.53 disabled -> enabling
Sep 05 18:07:57 vyos vrrp-wan[2816731]: bond0.53 enable commit took 4s
Sep 05 18:09:10 vyos vrrp-wan[2819736]: GUARD: lease stale (204s > 75s; is vrrp-wan-reconcile.timer running?) -- hanging up pppoe0
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 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
Sep 05 23:06:17 vyos vrrp-wan[213698]: not MASTER: hanging up pppoe0
Sep 05 23:06:18 vyos vrrp-wan[213859]: not MASTER but bond0.53 enabled -> releasing
Sep 05 23:06:23 vyos vrrp-wan[214503]: bond0.53 disable commit took 5s

35
migration/PPPOE-HA.md
View File

@@ -62,12 +62,45 @@ either "I do not hold the VIP" or "the lease is stale".
| | |
|---|---|
| Clean failover (`force-fault`) | `pppoe0` moves in **26s**, reproducible |
| Clean failover (`force-fault`) | `pppoe0` moves in **20-26s**, reproducible |
| 10 gig down → PPPoE | route falls to `pppoe0`; LAN back online in **5s** |
| Stale lease | guard hangs up within ~5s |
| Missing peers file | `NRestarts=0` — no loop |
| Flap holdoff vs live session | session survives a forged 900s holdoff |
| Invariant | AC never showed two `simdsl` sessions |
## Two failure modes found by running it, not by reading it
**The flap damper tore down a healthy WAN.** `ppp_dial()` checked the hold-off
and returned *before* renewing `may-dial`. That file is a lease the guard
expires after `LEASE_TTL`, 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. An active session now renews the lease and returns before
every other check; everything below only decides whether to start a **new**
session. T12 is the regression test.
**A missing peers file is silent.** `/etc/ppp/peers/pppoe0` is both pppd's
options file and the gate's second condition, and it is only written by a commit
that touches the pppoe subtree. Without it systemd logs
`skipped because of an unmet condition check` exactly once and then nothing —
a router that cannot dial at all looks identical to a healthy backup.
`ppp_dial()` now says so on every tick, and distinguishes the two causes:
configured-but-not-rendered (re-commit the subtree) versus no `pppoe0` in the
config at all.
The second cause is the one to watch in production: **a commit that was never
`save`d reverts on reboot and takes `pppoe0` with it.** That is exactly how the
sim secondary lost its WAN and spent hours looking like an ISP problem. After
any hand commit to the pppoe subtree, `save` — or the next reboot produces a
standby that can never take over.
## Deploying (not yet done)
1. `sudo /config/vyos-known-good save` on both.