Messages

1

24.7 Production Series / Re: PPPoE disconnects on high traffic demand scenarios

« on: September 22, 2024, 05:00:04 pm »

I made a debug sunday today as the issue seemed to happen more often in the last couple of days. I had no idea where to look further so I decided to switch the hardware and replaced the odroid H4 for a APU 4D4 with a completely different processor (AMD  GX-412TC  vs. Intel N97) and other type of interfaces (Intel i211-AT vs. Intel I226-V) and it is running fine without any issues even in high load scenarios (downloaded 33GB with 240Mbit/s so far - had the issue around 8GB on Full Speed before).

2

24.7 Production Series / [SOLVED] PPPoE disconnects on high traffic demand scenarios

« on: August 26, 2024, 10:01:01 am »

Hello to the forum and first of all: Thanks for creating such an incredible product! I switched from openwrt to opnsense a couple of weeks ago and am totally happy with the overall performance of that nice piece of software. The configuration options and the flexibility are simply awesome.
I'm using a odroid h4 (intel n97 processor) as my main router from now and got it up and running in a couple of minutes. But from day 0 I had an issue where my internet connection sometimes disconnects - first I thought it was randomly but later I was able to drill it down to a PPPoE interface disconnect. I digged a bit deeper and found out, that this is recreatable when I'm facing high traffic scenarios, e.g. I can force the issue with a download from a game platform with their client.
When I physically disconnect and connect the ethernet cable from the router to my Vigor 165 DSL Modem (set to modem mode) again, the PPPoE interface reconnects properly. For your full reference: The DSL line is rocking solid, no outage for at least half a year, the signal strength is pretty okay, so I assume it is not a physical issue with the DSL line.

I'm willing to identify the issue and fix it, but I have no clue where to further drill down to the root cause of this issue. Is there anybody out there who is be able to point me to the right direction?

I added the corresponding log files in the following code extract, newest to oldest:

Code: [Select]

2024-08-26T09:28:48 Informational ppp [wan] IFACE: Rename interface ng0 to pppoe0
2024-08-26T09:28:48 Informational ppp [wan] IFACE: Up event
2024-08-26T09:28:48 Informational ppp [wan]   91.10.96.153 -> 62.155.246.162
2024-08-26T09:28:48 Informational ppp [wan] IPCP: LayerUp
2024-08-26T09:28:48 Informational ppp [wan] IPCP: state change Ack-Sent --> Opened
2024-08-26T09:28:48 Informational ppp [wan]   IPADDR 91.10.96.153
2024-08-26T09:28:48 Informational ppp [wan] IPCP: rec'd Configure Ack #11 (Ack-Sent)
2024-08-26T09:28:48 Informational ppp [wan]   IPADDR 91.10.96.153
2024-08-26T09:28:48 Informational ppp [wan] IPCP: SendConfigReq #11
2024-08-26T09:28:48 Informational ppp [wan]     91.10.96.153 is OK
2024-08-26T09:28:48 Informational ppp [wan]   IPADDR 91.10.96.153
2024-08-26T09:28:48 Informational ppp [wan] IPCP: rec'd Configure Nak #10 (Ack-Sent)
2024-08-26T09:28:48 Informational ppp [wan]   IPADDR 0.0.0.0
2024-08-26T09:28:48 Informational ppp [wan] IPCP: SendConfigReq #10
2024-08-26T09:28:48 Informational ppp [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
2024-08-26T09:28:48 Informational ppp [wan] IPCP: rec'd Configure Reject #9 (Ack-Sent)
2024-08-26T09:28:48 Informational ppp [wan] IPCP: state change Req-Sent --> Ack-Sent
2024-08-26T09:28:48 Informational ppp [wan]   IPADDR 62.155.246.162
2024-08-26T09:28:48 Informational ppp [wan] IPCP: SendConfigAck #167
2024-08-26T09:28:48 Informational ppp [wan]     62.155.246.162 is OK
2024-08-26T09:28:48 Informational ppp [wan]   IPADDR 62.155.246.162
2024-08-26T09:28:48 Informational ppp [wan] IPCP: rec'd Configure Request #167 (Req-Sent)
2024-08-26T09:28:48 Informational ppp [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
2024-08-26T09:28:48 Informational ppp [wan]   IPADDR 0.0.0.0
2024-08-26T09:28:48 Informational ppp [wan] IPCP: SendConfigReq #9
2024-08-26T09:28:48 Informational ppp [wan] IPCP: state change Starting --> Req-Sent
2024-08-26T09:28:48 Informational ppp [wan] IPCP: Up event
2024-08-26T09:28:48 Informational ppp [wan] IPCP: LayerStart
2024-08-26T09:28:48 Informational ppp [wan] IPCP: state change Initial --> Starting
2024-08-26T09:28:48 Informational ppp [wan] IPCP: Open event
2024-08-26T09:28:48 Informational ppp [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
2024-08-26T09:28:48 Informational ppp [wan_link0] Link: Join bundle "wan"
2024-08-26T09:28:48 Informational ppp [wan_link0] Link: Matched action 'bundle "wan" ""'
2024-08-26T09:28:48 Informational ppp [wan_link0] LCP: authorization successful
2024-08-26T09:28:48 Informational ppp [wan_link0]   MESG: [UI-SBR:234434,44421;UI-LINEID:1UND1.DEU.DTAG.RS8PF;]
2024-08-26T09:28:48 Informational ppp [wan_link0] PAP: rec'd ACK #1 len: 58
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: LayerUp
2024-08-26T09:28:47 Informational ppp [wan_link0] PAP: sending REQUEST #1 len: 41
2024-08-26T09:28:47 Informational ppp [wan_link0] PAP: using authname "H*****/******@****.de"
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: auth: peer wants PAP, I want nothing
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: state change Ack-Sent --> Opened
2024-08-26T09:28:47 Informational ppp [wan_link0]   MAGICNUM 0xfafe8371
2024-08-26T09:28:47 Informational ppp [wan_link0]   MRU 1492
2024-08-26T09:28:47 Informational ppp [wan_link0]   PROTOCOMP
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: rec'd Configure Ack #6 (Ack-Sent)
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: state change Req-Sent --> Ack-Sent
2024-08-26T09:28:47 Informational ppp [wan_link0]   MAGICNUM 0x662d1e4b
2024-08-26T09:28:47 Informational ppp [wan_link0]   AUTHPROTO PAP
2024-08-26T09:28:47 Informational ppp [wan_link0]   MRU 1492
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: SendConfigAck #29
2024-08-26T09:28:47 Informational ppp [wan_link0]   MAGICNUM 0x662d1e4b
2024-08-26T09:28:47 Informational ppp [wan_link0]   AUTHPROTO PAP
2024-08-26T09:28:47 Informational ppp [wan_link0]   MRU 1492
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: rec'd Configure Request #29 (Req-Sent)
2024-08-26T09:28:47 Informational ppp [wan_link0]   MAGICNUM 0xfafe8371
2024-08-26T09:28:47 Informational ppp [wan_link0]   MRU 1492
2024-08-26T09:28:47 Informational ppp [wan_link0]   PROTOCOMP
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: SendConfigReq #6
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: state change Starting --> Req-Sent
2024-08-26T09:28:47 Informational ppp [wan_link0] LCP: Up event
2024-08-26T09:28:47 Informational ppp [wan_link0] Link: UP event
2024-08-26T09:28:47 Informational ppp [wan_link0] PPPoE: connection successful
2024-08-26T09:28:47 Informational ppp PPPoE: rec'd ACNAME "LANJ01"
2024-08-26T09:28:47 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:28:47 Informational ppp [wan_link0] Link: reconnection attempt 9
2024-08-26T09:28:46 Informational ppp [wan_link0] Link: reconnection attempt 9 in 1 seconds
2024-08-26T09:28:46 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:28:46 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:28:46 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-08-26T09:28:37 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:28:37 Informational ppp [wan_link0] Link: reconnection attempt 8
2024-08-26T09:28:35 Informational ppp [wan_link0] Link: reconnection attempt 8 in 2 seconds
2024-08-26T09:28:35 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:28:35 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:28:35 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-08-26T09:28:26 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:28:26 Informational ppp [wan_link0] Link: reconnection attempt 7
2024-08-26T09:28:24 Informational ppp [wan_link0] Link: reconnection attempt 7 in 2 seconds
2024-08-26T09:28:24 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:28:24 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:28:24 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-08-26T09:28:15 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:28:15 Informational ppp [wan_link0] Link: reconnection attempt 6
2024-08-26T09:28:11 Informational ppp [wan_link0] Link: reconnection attempt 6 in 4 seconds
2024-08-26T09:28:11 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:28:11 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:28:11 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-08-26T09:28:02 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:28:02 Informational ppp [wan_link0] Link: reconnection attempt 5
2024-08-26T09:27:58 Informational ppp [wan_link0] Link: reconnection attempt 5 in 4 seconds
2024-08-26T09:27:58 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:27:58 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:27:58 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-08-26T09:27:49 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:27:49 Informational ppp [wan_link0] Link: reconnection attempt 4
2024-08-26T09:27:48 Informational ppp [wan_link0] Link: reconnection attempt 4 in 1 seconds
2024-08-26T09:27:48 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:27:48 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:27:48 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-08-26T09:27:39 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:27:39 Informational ppp [wan_link0] Link: reconnection attempt 3
2024-08-26T09:27:37 Informational ppp [wan_link0] Link: reconnection attempt 3 in 2 seconds
2024-08-26T09:27:37 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:27:37 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:27:37 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-08-26T09:27:28 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:27:28 Informational ppp [wan_link0] Link: reconnection attempt 2
2024-08-26T09:27:27 Informational ppp [wan_link0] Link: reconnection attempt 2 in 1 seconds
2024-08-26T09:27:27 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:27:27 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:27:27 Informational ppp [wan_link0] PPPoE connection timeout after 9 seconds
2024-08-26T09:27:18 Informational ppp [wan_link0] PPPoE: Connecting to ''
2024-08-26T09:27:18 Informational ppp [wan_link0] Link: reconnection attempt 1
2024-08-26T09:27:16 Informational ppp [wan_link0] Link: reconnection attempt 1 in 2 seconds
2024-08-26T09:27:16 Informational ppp [wan_link0] LCP: LayerStart
2024-08-26T09:27:16 Informational ppp [wan_link0] LCP: state change Stopped --> Starting
2024-08-26T09:27:16 Informational ppp [wan_link0] LCP: Down event
2024-08-26T09:27:16 Informational ppp [wan_link0] Link: DOWN event
2024-08-26T09:27:16 Informational ppp [wan_link0] PPPoE: connection closed
2024-08-26T09:27:16 Informational ppp [wan_link0] LCP: LayerFinish
2024-08-26T09:27:16 Informational ppp [wan_link0] LCP: state change Stopping --> Stopped
2024-08-26T09:27:14 Informational ppp [wan_link0] LCP: SendTerminateReq #5
2024-08-26T09:27:12 Informational ppp [wan_link0] LCP: LayerDown
2024-08-26T09:27:12 Informational ppp [wan_link0] LCP: SendTerminateReq #4
2024-08-26T09:27:12 Informational ppp [wan] IPCP: state change Closing --> Initial
2024-08-26T09:27:12 Informational ppp [wan] Bundle: No NCPs left. Closing links...
2024-08-26T09:27:12 Informational ppp [wan] IPCP: LayerFinish
2024-08-26T09:27:12 Informational ppp [wan] IPCP: Down event
2024-08-26T09:27:12 Informational ppp [wan] IFACE: Rename interface pppoe0 to pppoe0
2024-08-26T09:27:12 Informational ppp [wan] IFACE: Down event
2024-08-26T09:27:11 Informational ppp [wan] IPCP: LayerDown
2024-08-26T09:27:11 Informational ppp [wan] IPCP: SendTerminateReq #8
2024-08-26T09:27:11 Informational ppp [wan] IPCP: state change Opened --> Closing
2024-08-26T09:27:11 Informational ppp [wan] IPCP: Close event
2024-08-26T09:27:11 Informational ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
2024-08-26T09:27:11 Informational ppp [wan_link0] Link: Leave bundle "wan"
2024-08-26T09:27:11 Informational ppp [wan_link0] LCP: state change Opened --> Stopping
2024-08-26T09:27:11 Informational ppp [wan_link0] LCP: peer not responding to echo requests
2024-08-26T09:27:11 Informational ppp [wan_link0] LCP: no reply to 5 echo request(s)
2024-08-26T09:27:01 Informational ppp [wan_link0] LCP: no reply to 4 echo request(s)
2024-08-26T09:26:51 Informational ppp [wan_link0] LCP: no reply to 3 echo request(s)
2024-08-26T09:26:41 Informational ppp [wan_link0] LCP: no reply to 2 echo request(s)
2024-08-26T09:26:31 Informational ppp [wan_link0] LCP: no reply to 1 echo request(s)