LINUX.ORG.RU
ФорумAdmin

Перестал работать xl2tp

 , ,


1

2

У меня была поднята VPN на xl2tpd, но неделю назад она ни с того-ни с сего упала и отказалась подниматься.

Вчера весь день курил интернеты и ковырял конфиги - все без толку.

Помогите разобраться в проблеме.

Конфиг /etc/xl2tpd/xl2tpd.conf:

[global]
port=1701
access control = no
ipsec saref = no

[lns default]
require authentication = no

[lns boulevard]
local ip = 10.0.0.1
assign ip = no
exclusive = no 
assign ip = yes
name = boulevard 

Конфиг /etc/ppp/options.xl2tpd:

asyncmap 0
auth
lock
hide-password
modem
name xl2tpd
debug
lcp-echo-interval 120
lcp-echo-failure 10
mtu 1200
mru 1200
proxyarp
nodefaultroute
noccp
novj
novjccomp
nopcomp
noaccomp
connect-delay 5000
debug

Конфиг ipsec:

version	2.0	# conforms to second version of ipsec.conf specification

# basic configuration

config setup
	# Do not set debug options to debug configuration issues!
	# plutodebug / klipsdebug = "all", "none" or a combation from below:
	# "raw crypt parsing emitting control klips pfkey natt x509 dpd private"
	# eg:
	# plutodebug="control parsing"
	# Again: only enable plutodebug or klipsdebug when asked by a developer
	#
	# enable to get logs per-peer
	# plutoopts="--perpeerlog"
	#
	# Enable core dumps (might require system changes, like ulimit -C)
	# This is required for abrtd to work properly
	# Note: incorrect SElinux policies might prevent pluto writing the core
	dumpdir=/var/run/pluto/
	#
	# NAT-TRAVERSAL support, see README.NAT-Traversal
	nat_traversal=yes
	# exclude networks used on server side by adding %v4:!a.b.c.0/24
	# It seems that T-Mobile in the US and Rogers/Fido in Canada are
	# using 25/8 as "private" address space on their 3G network.
	# This range has not been announced via BGP (at least upto 2010-12-21)
	virtual_private=%v4:10.0.0.0/8,%v4:192.168.0.0/16,%v4:172.16.0.0/12,%v4:25.0.0.0/8,%v6:fd00::/8,%v6:fe80::/10
	# OE is now off by default. Uncomment and change to on, to enable.
	oe=off
	# which IPsec stack to use. auto will try netkey, then klips then mast
	protostack=netkey
	# Use this to log to a file, or disable logging on embedded systems (like openwrt)
	#plutostderrlog=/dev/null

# Add connections here

# sample VPN connection
# for more examples, see /etc/ipsec.d/examples/
#conn sample
#		# Left security gateway, subnet behind it, nexthop toward right.
#		left=10.0.0.1
#		leftsubnet=172.16.0.0/24
#		leftnexthop=10.22.33.44
#		# Right security gateway, subnet behind it, nexthop toward left.
#		right=10.12.12.1
#		rightsubnet=192.168.0.0/24
#		rightnexthop=10.101.102.103
#		# To authorize this connection, but not actually start it, 
#		# at startup, uncomment this.
#		#auto=add

conn L2TP-PSK
    authby=secret
    pfs=no
    rekey=no
    type=tunnel
    esp=aes128-sha1
    ike=aes128-sha-modp1024
    ikelifetime=8h
    keylife=1h
    left=188.120.238.209
    leftnexthop=%defaultroute
    leftprotoport=17/1701
    right=%any
    rightprotoport=17/1701
    rightsubnetwithin=0.0.0.0/0
    auto=add
    dpddelay=30
    dpdtimeout=120
    dpdaction=clear
    keyingtries=3

/etc/ppp/chap-secrets выглядят примерно так:

user *   password 10.0.1.2

Лог:

IPsec SAref does not work with L2TP kernel mode yet, enabling forceuserspace=yes
Apr 22 11:51:00 boulevard xl2tpd[25495]: setsockopt recvref[30]: Protocol not available
Apr 22 11:51:00 boulevard xl2tpd[25495]: This binary does not support kernel L2TP.
Apr 22 11:51:00 boulevard xl2tpd[25496]: xl2tpd version xl2tpd-1.3.1 started on boulevard.inpark.me PID:25496
Apr 22 11:51:00 boulevard xl2tpd[25496]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
Apr 22 11:51:00 boulevard xl2tpd[25496]: Forked by Scott Balmos and David Stipp, (C) 2001
Apr 22 11:51:00 boulevard xl2tpd[25496]: Inherited by Jeff McAdams, (C) 2002
Apr 22 11:51:00 boulevard xl2tpd[25496]: Forked again by Xelerance (http://www.xelerance.com) (C) 2006
Apr 22 11:51:00 boulevard xl2tpd[25496]: Listening on IP address 0.0.0.0, port 1701
Apr 22 11:51:04 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 26631 twice, ignoring second one.
Apr 22 11:51:06 boulevard xl2tpd[25496]: Can not find tunnel 9618 (refhim=0)
Apr 22 11:51:06 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 9618 Dumping.
Apr 22 11:51:06 boulevard xl2tpd[25496]: Can not find tunnel 9618 (refhim=0)
Apr 22 11:51:06 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 9618 Dumping.
Apr 22 11:51:06 boulevard xl2tpd[25496]: Can not find tunnel 9618 (refhim=0)
Apr 22 11:51:06 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 9618 Dumping.
Apr 22 11:51:06 boulevard xl2tpd[25496]: Can not find tunnel 9618 (refhim=0)
Apr 22 11:51:06 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 9618 Dumping.
Apr 22 11:51:10 boulevard xl2tpd[25496]: Connection established to 95.78.169.87, 1701.  Local: 693, Remote: 26631 (ref=0/0).  LNS session is 'default'
Apr 22 11:51:10 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8207 twice, ignoring second one.
Apr 22 11:51:10 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8207 twice, ignoring second one.
Apr 22 11:51:12 boulevard xl2tpd[25496]: Connection established to 81.4.234.179, 1701.  Local: 4791, Remote: 9071 (ref=0/0).  LNS session is 'default'
Apr 22 11:51:12 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 26631 (got 1, expected 2)
Apr 22 11:51:12 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:12 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 26631 (got 3, expected 2)
Apr 22 11:51:12 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:12 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 26631 (got 3, expected 2)
Apr 22 11:51:12 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:16 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 64241.  Closing.
Apr 22 11:51:16 boulevard xl2tpd[25496]: Connection 8318 closed to 85.26.183.159, port 27770 (Timeout)
Apr 22 11:51:18 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 24352.  Closing.
Apr 22 11:51:18 boulevard xl2tpd[25496]: Connection 8207 closed to 89.188.119.130, port 1701 (Timeout)
Apr 22 11:51:18 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 30252 twice, ignoring second one.
Apr 22 11:51:18 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8207 twice, ignoring second one.
Apr 22 11:51:20 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 63969.  Closing.
Apr 22 11:51:20 boulevard xl2tpd[25496]: Connection 4865 closed to 213.141.130.34, port 1701 (Timeout)
Apr 22 11:51:22 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 23176.  Closing.
Apr 22 11:51:22 boulevard xl2tpd[25496]: Connection 1724 closed to 83.149.9.52, port 57482 (Timeout)
Apr 22 11:51:22 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 5362 twice, ignoring second one.
Apr 22 11:51:24 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 37314.  Closing.
Apr 22 11:51:24 boulevard xl2tpd[25496]: Connection 30252 closed to 205.157.146.166, port 11882 (Timeout)
Apr 22 11:51:26 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 59881.  Closing.
Apr 22 11:51:26 boulevard xl2tpd[25496]: Connection 5362 closed to 89.188.119.130, port 1036 (Timeout)
Apr 22 11:51:26 boulevard xl2tpd[25496]: Unable to deliver closing message for tunnel 64241. Destroying anyway.
Apr 22 11:51:26 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 9071 (got 3, expected 2)
Apr 22 11:51:26 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:26 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 26631 (got 1, expected 2)
Apr 22 11:51:26 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:26 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 26631 (got 3, expected 2)
Apr 22 11:51:26 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:26 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 30252 twice, ignoring second one.
Apr 22 11:51:26 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8210 twice, ignoring second one.
Apr 22 11:51:26 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 5362 twice, ignoring second one.
Apr 22 11:51:26 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8291 twice, ignoring second one.
Apr 22 11:51:26 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8189 twice, ignoring second one.
Apr 22 11:51:26 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8210 twice, ignoring second one.
Apr 22 11:51:28 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 65369.  Closing.
Apr 22 11:51:28 boulevard xl2tpd[25496]: Connection 8350 closed to 109.148.223.39, port 1701 (Timeout)
Apr 22 11:51:28 boulevard xl2tpd[25496]: Unable to deliver closing message for tunnel 24352. Destroying anyway.
Apr 22 11:51:28 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8291 twice, ignoring second one.
Apr 22 11:51:28 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8189 twice, ignoring second one.
Apr 22 11:51:28 boulevard xl2tpd[25496]: Can not find tunnel 24352 (refhim=0)
Apr 22 11:51:28 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 24352 Dumping.
Apr 22 11:51:28 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 9071 (got 1, expected 2)
Apr 22 11:51:28 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:28 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 9071 (got 3, expected 2)
Apr 22 11:51:28 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:28 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 26631 (got 3, expected 2)
Apr 22 11:51:28 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:28 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 30252 twice, ignoring second one.
Apr 22 11:51:28 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 5362 twice, ignoring second one.
Apr 22 11:51:28 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8210 twice, ignoring second one.
Apr 22 11:51:28 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8291 twice, ignoring second one.
Apr 22 11:51:28 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 8189 twice, ignoring second one.
Apr 22 11:51:28 boulevard xl2tpd[25496]: Can not find tunnel 24352 (refhim=0)
Apr 22 11:51:28 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 24352 Dumping.
Apr 22 11:51:28 boulevard xl2tpd[25496]: Can not find tunnel 24352 (refhim=0)
Apr 22 11:51:28 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 24352 Dumping.
Apr 22 11:51:28 boulevard xl2tpd[25496]: Can not find tunnel 24352 (refhim=0)
Apr 22 11:51:28 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 24352 Dumping.
Apr 22 11:51:28 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 9071 (got 3, expected 2)
Apr 22 11:51:28 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:28 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 26631 (got 1, expected 2)
Apr 22 11:51:28 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:28 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 26631 (got 3, expected 2)
Apr 22 11:51:28 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:28 boulevard xl2tpd[25496]: call_close: Call 54931 to 95.78.169.87 disconnected
Apr 22 11:51:28 boulevard xl2tpd[25496]: control_finish: Out of IP addresses on tunnel 26631!
Apr 22 11:51:30 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 43398.  Closing.
Apr 22 11:51:30 boulevard xl2tpd[25496]: Connection 8210 closed to 89.188.119.130, port 1037 (Timeout)
Apr 22 11:51:30 boulevard xl2tpd[25496]: Unable to deliver closing message for tunnel 63969. Destroying anyway.
Apr 22 11:51:32 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 54804.  Closing.
Apr 22 11:51:32 boulevard xl2tpd[25496]: Connection 9837 closed to 62.167.1.178, port 1701 (Timeout)
Apr 22 11:51:32 boulevard xl2tpd[25496]: Unable to deliver closing message for tunnel 23176. Destroying anyway.
Apr 22 11:51:34 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 57475.  Closing.
Apr 22 11:51:34 boulevard xl2tpd[25496]: Connection 8291 closed to 83.149.8.158, port 32378 (Timeout)
Apr 22 11:51:34 boulevard xl2tpd[25496]: Unable to deliver closing message for tunnel 37314. Destroying anyway.
Apr 22 11:51:34 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 5539 twice, ignoring second one.
Apr 22 11:51:34 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 17267 twice, ignoring second one.
Apr 22 11:51:34 boulevard xl2tpd[25496]: control_finish: Peer requested tunnel 1479 twice, ignoring second one.
Apr 22 11:51:34 boulevard xl2tpd[25496]: Can not find tunnel 24352 (refhim=0)
Apr 22 11:51:34 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 24352 Dumping.
Apr 22 11:51:34 boulevard xl2tpd[25496]: Can not find tunnel 24352 (refhim=0)
Apr 22 11:51:34 boulevard xl2tpd[25496]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 24352 Dumping.
Apr 22 11:51:34 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 9071 (got 1, expected 2)
Apr 22 11:51:34 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:34 boulevard xl2tpd[25496]: check_control: Received out of order control packet on tunnel 9071 (got 3, expected 2)
Apr 22 11:51:34 boulevard xl2tpd[25496]: handle_packet: bad control packet!
Apr 22 11:51:34 boulevard xl2tpd[25496]: call_close: Call 52553 to 81.4.234.179 disconnected
Apr 22 11:51:34 boulevard xl2tpd[25496]: control_finish: Out of IP addresses on tunnel 9071!
Apr 22 11:51:36 boulevard xl2tpd[25496]: Maximum retries exceeded for tunnel 31825.  Closing.
Apr 22 11:51:36 boulevard xl2tpd[25496]: Connection 8189 closed to 128.73.254.202, port 1701 (Timeout)
Apr 22 11:51:36 boulevard xl2tpd[25496]: Unable to deliver closing message for tunnel 59881. Destroying anyway.

Что-то еще нужно для определения проблемы?

★★
assign ip = no
exclusive = no 
assign ip = yes

Забавно. А вообще давай уж логи и pppd, и pluto, а то фиг знает.

thesis ★★★★★
()
Ответ на: комментарий от thesis

Где логи pppd посмотреть? В syslog нету, в /var/log ничего не находится по маске ppp*.

Вот все что удалось раскопать по поводу pluto:

$ tail -f /var/log/syslog | grep pluto
Apr 23 13:04:11 boulevard pluto: adjusting ipsec.d to /etc/ipsec.d
Apr 23 13:04:11 boulevard ipsec__plutorun: adjusting ipsec.d to /etc/ipsec.d
Apr 23 13:04:11 boulevard ipsec__plutorun: 002 added connection description «L2TP-PSK»
Dikar ★★
() автор топика
Ответ на: комментарий от thesis

Если сделать

sudo pppd file /etc/ppp/options.xl2tpd

то увидим в логах вот такую штуку:

Apr 23 17:28:14 boulevard pppd[13748]: pppd 2.4.5 started by user, uid 0
Apr 23 17:28:14 boulevard pppd[13748]: speed 4 not supported
Apr 23 17:28:14 boulevard pppd[13748]: using channel 2
Apr 23 17:28:14 boulevard pppd[13748]: Using interface ppp0
Apr 23 17:28:14 boulevard pppd[13748]: Connect: ppp0 <--> /dev/pts/0
Apr 23 17:28:14 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:17 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:20 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:23 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:26 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:29 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:32 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:35 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:38 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:41 boulevard pppd[13748]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth eap> <magic 0x91a80aa0>]
Apr 23 17:28:44 boulevard pppd[13748]: LCP: timeout sending Config-Requests
Apr 23 17:28:44 boulevard pppd[13748]: Connection terminated.
Apr 23 17:28:44 boulevard pppd[13748]: Modem hangup
Apr 23 17:28:44 boulevard pppd[13748]: Exit.

Dikar ★★
() автор топика
Ответ на: комментарий от Dikar

Ну, от такой штуки эффекта быть и не должно...
Насчет pluto, посмотри лог ipsec, нет ли там разрыва в процессе (в смысле, «в то время как») согласования ppp-соединения. Т.е. не рвется ли тоннель сразу после создания.

И боевой лог ppp таки полезно получить. " The packets are logged through
syslog with facility daemon and level debug." (с), хотя насчет убунты не знаю - может они изменили чего.

thesis ★★★★★
()
Вы не можете добавлять комментарии в эту тему. Тема перемещена в архив.