Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

"CHAP authentication succeeded" followed by "Authentication failed" #335

Closed
Bidski opened this issue Feb 7, 2022 · 15 comments
Closed

"CHAP authentication succeeded" followed by "Authentication failed" #335

Bidski opened this issue Feb 7, 2022 · 15 comments

Comments

@Bidski
Copy link

Bidski commented Feb 7, 2022 •
edited

I am trying to setup a L2TP/IPSec client on Arch Linux. The IPSec connection appears to work fine, but when setting up the L2TP connection on top of the IPSec connection I see the following output and I have no idea what to make of it. I'm not sure if this is a bug or just bad settings on my part, but after hours of googling and trying variations of the settings I am getting nowhere.

What is failing here? Why is it failing? How can I get further information?

pppd[74443]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MS-v2> <magic MAGIC_NUM_1>]
xl2tpd[74437]: xl2tpd[74437]: network_thread: recv packet from REMOTE_IP_ADDRESS, size = 12, tunnel = 16877, call = 36693 ref=0 refhim=0
xl2tpd[74437]: xl2tpd[74437]: network_thread: recv packet from REMOTE_IP_ADDRESS, size = 36, tunnel = 16877, call = 36693 ref=0 refhim=0
xl2tpd[74437]: xl2tpd[74437]: message_type_avp: message type 16 (Set-Link-Info)
xl2tpd[74437]: xl2tpd[74437]: ignore_avp : Ignoring AVP
xl2tpd[74437]: xl2tpd[74437]: control_finish: message type is Set-Link-Info(16).  Tunnel is 754, call is 754.
pppd[74443]: rcvd [LCP ConfReq id=0x1 <auth chap MS-v2> <magic MAGIC_NUM_2>]
pppd[74443]: sent [LCP ConfAck id=0x1 <auth chap MS-v2> <magic MAGIC_NUM_2>]
pppd[74443]: rcvd [LCP ConfRej id=0x1 <asyncmap 0x0>]
pppd[74443]: sent [LCP ConfReq id=0x2 <auth chap MS-v2> <magic MAGIC_NUM_1>]
pppd[74443]: rcvd [LCP ConfAck id=0x2 <auth chap MS-v2> <magic MAGIC_NUM_1>]
pppd[74443]: PPPoL2TP options: debugmask 0
pppd[74443]: sent [LCP EchoReq id=0x0 magic=MAGIC_NUM_1]
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Challenge id=0x1 <CHAP_CHALLENGE_RECV>, name = ""]
pppd[74443]: added response cache entry 0
pppd[74443]: sent [CHAP Response id=0x1 <CHAP_RESPONSE>, name = "MY_NAME"]
pppd[74443]: rcvd [LCP EchoRep id=0x0 magic=0x6a67adb7]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: rcvd [CHAP Success id=0x1 "S=CHAP_SUCCESS"]
pppd[74443]: response found in cache (entry 0)
pppd[74443]: CHAP authentication succeeded
xl2tpd[74437]: xl2tpd[74437]: network_thread: select timeout with max retries: 5 for tunnel: 16877
xl2tpd[74437]: xl2tpd[74437]: network_thread: select timeout with max retries: 5 for tunnel: 16877
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
xl2tpd[74437]: xl2tpd[74437]: network_thread: select timeout with max retries: 5 for tunnel: 16877
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: sent [CHAP Challenge id=0x52 <CHAP_CHALLENGE_SEND>, name = "MY_NAME"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: sent [LCP EchoReq id=0x1 magic=MAGIC_NUM_1]
pppd[74443]: rcvd [LCP EchoRep id=0x1 magic=MAGIC_NUM_2]
pppd[74443]: PPPoL2TP options: debugmask 0
pppd[74443]: sent [LCP TermReq id=0x3 "Authentication failed"]
pppd[74443]: rcvd [CHAP Response id=0x52 <>, name = ""]
pppd[74443]: Discarded non-LCP packet when LCP not open
pppd[74443]: rcvd [LCP TermAck id=0x3]
pppd[74443]: Connection terminated.
pppd[74443]: Exit.

pppd version 2.4.9
xl2tpd version 1.3.17
IPSec version Linux strongSwan U5.9.4/K5.16.5-arch1-1
@Neustradamus
Copy link
Member

@paulusmack, @nomis, @enaess: What do you think?

@nomis
Copy link

nomis commented Feb 19, 2022

@Bidski you're asking the "server" to authenticate too and it's unable to do that. Read the documentation.

@Neustradamus I don't think you understand or use PPP or you could have diagnosed this common problem yourself without sending messages to developers.

@Bidski
Copy link
Author

Bidski commented Feb 20, 2022

@Bidski you're asking the "server" to authenticate too and it's unable to do that. Read the documentation.

@nomis can you direct me to the part of the documentation that I should be reading? I have tried adding noauth to my ppp config but that doesn't appear to change anything. I have also tried adding refuse authentication = yes" and "require authentication = no to my xl2tp config as well (all three statements combined together) and this also didn't appear to change anything.

@enaess
Copy link
Contributor

enaess commented Feb 20, 2022

@Bidski

pppd[74443]: sent [LCP ConfReq id=0x2 <auth chap MS-v2> <magic MAGIC_NUM_1>]
pppd[74443]: rcvd [LCP ConfAck id=0x2 <auth chap MS-v2> <magic MAGIC_NUM_1>]

@nomis is right, your local pppd configuration is sending a LCP config request to the server asking it to authenticate using MSCHAPv2. The client session receives a CHAP SUCCESS packet (session: 0x01) from the server, however; the client is also sending repeated CHAP CHALLENGE to the server asking it to authenticate itself (session: 0x52), the server responds with a CHAP response and an empty name before it finally the client sends a LCP Term Request and terminates the tunnel.

I'd say, post your configuration here for both xsl2tpd and pppd for the current session (and any option files).

@Bidski
Copy link
Author

Bidski commented Feb 22, 2022

Here is xl2tpd.conf

[global]
access control = no
auth file = /etc/ppp/chap-secrets
debug avp = yes
debug network = yes
debug packet = yes
debug state = yes
debug tunnel = yes

[lac MY_CONNECTION]
lns = REMOTE_IP_ADDRESS
refuse pap = yes
refuse chap = yes
require authentication = yes
ppp debug = yes
pppoptfile = /etc/ppp/options.l2tpd.client
length bit = yes
hidden bit = yes
name = MY_NAME

And here is my ppp options file

ipcp-accept-local
ipcp-accept-remote
debug
dump
noauth
noccp
refuse-eap
refuse-pap
refuse-chap
refuse-mschap
require-mschap-v2
require-mppe
mppe-stateful
nodefaultroute
name MY_NAME
remotename REMOTE_NAME
proxyarp

As I said earlier, I have tried many different variations of options and settings, these are just my most recent attempts. I have tried setting require authentication = no and refuse authentication = yes in the xl2tpd.conf file, but this didnt seem to have any impact.

@enaess
Copy link
Contributor

enaess commented Feb 22, 2022

How are your server setup? Are you dialing into a Windows server via L2TP?

Even if you are, specifying "noccp" and the options "require-mppe" and "mppe-stateful" is a no-op. Don't think it would change anything.

@Bidski
Copy link
Author

Bidski commented Feb 22, 2022

I believe it is a Cisco server (probably running on Widows). I don't have the specifics of the server setup apart from the details that they provide everyone else (who is connecting from Windows and is also very little information -- L2TP/IPSec with a PSK). If you can tell me details that I need to know I can ask for them.

Even if you are, specifying "noccp" and the options "require-mppe" and "mppe-stateful" is a no-op. Don't think it would change anything.

As I said earlier, things aren't working and I am not sure on the specifics for why, so I started trying many many different options, none of the made any difference.

@enaess
Copy link
Contributor

enaess commented Feb 23, 2022

@Bidski

I do have a setup for SSTP and could easily switch it to L2TP on my windows server to test with. I'll need some time to configure this though ...

@Bidski
Copy link
Author

Bidski commented Mar 4, 2022 •
edited

If I add this line to /etc/ppp/options.l2tpd.client

allow-ip REMOTE_IP_ADDRESS

And if I remove this from /etc/ppp/chap-secrets

REMOTE_NAME NY_NAME "secret" *

Then the connection comes up and I get a ppp0 device in ip a

10: ppp0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UNKNOWN group default qlen 3
    link/ppp 
    inet 192.168.187.113 peer REMOTE_IP_ADDRESS/32 scope global ppp0
       valid_lft forever preferred_lft forever
    inet 192.168.187.113/32 brd REMOTE_IP_ADDRESS scope global ppp0
       valid_lft forever preferred_lft forever

And ip route shows

REMOTE_IP_ADDRESS dev ppp0 proto kernel scope link src 192.168.187.113

However, I am unable to set up a route so that all VPN traffic (should be anything on 192.68.0.0/16 subnet) is routed through ppp0 following this

# ip route add 192.168.0.0/16 via REMOTE_IP_ADDRESS dev ppp0
Error: Nexthop has invalid gateway.

I am also unable to ping any IP addresses that should be available through the VPN.

System logs now show

xl2tpd[263263]: xl2tpd[263263]: Not looking for kernel SAref support.
xl2tpd[263263]: xl2tpd[263263]: Using l2tp kernel support.
xl2tpd[263263]: xl2tpd[263263]: xl2tpd version xl2tpd-1.3.17 started on bidski-beast PID:263263
xl2tpd[263263]: xl2tpd[263263]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
xl2tpd[263263]: xl2tpd[263263]: Forked by Scott Balmos and David Stipp, (C) 2001
xl2tpd[263263]: xl2tpd[263263]: Inherited by Jeff McAdams, (C) 2002
xl2tpd[263263]: xl2tpd[263263]: Forked again by Xelerance (www.xelerance.com) (C) 2006-2016
xl2tpd[263263]: xl2tpd[263263]: Listening on IP address 0.0.0.0, port 1701
xl2tpd[263263]: xl2tpd[263263]: Connecting to host REMOTE_IP_ADDRESS, port 1701
xl2tpd[263263]: xl2tpd[263263]: Connection established to REMOTE_IP_ADDRESS, 1701.  Local: 32106, Remote: 1448 (ref=0/0).
xl2tpd[263263]: xl2tpd[263263]: Calling on tunnel 32106
xl2tpd[263263]: xl2tpd[263263]: Call established with REMOTE_IP_ADDRESS, Local: 41268, Remote: 1448, Serial: 1 (ref=0/0)
xl2tpd[263263]: xl2tpd[263263]: start_pppd: I'm running:
xl2tpd[263263]: xl2tpd[263263]: "/usr/sbin/pppd"
xl2tpd[263263]: xl2tpd[263263]: "plugin"
xl2tpd[263263]: xl2tpd[263263]: "pppol2tp.so"
xl2tpd[263263]: xl2tpd[263263]: "pppol2tp"
xl2tpd[263263]: xl2tpd[263263]: "7"
xl2tpd[263263]: xl2tpd[263263]: "passive"
xl2tpd[263263]: xl2tpd[263263]: "nodetach"
xl2tpd[263263]: xl2tpd[263263]: ":"
xl2tpd[263263]: xl2tpd[263263]: "refuse-pap"
xl2tpd[263263]: xl2tpd[263263]: "refuse-chap"
xl2tpd[263263]: xl2tpd[263263]: "name"
xl2tpd[263263]: xl2tpd[263263]: "MY_NAME"
xl2tpd[263263]: xl2tpd[263263]: "file"
xl2tpd[263263]: xl2tpd[263263]: "/etc/ppp/options.l2tpd.client"
pppd[263275]: Plugin pppol2tp.so loaded.
pppd[263275]: pppd 2.4.9 started by root, uid 0
pppd[263275]: Using interface ppp0
pppd[263275]: Connect: ppp0 <-->
pppd[263275]: CHAP authentication succeeded
pppd[263275]: Cannot determine ethernet address for proxy ARP
pppd[263275]: local  IP address 192.168.187.113
pppd[263275]: remote IP address REMOTE_IP_ADDRESS
xl2tpd[263263]: xl2tpd[263263]: Can not find tunnel 1448 (refhim=0)
xl2tpd[263263]: xl2tpd[263263]: network_thread: unable to find call or tunnel to handle packet.  call = 1448, tunnel = 1448 Dumping.
xl2tpd[263263]: xl2tpd[263263]: Can not find tunnel 1448 (refhim=0)
xl2tpd[263263]: xl2tpd[263263]: network_thread: unable to find call or tunnel to handle packet.  call = 1448, tunnel = 1448 Dumping.

...... SNIP ......

xl2tpd[263263]: xl2tpd[263263]: udp_xmit failed to REMOTE_IP_ADDRESS:1701 with err=-1:Permission denied
xl2tpd[263263]: xl2tpd[263263]: udp_xmit failed to REMOTE_IP_ADDRESS:1701 with err=-1:Permission denied
xl2tpd[263263]: xl2tpd[263263]: udp_xmit failed to REMOTE_IP_ADDRESS:1701 with err=-1:Permission denied
xl2tpd[263263]: xl2tpd[263263]: udp_xmit failed to REMOTE_IP_ADDRESS:1701 with err=-1:Permission denied
xl2tpd[263263]: xl2tpd[263263]: Can not find tunnel 1448 (refhim=0)
xl2tpd[263263]: xl2tpd[263263]: network_thread: unable to find call or tunnel to handle packet.  call = 1448, tunnel = 1448 Dumping.
xl2tpd[263263]: xl2tpd[263263]: Can not find tunnel 1448 (refhim=0)
xl2tpd[263263]: xl2tpd[263263]: network_thread: unable to find call or tunnel to handle packet.  call = 1448, tunnel = 1448 Dumping.

...... SNIP ......

xl2tpd[263263]: xl2tpd[263263]: Maximum retries exceeded for tunnel 32106.  Closing.
xl2tpd[263263]: xl2tpd[263263]: udp_xmit failed to REMOTE_IP_ADDRESS:1701 with err=-1:Permission denied
xl2tpd[263263]: xl2tpd[263263]: Terminating pppd: sending TERM signal to pid 263275
xl2tpd[263263]: xl2tpd[263263]: Connection 1448 closed to REMOTE_IP_ADDRESS, port 1701 (Timeout)
pppd[263275]: Terminating on signal 15
pppd[263275]: Connect time 1.6 minutes.
pppd[263275]: Sent 242566 bytes, received 0 bytes.
pppd[263275]: Connection terminated.
pppd[263275]: Exit.
xl2tpd[263263]: xl2tpd[263263]: Unable to deliver closing message for tunnel 32106. Destroying anyway.

The "Can not find tunnel" and "unable to find call or tunnel to handle packet" are repeated many times so I cut them out for brevity.

Are these problems still part of the previous problems I was seeing or is this more to do with xl2tpd or something else now?

@Neustradamus
Copy link
Member

@paulusmack, @enaess: What do you think?

@paulusmack
Copy link
Collaborator

Sorry, I haven't used xl2tpd. I don't know anything about how to configure it. The best I can suggest is to add the 'dump' option to /etc/ppp/options, try to connect, then look in the logs for which options are enabled to see if there are any that shouldn't be there.

@enaess
Copy link
Contributor

enaess commented Oct 26, 2022

Looks to me that the user were able to overcome the authentication issues he had. Now, it's up to the xl2tpd to send forward these packets. Why it is having problem passing udp packets to the remote host with "permission denied" is likely a problem on xl2tpd side. Have he tried to ask someone on their mailing list?

@Bidski
Copy link
Author

Bidski commented Oct 26, 2022

I did manage to eventually resolve this issue and I can now successfully establish a connection

@Bidski Bidski closed this as completed Oct 26, 2022
@onebyoneby
Copy link

诺

what is fix with this

@Bidski
Copy link
Author

Bidski commented May 26, 2023

Some more information can be found here. IIRC one of the main issues was that I had configured PPP but not XL2TP

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@nomis @Neustradamus @enaess @paulusmack @Bidski @onebyoneby