[SOLVED]Connecting to L2TP/IPSec VPN problem: pppd seems not starting

nnkken · 2014-08-20 17:28:45

I'm trying to connect to an L2TP/IPsec VPN server, by ipsec-tools + xl2tpd.
Here is my setup:

/etc/racoon.conf:

log debug;
path pre_shared_key "/etc/racoon/psk.txt";
padding {
maximum_length 20;
randomize off;
strict_check off;
exclusive_tail off;
}
remote anonymous {
exchange_mode main;
doi ipsec_doi;
situation identity_only;
generate_policy on;
nat_traversal on;
proposal_check obey;
proposal {
encryption_algorithm aes 256;
lifetime time 3600 sec;
hash_algorithm sha1;
authentication_method pre_shared_key;
dh_group modp1024;
}
}
sainfo anonymous {
lifetime time 3600 sec;
encryption_algorithm aes 256;
authentication_algorithm hmac_sha1;
compression_algorithm deflate;
}

/etc/racoon/psk.txt:

#broadband
137.189.192.201 the-server-psk
137.189.192.204 the-server-psk

Here the two IPs are the IPs of vpn.cuhk.edu.hk, which is the VPN server.

/etc/xl2tpd/xl2tpd.conf:

[global]
port = 1701
auth file = /etc/ppp/pap-secrets
debug network = yes
debug avp = yes
debug packet = yes
debug state = yes
debug tunnel = yes
[lac connect]
lns = vpn.cuhk.edu.hk
name = vpn-server
redial = yes
redial timeout = 15
max redials = 5
hidden bit = yes
refuse chap = yes
require pap = yes
ppp debug = yes
pppoptfile = /etc/ppp/options.xl2tpd

/etc/ppp/pap-secrets:

# Secrets for authentication using PAP
# client        server  secret                  IP addresses
myusername * mypassword *

/etc/ppp/options.xl2tpd:

lock
debug
mtu 1000
nobsdcomp
nodeflate
noaccomp
nopcomp
novj
defaultroute
refuse-chap
refuse-mschap
refuse-mschap-v2
connect-delay 5000
name myusername
password mypassword

spd.sh:

#!/bin/sh

Then I do the following:
# 192.168.1.1 is my lan gateway
sudo ip route add 137.189.192.201 via 192.168.1.1
sudo ip route add 137.189.192.204 via 192.168.1.1
# For adding spd, script from the VPN server
echo -e flush\; | sudo setkey -c
echo -e spdflush\; | sudo setkey -c
echo -e spdadd 192.168.1.173/32\[1701\] 0.0.0.0\/0\[0\] any \-P out ipsec esp\/transport\/\/require\; | sudo setkey -c
sudo systemctl start racoon
sudo systemctl start xl2tpd
echo "c connect" | sudo tee /var/run/xl2tpd/l2tp-control

I expect that some network interface like ppp0 will be created, but nothing happened.
Then I check the record, and find something weird in xl2tpd log (from journalctl, racoon and sudo logs skipped):

 8月 21 01:13:40 nkdesktop systemd[1]: Stopped Level 2 Tunnel Protocol Daemon (L2TP).
 8月 21 01:13:41 nkdesktop systemd[1]: Starting Racoon IKEv1 key management daemon for IPSEC...
 8月 21 01:13:41 nkdesktop systemd[1]: Started Racoon IKEv1 key management daemon for IPSEC.
 8月 21 01:13:43 nkdesktop systemd[1]: Starting Level 2 Tunnel Protocol Daemon (L2TP)...
 8月 21 01:13:43 nkdesktop systemd[1]: Started Level 2 Tunnel Protocol Daemon (L2TP).
 8月 21 01:13:43 nkdesktop xl2tpd[19639]: xl2tpd[19639]: setsockopt recvref[30]: Protocol not available
 8月 21 01:13:43 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Using l2tp kernel support.
 8月 21 01:13:43 nkdesktop xl2tpd[19639]: xl2tpd[19639]: xl2tpd version xl2tpd-1.3.6 started on nkdesktop PID:19639
 8月 21 01:13:43 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
 8月 21 01:13:43 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Forked by Scott Balmos and David Stipp, (C) 2001
 8月 21 01:13:43 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Inherited by Jeff McAdams, (C) 2002
 8月 21 01:13:43 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Forked again by Xelerance (www.xelerance.com) (C) 2006
 8月 21 01:13:43 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Listening on IP address 0.0.0.0, port 1701
 8月 21 01:13:45 nkdesktop xl2tpd[19639]: xl2tpd[19639]: get_call: allocating new tunnel for host 137.189.192.204, port 1701.
 8月 21 01:13:45 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Connecting to host vpn.cuhk.edu.hk, port 1701
 8月 21 01:13:45 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: message type is (null)(0).  Tunnel is 0, call is 0.
 8月 21 01:13:45 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: sending SCCRQ
 8月 21 01:13:46 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: select timeout
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: select timeout
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: recv packet from 137.189.192.204, size = 103, tunnel = 30858, call = 0 ref=0 refhim=0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: handle_avps: handling avp's for tunnel 30858, call 0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: message_type_avp: message type 2 (Start-Control-Connection-Reply)
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: protocol_version_avp: peer is using version 1, revision 0.
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: framing_caps_avp: supported peer frames: async sync
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: bearer_caps_avp: supported peer bearers:
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: firmware_rev_avp: peer reports firmware version 1648 (0x0670)
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: hostname_avp: peer reports hostname 'eriwan'
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: vendor_avp: peer reports vendor 'Adtran, l2tpd'
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: assigned_tunnel_avp: using peer's tunnel 4733
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: receive_window_size_avp: peer wants RWS of 4.  Will use flow control.
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: message type is Start-Control-Connection-Reply(2).  Tunnel is 4733, call is 0.
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: sending SCCCN
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Connection established to 137.189.192.204, 1701.  Local: 30858, Remote: 4733 (ref=0/0).
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Calling on tunnel 30858
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: message type is (null)(0).  Tunnel is 4733, call is 0.
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: sending ICRQ
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: recv packet from 137.189.192.204, size = 12, tunnel = 30858, call = 0 ref=0 refhim=0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: recv packet from 137.189.192.204, size = 28, tunnel = 30858, call = 63662 ref=0 refhim=0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: handle_avps: handling avp's for tunnel 30858, call 63662
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: message_type_avp: message type 11 (Incoming-Call-Reply)
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: assigned_call_avp: using peer's call 31346
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: message type is Incoming-Call-Reply(11).  Tunnel is 4733, call is 31346.
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: Sending ICCN
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Call established with 137.189.192.204, Local: 63662, Remote: 31346, Serial: 1 (ref=0/0)
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: start_pppd: I'm running:
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "/usr/sbin/pppd"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "passive"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "nodetach"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: ":"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "refuse-chap"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "name"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "vpn-server"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "debug"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "file"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "/etc/ppp/options.xl2tpd"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "plugin"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "pppol2tp.so"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "pppol2tp"
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: "7"
 8月 21 01:13:47 nkdesktop pppd[19647]: Plugin pppol2tp.so loaded.
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: recv packet from 137.189.192.204, size = 12, tunnel = 30858, call = 0 ref=0 refhim=0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: recv packet from 137.189.192.204, size = 12, tunnel = 30858, call = 63662 ref=0 refhim=0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: recv packet from 137.189.192.204, size = 38, tunnel = 30858, call = 63662 ref=0 refhim=0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: handle_avps: handling avp's for tunnel 30858, call 63662
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: message_type_avp: message type 14 (Call-Disconnect-Notify)
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: result_code_avp: peer closing for reason 1 (General request to clear control connection), error = 0 ()
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: assigned_call_avp: using peer's call 31346
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: message type is Call-Disconnect-Notify(14).  Tunnel is 4733, call is 31346.
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: Connection closed to 137.189.192.204, serial 1 ()
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: Terminating pppd: sending TERM signal to pid 19647
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: recv packet from 137.189.192.204, size = 38, tunnel = 30858, call = 0 ref=0 refhim=0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: handle_avps: handling avp's for tunnel 30858, call 0
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: message_type_avp: message type 4 (Stop-Control-Connection-Notification)
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: assigned_tunnel_avp: using peer's tunnel 4733
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: result_code_avp: peer closing for reason 1 (General request to clear control connection), error = 0 ()
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: message type is Stop-Control-Connection-Notification(4).  Tunnel is 4733, call is 0.
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: control_finish: Connection closed to 137.189.192.204, port 1701 (), Local: 30858, Remote: 4733
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: build_fdset: closing down tunnel 30858
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: select returned error 9 (Bad file descriptor)
 8月 21 01:13:47 nkdesktop xl2tpd[19639]: xl2tpd[19639]: network_thread: select returned error 4 (Interrupted system call)
... then xl2tpd repeatedly trying to build a connection and fails for every 15s ...

I think pppd should have showed more logs, rather than just loading a module.
But I have no idea about what's wrong.
Or did I just forget to turn on the log function of pppd? If so, how should I turn it on?
Anyone can help?

Last edited by nnkken (2014-08-24 08:42:03)

nnkken · 2014-08-22 14:37:52

Additional information:
Today I decrypted the IPSec ESP packets by Wireshark (what an awesome function) and compared the L2TP message of my ArchLinux and MacOSX to the same VPN Server.
And I found that while both ArchLinux and MacOSX sends Incomming_Call_Connection (ICCN) packet, the packet are quite different:
The ArchLinux ICCN Packet has 2 additional AVP fields: Random Vector AVP and RX Connect Speed AVP.
Also, the Connect Speed AVP (and also the RX Connect Speed AVP) field is 0, which is different from MacOSX (100000).
After the ICCN packet, MacOCX sends a PPP packet over L2TP, while ArchLinux sends nothing and the server sends a Call_Disconnect_Notification to ArchLinux.
Anyone knows whether this is a bug or something wrong in config?

Last edited by nnkken (2014-08-22 20:19:49)

nnkken · 2014-08-24 08:41:43

Finally solved the problem, by adding

bps = 1000000

in /etc/xl2tpd/xl2tpd.conf

akiroz · 2015-09-07 15:09:13

Fellow CUHK student here.
Thank you so much for your efforts, I would never have got this working on my own without this post!

WorMzy · 2015-09-08 22:28:35

akiroz, please don't necrobump, particularly solved threads.

https://wiki.archlinux.org/index.php/Fo … bumping.22

Closing.

Arch Linux

#1 2014-08-20 17:28:45

[SOLVED]Connecting to L2TP/IPSec VPN problem: pppd seems not starting

#2 2014-08-22 14:37:52

Re: [SOLVED]Connecting to L2TP/IPSec VPN problem: pppd seems not starting

#3 2014-08-24 08:41:43

Re: [SOLVED]Connecting to L2TP/IPSec VPN problem: pppd seems not starting

#4 2015-09-07 15:09:13

Re: [SOLVED]Connecting to L2TP/IPSec VPN problem: pppd seems not starting

#5 2015-09-08 22:28:35

Re: [SOLVED]Connecting to L2TP/IPSec VPN problem: pppd seems not starting

Board footer