WAN Interface PPPoE sometimes becomes disconnected
-
Hi all, been having an issue where the WAN Interface PPPoE sometimes becomes disconnected. When the issue happens the WAN interface under Traffic Graphic disappears and only the LAN interface is shown.
I then get errors like WAN_PPPOE myIpAddress: sendto error: 65To fix I have to go to Interfaces/WAN untick Enable interface ,save, tick Enable interface, save. Then everything works again.
This is not the internet dropping out but looks like the WAN interface is dropping and needs to be enabled again.
This seems to happen once or twice a month.
-
What do you see in the System and/or ppp logs when that happens?
Is this in 2.6?
Steve
-
@stephenw10 Have had the issue with both 2.6 and 2.5.2.
Jul 24 03:09:51 pfsense ppp[64650]: caught fatal signal TERM Jul 24 03:09:51 pfsense ppp[64650]: [wan] IFACE: Close event Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: Close event Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: state change Opened --> Closing Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: SendTerminateReq #4 Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: LayerDown Jul 24 03:09:51 pfsense check_reload_status[402]: Rewriting resolv.conf Jul 24 03:09:51 pfsense ppp[64650]: [wan] IFACE: Down event Jul 24 03:09:51 pfsense ppp[64650]: [wan] IFACE: Rename interface pppoe2 to pppoe2 Jul 24 03:09:51 pfsense ppp[64650]: [wan] IFACE: Set description "WAN" Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: rec'd Terminate Ack #4 (Closing) Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: state change Closing --> Closed Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: LayerFinish Jul 24 03:09:51 pfsense ppp[64650]: [wan] Bundle: No NCPs left. Closing links... Jul 24 03:09:51 pfsense ppp[64650]: [wan] Bundle: closing link "wan_link0"... Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] Link: CLOSE event Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: Close event Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: state change Opened --> Closing Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] Link: Leave bundle "wan" Jul 24 03:09:51 pfsense ppp[64650]: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: Close event Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: Down event Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: state change Closed --> Initial Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: SendTerminateReq #2 Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: LayerDown Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: rec'd Terminate Ack #2 (Closing) Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: state change Closing --> Closed Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: LayerFinish Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] Link: DOWN event Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: Down event Jul 24 03:09:51 pfsense ppp[64650]: [wan_link0] LCP: state change Closed --> Initial Jul 24 03:09:53 pfsense ppp[64650]: [wan] Bundle: Shutdown Jul 24 03:09:54 pfsense ppp[64650]: [wan_link0] Link: Shutdown Jul 24 03:09:54 pfsense ppp[64650]: process 64650 terminated
-
It looks like that closed deliberately by something else. Is there nothing in the system log just before that?
-
@stephenw10 No the log before are
Jul 24 01:45:00 pfsense sshguard[92931]: Exiting on signal. Jul 24 01:45:00 pfsense sshguard[65352]: Now monitoring attacks. Jul 24 02:30:00 pfsense sshguard[65352]: Exiting on signal. Jul 24 02:30:00 pfsense sshguard[45031]: Now monitoring attacks. Jul 24 02:35:00 pfsense sshguard[45031]: Exiting on signal. Jul 24 02:35:00 pfsense sshguard[44325]: Now monitoring attacks. Jul 24 03:09:51 pfsense ppp[64650]: caught fatal signal TERM Jul 24 03:09:51 pfsense ppp[64650]: [wan] IFACE: Close event Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: Close event Jul 24 03:09:51 pfsense ppp[64650]: [wan] IPCP: state change Opened --> Closing
-
Hmm, does it reconnect if your physically pull the port and reconnect it?
-
@stephenw10 Will try it the next time it happens
-
@stephenw10 Ok had it happen again, yes physically pulling the Ethernet WAN port does reconnect the wan interface. But pfsense is not auto reconnecting it.
system logs Aug 1 01:37:55 ppp 80835 caught fatal signal TERM Aug 1 01:37:55 ppp 80835 [wan] IFACE: Close event Aug 1 01:37:55 ppp 80835 [wan] IPCP: Close event Aug 1 01:37:55 ppp 80835 [wan] IPCP: state change Opened --> Closing Aug 1 01:37:55 ppp 80835 [wan] IPCP: SendTerminateReq #4 Aug 1 01:37:55 ppp 80835 [wan] IPCP: LayerDown Aug 1 01:37:55 check_reload_status 402 Rewriting resolv.conf Aug 1 01:37:55 ppp 80835 [wan] IFACE: Down event Aug 1 01:37:55 ppp 80835 [wan] IFACE: Rename interface pppoe2 to pppoe2 Aug 1 01:37:55 ppp 80835 [wan] IFACE: Set description "WAN" Aug 1 01:37:55 ppp 80835 [wan] IPCP: rec'd Terminate Ack #4 (Closing) Aug 1 01:37:55 ppp 80835 [wan] IPCP: state change Closing --> Closed Aug 1 01:37:55 ppp 80835 [wan] IPCP: LayerFinish Aug 1 01:37:55 ppp 80835 [wan] Bundle: No NCPs left. Closing links... Aug 1 01:37:55 ppp 80835 [wan] Bundle: closing link "wan_link0"... Aug 1 01:37:55 ppp 80835 [wan_link0] Link: CLOSE event Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: Close event Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: state change Opened --> Closing Aug 1 01:37:55 ppp 80835 [wan_link0] Link: Leave bundle "wan" Aug 1 01:37:55 ppp 80835 [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Aug 1 01:37:55 ppp 80835 [wan] IPCP: Close event Aug 1 01:37:55 ppp 80835 [wan] IPCP: Down event Aug 1 01:37:55 ppp 80835 [wan] IPCP: state change Closed --> Initial Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: SendTerminateReq #2 Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: LayerDown Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: rec'd Terminate Ack #2 (Closing) Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: state change Closing --> Closed Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: LayerFinish Aug 1 01:37:55 ppp 80835 [wan_link0] Link: DOWN event Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: Down event Aug 1 01:37:55 ppp 80835 [wan_link0] LCP: state change Closed --> Initial Aug 1 01:37:57 ppp 80835 [wan] Bundle: Shutdown Aug 1 01:37:57 ppp 80835 [wan_link0] Link: Shutdown Aug 1 01:37:57 ppp 80835 process 80835 terminated gateways Aug 1 01:37:55 dpinger 63440 WAN_PPPOE myIpAddress: sendto error: 65 routting Aug 1 01:37:55 miniupnpd 67921 ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Aug 1 01:37:55 miniupnpd 67921 ioctl(s, SIOCGIFADDR, ...): Can't assign requested address Aug 1 01:37:55 miniupnpd 67921 Failed to get IP for interface pppoe2 Aug 1 01:37:55 miniupnpd 67921 SendNATPMPPublicAddressChangeNotification: cannot get public IP address, stopping Aug 1 01:37:55 miniupnpd 67921 PCPSendUnsolicitedAnnounce(sockets[0]) sendto(): No route to host
I am thinking i might need to temporary try creating a cron job to check if the wan port becomes disconnected and try and reconnect it via a script.
-
Do you have the log showing it reconnect successfully after pulling the WAN? How does it differ from the failures before that?
-
Aug 1 07:52:23 check_reload_status 402 Linkup starting bge1 Aug 1 07:52:23 kernel bge1: link state changed to DOWN Aug 1 07:52:24 check_reload_status 402 Reloading filter Aug 1 07:52:26 xinetd 76035 Starting reconfiguration Aug 1 07:52:26 xinetd 76035 Swapping defaults Aug 1 07:52:26 xinetd 76035 readjusting service 6969-udp Aug 1 07:52:26 xinetd 76035 service 19000-tcp deactivated Aug 1 07:52:26 xinetd 76035 19000-tcp: svc_release with 0 count Aug 1 07:52:26 xinetd 76035 service 19001-tcp deactivated Aug 1 07:52:26 xinetd 76035 19001-tcp: svc_release with 0 count Aug 1 07:52:26 xinetd 76035 service 19002-tcp deactivated Aug 1 07:52:26 xinetd 76035 19002-tcp: svc_release with 0 count Aug 1 07:52:26 xinetd 76035 service 19003-udp deactivated Aug 1 07:52:26 xinetd 76035 19003-udp: svc_release with 0 count Aug 1 07:52:26 xinetd 76035 service 19004-tcp deactivated Aug 1 07:52:26 xinetd 76035 19004-tcp: svc_release with 0 count Aug 1 07:52:26 xinetd 76035 service 19005-tcp deactivated Aug 1 07:52:26 xinetd 76035 19005-tcp: svc_release with 0 count Aug 1 07:52:26 xinetd 76035 Reconfigured: new=0 old=1 dropped=6 (services) Aug 1 07:52:27 check_reload_status 402 Linkup starting bge1 Aug 1 07:52:27 kernel bge1: link state changed to UP Aug 1 07:52:28 ppp 41093 Multi-link PPP daemon for FreeBSD Aug 1 07:52:28 ppp 41093 process 41093 started, version 5.9 Aug 1 07:52:28 ppp 41093 web: web is not running Aug 1 07:52:28 ppp 41093 [wan] Bundle: Interface ng0 created Aug 1 07:52:28 ppp 41093 [wan_link0] Link: OPEN event Aug 1 07:52:28 kernel ng0: changing name to 'pppoe2' Aug 1 07:52:28 ppp 41093 [wan_link0] LCP: Open event Aug 1 07:52:28 ppp 41093 [wan_link0] LCP: state change Initial --> Starting Aug 1 07:52:28 ppp 41093 [wan_link0] LCP: LayerStart Aug 1 07:52:28 ppp 41093 [wan_link0] PPPoE: Connecting to '' Aug 1 07:52:30 ppp 41093 PPPoE: rec'd ACNAME "nme-apt-bur-bras252" Aug 1 07:52:30 ppp 41093 [wan_link0] PPPoE: connection successful Aug 1 07:52:30 ppp 41093 [wan_link0] Link: UP event
So either repluging in the WAN or going to Interfaces/WAN and disabling and reenabling the interface brings the WAN interface back online.
I am not really seeing any difference from the failure before, maybe it is the network card. I am planning on building a new pfsense router soon so maybe that will resolve the issue as it does not seem to be a wide spread issue.