PPPoE WAN does not restart correctly after reconfiguring interfaces.
-
No VIPs, same problem.
Nov 12 08:56:45 ppp 15723 process 15723 terminated Nov 12 08:56:45 ppp 15723 [wan_link0] Link: Shutdown Nov 12 08:56:45 ppp 15723 [wan] Bundle: Shutdown Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: state change Closed --> Initial Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: Down event Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: Close event Nov 12 08:56:43 ppp 15723 [wan_link0] Link: giving up after 0 reconnection attempts Nov 12 08:56:43 ppp 15723 [wan_link0] Link: DOWN event Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: LayerFinish Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: state change Closing --> Closed Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: rec'd Terminate Ack #3 (Closing) Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: LayerDown Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: SendTerminateReq #3 Nov 12 08:56:43 ppp 15723 [wan] IPV6CP: state change Closed --> Initial Nov 12 08:56:43 ppp 15723 [wan] IPV6CP: Down event Nov 12 08:56:43 ppp 15723 [wan] IPCP: state change Closed --> Initial Nov 12 08:56:43 ppp 15723 [wan] IPCP: Down event Nov 12 08:56:43 ppp 15723 [wan] IPV6CP: Close event Nov 12 08:56:43 ppp 15723 [wan] IPCP: Close event Nov 12 08:56:43 ppp 15723 [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Nov 12 08:56:43 ppp 15723 [wan_link0] Link: Leave bundle "wan" Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: state change Opened --> Closing Nov 12 08:56:43 ppp 15723 [wan_link0] LCP: Close event Nov 12 08:56:43 ppp 15723 [wan_link0] Link: CLOSE event Nov 12 08:56:43 ppp 15723 [wan] IPCP: rec'd Terminate Ack #5 (Closed) Nov 12 08:56:43 ppp 15723 [wan] IPV6CP: rec'd Terminate Ack #4 (Closed) Nov 12 08:56:43 ppp 15723 [wan] Bundle: closing link "wan_link0"... Nov 12 08:56:43 ppp 15723 [wan] Bundle: No NCPs left. Closing links... Nov 12 08:56:43 ppp 15723 [wan] IPV6CP: LayerFinish Nov 12 08:56:43 ppp 15723 [wan] IPV6CP: state change Closing --> Closed Nov 12 08:56:43 ppp 15723 [wan] IPV6CP: rec'd Terminate Ack #3 (Closing) Nov 12 08:56:43 ppp 15723 [wan] IPCP: LayerFinish Nov 12 08:56:43 ppp 15723 [wan] IPCP: state change Closing --> Closed Nov 12 08:56:43 ppp 15723 [wan] IPCP: rec'd Terminate Ack #4 (Closing) Nov 12 08:56:43 ppp 15723 [wan] IPCP: SendTerminateReq #5 Nov 12 08:56:43 ppp 15723 [wan] IPV6CP: SendTerminateReq #4 Nov 12 08:56:43 ppp 15723 [wan] IFACE: Set description "WAN" Nov 12 08:56:43 ppp 15723 [wan] IFACE: Rename interface pppoe0 to pppoe0 Nov 12 08:56:43 ppp 15723 [wan] IFACE: Down event Nov 12 08:56:40 ppp 15723 [wan] IPV6CP: LayerDown Nov 12 08:56:40 ppp 15723 [wan] IPV6CP: SendTerminateReq #3 Nov 12 08:56:40 ppp 15723 [wan] IPV6CP: state change Opened --> Closing Nov 12 08:56:40 ppp 15723 [wan] IPV6CP: Close event Nov 12 08:56:40 ppp 15723 [wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address Nov 12 08:55:47 ppp 6735 can't lock /var/run/pppoe_wan.pid after 30 attempts Nov 12 08:55:46 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:45 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:44 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:43 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:42 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:41 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:40 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:39 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:38 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:37 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:36 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:35 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:34 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:33 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:32 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:31 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:30 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:29 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:28 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:27 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:26 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:25 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:24 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:23 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:22 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:21 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:20 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:19 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:18 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:17 ppp 6735 waiting for process 15723 to die... Nov 12 08:55:17 ppp 6735 process 6735 started, version 5.9 Nov 12 08:55:17 ppp 15723 [wan] IPCP: LayerDown Nov 12 08:55:17 ppp 15723 [wan] IPCP: SendTerminateReq #4 Nov 12 08:55:17 ppp 15723 [wan] IPCP: state change Opened --> Closing Nov 12 08:55:17 ppp 15723 [wan] IPCP: Close event Nov 12 08:55:17 ppp 15723 [wan] IFACE: Close event Nov 12 08:55:17 ppp 15723 caught fatal signal TERM Nov 12 08:55:17 ppp 6735 Multi-link PPP daemon for FreeBSDSystem log also contains:
Nov 12 08:56:58 php-fpm 29419 /rc.filter_configure_sync: GW States: Gateway is down but its IP address cannot be located. Skipping state kill.: WAN_PPPOESo no, it is not related to VIPs
-
Hmm, interesting. It's still two competing mpd processes though, each one starts a new process when it dies even though another one is already running.
-
@stephenw10
Yep…
ps aux | grep mpd5
right arter /usr/local/sbin/pfSctl -c 'interface reload wan'
shows two mpd5 with same command line used, not sure what was caused that. Will triple check if I have some forgotten scripts somewhere
-
It's probably the same race condition caused by VIPs on PPPoE. Not sure what would trigger it in your case though.
-
@stephenw10
Can PPPoE itself be comparable to a VIP - it is a tunnel within a real interface IP?
️ -
@stephenw10
Any thoughts how to debug this? -
@RobbieTT said in PPPoE WAN does not restart correctly after reconfiguring interfaces.:
@stephenw10
Can PPPoE itself be comparable to a VIP - it is a tunnel within a real interface IP?Yes interesting question. Certainly there are plenty of people doing that. If you get a 'business' connection with a /29 from BT for example that is how you might use them.
But is that valid on a point to point connection? It seems like a regression but possibly it worked previously just by luck. -
Continuing the thinking, do all the different IPv6 addresses we create on an interface count as VIPs?
️ -
No, not in the same way that's triggering that flapping. I've never seen the competing mpd instances here for example.
-
@stephenw10
Well, can’t the mpd itself be the cause? It starts with the -k key, but for some reason it cannot access the PID file of the previously started process. I looked at your competitors project, it seems like they have a similar problem and Franco suggested that it’s the MPD itself, their patch calls a external non mpd function that kills the process by the PID, this is, of course, if I understood everything correctly. -
It's certainly possible. It feels more like a regression in the boot code though. Or at least a change there. It didn't used to do this in earlier versions and mpd really hasn't changed much. Though it was never that great!
-
I have two WAN interfaces, and both are configured for DHCP6 (next to PPPoE for IPv4 on one of them, and DHCP on the other). In that case an automatic periodic reset configured for PPPoE or manually issuing
/usr/local/sbin/pfSctl -c 'interface reload wan'will break PPPoE, and a second mpd is active for about 30 seconds before it vanishes.
However, as soon as I disable DHCP6 on either of them, issuing the command will not break PPPoE, and a second mpd is active for only about 5 seconds before it vanishes.
Note that this happens even if one of the WAN interfaces actually has no communication because I interrupted the link one hop behind the router. So the bug seems to be related to multiple IPv6 configurations (and not primarily to multiple PPPoE or DHCP communications)?Is there a bug associated to this issue?
-
Hmm, do those IPv6 link both work initially? There have been problems with dual PPPoE link carrying IPv6 in the past: https://redmine.pfsense.org/issues/13939
There is only a problem when it resets?
-
@stephenw10 said in PPPoE WAN does not restart correctly after reconfiguring interfaces.:
Hmm, do those IPv6 link both work initially? There have been problems with dual PPPoE link carrying IPv6 in the past: https://redmine.pfsense.org/issues/13939
That is not the issue here. My configuration is
- WAN1: PPPoE and DHCP6
- WAN2: DHCP and DHCP6
When I remove one of the DHCP6 configurations and reload, the PPPoE on WAN1 immediately activates. If I keep both and reload, even after hours PPPoE on WAN1 remains dead.
-
Ah I see. Does restarting the DHCP WAN also trigger it?
-
I do not know the syntax to send a reload command just for interface WAN2.
/usr/local/sbin/pfSctl -c 'interface reload wan2'does not work.
Using the GUI though, when I enable interface WAN2 with a DHCP6 configuration where it didn't have one before, that does not kill PPPoE on interface WAN1. But I am not sure whether that is equivalent to an 'interface reload' command.
-
You'd have to use the internal interface name there so possibly:
/usr/local/sbin/pfSctl -c 'interface reload opt1'Check the config or console menu to see those like:
WAN (wan) -> ix3 -> v4/DHCP4: 172.21.16.23/24 LAN (lan) -> igc0 -> v4: 192.168.23.1/24 WAN2 (opt1) -> ix2 -> WAN3 (opt2) -> ix0 -> WAN4 (opt3) -> ix1 -> LAN2 (opt4) -> igc1 -> -
It is indeed opt1. And no, issuing
/usr/local/sbin/pfSctl -c 'interface reload opt1'does not break PPPoE on interface WAN1. Only
/usr/local/sbin/pfSctl -c 'interface reload wan'does.
-
We're probably going to need to see some logs.
How do you have the periodic reset configured?
-
It is configured as "Custom" periodic reset within the PPPoE configuration of interface WAN1.
