Failed to detect IP for WAN - PPPOE

Started by elclay, April 11, 2023, 08:40:56 PM

Previous topic - Next topic
April 11, 2023, 08:40:56 PM Last Edit: April 21, 2023, 12:50:51 AM by elclay
OPNsense 23.1.5_4-amd64

The WAN connection goes from the ISP Router using pppoe, at least 1 time a day I run out of internet and the only way to restore it is by restarting opnsense.
- I tried restarting only my ISP Router and it didn't work.
- Disconnected and connected the ethernet cable of the WAN did not work.
- Restarting the opnsense services did not work.
Only opnsense reset works.

Interfaces: [WAN] config



System: Log Files: General
2023-04-11T05:37:42-04:00 Notice opnsense /usr/local/etc/rc.newwanip: Failed to detect IP for WAN[wan]

Interfaces: Point-to-Point: Log File
2023-04-11T05:38:12-04:00 Informational ppp [wan_link0] Link: reconnection attempt 3
2023-04-11T05:38:10-04:00 Informational ppp [wan_link0] Link: reconnection attempt 3 in 2 seconds
2023-04-11T05:38:10-04:00 Informational ppp [wan_link0] LCP: Down event
2023-04-11T05:38:10-04:00 Informational ppp [wan_link0] Link: DOWN event
2023-04-11T05:38:10-04:00 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2023-04-11T05:38:01-04:00 Informational ppp [wan_link0] PPPoE: Connecting to ''
2023-04-11T05:38:01-04:00 Informational ppp [wan_link0] Link: reconnection attempt 2
2023-04-11T05:37:57-04:00 Informational ppp [wan_link0] Link: reconnection attempt 2 in 4 seconds
2023-04-11T05:37:57-04:00 Informational ppp [wan_link0] LCP: Down event
2023-04-11T05:37:57-04:00 Informational ppp [wan_link0] Link: DOWN event
2023-04-11T05:37:57-04:00 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2023-04-11T05:37:48-04:00 Informational ppp [wan_link0] PPPoE: Connecting to ''
2023-04-11T05:37:48-04:00 Informational ppp [wan_link0] Link: reconnection attempt 1
2023-04-11T05:37:46-04:00 Informational ppp [wan_link0] Link: reconnection attempt 1 in 2 seconds
2023-04-11T05:37:46-04:00 Informational ppp [wan_link0] LCP: LayerStart
2023-04-11T05:37:46-04:00 Informational ppp [wan_link0] LCP: state change Stopped --> Starting
2023-04-11T05:37:46-04:00 Informational ppp [wan_link0] LCP: Down event
2023-04-11T05:37:46-04:00 Informational ppp [wan_link0] Link: DOWN event
2023-04-11T05:37:46-04:00 Informational ppp [wan_link0] PPPoE: connection closed
2023-04-11T05:37:46-04:00 Informational ppp [wan_link0] LCP: LayerFinish
2023-04-11T05:37:46-04:00 Informational ppp [wan_link0] LCP: state change Stopping --> Stopped
2023-04-11T05:37:44-04:00 Informational ppp [wan_link0] LCP: SendTerminateReq #4
2023-04-11T05:37:42-04:00 Informational ppp [wan_link0] LCP: LayerDown
2023-04-11T05:37:42-04:00 Informational ppp [wan_link0] LCP: SendTerminateReq #3
2023-04-11T05:37:42-04:00 Informational ppp [wan] IPCP: state change Closing --> Initial
2023-04-11T05:37:42-04:00 Informational ppp [wan] Bundle: No NCPs left. Closing links...
2023-04-11T05:37:42-04:00 Informational ppp [wan] IPCP: LayerFinish
2023-04-11T05:37:42-04:00 Informational ppp [wan] IPCP: Down event
2023-04-11T05:37:42-04:00 Informational ppp [wan] IFACE: Rename interface pppoe0 to pppoe0
2023-04-11T05:37:42-04:00 Informational ppp [wan] IFACE: Down event
2023-04-11T05:37:42-04:00 Informational ppp [wan] IPCP: LayerDown
2023-04-11T05:37:42-04:00 Informational ppp [wan] IPCP: SendTerminateReq #4
2023-04-11T05:37:42-04:00 Informational ppp [wan] IPCP: state change Opened --> Closing
2023-04-11T05:37:42-04:00 Informational ppp [wan] IPCP: Close event
2023-04-11T05:37:42-04:00 Informational ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
2023-04-11T05:37:42-04:00 Informational ppp [wan_link0] Link: Leave bundle "wan"
2023-04-11T05:37:42-04:00 Informational ppp [wan_link0] LCP: state change Opened --> Stopping
2023-04-11T05:37:42-04:00 Informational ppp [wan_link0] LCP: peer not responding to echo requests
2023-04-11T05:37:42-04:00 Informational ppp [wan_link0] LCP: no reply to 5 echo request(s)
2023-04-11T05:37:32-04:00 Informational ppp [wan_link0] LCP: no reply to 4 echo request(s)
2023-04-11T05:37:22-04:00 Informational ppp [wan_link0] LCP: no reply to 3 echo request(s)
2023-04-11T05:37:12-04:00 Informational ppp [wan_link0] LCP: no reply to 2 echo request(s)
2023-04-11T05:37:02-04:00 Informational ppp [wan_link0] LCP: no reply to 1 echo request(s)


I hope you can help me with a solution, if you need additional information or perform some tests, I am available ;)

I have 3 days without internet drops until today, today the connectivity shut down again but it happened when downloading torrents, it happened a few minutes after starting the download of 5 movies in 4k, in fact I couldn't even enter opnsense, it didn't load the login page, important to note that I download torrents from another machine.
I keep investigating...

I thought it was because I was using torrents but I was not correct, without downloading anything via torrent, in the same way I lose the internet every time this error appears

2023-04-20T14:17:08-04:00 Notice syslog-ng Configuration reload finished;
2023-04-20T14:17:08-04:00 Notice syslog-ng Configuration reload request received, reloading configuration;
2023-04-20T14:17:08-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: Chose to bind WAN_PPPOE on 201.188.444.777 since we could not find a proper match.
2023-04-20T14:17:08-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: plugins_configure monitor (execute task : dpinger_configure_do(1))
2023-04-20T14:17:08-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: plugins_configure monitor (1)
2023-04-20T14:17:08-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: ROUTING: keeping current inet default gateway '201.188.888.8'
2023-04-20T14:17:08-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: ROUTING: setting IPv4 default route to 201.188.888.8
2023-04-20T14:17:08-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: ROUTING: IPv4 default gateway set to wan
2023-04-20T14:17:08-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: ROUTING: entering configure using defaults
2023-04-20T14:17:08-04:00 Notice flowd_aggregate.py startup, check database.
2023-04-20T14:17:07-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : ntpd_configure_do())
2023-04-20T14:17:07-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : dnsmasq_configure_do())
2023-04-20T14:17:07-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (,wan)
2023-04-20T14:17:07-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure vpn (execute task : openvpn_configure_do(,wan))
2023-04-20T14:17:07-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure vpn (execute task : ipsec_configure_do(,wan))
2023-04-20T14:17:07-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure vpn (,wan)
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: Chose to bind WAN_PPPOE on 201.188.444.777 since we could not find a proper match.
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: plugins_configure monitor (execute task : dpinger_configure_do(1))
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: plugins_configure monitor (1)
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: ROUTING: keeping current inet default gateway '201.188.888.8'
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: ROUTING: setting IPv4 default route to 201.188.888.8
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: ROUTING: IPv4 default gateway set to wan
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.routing_configure: ROUTING: entering configure using defaults
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.newwanip: Chose to bind WAN_PPPOE on 201.188.444.777 since we could not find a proper match.
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure monitor (execute task : dpinger_configure_do(,WAN_PPPOE))
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure monitor (,WAN_PPPOE)
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.newwanip: ROUTING: keeping current inet default gateway '201.188.888.8'
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.newwanip: ROUTING: setting IPv4 default route to 201.188.888.8
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.newwanip: ROUTING: IPv4 default gateway set to wan
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.newwanip: ROUTING: entering configure using 'wan'
2023-04-20T14:17:06-04:00 Notice opnsense /usr/local/etc/rc.newwanip: IP renewal starting (new: 201.188.444.777, old: , interface: WAN[wan], device: pppoe0, force: no)
2023-04-20T14:16:57-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure bootup (execute task : unbound_configure_do(1))
2023-04-20T14:16:57-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure bootup (execute task : opendns_configure_do(1))
2023-04-20T14:16:54-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure bootup (execute task : ntpd_configure_do(1))
2023-04-20T14:16:54-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure bootup (1)
2023-04-20T14:16:54-04:00 Notice opnsense /usr/local/etc/rc.bootup: Resyncing OpenVPN instances.
2023-04-20T14:16:54-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure vpn (execute task : openvpn_configure_do(1))
2023-04-20T14:16:51-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure vpn (execute task : ipsec_configure_do(1))
2023-04-20T14:16:51-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure vpn (1)
2023-04-20T14:16:48-04:00 Notice opnsense /usr/local/etc/rc.bootup: Chose to bind WAN_PPPOE on 201.188.444.777 since we could not find a proper match.
2023-04-20T14:16:48-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure monitor (execute task : dpinger_configure_do(1,null,1))
2023-04-20T14:16:48-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure monitor (1,null,1)
2023-04-20T14:16:45-04:00 Notice opnsense /usr/local/etc/rc.newwanip: IP renewal deferred during boot on 'pppoe0'
2023-04-20T14:16:37-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure dns (execute task : unbound_configure_do(1))
2023-04-20T14:16:37-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure dns (execute task : dnsmasq_configure_do(1))
2023-04-20T14:16:37-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure dns (1)
2023-04-20T14:16:37-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure dhcrelay (execute task : dhcpd_dhcrelay_configure(1))
2023-04-20T14:16:37-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure dhcrelay (1)
2023-04-20T14:16:37-04:00 Warning opnsense /usr/local/etc/rc.bootup: dhcpd_radvd_configure(auto) found no suitable IPv6 address on re0
2023-04-20T14:16:36-04:00 Error opnsense /usr/local/etc/rc.bootup: The command '/bin/kill -'TERM' '57809'' returned exit code '1', the output was 'kill: 57809: No such process'
2023-04-20T14:16:36-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure dhcp (execute task : dhcpd_dhcp_configure(1))
2023-04-20T14:16:36-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure dhcp (1)
2023-04-20T14:16:36-04:00 Notice opnsense /usr/local/etc/rc.bootup: ROUTING: entering configure using defaults
2023-04-20T14:16:36-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure early (execute task : webgui_configure_do(1))
2023-04-20T14:16:36-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure early (execute task : unbound_cache_flush(1))
2023-04-20T14:16:36-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure early (execute task : openssh_configure_do(1))
2023-04-20T14:16:36-04:00 Notice opnsense /usr/local/etc/rc.bootup: plugins_configure early (1)
2023-04-20T14:16:36-04:00 Error opnsense /usr/local/etc/rc.bootup: Unable to configure nonexistent interface opt1 (wg1)
2023-04-20T14:16:36-04:00 Error opnsense /usr/local/etc/rc.bootup: The command '/usr/sbin/ngctl msg 're1': setautosrc 1' returned exit code '71', the output was 'ngctl: send msg: No such file or directory'
2023-04-20T14:16:32-04:00 Notice syslog-ng syslog-ng starting up; version='3.38.1'
2023-04-20T14:15:20-04:00 Notice syslog-ng syslog-ng shutting down; version='3.38.1'
2023-04-20T14:15:10-04:00 Notice opnsense /usr/local/etc/rc.newwanip: Failed to detect IP for WAN[wan]
2023-04-20T14:13:53-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : webgui_configure_do(,wan))
2023-04-20T14:13:53-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : vxlan_configure_do())
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : unbound_configure_do(,wan))
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : openssh_configure_do(,wan))
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : opendns_configure_do())
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : ntpd_configure_do())
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (execute task : dnsmasq_configure_do())
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure newwanip (,wan)
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure vpn (execute task : openvpn_configure_do(,wan))
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure vpn (execute task : ipsec_configure_do(,wan))
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure vpn (,wan)
2023-04-20T14:13:51-04:00 Notice opnsense /usr/local/etc/rc.newwanip: IP address change detected, killing states of old ip 201.188.444.555
2023-04-20T14:13:50-04:00 Notice opnsense /usr/local/etc/rc.newwanip: Chose to bind WAN_PPPOE on 201.188.111.222 since we could not find a proper match.
2023-04-20T14:13:50-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure monitor (execute task : dpinger_configure_do(,WAN_PPPOE))
2023-04-20T14:13:50-04:00 Notice opnsense /usr/local/etc/rc.newwanip: plugins_configure monitor (,WAN_PPPOE)
2023-04-20T14:13:50-04:00 Notice opnsense /usr/local/etc/rc.newwanip: ROUTING: keeping current inet default gateway '201.188.888.8'
2023-04-20T14:13:50-04:00 Notice opnsense /usr/local/etc/rc.newwanip: ROUTING: setting IPv4 default route to 201.188.888.8
2023-04-20T14:13:50-04:00 Notice opnsense /usr/local/etc/rc.newwanip: ROUTING: IPv4 default gateway set to wan
2023-04-20T14:13:50-04:00 Notice opnsense /usr/local/etc/rc.newwanip: ROUTING: entering configure using 'wan'
2023-04-20T14:13:50-04:00 Notice opnsense /usr/local/etc/rc.newwanip: IP renewal starting (new: 201.188.111.222, old: 201.188.444.555, interface: WAN[wan], device: pppoe0, force: yes)
2023-04-20T14:08:35-04:00 Notice opnsense /usr/local/etc/rc.newwanip: Failed to detect IP for WAN[wan]


Services running

I may be barking up the completely wrong tree here, but from your problem description it sounds like the same symptoms I had and which were completely cured by ticking "Interfaces -> Settings -> IPv6 DHCP: Prevent release".

Quote from: sbellon on April 21, 2023, 11:20:40 AM
I may be barking up the completely wrong tree here, but from your problem description it sounds like the same symptoms I had and which were completely cured by ticking "Interfaces -> Settings -> IPv6 DHCP: Prevent release".

I don't lose anything by trying it, now I'm trying the latest update OPNsense 23.1.6-amd64 if the problem continues I'll try the alternative you tell me.
Whatever happens I will report it here

Quote from: elclay on April 21, 2023, 03:37:20 PM
Whatever happens I will report it here

Did you get to the bottom this?  Think I'm seeing the same... albeit now on 23.7.x

Unfortunately I couldn't find the solution, but I have the latest version 23.7.7_3 and it happens to me much less frequently.

Did you try putting a 'dumb' switch between opnsense and the ONT/modem?  I think that's my next thing to try.

Few reports in the last year or so, that this resolved problems for a number of pfsense users.

If you do, comment here how it goes, the truth is I did 2 things, I changed my internet provider and updated to the latest version and on rare occasions it happens to me

Again I started to have the same problem where the WAN runs out of IP and since I did not find any decent solution, I have a patch solution, I created a script that, when it does not detect an internet connection, restarts the opnsense

Script: https://github.com/elclay7/restarOS/blob/main/restarOS.sh

Create this file: vim /usr/local/opnsense/service/conf/actions.d/actions_restaros.conf

[start]
command:/bin/sh /root/restarOS.sh &
parameters:
type:script
message:Iniciando script restarOS.sh
description:Monitoreo de internet para reiniciar el S.O


opnSense Cron Jobs info: http://kb.unixservertech.com/other/networking/opnsense/cron-jobs

And every time the opnsense is restarted the script will start, it will monitor the internet connection by ping when the pings fail for 2 minutes it will restart the server

I seem to have 'fixed' my issue - although I haven't quite narrowed down the root cause:

https://forum.opnsense.org/index.php?topic=37006.msg183168#msg183168

Disabling MSIX fixed it for me - although I have also since disabled all sorts of other (unused/un-needed) things: onboard audio, PCI ASPM, legacy USB etc.

... I'm going to try re-enabling MSIX at some point in the new year, to see if the 'disabling stuff' makes any difference.

But mine has been rock solid for about a month now, versus multiple drops and restarts required per day.