PPPoE not reconnecting if power outage or powering off OPNsens for a few minutes

[sergiy0]

Hello guys,

I'm very happy with my OPNsense FW while is connected.

The problem comes after a power outage or when connecting for the first time after switching OFF the FW for a couple of minutes. OPNsense has difficulties to make the connection over PPPoE.

Connecting with PC PPPoE client > ISP Modem is working fine

Current setup:
ISP Modem in Bridge mode (All in One router provided by ISP) port 1 > OPNsense port 1 igc0 (WAN)
OPNsense 24.1.10_8-amd64
FreeBSD 13.2-RELEASE-p11
OpenSSL 3.0.14




Uploading LOGS for a more detailed comprehesion:

Code: [Select]

ppps.log
2024-07-16T22:06:13 Informational ppp Multi-link PPP daemon for FreeBSD
2024-07-16T22:06:13 Informational ppp process 71529 terminated
2024-07-16T22:06:13 Informational ppp [wan_link0] Link: Shutdown
2024-07-16T22:06:13 Informational ppp [wan] Bundle: Shutdown
2024-07-16T22:06:12 Informational ppp [wan_link0] LCP: Down event
2024-07-16T22:06:12 Informational ppp [wan_link0] LCP: LayerFinish
2024-07-16T22:06:12 Informational ppp [wan_link0] LCP: state change Starting --> Initial
2024-07-16T22:06:12 Informational ppp [wan_link0] LCP: Close event
2024-07-16T22:06:12 Informational ppp [wan_link0] Link: giving up after 5 reconnection attempts
2024-07-16T22:06:12 Informational ppp [wan_link0] Link: DOWN event
2024-07-16T22:06:12 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-07-16T22:06:11 Informational ppp [wan] IPCP: Close event
2024-07-16T22:06:11 Informational ppp [wan] IFACE: Close event
2024-07-16T22:06:11 Informational ppp caught fatal signal TERM
2024-07-16T22:06:03 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-07-16T22:06:03 Informational ppp [wan_link0] Link: reconnection attempt 5
2024-07-16T22:06:00 Informational ppp [wan_link0] Link: reconnection attempt 5 in 3 seconds
2024-07-16T22:06:00 Informational ppp [wan_link0] LCP: Down event
2024-07-16T22:06:00 Informational ppp [wan_link0] Link: DOWN event
2024-07-16T22:06:00 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-07-16T22:05:51 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-07-16T22:05:51 Informational ppp [wan_link0] Link: reconnection attempt 4
2024-07-16T22:05:47 Informational ppp [wan_link0] Link: reconnection attempt 4 in 4 seconds
2024-07-16T22:05:47 Informational ppp [wan_link0] LCP: Down event
2024-07-16T22:05:47 Informational ppp [wan_link0] Link: DOWN event
2024-07-16T22:05:47 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-07-16T22:05:38 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-07-16T22:05:38 Informational ppp [wan_link0] Link: reconnection attempt 3
2024-07-16T22:05:36 Informational ppp [wan_link0] Link: reconnection attempt 3 in 2 seconds
2024-07-16T22:05:36 Informational ppp [wan_link0] LCP: Down event
2024-07-16T22:05:36 Informational ppp [wan_link0] Link: DOWN event
2024-07-16T22:05:36 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-07-16T22:05:27 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-07-16T22:05:27 Informational ppp [wan_link0] Link: reconnection attempt 2
2024-07-16T22:05:24 Informational ppp [wan_link0] Link: reconnection attempt 2 in 3 seconds
2024-07-16T22:05:24 Informational ppp [wan_link0] LCP: Down event
2024-07-16T22:05:24 Informational ppp [wan_link0] Link: DOWN event
2024-07-16T22:05:24 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-07-16T22:05:15 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-07-16T22:05:15 Informational ppp [wan_link0] Link: reconnection attempt 1
2024-07-16T22:05:11 Informational ppp [wan_link0] Link: reconnection attempt 1 in 4 seconds
2024-07-16T22:05:11 Informational ppp [wan_link0] LCP: Down event
2024-07-16T22:05:11 Informational ppp [wan_link0] Link: DOWN event
2024-07-16T22:05:11 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-07-16T22:05:02 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-07-16T22:05:02 Informational ppp [wan_link0] LCP: LayerStart
2024-07-16T22:05:02 Informational ppp [wan_link0] LCP: state change Initial --> Starting
2024-07-16T22:05:02 Informational ppp [wan_link0] LCP: Open event
2024-07-16T22:05:02 Informational ppp [wan_link0] Link: OPEN event
2024-07-16T22:05:02 Informational ppp [wan] Bundle: Interface ng0 created
2024-07-16T22:05:02 Informational ppp web: web is not running
2024-07-16T22:05:02 Informational ppp process 71529 started, version 5.9
2024-07-16T22:05:02 Informational ppp
2024-07-16T22:05:02 Informational ppp Multi-link PPP daemon for FreeBSD

After various reboots, reset of ISP modem with a backup config, crossing fingers and so on then I get the connection working as below (I would accept if rebooting both modem+FW fix the issue but it is not the case)

Code: [Select]

2024-07-16T22:32:01 Informational ppp [wan_link0] PPPoE: connection successful
2024-07-16T22:32:01 Informational ppp PPPoE: rec'd ACNAME "hl4mov4-301"
2024-07-16T22:32:01 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-07-16T22:32:01 Informational ppp [wan_link0] Link: reconnection attempt 10
2024-07-16T22:32:00 Informational ppp [wan_link0] Link: reconnection attempt 10 in 1 seconds
2024-07-16T22:32:00 Informational ppp [wan_link0] LCP: Down event
2024-07-16T22:32:00 Informational ppp [wan_link0] Link: DOWN event
2024-07-16T22:32:00 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-07-16T22:31:51 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-07-16T22:31:51 Informational ppp [wan_link0] Link: reconnection attempt 9
2024-07-16T22:31:47 Informational ppp [wan_link0] Link: reconnection attempt 9 in 4 seconds
2024-07-16T22:31:47 Informational ppp [wan_link0] LCP: Down event
2024-07-16T22:31:47 Informational ppp [wan_link0] Link: DOWN event
2024-07-16T22:31:47 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-07-16T22:31:38 Informational ppp [wan_link0] PPPoE: Connecting to ''
Any advice to improve the connection? It's annoying being out of home and unable to fix the connection after a power failure.

The only "fix" I could think at the moment is to buy an UPS then connect ISP modem + OPNsense there but not the best solution...

Thank you in advance

[meyergru]

Sometimes, in a situation like this, the ISP still thinks the PPPoE connection is open. It may take a long time to notice that your end has died. Probably, resetting your ONT might help.

I would try to experiment with the advanced PPPoE setting "Idle Timeout" in order to have the connection close if no packets are received. BTW: Behind the scenes, mpd5 uses "set link keep-alive 10 60" in order to keep an existing connection alive.

[sergiy0]

Sometimes, in a situation like this, the ISP still thinks the PPPoE connection is open. It may take a long time to notice that your end has died. Probably, resetting your ONT might help.

I would try to experiment with the advanced PPPoE setting "Idle Timeout" in order to have the connection close if no packets are received. BTW: Behind the scenes, mpd5 uses "set link keep-alive 10 60" in order to keep an existing connection alive.

Hi Meyergru,

Thanks a lot for your help on that annoying behaviour

The weird thing is on my previous tests (IIRC) I got PPPoE working just only after a factory reset of my ISP ONT/MODEM (a restart wasn't enough). That maybe explain what you say about ISP still thinks connection is Open... BUT before doing the factory reset PPPoE over my PC worked (dafuq!)

If the connection remains "open" from the ISP side, why should I enable "Idle Timeout" in OPNsense? If it's unnable to connect should be unnable to disconnect, right? I remember to have tested this value setting it as "0" and after changing it I was unable to revert back it to empty (what would be the default value for this field?)

[meyergru]

I think that the "Idle timeout" is a value you give to the ISP as an indication when they should assume that the connection is broken. They way it is defined, it cannot trigger more than a signalisation on OpnSense's behalf.

Zero is the default value anyway, which means there is no idle timeout. I know that after a PPPoE connection is established, any other PADI requests are ignored, which is exactly what you see, so I assume that this is the case.

I would set the value to something like 90 seconds, such that the keepalive will keep the connection open as long as OpnSense is there, but if it fails, there will be no keepalives and the ISP should end the PPPoE connection after 90 seconds of idle time.

[sergiy0]

I think that the "Idle timeout" is a value you give to the ISP as an indication when they should assume that the connection is broken. They way it is defined, it cannot trigger more than a signalisation on OpnSense's behalf.

Zero is the default value anyway, which means there is no idle timeout. I know that after a PPPoE connection is established, any other PADI requests are ignored, which is exactly what you see, so I assume that this is the case.

I would set the value to something like 90 seconds, such that the keepalive will keep the connection open as long as OpnSense is there, but if it fails, there will be no keepalives and the ISP should end the PPPoE connection after 90 seconds of idle time.

Thanks a ton for the clarification. I Will try this setting during the weekend and check the result (fingers crossed)

Edit: In the meantime I have done a test just restarting the WAN interface 'configctl interface reconfigure wan' as I am sure this reconnection always works (PPPoE only fails when OPNsense is OFF for a while).

Here are the packet list for a successful reconnection on physical WAN interface 'igc0' (virtual interface 'PPPoE0 (WAN)' didn't have any PPPoE log -.-") in Wireshark for PPP_IPCP, PPP_LCP, PPPoED, PPP_CHAP protocols:

Code: [Select]

      1 2024-08-28 09:50:24,567786    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPP IPCP 26     Termination Request
      2 2024-08-28 09:50:24,569722    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP IPCP 60     Termination Ack
      3 2024-08-28 09:50:24,569793    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP LCP  60     Termination Request
      4 2024-08-28 09:50:24,569935    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPPoED   60     Active Discovery Terminate (PADT)
      5 2024-08-28 09:50:24,569962    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPPoED   38     Active Discovery Terminate (PADT)
      6 2024-08-28 09:50:26,847954    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPPoED   71     Active Discovery Offer (PADO) AC-Name='hl4mov4-301'
      7 2024-08-28 09:50:26,847981    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPPoED   71     Active Discovery Request (PADR) AC-Name='hl4mov4-301'
      8 2024-08-28 09:50:26,853645    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPPoED   71     Active Discovery Session-confirmation (PADS) AC-Name='hl4mov4-301'
      9 2024-08-28 09:50:26,853963    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPP LCP  38     Configuration Request
     10 2024-08-28 09:50:26,857930    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP LCP  60     Configuration Request
     11 2024-08-28 09:50:26,857978    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP LCP  60     Configuration Ack
     12 2024-08-28 09:50:26,858144    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPP LCP  37     Configuration Ack
     13 2024-08-28 09:50:26,861853    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP CHAP 64     Challenge (NAME='JUNOS', VALUE=0x31e112c3b86a5bbcac587276744b6defcd360e91d42a5e01ef177e312ecce754)
     14 2024-08-28 09:50:26,862113    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPP CHAP 66     Response (NAME='adslppp@telefonicane...', VALUE=0x0f37973ba745263ab52afa29becd6d4f)
     15 2024-08-28 09:50:26,930415    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP CHAP 60     Success (MESSAGE='')
     16 2024-08-28 09:50:26,931005    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPP IPCP 38     Configuration Request
     17 2024-08-28 09:50:26,935095    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP IPCP 60     Configuration Request
     18 2024-08-28 09:50:26,935168    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP IPCP 60     Configuration Reject
     19 2024-08-28 09:50:26,935293    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPP IPCP 32     Configuration Ack
     20 2024-08-28 09:50:26,935413    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPP IPCP 32     Configuration Request
     21 2024-08-28 09:50:26,938830    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP IPCP 60     Configuration Nak
     22 2024-08-28 09:50:26,939048    SBluetech_15:32:d4    JuniperNetwo_58:7f:d1 PPP IPCP 32     Configuration Request
     23 2024-08-28 09:50:26,992138    JuniperNetwo_58:7f:d1 SBluetech_15:32:d4    PPP IPCP 60     Configuration Ack

SBluetech_15:32:d4 is my WAN interface
JuniperNetwo_58:7f:d1 is the ISP PPPoE server

Edit2: another test with results from OPNsense packet capture to simplify the process (PADI, PADO, PADR, PADS):

Code: [Select]

igc0 2024-08-28
22:08:24.862713 60:be:b4:15:32:d4 ff:ff:ff:ff:ff:ff ethertype PPPoE D (0x8863), length 36: PPPoE PADI [Host-Uniq 0x80D3126B01F8FFFF] [Service-Name]

igc0 2024-08-28
22:08:24.865773 44:aa:50:58:7f:d1 60:be:b4:15:32:d4 ethertype PPPoE D (0x8863), length 71: PPPoE PADO [AC-Name "hl4mov4-301"] [Host-Uniq 0x80D3126B01F8FFFF] [Service-Name] [AC-Cookie 0x1A89B2039AC7C5951A7E54E952018B4F]

igc0 2024-08-28
22:08:24.865801 60:be:b4:15:32:d4 44:aa:50:58:7f:d1 ethertype PPPoE D (0x8863), length 71: PPPoE PADR [Host-Uniq 0x80D3126B01F8FFFF] [AC-Cookie 0x1A89B2039AC7C5951A7E54E952018B4F] [AC-Name "hl4mov4-301"] [Service-Name]

igc0 2024-08-28
22:08:24.869294 44:aa:50:58:7f:d1 60:be:b4:15:32:d4 ethertype PPPoE D (0x8863), length 71: PPPoE PADS [ses 0xb7] [Service-Name] [Host-Uniq 0x80D3126B01F8FFFF] [AC-Name "hl4mov4-301"] [AC-Cookie 0x1A89B2039AC7C5951A7E54E952018B4F]

Will check and debug during the weekend and compare both logs to check more in detail.

[sergiy0]

OK! I did more tests today. I maybe found the root cause of the issue but need to do more tests to confirm this is the real problem. Currently I have connected 2 cables to my ISP modem.

1 goes to OPNsense WAN because the modem is set in "Bridging" mode for PPPoE
1 that it goes to my main managed switch connected to OPNsense (basically because I'm using the modem as an AP for WiFi clients and I want to isolate them in a dedicated VLAN).

After debugging the PPPoE connection from OPNsense and also from my Windows PC acting as client in Wireshark I saw only PADI's requests.

Never got PADO's until I disconnected the 2nd cable from the modem leaving only the cable WAN to OPNsense (PPPoE). THIS IS SOMETHING I NEED TO DOUBLE CHECK BECAUSE I JUST TESTED ONCE BUT SPENT 3H. TODAY DON'T HAVE MORE TIME BUT WILL TEST VERY SOON TO CONFIRM THAT INFO

What's the next step? Maybe I buy a separate ONT for the WAN (PPPoE) > OPNsense and my modem as a single AP for WiFi clients.

Any advice?

Edit: maybe I try the following connection:
ISP modem > managed switch > WAN OPNsense instead of the current config ISP modem > OPNsense

[sergiy0]

After testing during the weekend I finally found the issue. ISP modem (in Bridge mode) has 2 cables connected:

- ISP modem > OPNsense (WAN PPPoE)
- ISP modem > main managed switch connected to OPNsense (clients connected to modem WIFI are separated in the vlan WIFI)

so the workaround I found is to disconnect non-wan cable to get PPPoE connected and then reconnect the cable once PPPoE has been connected so the WIFI works again.

Tried setting up WAN and VLAN WIFI on the same cable but WIFI was not working and I had to revert to a working state.

The workaround would work if I'm at home and power outage occurs but not when I'm out of home... So maybe I buy a separated ONT (or a dedicated AP why not) to test an alternative setup.