ppp
ppp copied to clipboard
ppp-project
Problem CHAP Challenge with PPP v2.5.0 or v2.5.1-dev
Hello,
For an embedded system using ppp v2.4.7 on a linux from scratch v4.14 base, this works without a hitch. For security reasons, we're migrating to linux from scratch v6.1 and ppp v2.5.1-dev.
With the same modem, the same configuration, the same SIM card, I encounter the following problem:
2024-06-14T10:52:56.761615+02:00 REDY: Script /usr/sbin/chat -f /etc/ppp/modem/chat-dialer-3G finished (pid 1791), status = 0x0
2024-06-14T10:52:56.761666+02:00 REDY: Serial connection established.
2024-06-14T10:52:56.761693+02:00 REDY: using channel 6
2024-06-14T10:52:56.764893+02:00 REDY: Using interface ppp0
2024-06-14T10:52:56.767072+02:00 REDY: Connect: ppp0 <--> /dev/ttymxc0
2024-06-14T10:52:56.774101+02:00 REDY: Warning - secret file /etc/ppp/pap-secrets has world and/or group access
2024-06-14T10:52:56.775690+02:00 REDY: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000>]
2024-06-14T10:52:56.789506+02:00 REDY: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000>]
2024-06-14T10:52:57.745536+02:00 REDY: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x52181044>
Here is the file /etc/ppp/chap-secrets
orange * orange *
when I delete the chap-secrets file it forces PAP authentication and the connection works again. As it is preferable to work in CHAP, I need to solve this problem.
2024-06-14T10:35:06.757817+02:00 REDY: Script /usr/sbin/chat -f /etc/ppp/modem/chat-dialer-3G finished (pid 1447), status = 0x0
2024-06-14T10:35:06.757866+02:00 REDY: Serial connection established.
2024-06-14T10:35:06.757892+02:00 REDY: using channel 4
2024-06-14T10:35:06.760979+02:00 REDY: Using interface ppp0
2024-06-14T10:35:06.762779+02:00 REDY: Connect: ppp0 <--> /dev/ttymxc0
2024-06-14T10:35:06.769482+02:00 REDY: Warning - secret file /etc/ppp/pap-secrets has world and/or group access
2024-06-14T10:35:06.771248+02:00 REDY: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000>]
2024-06-14T10:35:06.784789+02:00 REDY: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000>]
2024-06-14T10:35:07.740286+02:00 REDY: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x52181044>
the file /etc/ppp/pap-secrets is the same as /etc/ppp/chap-secrets
The pppd v2.5.0 has the same problem with different folder locations.
thank you for your help
Hello,
Information to help understand the problem: With pppd v2.4.9, the same configuration environment, the same compilation environment, the same libraries, the same modem, the same SIM card, it all works. I'll stick with this version.
The difference is clearly visible in the CHAP response :) I tried a search in the sources with no success. :(
2024-06-25T14:43:16.788297+02:00 REDY: Warning - secret file /etc/ppp/pap-secrets has world and/or group access
2024-06-25T14:43:16.791968+02:00 REDY: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000>]
2024-06-25T14:43:16.805727+02:00 REDY: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000>]
2024-06-25T14:43:17.739754+02:00 REDY: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x52181044>
@enaess any idea why we're sending such an enormously long CHAP response?
2024-06-14T10:52:57.801692+02:00 REDY: sent [CHAP Response id=0x1 <84ec7e00000000000000003b00000000000000161cd73a0000000038c0a67400bac779000d0000c0db877e09000000e44e060038c0a67468b3030028bda67400000000acdb877e4454437470da877e000d00003b0000000000000027100f00000000000000000000bac77984dd877ef4c60400c0db877e00000000288e2901c0db877ec4da877e0000000000000000000000000000000000000000000000000000000000000000000000000000000000>, name = "orange"]
I have no clue to why that clen would be anything but the 49 (decimal) for the response generated by pppd. If you look at the chap_respond function, it will setup the packet to be written, then call cs->digest->make_response() which will eventually call either chap_make_response (or chapms2_make_response -- and I note that the above output doesn't indicate what authentication the peer wants, lcp says asyncmap 0x00 or magic).
Both the make_response functions will either set the first field in the packet to be either MS_CHAP2_RESPONSE_LEN or MS_CHAP_RESPONSE_LEN which the field is only a byte wide. This field is used when calling dump_packet or format_packet in utils.c.
Given the fixed values for much of this, maybe the value is somehow overwritten by a memcpy or so during the ChapMS or ChapMS2 functions. Given that the reporter of the issue is on an embedded system, it could be useful to knowing the endianess of the system. However, I would almost advice the user to run the pppd in gdb and enable a breakpoint in chap_respond at where make_response is being called), then enable a watch on the memory of p[0]; it should only hit once when the length of the packet is being written, anytime later before returning could yield the culprit.
One thing strikes me as odd, in both the working (2.4.9) and non-working (2.5.x) cases: the peer apparently does not send an LCP Authentication-Protocol option in its LCP configure-request, yet it then requests authentication via a CHAP Challenge. Have the logs been edited to remove the authentication-protocol option? If not, then how does the peer know to do CHAP in the first case and PAP in the second?
If the logs have been edited, then please show us the full LCP negotiation so we can see what digest and other parameters are being requested. There is nothing sensitive in the LCP packets.
Hello,
for enaess, Your proposal is complicated to implement. I only use Hayes commands in a totally independent software, and the daemon PPP. How do you explain that v2.4.9 works correctly ?
for Paulusmack, The logs are full. The only change in the v2.4.9 example are the xxx in the IP address. By default, the connection is always made in CHAP without specifying anything. To obtain a PAP connection, I deleted the file /etc/ppp/chap-secrets.
thank you for your help.
If the logs haven't been edited, then it is completely unclear to me why pppd would have sent a PAP Auth-Req when no authentication was negotiated at the LCP stage.
Hello Paulusmack,
I confirm that the logs have not been modified.
I don't understand what “PAP Auth-Req” we're talking about. As the message is already some time old, I'll rephrase the problem. In CHAP authentication, the CHAP response is abnormally long. PAP tests are only done to demonstrate that the modem environment is correct. Thank you for your help.
Hello,
I have the exact (at least it appears to me like that) same issue on embedded system too (linux yocto) , the exact same setup works perfectly with ppp-2.4.9 and starts to break with ppp-2.5.0 . I also tried with the latest git revision. I noticed the difference about the "very long" CHAP response when it doesn't work.
My setup is with NetworkManager software which spawn and watch pppd. I notice that it doesn't always failed (after some retry , it started to work) . Below is a sequence of log where the CHAP failed (from 10:24:32 to 10:24:42) and we retry the sequence 5s after and it works (from 10:24:48 to 10:24:49):
Aug 19 10:24:32.873128 tap-0000C99B pppd[3225]: Plugin /usr/lib/pppd/2.5.1-dev/nm-pppd-plugin.so loaded.
Aug 19 10:24:32.877160 tap-0000C99B pppd[3225]: pppd 2.5.1-dev started by root, uid 0
Aug 19 10:24:32.897580 tap-0000C99B pppd[3225]: using channel 54
Aug 19 10:24:32.897731 tap-0000C99B pppd[3225]: Using interface ppp0
Aug 19 10:24:32.897793 tap-0000C99B pppd[3225]: Connect: ppp0 <--> /dev/ttyUSB1
Aug 19 10:24:32.897919 tap-0000C99B pppd[3225]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xbc8f60d> <pcomp> <accomp>]
Aug 19 10:24:33.373123 tap-0000C99B pppd[3225]: rcvd [LCP ConfReq id=0x1 <accomp> <pcomp> <asyncmap 0x0> <mru 1500> <magic 0x549> <auth chap MD5>]
Aug 19 10:24:33.373146 tap-0000C99B pppd[3225]: sent [LCP ConfAck id=0x1 <accomp> <pcomp> <asyncmap 0x0> <mru 1500> <magic 0x549> <auth chap MD5>]
Aug 19 10:24:33.373189 tap-0000C99B pppd[3225]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xbc8f60d> <pcomp> <accomp>]
Aug 19 10:24:33.373217 tap-0000C99B pppd[3225]: sent [LCP EchoReq id=0x0 magic=0xbc8f60d]
Aug 19 10:24:33.373813 tap-0000C99B pppd[3225]: rcvd [CHAP Challenge id=0x1 <3f0acd555db374e26b77ce50272391b2>, name = "HUAWEI_CHAP_SRVR"]
Aug 19 10:24:33.375494 tap-0000C99B pppd[3225]: sent [CHAP Response id=0x1 <550000ae83350291550000ffffffff0000000000400000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000638abb14a4f1d3000000000000000060cf3b0291550000290000000000>, name = ""]
Aug 19 10:24:33.375530 tap-0000C99B pppd[3225]: rcvd [LCP EchoRep id=0x0 magic=0x549]
Aug 19 10:24:36.374371 tap-0000C99B pppd[3225]: rcvd [CHAP Challenge id=0x2 <3f0acd555db374e26b77ce50272391b2>, name = "HUAWEI_CHAP_SRVR"]
Aug 19 10:24:36.376247 tap-0000C99B pppd[3225]: sent [CHAP Response id=0x2 <550000ae83350291550000ffffffff0000000000400000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000638abb14a4f1d3000000000000000060cf3b0291550000290000000000>, name = ""]
Aug 19 10:24:39.375122 tap-0000C99B pppd[3225]: rcvd [CHAP Challenge id=0x3 <3f0acd555db374e26b77ce50272391b2>, name = "HUAWEI_CHAP_SRVR"]
Aug 19 10:24:39.376186 tap-0000C99B pppd[3225]: sent [CHAP Response id=0x3 <550000ae83350291550000ffffffff0000000000400000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000638abb14a4f1d3000000000000000060cf3b0291550000290000000000>, name = ""]
Aug 19 10:24:42.375736 tap-0000C99B pppd[3225]: rcvd [LCP TermReq id=0x2]
Aug 19 10:24:42.375748 tap-0000C99B pppd[3225]: LCP terminated by peer
Aug 19 10:24:42.375859 tap-0000C99B pppd[3225]: sent [LCP TermAck id=0x2]
Aug 19 10:24:42.383192 tap-0000C99B pppd[3225]: Modem hangup
Aug 19 10:24:42.383270 tap-0000C99B pppd[3225]: Connection terminated.
Aug 19 10:24:43.394710 tap-0000C99B pppd[3225]: Exit.
Aug 19 10:24:48.873385 tap-0000C99B pppd[3235]: Plugin /usr/lib/pppd/2.5.1-dev/nm-pppd-plugin.so loaded.
Aug 19 10:24:48.880539 tap-0000C99B pppd[3235]: pppd 2.5.1-dev started by root, uid 0
Aug 19 10:24:48.901596 tap-0000C99B pppd[3235]: using channel 55
Aug 19 10:24:48.902221 tap-0000C99B pppd[3235]: Using interface ppp0
Aug 19 10:24:48.902307 tap-0000C99B pppd[3235]: Connect: ppp0 <--> /dev/ttyUSB1
Aug 19 10:24:48.902692 tap-0000C99B pppd[3235]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xaec94955> <pcomp> <accomp>]
Aug 19 10:24:49.373236 tap-0000C99B pppd[3235]: rcvd [LCP ConfReq id=0x1 <accomp> <pcomp> <asyncmap 0x0> <mru 1500> <magic 0x54b> <auth chap MD5>]
Aug 19 10:24:49.373263 tap-0000C99B pppd[3235]: sent [LCP ConfAck id=0x1 <accomp> <pcomp> <asyncmap 0x0> <mru 1500> <magic 0x54b> <auth chap MD5>]
Aug 19 10:24:49.373313 tap-0000C99B pppd[3235]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xaec94955> <pcomp> <accomp>]
Aug 19 10:24:49.373352 tap-0000C99B pppd[3235]: sent [LCP EchoReq id=0x0 magic=0xaec94955]
Aug 19 10:24:49.374349 tap-0000C99B pppd[3235]: rcvd [CHAP Challenge id=0x1 <de2a568eb50a1dba5d62c403220be373>, name = "HUAWEI_CHAP_SRVR"]
Aug 19 10:24:49.376619 tap-0000C99B pppd[3235]: sent [CHAP Response id=0x1 <560000aee3a96810560000ffffffff00>, name = ""]
Aug 19 10:24:49.376671 tap-0000C99B pppd[3235]: rcvd [LCP EchoRep id=0x0 magic=0x54b]
Aug 19 10:24:49.377412 tap-0000C99B pppd[3235]: rcvd [CHAP Success id=0x1 "Welcome!!"]
Aug 19 10:24:49.377435 tap-0000C99B pppd[3235]: CHAP authentication succeeded: Welcome!!
Aug 19 10:24:49.377446 tap-0000C99B pppd[3235]: CHAP authentication succeeded
Aug 19 10:24:49.387552 tap-0000C99B pppd[3235]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15>]
Aug 19 10:24:49.387600 tap-0000C99B pppd[3235]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Aug 19 10:24:49.387638 tap-0000C99B pppd[3235]: rcvd [IPCP ConfReq id=0x1]
Aug 19 10:24:49.387650 tap-0000C99B pppd[3235]: sent [IPCP ConfNak id=0x1 <addr 0.0.0.0>]
Aug 19 10:24:49.388840 tap-0000C99B pppd[3235]: rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0c 1a 04 78 00 18 04 78 00]
Aug 19 10:24:49.388860 tap-0000C99B pppd[3235]: Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
Aug 19 10:24:49.388891 tap-0000C99B pppd[3235]: rcvd [IPCP ConfNak id=0x1]
Aug 19 10:24:49.388907 tap-0000C99B pppd[3235]: sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Aug 19 10:24:49.388931 tap-0000C99B pppd[3235]: rcvd [IPCP ConfReq id=0x2]
Aug 19 10:24:49.388941 tap-0000C99B pppd[3235]: sent [IPCP ConfAck id=0x2]
Aug 19 10:24:49.389417 tap-0000C99B pppd[3235]: rcvd [IPCP ConfRej id=0x2 <compress VJ 0f 01>]
Aug 19 10:24:49.389433 tap-0000C99B pppd[3235]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Aug 19 10:24:49.389774 tap-0000C99B pppd[3235]: rcvd [IPCP ConfNak id=0x3 <addr 10.64.221.84> <ms-dns1 192.168.10.110> <ms-dns2 194.51.3.56>]
Aug 19 10:24:49.389795 tap-0000C99B pppd[3235]: sent [IPCP ConfReq id=0x4 <addr 10.64.221.84> <ms-dns1 192.168.10.110> <ms-dns2 194.51.3.56>]
Aug 19 10:24:49.390138 tap-0000C99B pppd[3235]: rcvd [IPCP ConfAck id=0x4 <addr 10.64.221.84> <ms-dns1 192.168.10.110> <ms-dns2 194.51.3.56>]
I can easily test a patch if someone suggest anything.
Thanks
for Paulusmack, The logs are full. The only change in the v2.4.9 example are the xxx in the IP address. By default, the connection is always made in CHAP without specifying anything. To obtain a PAP connection, I deleted the file /etc/ppp/chap-secrets.
There are various different varieties of CHAP, using different hash functions. If you look in the comment by fmartinsons above, you will see in the LCP configure-request received from the peer this: "<auth chap MD5>", which is the peer asking us to authenticate ourselves with CHAP using a MD5 hash. The default defined in the PPP protocol specification is no authentication unless a specific type of authentication is negotiated at LCP time. In your logs there is no authentication negotiated at LCP time, yet the local pppd goes ahead and authenticates itself. That's what makes me think that either the logs were edited or else pppd has been modified from the upstream source.
The problem with not being able to see any authentication negotiated at LCP time is that I then don't know what hash CHAP would be using. Since the generation of the response depends on the hash, that makes it impossible to work out which part of the code could be at fault.
I can easily test a patch if someone suggest anything.
Great! Here is a patch to test. I noticed that in chap_md5_make_response(), if any of the steps in preparing the response fail, we return with response[0] uninitialized, but with no indication to the caller that an error occurred (@enaess). With this patch the behaviour would now be to return a 0-length response and log an error.
index d9259d2..bf5a974 100644
--- a/pppd/chap-md5.c
+++ b/pppd/chap-md5.c
@@ -111,21 +111,25 @@ chap_md5_make_response(unsigned char *response, int id, char *our_name,
unsigned char idbyte = id;
int challenge_len = *challenge++;
int hash_len = MD5_DIGEST_LENGTH;
+ int step = 0;
PPP_MD_CTX* ctx = PPP_MD_CTX_new();
if (ctx) {
if (PPP_DigestInit(ctx, PPP_md5())) {
+ step = 1;
if (PPP_DigestUpdate(ctx, &idbyte, 1)) {
+ step = 2;
if (PPP_DigestUpdate(ctx, secret, secret_len)) {
+ step = 3;
if (PPP_DigestUpdate(ctx, challenge, challenge_len)) {
+ step = 4;
if (PPP_DigestFinal(ctx, &response[1], &hash_len)) {
-
- response[0] = hash_len;
+ step = 5;
}
}
}
@@ -133,6 +137,12 @@ chap_md5_make_response(unsigned char *response, int id, char *our_name,
}
PPP_MD_CTX_free(ctx);
}
+ if (step == 5) {
+ response[0] = hash_len;
+ } else {
+ error("chap_md5_make_response failed at step %d", step);
+ response[0] = 0;
+ }
}
static struct chap_digest_type md5_digest = {
I can easily test a patch if someone suggest anything.
Great! Here is a patch to test. I noticed that in chap_md5_make_response(), if any of the steps in preparing the response fail, we return with response[0] uninitialized, but with no indication to the caller that an error occurred (@enaess). With this patch the behaviour would now be to return a 0-length response and log an error.
index d9259d2..bf5a974 100644 --- a/pppd/chap-md5.c +++ b/pppd/chap-md5.c
Hey, thanks for your quick answer.
Yesterday, I made some progress. Since I saw that chap_md5_make_response was the responsible of creating the (unexpectedly long) response, I started adding some logs in this function.
My setup sometimes fails in PPP_DigestInit , under this one there was call on openssl lib that fail (I still don't know why since there is no error message printed there).
Since I had my fair amount of problem with openssl (by the way , I use openssl 3.0.14) in the past and considering that ppp provides its own implementation of md5, I build without openssl (--without-openssl --disable-eaptls --disable-pea)
At this point, I had no more issues.
I'll apply your patch and dig a little more to understand why openssl call fails but at least, there is a workaround (only tested on latest git head though)
Here is the log with your patch applied @paulusmack :
Aug 20 07:12:03.909916 tap-0000C99B pppd[1797]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb562ab25> <pcomp> <accomp>]
Aug 20 07:12:04.386214 tap-0000C99B pppd[1797]: rcvd [LCP ConfReq id=0x1 <accomp> <pcomp> <asyncmap 0x0> <mru 1500> <magic 0x543> <auth chap MD5>]
Aug 20 07:12:04.386239 tap-0000C99B pppd[1797]: sent [LCP ConfAck id=0x1 <accomp> <pcomp> <asyncmap 0x0> <mru 1500> <magic 0x543> <auth chap MD5>]
Aug 20 07:12:04.386293 tap-0000C99B pppd[1797]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xb562ab25> <pcomp> <accomp>]
Aug 20 07:12:04.386324 tap-0000C99B pppd[1797]: sent [LCP EchoReq id=0x0 magic=0xb562ab25]
Aug 20 07:12:04.386895 tap-0000C99B pppd[1797]: rcvd [CHAP Challenge id=0x1 <6107e1fc543bb8dc6eadc1e3a3477d0d>, name = "HUAWEI_CHAP_SRVR"]
Aug 20 07:12:04.388576 tap-0000C99B pppd[1797]: chap_md5_make_response failed at step 0
Aug 20 07:12:04.388592 tap-0000C99B pppd[1797]: sent [CHAP Response id=0x1 <>, name = ""]
Aug 20 07:12:04.388641 tap-0000C99B pppd[1797]: rcvd [LCP EchoRep id=0x0 magic=0x543]
Aug 20 07:12:07.387593 tap-0000C99B pppd[1797]: rcvd [CHAP Challenge id=0x2 <6107e1fc543bb8dc6eadc1e3a3477d0d>, name = "HUAWEI_CHAP_SRVR"]
Aug 20 07:12:07.389435 tap-0000C99B pppd[1797]: chap_md5_make_response failed at step 0
Aug 20 07:12:07.389447 tap-0000C99B pppd[1797]: sent [CHAP Response id=0x2 <>, name = ""]
Aug 20 07:12:10.388344 tap-0000C99B pppd[1797]: rcvd [CHAP Challenge id=0x3 <6107e1fc543bb8dc6eadc1e3a3477d0d>, name = "HUAWEI_CHAP_SRVR"]
Aug 20 07:12:10.389543 tap-0000C99B pppd[1797]: chap_md5_make_response failed at step 0
Aug 20 07:12:10.389558 tap-0000C99B pppd[1797]: sent [CHAP Response id=0x3 <>, name = ""]
Of course, since openssl is the culprit in my case, the authent fail but at least , we have a clearer reason here.
@enaess any idea why PPP_DigestInit() would sometimes fail?
I found the reason with the following patch:
--- a/pppd/ppp-md5.c
+++ b/pppd/ppp-md5.c
@@ -40,6 +40,20 @@
#ifdef OPENSSL_HAVE_MD5
#include <openssl/evp.h>
+#include "pppd.h"
+
+static char *ossl_err_as_string (void)
+{
+ BIO *bio = BIO_new (BIO_s_mem ());
+ ERR_print_errors (bio);
+ char *buf = NULL;
+ size_t len = BIO_get_mem_data (bio, &buf);
+ char *ret = (char *) calloc (1, 1 + len);
+ if (ret)
+ memcpy (ret, buf, len);
+ BIO_free (bio);
+ return ret;
+}
#if OPENSSL_VERSION_NUMBER < 0x10100000L
#define EVP_MD_CTX_free EVP_MD_CTX_destroy
@@ -54,6 +68,10 @@ static int md5_init(PPP_MD_CTX *ctx)
if (EVP_DigestInit((EVP_MD_CTX*) mctx, EVP_md5())) {
ctx->priv = mctx;
return 1;
+ } else {
+ char* err = ossl_err_as_string();
+ error("EVP_DigestInit failed: %s", err);
+ free(err);
}
EVP_MD_CTX_free(mctx);
}
which show me that:
Aug 20 07:49:05.912267 tap-0000C99B pppd[1797]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xf908e185> <pcomp> <accomp>]
Aug 20 07:49:06.386213 tap-0000C99B pppd[1797]: rcvd [LCP ConfReq id=0x1 <accomp> <pcomp> <asyncmap 0x0> <mru 1500> <magic 0x543> <auth chap MD5>]
Aug 20 07:49:06.386231 tap-0000C99B pppd[1797]: sent [LCP ConfAck id=0x1 <accomp> <pcomp> <asyncmap 0x0> <mru 1500> <magic 0x543> <auth chap MD5>]
Aug 20 07:49:06.386256 tap-0000C99B pppd[1797]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xf908e185> <pcomp> <accomp>]
Aug 20 07:49:06.386289 tap-0000C99B pppd[1797]: sent [LCP EchoReq id=0x0 magic=0xf908e185]
Aug 20 07:49:06.386908 tap-0000C99B pppd[1797]: rcvd [CHAP Challenge id=0x1 <6562365bfde5abc241ce8b39c87ff04c>, name = "HUAWEI_CHAP_SRVR"]
Aug 20 07:49:06.388563 tap-0000C99B pppd[1797]: EVP_DigestInit failed: C0A1FAE8227F0000:error:12800067:DSO support routines:dlfcn_load:could not load the shared library:/usr/src/debug/openssl/3.0.14-r0/crypto/dso/dso_dlfcn.c:118:filename(/usr/lib/ossl-modules/legacy.so): /usr/lib/ossl-modules/legacy.so: cannot open shared object file: No such file or directory
C0A1FAE8227F0000:error:12800067:DSO support routines:DSO_load:could not load the shared library:/usr/src/debug/openssl/3.0.14-r0/crypto/dso/dso_lib.c:152:
C0A1FAE8227F0000:error:07880025:common libcrypto routines:provider_init:reason(524325):/usr/src/debug/openssl/3.0.14-r0/crypto/provider_core.c:919:name=legacy
C0A1FAE8227F0000:error:0308010C:digital envelope routines:inner_evp_generic_fetch:unsupported:/usr/src/debug/openssl/3.0.14-r0/crypto/evp/evp_fetch.c:386:Global default library context, Algorithm (MD5 : 102), Properties ()
C0A1FAE8227F0000:error:03000086:digital envelope routines:evp_md_init_internal:initialization error:/usr/src/debug/openssl/3.0.14-r0/crypto/evp/digest.c:254:
Aug 20 07:49:06.388574 tap-0000C99B pppd[1797]: chap_md5_make_response failed at step 0
So in the end, the openssl legacy module was missing from my setup, I shipped it and got no more problem. If you think adding openssl error printing in pppd, I can open a PR .
Anyway thank you for your support on that issue.
Ok I'll cook something in the coming days then, will you open a dedicated PR for the error management in chap-md5.c too ?
Hello,
thank you both for your solutions. I'm getting the same error in the same place as @fmartinsons The search path is that of my build machine. What do I need to change during compilation so that the legacy.so file is searched in the “/lib” folder of my execution target?
2024-08-20T15:49:52.790271+02:00 REDY-02448-00029 REDY: EVP_DigestInit failed: 20004C74:error:12800067:DSO support routines:dlfcn_load:could not load the shared library:crypto/dso/dso_dlfcn.c:118:filename(/opt/arm-linux/arm-unknown-linux-gnueabihf/sysroot/usr/lib/ossl-modules/legacy.so): /opt/arm-linux/arm-unknown-linux-gnueabihf/sysroot/usr/lib/ossl-modules/legacy.so: cannot open shared object file: No such file or directory
2024-08-20T15:49:52.790318+02:00 REDY-02448-00029 REDY: 20004C74:error:12800067:DSO support routines:DSO_load:could not load the shared library:crypto/dso/dso_lib.c:152:
2024-08-20T15:49:52.790344+02:00 REDY-02448-00029 REDY: 20004C74:error:07880025:common libcrypto routines:provider_init:reason(524325):crypto/provider_core.c:912:name=legacy
2024-08-20T15:49:52.790366+02:00 REDY-02448-00029 REDY: 20004C74:error:0308010C:digital envelope routines:inner_evp_generic_fetch:unsupported:crypto/evp/evp_fetch.c:373:Global default library context, Algorithm (MD5 : 102), Properties ()
2024-08-20T15:49:52.791642+02:00 REDY-02448-00029 REDY: 20004C74:error:03000086:digital envelope routines:evp_md_init_internal:initialization error:crypto/evp/digest.c:254:
2024-08-20T15:49:52.793111+02:00 REDY-02448-00029 REDY: chap_md5_make_response failed at step 0
Thanks for your help.
@Tyrrell06 it depends on your build system but since it showed you a path to your build machine during runtime, I think that openssl is wrongly configured for cross compilation (runtime path issue ?)
You should take a look at how openssl and/or pppd is configured/build and installed with your build system
I am sorry, but the missing legacy.so as a OpenSSL provider will cause this error, and it would do so silently. Also worth noting that your unit-tests running make check would also fail. Running those tests (less you are in a cross-compiler environment, you'd have to load and run the check executable on your target device).
A reasonable addition to the PPP_EVP_digest_init() and other functions related to the PPP crypto shim is to add a PPP_EVP_error() function that returns e.g. a zero-terminated string and allows the caller print the error out.
The real fix here would probably be to halt execution of pppd if the required crypto cannot be initialized. Consider main.c:
PPP_crypto_init();
Should probably read something like:
if (!PPP_crypto_init()) {
error("Could not initialize cryptographic libraries");
}
That was my mistake, sorry for the bad quality code here.
@enaess I suggested a crypto erro implem (just for digest init) in https://github.com/ppp-project/ppp/pull/508
let's talk about that there.
@Tyrrell06 it depends on your build system but since it showed you a path to your build machine during runtime, I think that openssl is wrongly configured for cross compilation (runtime path issue ?)
You should take a look at how openssl and/or pppd is configured/build and installed with your build system
@fmartinsons, thank you very much for your analysis. indeed, it was Openssl that was misconfigured. After rectification, everything works fine.
With the improved error messages from 077141058aab, I think this one is solved.
PPP 2.5.1 has been released (2024-09-18)
- https://github.com/ppp-project/ppp/releases/tag/v2.5.1
- https://github.com/ppp-project/ppp/issues/460
