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
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.
-
OK, that should work.
If the second WAN is disabled does the dhcpv6 on WAN reconnect correctly?
-
Yes, both PPPoE (IPv4) and DHCP6 connect correctly.
-
Ok I thing we're going to need to see some logs of the reconnection to see what's happening there.
-
Here's the PPP log when it failed.
PPPoE failing.txt -
That reads like there was other stuff happening before that log except starts?
When was the reset?
What does the system log show over that period?
-
The reset is at 5:55. Here is the system log starting at 4:00:
log.txt -
Hmm, so it appears that something prevents the old mpd process closing for an excessively long time!
It doesn't actually close out until here:
Apr 17 05:57:30 gate1 check_reload_status[457]: updating dyndns opt8 Apr 17 05:57:30 gate1 check_reload_status[457]: Rewriting resolv.conf Apr 17 05:57:30 gate1 ppp[47767]: [wan] IFACE: Down event
By which time the new mpd5 has given up.
Unclear why that would delay it. Or why a second dhcpv6 instance would make any difference.
With the other WAN disabled for v6 does the mpd process finish without that min wait?
-
hi
, the main problem I see is that when a new mpd process is started, the previously started processes are checked (whether the file /var/run/pppoe_wan.pid exists) if the file exists, a command is sent to terminate the process.Apr 17 05:55:01 gate1 ppp[90881]: process 90881 started, version 5.9
Apr 17 05:55:01 gate1 ppp[90881]: waiting for process 47767 to die...Then, within 30 seconds (30 attempts), the closing of the previous mpd process is checked again. If this does not happen, then the program terminates (your case)
Apr 17 05:55:31 gate1 ppp[90881]: waiting for process 47767 to die...
Apr 17 05:55:32 gate1 ppp[90881]: can't lock /var/run/pppoe_wan.pid after 30 attempts. In your case, the previous process, for some unknown reason, was completed not within 30 seconds, but after 2 minutes and 30 seconds .
Apr 17 05:57:32 gate1 ppp[47767]: process 47767 terminated
-
BTW on the latest 24.03 RC builds I can't replicate this by issuing /usr/local/sbin/pfSctl -c 'interface reload wan' as before.
EDIT:
Got something, after switching to secondary firewall
2024-04-20 13:19:36.596539+03:00 ppp 98029 process 98029 terminated 2024-04-20 13:19:36.595640+03:00 ppp 98029 [wan_link0] Link: Shutdown 2024-04-20 13:19:36.498909+03:00 ppp 98029 [wan] Bundle: Shutdown 2024-04-20 13:19:35.807384+03:00 ppp 92838 waiting for process 98029 to die... 2024-04-20 13:19:34.804613+03:00 ppp 92838 waiting for process 98029 to die... 2024-04-20 13:19:34.496426+03:00 ppp 98029 [wan_link0] LCP: state change Closed --> Initial 2024-04-20 13:19:34.496379+03:00 ppp 98029 [wan_link0] LCP: Down event 2024-04-20 13:19:34.496330+03:00 ppp 98029 [wan_link0] LCP: Close event 2024-04-20 13:19:34.496281+03:00 ppp 98029 [wan_link0] Link: giving up after 0 reconnection attempts 2024-04-20 13:19:34.496227+03:00 ppp 98029 [wan_link0] Link: DOWN event 2024-04-20 13:19:34.495982+03:00 ppp 98029 [wan_link0] LCP: LayerFinish 2024-04-20 13:19:34.495923+03:00 ppp 98029 [wan_link0] LCP: state change Closing --> Closed 2024-04-20 13:19:34.495866+03:00 ppp 98029 [wan_link0] LCP: rec'd Terminate Ack #3 (Closing) 2024-04-20 13:19:34.495045+03:00 ppp 98029 [wan_link0] LCP: LayerDown 2024-04-20 13:19:34.494921+03:00 ppp 98029 [wan_link0] LCP: SendTerminateReq #3 2024-04-20 13:19:34.494857+03:00 ppp 98029 [wan] IPCP: state change Closed --> Initial 2024-04-20 13:19:34.494806+03:00 ppp 98029 [wan] IPCP: Down event 2024-04-20 13:19:34.494749+03:00 ppp 98029 [wan] IPCP: Close event 2024-04-20 13:19:34.494668+03:00 ppp 98029 [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps 2024-04-20 13:19:34.494075+03:00 ppp 98029 [wan_link0] Link: Leave bundle "wan" 2024-04-20 13:19:34.494024+03:00 ppp 98029 [wan_link0] LCP: state change Opened --> Closing 2024-04-20 13:19:34.493975+03:00 ppp 98029 [wan_link0] LCP: Close event 2024-04-20 13:19:34.493916+03:00 ppp 98029 [wan_link0] Link: CLOSE event 2024-04-20 13:19:34.493714+03:00 ppp 98029 [wan] IPCP: rec'd Terminate Ack #5 (Closed) 2024-04-20 13:19:34.493498+03:00 ppp 98029 [wan] Bundle: closing link "wan_link0"... 2024-04-20 13:19:34.493448+03:00 ppp 98029 [wan] Bundle: No NCPs left. Closing links... 2024-04-20 13:19:34.493399+03:00 ppp 98029 [wan] IPCP: LayerFinish 2024-04-20 13:19:34.493340+03:00 ppp 98029 [wan] IPCP: state change Closing --> Closed 2024-04-20 13:19:34.493281+03:00 ppp 98029 [wan] IPCP: rec'd Terminate Ack #4 (Closing) 2024-04-20 13:19:34.492968+03:00 ppp 98029 [wan] IPCP: SendTerminateReq #5 2024-04-20 13:19:34.492804+03:00 ppp 98029 [wan] IFACE: Set description "WAN" 2024-04-20 13:19:34.492667+03:00 ppp 98029 [wan] IFACE: Rename interface pppoe0 to pppoe0 2024-04-20 13:19:34.492452+03:00 ppp 98029 [wan] IFACE: Down event 2024-04-20 13:19:34.492224+03:00 ppp 98029 [wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address 2024-04-20 13:19:33.789243+03:00 ppp 92838 waiting for process 98029 to die... 2024-04-20 13:19:32.747960+03:00 ppp 92838 waiting for process 98029 to die... 2024-04-20 13:19:31.746052+03:00 ppp 92838 waiting for process 98029 to die... 2024-04-20 13:19:30.744279+03:00 ppp 92838 waiting for process 98029 to die... 2024-04-20 13:19:29.742824+03:00 ppp 92838 waiting for process 98029 to die... 2024-04-20 13:19:29.740665+03:00 ppp 92838 process 92838 started, version 5.9 2024-04-20 13:19:29.742544+03:00 ppp 98029 [wan] IPCP: LayerDown 2024-04-20 13:19:29.742278+03:00 ppp 98029 [wan] IPCP: SendTerminateReq #4 2024-04-20 13:19:29.742176+03:00 ppp 98029 [wan] IPCP: state change Opened --> Closing 2024-04-20 13:19:29.742077+03:00 ppp 98029 [wan] IPCP: Close event 2024-04-20 13:19:29.741967+03:00 ppp 98029 [wan] IFACE: Close event 2024-04-20 13:19:29.741737+03:00 ppp 98029 caught fatal signal TERM 2024-04-20 13:19:29.738833+03:00 ppp 92838 Multi-link PPP daemon for FreeBSD
It does appear different. It seems to be connected to the 'Multilink extensions over single link' option. I can't replicate the issue after unchecking this option and issuing
/usr/local/sbin/pfSctl -c 'interface reload wan'
However, when it's checked, it consistently fails to reconnect. It doesn't seem to be a direct bug, but there's definitely something wrong when the multilink configuration is applied. The primary firewall has this option unchecked.
But I remember I have had exactly the same behaviour as posted here https://forum.netgate.com/post/1163644 can't find now when it's changed
-
Huh, that's interesting. That's not set by default, was there some reason you enabled it?
-
@stephenw10
At some point, I was testing the capabilities of the provider and forgot to disable this option. However, it was definitely not related to the initially discussed issue, which is why I brought up this topic. -
@stephenw10 said in PPPoE WAN does not restart correctly after reconfiguring interfaces.:
With the other WAN disabled for v6 does the mpd process finish without that min wait?
Seems so. See attached log file:
PPPoE not failing.txt