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

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.

Hi,

first: Welcome to the IPFire community. :slight_smile:

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

1 Like

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.

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… :expressionless:

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

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

Hi,

welcome to the IPFire community. :slight_smile:

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. :slight_smile: 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. :slight_smile:

Thanks, and best regards,
Peter MĂĽller

1 Like

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.

2 Likes

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. :expressionless:

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

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.”

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

Hi all,

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

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:

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. :slight_smile: 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. :slight_smile:

(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

3 Likes

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

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

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

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

1 Like

Hi Steve,

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

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. :slight_smile:

Thanks, and best regards,
Peter MĂĽller