Core Update 157: pppd tries to fetch an IPv6 configuration despite it shouldn't, causing dial-up connections to be terminated by some ISPs

racerock · 22 June 2021 13:00

On three separate systems 1 virtual 2 real, post the upgrade and its restart the PPPOE connections cycles on and off stays connected for some seconds then reconnects.

pmueller · 22 June 2021 14:44

Hi,

first: Welcome to the IPFire community.

Second: pppd, the piece of software doing PPPoE dial-up, has been updated in Core Update 157.
Please refer to this commit and the release note for further information.

Third: Please provide us detailed information, log messages, etc. Simply stating “xyz does not work”
is unfortunately way too little information to start debugging. Also, if you are reasonably sure you discovered
an actual bug, please file a bug report at https://bugzilla.ipfire.org/ (your login credentials work there
as well). Please refer to this wiki page for information on how
to deal with Bugzilla, and how to write good bug reports.

Thanks, and best regards,
Peter Müller

racerock · 23 June 2021 04:46

Thanks for your speedy reply:
I have attached the details from the first system that hit this issue and is still running the new version 157:
("I would like to follow on by saying from yesterday I did a full shutdown of both Firewall hardware and modem router, then a power back on and so far everything would appear to be normal, including a scheduled overnight restart" )
But to help others plan and especially if like many of mine the system is remote and causes this issue and or in case there is more to it as we are less than 24 hours in etc…
BTW this connection is not IPV6 capable form ISP but my other sites that displayed similar issues do have ipv6 available does the new PPPd 2.49 try and get an assignment or is it ignored ?

Hardware:
Fireinfo fireinfo.ipfire.org - Profile 142aba0c064ba7f3c7a6bdedd744232b776fcb24
The Red Interface uses TP Link PCI-e add-on card based on R8169

The Modem router varied from site to site but this is a speedport Entry 2i ( Otenet telecom provided)
Note this and the other sites that displayed the same issues the connection uses a single static IP assigned from provider ( Hidden for obvious reasons)

You will see from below log at about 09:45 I did the upgrade and the system was sent for reboot and closed the connection i assume as it should after being connected 20 hours or so:
Upon the restart post upgrade you can see the endless connection / disconnection

09:48:50	pppd[5157]:	Modem hangup
09:48:50	pppd[5157]:	Sent 0 bytes, received 4 bytes.
09:48:50	pppd[5157]:	Connect time 0.0 minutes.
09:48:50	pppd[5157]:	IPCP terminated by peer
09:48:50	pppd[5157]:	secondary DNS address 195.170.0.1
09:48:50	pppd[5157]:	primary DNS address 212.205.212.205
09:48:50	pppd[5157]:	remote IP address XX.XX.XX.XX
09:48:50	pppd[5157]:	local IP address XX.XX.XX.XX
09:48:50	pppd[5157]:	peer from calling number E0:AC:F1:2B:2F:44 authorized
09:48:50	pppd[5157]:	PAP authentication succeeded
09:48:50	pppd[5157]:	Connect: ppp0 <–> red0
09:48:50	pppd[5157]:	Using interface ppp0
09:48:50	pppd[5157]:	Connected to e0:ac:f1:2b:2f:44 via interface red0
09:48:50	pppd[5157]:	PPP session is 8343
09:48:44	pppd[5157]:	pppd 2.4.9 started by root, uid 0
09:48:44	pppd[5157]:	PPPoE plugin from pppd 2.4.9
09:48:44	pppd[5157]:	Plugin rp-pppoe.so loaded.
09:48:43	pppd[4035]:	Exit.
09:48:32	pppd[4035]:	Connection terminated.
09:48:32	pppd[4035]:	Modem hangup
09:48:32	pppd[4035]:	Sent 0 bytes, received 4 bytes.
09:48:32	pppd[4035]:	Connect time 0.0 minutes.
09:48:32	pppd[4035]:	IPCP terminated by peer
09:48:32	pppd[4035]:	secondary DNS address 195.170.0.1
09:48:32	pppd[4035]:	primary DNS address 212.205.212.205
09:48:32	pppd[4035]:	remote IP address XX.XX.XX.XX
09:48:32	pppd[4035]:	local IP address XX.XX.XX.XX
09:48:32	pppd[4035]:	peer from calling number E0:AC:F1:2B:2F:44 authorized
09:48:32	pppd[4035]:	PAP authentication succeeded
09:48:31	pppd[4035]:	Connect: ppp0 <–> red0
09:48:31	pppd[4035]:	Using interface ppp0
09:48:31	pppd[4035]:	Connected to e0:ac:f1:2b:2f:44 via interface red0
09:48:31	pppd[4035]:	PPP session is 8338
09:48:26	pppd[4035]:	pppd 2.4.9 started by root, uid 0
09:48:26	pppd[4035]:	PPPoE plugin from pppd 2.4.9
09:48:26	pppd[4035]:	Plugin rp-pppoe.so loaded.
09:48:24	pppd[2923]:	Exit.
09:48:14	pppd[2923]:	Connection terminated.
09:48:14	pppd[2923]:	Modem hangup
09:48:14	pppd[2923]:	Sent 0 bytes, received 4 bytes.
09:48:14	pppd[2923]:	Connect time 0.0 minutes.
09:48:14	pppd[2923]:	IPCP terminated by peer
09:48:14	pppd[2923]:	secondary DNS address 195.170.0.1
09:48:14	pppd[2923]:	primary DNS address 212.205.212.205
09:48:14	pppd[2923]:	remote IP address XX.XX.XX.XX
09:48:14	pppd[2923]:	local IP address XX.XX.XX.XX
09:48:14	pppd[2923]:	peer from calling number E0:AC:F1:2B:2F:44 authorized
09:48:14	pppd[2923]:	PAP authentication succeeded
09:48:14	pppd[2923]:	Connect: ppp0 <–> red0
09:48:14	pppd[2923]:	Using interface ppp0
09:48:14	pppd[2923]:	Connected to e0:ac:f1:2b:2f:44 via interface red0
09:48:14	pppd[2923]:	PPP session is 8333
09:48:09	pppd[2923]:	pppd 2.4.9 started by root, uid 0
09:48:09	pppd[2923]:	PPPoE plugin from pppd 2.4.9
09:48:09	pppd[2923]:	Plugin rp-pppoe.so loaded.
09:48:07	pppd[1561]:	Exit.
09:47:54	pppd[1561]:	Connection terminated.
09:47:54	pppd[1561]:	Modem hangup
09:47:54	pppd[1561]:	Sent 0 bytes, received 4 bytes.
09:47:54	pppd[1561]:	Connect time 0.0 minutes.
09:47:54	pppd[1561]:	IPCP terminated by peer
09:47:54	pppd[1561]:	secondary DNS address 195.170.0.1
09:47:54	pppd[1561]:	primary DNS address 212.205.212.205
09:47:54	pppd[1561]:	remote IP address XX.XX.XX.XX
09:47:54	pppd[1561]:	local IP address XX.XX.XX.XX
09:47:54	pppd[1561]:	peer from calling number E0:AC:F1:2B:2F:44 authorized
09:47:54	pppd[1561]:	PAP authentication succeeded
09:47:54	pppd[1561]:	Connect: ppp0 <–> red0
09:47:54	pppd[1561]:	Using interface ppp0
09:47:54	pppd[1561]:	Connected to e0:ac:f1:2b:2f:44 via interface red0
09:47:54	pppd[1561]:	PPP session is 8329
09:47:48	pppd[1561]:	pppd 2.4.9 started by root, uid 0
09:47:48	pppd[1561]:	PPPoE plugin from pppd 2.4.9
09:47:48	pppd[1561]:	Plugin rp-pppoe.so loaded.
09:46:43	pppd[1584]:	Exit.
09:46:42	pppd[1584]:	Sent PADT
09:46:42	pppd[1584]:	error sending pppoe packet: Network is down
09:46:42	pppd[1584]:	Connection terminated.
09:46:42	pppd[1584]:	Sent 190358100 bytes, received 1544598976 bytes.
09:46:42	pppd[1584]:	Connect time 1224.0 minutes.
09:46:42	pppd[1584]:	Modem hangup

Normal connection now observed post full shutdown of router and firewall… and then an early morning scheduled restart: I notice however an extra line from previous refering to IPV6?? “|06:02:09|pppd[1560]: |IPV6CP: timeout sending Config-Requests|”

06:02:09	pppd[1560]:	IPV6CP: timeout sending Config-Requests
06:01:38	pppd[1560]:	secondary DNS address 195.170.0.1
06:01:38	pppd[1560]:	primary DNS address 212.205.212.205
06:01:38	pppd[1560]:	remote IP address xx.xx.xx.xx
06:01:38	pppd[1560]:	local IP address xx.xx.xx.xx
06:01:38	pppd[1560]:	peer from calling number E0:AC:F1:2B:2F:44 authorized
06:01:38	pppd[1560]:	PAP authentication succeeded
06:01:38	pppd[1560]:	Connect: ppp0 <–> red0
06:01:38	pppd[1560]:	Using interface ppp0
06:01:38	pppd[1560]:	Connected to e0:ac:f1:2b:2f:44 via interface red0
06:01:38	pppd[1560]:	PPP session is 23660
06:01:32	pppd[1560]:	pppd 2.4.9 started by root, uid 0
06:01:32	pppd[1560]:	PPPoE plugin from pppd 2.4.9
06:01:32	pppd[1560]:	Plugin rp-pppoe.so loaded.
06:00:26	pppd[1560]:	Exit.
06:00:25	pppd[1560]:	Connection terminated.
06:00:25	pppd[1560]:	Sent 176661876 bytes, received 2004436070 bytes.
06:00:25	pppd[1560]:	Connect time 1204.1 minutes.
06:00:25	pppd[1560]:	Terminating on signal 15

Br Ian.

pmueller · 25 June 2021 11:16

Hi,

thanks for your detailed reply.

09:47:54 pppd[1561]: IPCP terminated by peer

Hm, this looks like somehow your ISP terminates the connection right after having established it.
Some ISPs used to ratelimit PPPoE logins, but I have not seen that for a long time. Also, they would/should
not terminate connections after a successful (!) authentication.

06:02:09 pppd[1560]: IPV6CP: timeout sending Config-Requests

This is odd indeed…

Since we do not yet know why your ISP is terminating the connection, could you please enable debugging
(please refer to this wiki page for further information) and provide us with the debug log the next time this happens?

Thanks in advance, and best regards,
Peter Müller

grantm · 30 June 2021 21:56

Hi,
I can confirm exactly the same behavior.
IPFire failed after the upgrade to 157 with PPPoE connecting then disconnecting after about 3 seconds - this repeating over and over. This is on hardware that has been running IPFire for several years with no issues (until now). A new IPFire 157 install on the same hardware behaves the same.
IPFire 151 on another machine is working fine - I don’t want to update it.
Many thanks,
Grant

pmueller · 1 July 2021 06:49

Hi,

welcome to the IPFire community.

As mentioned above, could you please enable dial-up debugging and post the pppd logs here?

Well, this might not be convincing at the moment, but we are doing security here, and not installing updates kind of contradicts that. If you can, please help us testing new Core Updates in your environments, and report bugs you find.

That way, we can stomp them before releasing an update.

Thanks, and best regards,
Peter Müller

racerock · 1 July 2021 07:06

From my side I can confirm that clean installs would appear to be fine.
As I detailed above an upgraded install is fine once a full shutdown of router (left router off for 5mins to clear its connection with my ISP, and then restart ipfire once this is done then connection appears to be working without any issues.
From my testing… (only) during upgrade Its almost like isp thinks the ipfire is still connected after the upgrade and its reboot ipfire comes back with a different version of the dialer and won’t connect.
On one of my upgrades I just left it and after about 5 min of connect and disconnects finally it remained connected and from then on no issues works as expected.

pmueller · 1 July 2021 09:17

Hi,

well, so we are dealing with at least one problem that might or might not occur after a fresh install of Core Update 157.

Given the information I have at hand, I unfortunately do not see any way of digging deeper into this. Should this problem occur again or continue to occur, please provide detailed debug (!) logs here.

Thanks, and best regards,
Peter Müller

blighty_ex_pat · 1 July 2021 15:32

Same issues here with BT fibre to home. All updates fine until Core 157 update. Connects only momentarily, IP address assigned, then disconnects.

23:02:09 pppd[6500]: Plugin rp-pppoe.so loaded.
23:02:09 pppd[6500]: PPPoE plugin from pppd 2.4.9
23:02:09 pppd[6500]: pppd 2.4.9 started by root, uid 0
23:02:14 pppd[6500]: PPP session is 5084
23:02:14 pppd[6500]: Connected to a4:7b:2c:10:39:6d via interface red0
23:02:14 pppd[6500]: Using interface ppp0
23:02:14 pppd[6500]: Connect: ppp0 <–> red0
23:02:15 pppd[6500]: CHAP authentication succeeded: CHAP authentication success
23:02:15 pppd[6500]: CHAP authentication succeeded
23:02:15 pppd[6500]: peer from calling number A4:7B:2C:10:39:6D authorized
23:02:15 pppd[6500]: sif6addr: ioctl(SIOCSIFADDR): Permission denied (line 2986)
23:02:15 pppd[6500]: cif6addr: ioctl(SIOCDIFADDR): No such address
23:02:15 pppd[6500]: local IP address 86.144.21.9
23:02:15 pppd[6500]: remote IP address 172.16.15.29
23:02:15 pppd[6500]: primary DNS address 81.139.56.100
23:02:15 pppd[6500]: secondary DNS address 81.139.57.100
23:02:15 pppd[6500]: LCP terminated by peer
23:02:15 pppd[6500]: Connect time 0.0 minutes.
23:02:15 pppd[6500]: Sent 0 bytes, received 40 bytes.
23:02:15 pppd[6500]: Modem hangup
23:02:15 pppd[6500]: Connection terminated.
23:02:24 pppd[6500]: Exit.

Finally managed to reinstal to Core 154 and all is fine, again.

Obviously reluctant to update back to 157 at the moment.

“Notice: There is an core-update from 154 to 157 available.”

grantm · 2 July 2021 01:14

From /var/log/messages …

Jul 2 12:45:16 ipfire pppd[8104]: rcvd [CHAP Success id=0x1 “CHAP authentication success”]
Jul 2 12:45:16 ipfire pppd[8104]: CHAP authentication succeeded: CHAP authentication success
Jul 2 12:45:16 ipfire pppd[8104]: CHAP authentication succeeded
Jul 2 12:45:16 ipfire pppd[8104]: peer from calling number E4:81:84:10:F8:21 authorized
Jul 2 12:45:16 ipfire pppd[8104]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jul 2 12:45:16 ipfire pppd[8104]: sent [IPV6CP ConfReq id=0x1 ]
Jul 2 12:45:16 ipfire pppd[8104]: rcvd [IPCP ConfReq id=0x1e <addr 114.23.3.255>]
Jul 2 12:45:16 ipfire pppd[8104]: sent [IPCP ConfAck id=0x1e <addr 114.23.3.255>]
Jul 2 12:45:16 ipfire pppd[8104]: rcvd [IPV6CP ConfReq id=0x5c ]
Jul 2 12:45:16 ipfire pppd[8104]: sent [IPV6CP ConfAck id=0x5c ]
Jul 2 12:45:16 ipfire pppd[8104]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 114.23.1.1> <ms-dns2 114.23.2.2>]
Jul 2 12:45:16 ipfire pppd[8104]: sent [IPCP ConfReq id=0x2 <ms-dns1 114.23.1.1> <ms-dns2 114.23.2.2>]
Jul 2 12:45:16 ipfire pppd[8104]: rcvd [IPV6CP ConfAck id=0x1 ]
Jul 2 12:45:16 ipfire pppd[8104]: sif6addr: ioctl(SIOCSIFADDR): Permission denied (line 2986)
Jul 2 12:45:16 ipfire pppd[8104]: sif6addr failed
Jul 2 12:45:16 ipfire pppd[8104]: cif6addr: ioctl(SIOCDIFADDR): No such address
Jul 2 12:45:16 ipfire pppd[8104]: sent [IPV6CP TermReq id=0x2 “Interface configuration failed”]
Jul 2 12:45:16 ipfire pppd[8104]: rcvd [IPCP ConfAck id=0x2 <ms-dns1 114.23.1.1> <ms-dns2 114.23.2.2>]
Jul 2 12:45:16 ipfire pppd[8104]: local IP address xxx.xxx.xxx.xxx
Jul 2 12:45:16 ipfire pppd[8104]: remote IP address xxx.xxx.xxx.xxx
Jul 2 12:45:16 ipfire pppd[8104]: primary DNS address 114.23.1.1
Jul 2 12:45:16 ipfire pppd[8104]: secondary DNS address 114.23.2.2
Jul 2 12:45:16 ipfire pppd[8104]: Script /etc/ppp/ip-up started (pid 8166)
Jul 2 12:45:16 ipfire pppd[8104]: rcvd [LCP TermReq id=0xf3]
Jul 2 12:45:16 ipfire pppd[8104]: LCP terminated by peer
Jul 2 12:45:16 ipfire pppd[8104]: Connect time 0.0 minutes.
Jul 2 12:45:16 ipfire pppd[8104]: Sent 0 bytes, received 4 bytes.
Jul 2 12:45:16 ipfire pppd[8104]: sent [LCP TermAck id=0xf3]
Jul 2 12:45:16 ipfire pppd[8104]: rcvd [IPV6CP TermAck id=0x2]
Jul 2 12:45:16 ipfire pppd[8104]: Discarded non-LCP packet when LCP not open
Jul 2 12:45:16 ipfire pppd[8104]: Modem hangup
Jul 2 12:45:16 ipfire pppd[8104]: Connection terminated.

Modem is a Draytek Vigor130 using 1483 Bridged IP (IPoE)

I note that the WAN 1 IPV6 Internet Access Mode on the modem is set to Offline (choices are Offline, PPP, TSPC, AICCU, DHCPv6 Client, 6in4 Static Channel, 6rd).

I don’t know if this is relevant.

Many thanks,
Grant

pmueller · 2 July 2021 10:53

Hi all,

thank you for providing logs (“The logs, the logs. All the answers are in the logs.” - Wietse Venema).

Apparently, the updated version of pppd tries to get an IPv6 configuration during the dial-up procedure, too. Some ISPs already assign IPv6 addresses to their customers, but since IPv6 is disabled in IPFire 2.x kernel, pppd fails to configure it:

grantm:

Jul 2 12:45:16 ipfire pppd[8104]: sif6addr: ioctl(SIOCSIFADDR): Permission denied (line 2986)
Jul 2 12:45:16 ipfire pppd[8104]: sif6addr failed
Jul 2 12:45:16 ipfire pppd[8104]: cif6addr: ioctl(SIOCDIFADDR): No such address
Jul 2 12:45:16 ipfire pppd[8104]: sent [IPV6CP TermReq id=0x2 “Interface configuration failed”]

The last line is interesting: It tells the ISP that it could not configure IPv6 properly. As an ISP, I would choose to ignore such events (maybe count them for statistical/network engineering purposes), but in case of BT, it looks like the ISP is shutting down the connection afterwards:

So, the root cause of this is pppd attempting to obtain an IPv6 configuration despite it shouldn’t - I will open up a bug later, and work on this.

EDIT: Done, please refer to bug #12651.

At least German DTAG behaves more fault-tolerant here - we have a lot of IPFire users sitting in their networks, and would have heard of if we broke all their setups. Either way, some ISPs in the world seem to handle this more strict on purpose or by chance, so it is somewhat of a combined issue.

Since my ISP does not support IPv6, yet: Could I eventually rely on you folks to test solutions before we release them? That would be very helpful.

(And to overcome the question: Yes, we know it’s 2021, and IPFire 2.x does not support IPv6 out of the box yet. Last year was 2020, where we didn’t either. Yes, we certainly will support IPv6 in the future, but for the moment, we simply lack resources to implement it in a secure manner.)

Thanks, and best regards,
Peter Müller

grantm · 3 July 2021 02:14

Thank you very much. It is great to get some clarification. I will look at enabling the Core Updates testing.

Has IPFire 157 had pppd changed back to the older release yet? Looking forward to upgrading.

Many thanks,
Grant

pmueller · 3 July 2021 07:10

Hi,

yes, @ms reverted the pppd update, see this and this commit.

Users who already have Core Update 157 installed will stay with pppd 2.4.9, though. Since Core Update 158 is already available for testing, it will probably take until Core Update 159 until we finally ship a corrected version of pppd 2.4.9 again.

Will keep you informed here. For technical details, please refer to Bugzilla.

Thanks, and best regards,
Peter Müller

pmueller · 13 July 2021 19:45

Hi all,

may I ask those of you who observed this problem after upgrading to Core Update 157 to test a (hopefully fixed) version of pppd and the corresponding initscript?

Please refer to the mailing list below for information on how to do so, and report back here or in Bugzilla.

https://lists.ipfire.org/pipermail/development/2021-July/010794.html

Thank you very much in advance for doing so.

Thanks, and best regards,
Peter Müller

blighty_ex_pat · 14 July 2021 18:43

OK, Peter…

Not really sufficiently experienced to test your modified version of pppd, but persevered and managed to successfully follow your comprehensive guidance notes!

I can report that there are no references to IPV6CP in the logs and that my IPFire is running OK with pppd version 2.4.9

[root@ipfire ~]# /usr/sbin/pppd --version
pppd version 2.4.9
[root@ipfire ~]# /etc/rc.d/init.d/network start red
Bringing up the red0 interface…
Bringing up the pppoe interface on red0 … [ OK ]
Starting connection daemon… [ OK ]
RTNETLINK answers: No such file or directory
Adding static routes… [ OK ]
Adding static routes… [ OK ]
Mounting network file systems… [ OK ]
[root@ipfire ~]# ps aux | grep pppd | grep noipv6
root 30766 0.0 0.1 7300 3496 pts/0 S 19:29 0:00 /usr/sbin/pppd plugin rp-pppoe.so red0 usepeerdns defaultroute noipdefault noauth default-asyncmap hide-password nodetach noipv6 noaccomp nodeflate nopcomp novj novjccomp nobsdcomp user bthomehub@btbroadband.com lcp-echo-interval 20 lcp-echo-failure 5 mtu 1492 mru 1492
[root@ipfire ~]#

Am I correct to assume that I can apply the normal update, from my current Core 156 to 158 or 159 when they are released, and avoid 157 for the time being?

Hope this makes sense and helps you?
Kind Rgds
Steve

pmueller · 15 July 2021 17:35

Hi Steve,

thank you for reporting back. Glad to know things work as intended.

Since the ppp change has been reverted very soon after releasing Core Update 157 as mentioned above, you can safely update to it without risking your internet connection to become unstable due to this bug.

The fixed update to ppp 2.4.9 won’t make it into Core Update 158, which is already finalised and available for testing. So Core Update 159 is it, then.

Thanks, and best regards,
Peter Müller

hjkl · 17 August 2021 18:46

Just giving a try: core 158, pppd 2.4.8 frequently loses connection (day or night - I specify this to exclude problems generated by extreme heat we had these days that melt everything)
Logs: as you can see time varies a lot between disconnects and the only constant thing is “No response to 5 echo-requests”
I checked cables - all seems ok.
my ISP is not IPV6 capable…
These happen after upgrade to c158 from c156…

/usr/sbin/pppd --version
pppd version 2.4.8
[root@silver-x86-64 ~]# grep pppd /var/log/messages | grep -C 7 ‘rp-pppoe.so’
Aug 15 20:40:13 silver-x86-64 pppd[16400]: No response to 5 echo-requests
Aug 15 20:40:13 silver-x86-64 pppd[16400]: Serial link appears to be disconnected.
Aug 15 20:40:13 silver-x86-64 pppd[16400]: Connect time 22749.1 minutes.
Aug 15 20:40:13 silver-x86-64 pppd[16400]: Sent 259886995 bytes, received 1818073421 bytes.
Aug 15 20:40:13 silver-x86-64 pppd[16400]: Connection terminated.
Aug 15 20:40:13 silver-x86-64 pppd[16400]: Sent PADT
Aug 15 20:40:50 silver-x86-64 pppd[16400]: Exit.
Aug 15 20:40:52 silver-x86-64 pppd[23933]: Plugin rp-pppoe.so loaded.
Aug 15 20:40:52 silver-x86-64 pppd[23933]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 15 20:40:52 silver-x86-64 pppd[23933]: pppd 2.4.8 started by root, uid 0
Aug 15 20:41:09 silver-x86-64 pppd[23933]: PPP session is 2235
Aug 15 20:41:09 silver-x86-64 pppd[23933]: Connected to a4:00:e2:d2:0e:cd via interface red0
Aug 15 20:41:09 silver-x86-64 pppd[23933]: Using interface ppp0
Aug 15 20:41:09 silver-x86-64 pppd[23933]: Connect: ppp0 ↔ red0
Aug 15 20:41:12 silver-x86-64 pppd[23933]: PAP authentication succeeded

Aug 15 21:06:53 silver-x86-64 pppd[23933]: No response to 5 echo-requests
Aug 15 21:06:53 silver-x86-64 pppd[23933]: Serial link appears to be disconnected.
Aug 15 21:06:53 silver-x86-64 pppd[23933]: Connect time 25.7 minutes.
Aug 15 21:06:53 silver-x86-64 pppd[23933]: Sent 5744881 bytes, received 526513996 bytes.
Aug 15 21:06:53 silver-x86-64 pppd[23933]: Connection terminated.
Aug 15 21:06:53 silver-x86-64 pppd[23933]: Sent PADT
Aug 15 21:07:31 silver-x86-64 pppd[23933]: Exit.
Aug 15 21:07:32 silver-x86-64 pppd[29768]: Plugin rp-pppoe.so loaded.
Aug 15 21:07:32 silver-x86-64 pppd[29768]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 15 21:07:32 silver-x86-64 pppd[29768]: pppd 2.4.8 started by root, uid 0
Aug 15 21:07:39 silver-x86-64 pppd[29768]: PPP session is 5079
Aug 15 21:07:39 silver-x86-64 pppd[29768]: Connected to 1c:20:db:b0:ac:37 via interface red0
Aug 15 21:07:39 silver-x86-64 pppd[29768]: Using interface ppp0
Aug 15 21:07:39 silver-x86-64 pppd[29768]: Connect: ppp0 ↔ red0
Aug 15 21:07:42 silver-x86-64 pppd[29768]: PAP authentication succeeded

Aug 16 04:19:17 silver-x86-64 pppd[29768]: No response to 5 echo-requests
Aug 16 04:19:17 silver-x86-64 pppd[29768]: Serial link appears to be disconnected.
Aug 16 04:19:17 silver-x86-64 pppd[29768]: Connect time 431.6 minutes.
Aug 16 04:19:17 silver-x86-64 pppd[29768]: Sent 24324551 bytes, received 1880741843 bytes.
Aug 16 04:19:20 silver-x86-64 pppd[29768]: Connection terminated.
Aug 16 04:19:20 silver-x86-64 pppd[29768]: Sent PADT
Aug 16 04:19:55 silver-x86-64 pppd[29768]: Exit.
Aug 16 04:19:56 silver-x86-64 pppd[19561]: Plugin rp-pppoe.so loaded.
Aug 16 04:19:56 silver-x86-64 pppd[19561]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 16 04:19:56 silver-x86-64 pppd[19561]: pppd 2.4.8 started by root, uid 0
Aug 16 04:20:02 silver-x86-64 pppd[19561]: PPP session is 6541
Aug 16 04:20:02 silver-x86-64 pppd[19561]: Connected to ac:1f:6b:f8:6f:3f via interface red0
Aug 16 04:20:02 silver-x86-64 pppd[19561]: Using interface ppp0
Aug 16 04:20:02 silver-x86-64 pppd[19561]: Connect: ppp0 ↔ red0
Aug 16 04:20:05 silver-x86-64 pppd[19561]: PAP authentication succeeded

Aug 16 04:34:25 silver-x86-64 pppd[19561]: No response to 5 echo-requests
Aug 16 04:34:25 silver-x86-64 pppd[19561]: Serial link appears to be disconnected.
Aug 16 04:34:25 silver-x86-64 pppd[19561]: Connect time 14.4 minutes.
Aug 16 04:34:25 silver-x86-64 pppd[19561]: Sent 111879 bytes, received 230438 bytes.
Aug 16 04:34:28 silver-x86-64 pppd[19561]: Connection terminated.
Aug 16 04:34:28 silver-x86-64 pppd[19561]: Sent PADT
Aug 16 04:35:14 silver-x86-64 pppd[19561]: Exit.
Aug 16 04:35:16 silver-x86-64 pppd[25112]: Plugin rp-pppoe.so loaded.
Aug 16 04:35:16 silver-x86-64 pppd[25112]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 16 04:35:16 silver-x86-64 pppd[25112]: pppd 2.4.8 started by root, uid 0
Aug 16 04:35:21 silver-x86-64 pppd[25112]: PPP session is 4279
Aug 16 04:35:21 silver-x86-64 pppd[25112]: Connected to ac:1f:6b:f8:6f:3f via interface red0
Aug 16 04:35:21 silver-x86-64 pppd[25112]: Using interface ppp0
Aug 16 04:35:21 silver-x86-64 pppd[25112]: Connect: ppp0 ↔ red0
Aug 16 04:35:24 silver-x86-64 pppd[25112]: PAP authentication succeeded

Aug 16 14:25:06 silver-x86-64 pppd[25112]: No response to 5 echo-requests
Aug 16 14:25:06 silver-x86-64 pppd[25112]: Serial link appears to be disconnected.
Aug 16 14:25:06 silver-x86-64 pppd[25112]: Connect time 589.8 minutes.
Aug 16 14:25:06 silver-x86-64 pppd[25112]: Sent 106908345 bytes, received 1080772953 bytes.
Aug 16 14:25:10 silver-x86-64 pppd[25112]: Connection terminated.
Aug 16 14:25:10 silver-x86-64 pppd[25112]: Sent PADT
Aug 16 14:25:44 silver-x86-64 pppd[25112]: Exit.
Aug 16 14:25:46 silver-x86-64 pppd[17633]: Plugin rp-pppoe.so loaded.
Aug 16 14:25:46 silver-x86-64 pppd[17633]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 16 14:25:46 silver-x86-64 pppd[17633]: pppd 2.4.8 started by root, uid 0
Aug 16 14:25:53 silver-x86-64 pppd[17633]: PPP session is 2533
Aug 16 14:25:53 silver-x86-64 pppd[17633]: Connected to a4:00:e2:d2:0e:cd via interface red0
Aug 16 14:25:53 silver-x86-64 pppd[17633]: Using interface ppp0
Aug 16 14:25:53 silver-x86-64 pppd[17633]: Connect: ppp0 ↔ red0
Aug 16 14:25:56 silver-x86-64 pppd[17633]: PAP authentication succeeded

Aug 17 00:52:40 silver-x86-64 pppd[17633]: No response to 5 echo-requests
Aug 17 00:52:40 silver-x86-64 pppd[17633]: Serial link appears to be disconnected.
Aug 17 00:52:40 silver-x86-64 pppd[17633]: Connect time 626.8 minutes.
Aug 17 00:52:40 silver-x86-64 pppd[17633]: Sent 168829640 bytes, received 457535194 bytes.
Aug 17 00:52:43 silver-x86-64 pppd[17633]: Connection terminated.
Aug 17 00:52:43 silver-x86-64 pppd[17633]: Sent PADT
Aug 17 00:53:18 silver-x86-64 pppd[17633]: Exit.
Aug 17 00:53:19 silver-x86-64 pppd[11388]: Plugin rp-pppoe.so loaded.
Aug 17 00:53:19 silver-x86-64 pppd[11388]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 17 00:53:19 silver-x86-64 pppd[11388]: pppd 2.4.8 started by root, uid 0
Aug 17 00:53:26 silver-x86-64 pppd[11388]: PPP session is 4200
Aug 17 00:53:26 silver-x86-64 pppd[11388]: Connected to ac:1f:6b:f8:6f:3f via interface red0
Aug 17 00:53:26 silver-x86-64 pppd[11388]: Using interface ppp0
Aug 17 00:53:26 silver-x86-64 pppd[11388]: Connect: ppp0 ↔ red0
Aug 17 00:53:29 silver-x86-64 pppd[11388]: PAP authentication succeeded

Aug 17 01:24:30 silver-x86-64 pppd[11388]: No response to 5 echo-requests
Aug 17 01:24:30 silver-x86-64 pppd[11388]: Serial link appears to be disconnected.
Aug 17 01:24:30 silver-x86-64 pppd[11388]: Connect time 31.1 minutes.
Aug 17 01:24:30 silver-x86-64 pppd[11388]: Sent 3716062 bytes, received 172779791 bytes.
Aug 17 01:24:30 silver-x86-64 pppd[11388]: Connection terminated.
Aug 17 01:24:30 silver-x86-64 pppd[11388]: Sent PADT
Aug 17 01:25:08 silver-x86-64 pppd[11388]: Exit.
Aug 17 01:25:10 silver-x86-64 pppd[17718]: Plugin rp-pppoe.so loaded.
Aug 17 01:25:10 silver-x86-64 pppd[17718]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 17 01:25:10 silver-x86-64 pppd[17718]: pppd 2.4.8 started by root, uid 0
Aug 17 01:25:16 silver-x86-64 pppd[17718]: PPP session is 2156
Aug 17 01:25:16 silver-x86-64 pppd[17718]: Connected to ac:1f:6b:f8:6f:3f via interface red0
Aug 17 01:25:16 silver-x86-64 pppd[17718]: Using interface ppp0
Aug 17 01:25:16 silver-x86-64 pppd[17718]: Connect: ppp0 ↔ red0
Aug 17 01:25:19 silver-x86-64 pppd[17718]: PAP authentication succeeded

Aug 17 03:21:43 silver-x86-64 pppd[17718]: No response to 5 echo-requests
Aug 17 03:21:43 silver-x86-64 pppd[17718]: Serial link appears to be disconnected.
Aug 17 03:21:43 silver-x86-64 pppd[17718]: Connect time 116.4 minutes.
Aug 17 03:21:43 silver-x86-64 pppd[17718]: Sent 716167 bytes, received 859666 bytes.
Aug 17 03:21:43 silver-x86-64 pppd[17718]: Connection terminated.
Aug 17 03:21:43 silver-x86-64 pppd[17718]: Sent PADT
Aug 17 03:22:20 silver-x86-64 pppd[17718]: Exit.
Aug 17 03:22:22 silver-x86-64 pppd[26652]: Plugin rp-pppoe.so loaded.
Aug 17 03:22:22 silver-x86-64 pppd[26652]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 17 03:22:22 silver-x86-64 pppd[26652]: pppd 2.4.8 started by root, uid 0
Aug 17 03:22:28 silver-x86-64 pppd[26652]: PPP session is 1538
Aug 17 03:22:28 silver-x86-64 pppd[26652]: Connected to 1c:20:db:b0:b3:57 via interface red0
Aug 17 03:22:28 silver-x86-64 pppd[26652]: Using interface ppp0
Aug 17 03:22:28 silver-x86-64 pppd[26652]: Connect: ppp0 ↔ red0
Aug 17 03:22:31 silver-x86-64 pppd[26652]: PAP authentication succeeded

Aug 17 07:49:00 silver-x86-64 pppd[26652]: No response to 5 echo-requests
Aug 17 07:49:00 silver-x86-64 pppd[26652]: Serial link appears to be disconnected.
Aug 17 07:49:00 silver-x86-64 pppd[26652]: Connect time 266.5 minutes.
Aug 17 07:49:00 silver-x86-64 pppd[26652]: Sent 107198483 bytes, received 15302151 bytes.
Aug 17 07:49:03 silver-x86-64 pppd[26652]: Connection terminated.
Aug 17 07:49:03 silver-x86-64 pppd[26652]: Sent PADT
Aug 17 07:49:37 silver-x86-64 pppd[26652]: Exit.
Aug 17 07:49:39 silver-x86-64 pppd[8068]: Plugin rp-pppoe.so loaded.
Aug 17 07:49:39 silver-x86-64 pppd[8068]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 17 07:49:39 silver-x86-64 pppd[8068]: pppd 2.4.8 started by root, uid 0
Aug 17 07:49:45 silver-x86-64 pppd[8068]: PPP session is 1847
Aug 17 07:49:45 silver-x86-64 pppd[8068]: Connected to 1c:20:db:b0:ac:37 via interface red0
Aug 17 07:49:45 silver-x86-64 pppd[8068]: Using interface ppp0
Aug 17 07:49:45 silver-x86-64 pppd[8068]: Connect: ppp0 ↔ red0
Aug 17 07:49:51 silver-x86-64 pppd[8068]: PAP authentication succeeded

Aug 17 15:53:31 silver-x86-64 pppd[8068]: No response to 5 echo-requests
Aug 17 15:53:31 silver-x86-64 pppd[8068]: Serial link appears to be disconnected.
Aug 17 15:53:31 silver-x86-64 pppd[8068]: Connect time 483.7 minutes.
Aug 17 15:53:31 silver-x86-64 pppd[8068]: Sent 172479847 bytes, received 1151804395 bytes.
Aug 17 15:53:34 silver-x86-64 pppd[8068]: Connection terminated.
Aug 17 15:53:34 silver-x86-64 pppd[8068]: Sent PADT
Aug 17 15:54:09 silver-x86-64 pppd[8068]: Exit.
Aug 17 15:54:11 silver-x86-64 pppd[31660]: Plugin rp-pppoe.so loaded.
Aug 17 15:54:11 silver-x86-64 pppd[31660]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 17 15:54:11 silver-x86-64 pppd[31660]: pppd 2.4.8 started by root, uid 0
Aug 17 15:54:17 silver-x86-64 pppd[31660]: PPP session is 5611
Aug 17 15:54:17 silver-x86-64 pppd[31660]: Connected to a4:00:e2:d2:0e:cd via interface red0
Aug 17 15:54:17 silver-x86-64 pppd[31660]: Using interface ppp0
Aug 17 15:54:17 silver-x86-64 pppd[31660]: Connect: ppp0 ↔ red0
Aug 17 15:54:20 silver-x86-64 pppd[31660]: PAP authentication succeeded

Aug 17 16:26:42 silver-x86-64 pppd[31660]: No response to 5 echo-requests
Aug 17 16:26:42 silver-x86-64 pppd[31660]: Serial link appears to be disconnected.
Aug 17 16:26:42 silver-x86-64 pppd[31660]: Connect time 32.4 minutes.
Aug 17 16:26:42 silver-x86-64 pppd[31660]: Sent 9941850 bytes, received 45024073 bytes.
Aug 17 16:26:45 silver-x86-64 pppd[31660]: Connection terminated.
Aug 17 16:26:45 silver-x86-64 pppd[31660]: Sent PADT
Aug 17 16:27:20 silver-x86-64 pppd[31660]: Exit.
Aug 17 16:27:22 silver-x86-64 pppd[5358]: Plugin rp-pppoe.so loaded.
Aug 17 16:27:22 silver-x86-64 pppd[5358]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 17 16:27:22 silver-x86-64 pppd[5358]: pppd 2.4.8 started by root, uid 0
Aug 17 16:27:29 silver-x86-64 pppd[5358]: PPP session is 5374
Aug 17 16:27:29 silver-x86-64 pppd[5358]: Connected to 1c:20:db:b0:ac:37 via interface red0
Aug 17 16:27:29 silver-x86-64 pppd[5358]: Using interface ppp0
Aug 17 16:27:29 silver-x86-64 pppd[5358]: Connect: ppp0 ↔ red0
Aug 17 16:27:32 silver-x86-64 pppd[5358]: PAP authentication succeeded

Aug 17 18:02:36 silver-x86-64 pppd[5358]: No response to 5 echo-requests
Aug 17 18:02:36 silver-x86-64 pppd[5358]: Serial link appears to be disconnected.
Aug 17 18:02:36 silver-x86-64 pppd[5358]: Connect time 95.1 minutes.
Aug 17 18:02:36 silver-x86-64 pppd[5358]: Sent 26353071 bytes, received 145304026 bytes.
Aug 17 18:02:39 silver-x86-64 pppd[5358]: Connection terminated.
Aug 17 18:02:39 silver-x86-64 pppd[5358]: Sent PADT
Aug 17 18:03:14 silver-x86-64 pppd[5358]: Exit.
Aug 17 18:03:15 silver-x86-64 pppd[13594]: Plugin rp-pppoe.so loaded.
Aug 17 18:03:15 silver-x86-64 pppd[13594]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 17 18:03:16 silver-x86-64 pppd[13594]: pppd 2.4.8 started by root, uid 0
Aug 17 18:03:22 silver-x86-64 pppd[13594]: PPP session is 5623
Aug 17 18:03:22 silver-x86-64 pppd[13594]: Connected to 1c:20:db:b0:ac:37 via interface red0
Aug 17 18:03:22 silver-x86-64 pppd[13594]: Using interface ppp0
Aug 17 18:03:22 silver-x86-64 pppd[13594]: Connect: ppp0 ↔ red0
Aug 17 18:03:25 silver-x86-64 pppd[13594]: PAP authentication succeeded

Aug 17 19:03:08 silver-x86-64 pppd[13594]: No response to 5 echo-requests
Aug 17 19:03:08 silver-x86-64 pppd[13594]: Serial link appears to be disconnected.
Aug 17 19:03:08 silver-x86-64 pppd[13594]: Connect time 59.8 minutes.
Aug 17 19:03:08 silver-x86-64 pppd[13594]: Sent 37842792 bytes, received 55237441 bytes.
Aug 17 19:03:11 silver-x86-64 pppd[13594]: Connection terminated.
Aug 17 19:03:11 silver-x86-64 pppd[13594]: Sent PADT
Aug 17 19:03:46 silver-x86-64 pppd[13594]: Exit.
Aug 17 19:03:47 silver-x86-64 pppd[20625]: Plugin rp-pppoe.so loaded.
Aug 17 19:03:47 silver-x86-64 pppd[20625]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Aug 17 19:03:47 silver-x86-64 pppd[20625]: pppd 2.4.8 started by root, uid 0
Aug 17 19:03:54 silver-x86-64 pppd[20625]: PPP session is 9301
Aug 17 19:03:54 silver-x86-64 pppd[20625]: Connected to ac:1f:6b:f8:6f:3f via interface red0
Aug 17 19:03:54 silver-x86-64 pppd[20625]: Using interface ppp0
Aug 17 19:03:54 silver-x86-64 pppd[20625]: Connect: ppp0 ↔ red0
Aug 17 19:03:57 silver-x86-64 pppd[20625]: PAP authentication succeeded

arne_f · 18 August 2021 10:09

ppp 2.4.9 is not merged yet. (Not even for core160 yet)
are there any testreports that it now works?

arne_f · 18 August 2021 10:11

Looks like the line has lost the sync. In this case it need some time until the modem has reestablished the connection. IPFire has nothing to do with this error.

pmueller · 18 August 2021 18:52

Hi Arne,

yes, please see this post.

IMHO ppp 2.4.9 is ready for Core Update 160, but since you are in charge of this one, it’s up to you.

Thanks, and best regards,
Peter Müller