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.

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

★★

А, вот еще... ppp0 пропал из списка интерфейсов.

Dikar ★★
() автор топика

Делал service ipsec restart? Какой дистрибутив сервера и клиента?

покажи 

ip a
uname -a

В /etc/ipsec.conf поменяй

type=transport
rightprotoport=17/%any
Добавь: 
rightid=%any

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

ipsec конечно же рестартил раньше

Лог после изменений конфига и рестарта ipsec: 

Apr 22 14:44:51 boulevard xl2tpd[28092]: Can not find tunnel 61581 (refhim=0)
Apr 22 14:44:51 boulevard xl2tpd[28092]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 61581 Dumping.
Apr 22 14:44:52 boulevard kernel: [72184.712707] Initializing XFRM netlink socket
Apr 22 14:44:52 boulevard kernel: [72184.946342] padlock_sha: VIA PadLock Hash Engine not detected.
Apr 22 14:44:52 boulevard kernel: [72185.026702] Intel AES-NI instructions are not detected.
Apr 22 14:44:52 boulevard kernel: [72185.090681] Intel AES-NI instructions are not detected.
Apr 22 14:44:53 boulevard xl2tpd[28092]: Maximum retries exceeded for tunnel 7595.  Closing.
Apr 22 14:44:53 boulevard xl2tpd[28092]: Connection 30556 closed to 205.157.146.166, port 11882 (Timeout)
Apr 22 14:44:53 boulevard xl2tpd[28092]: Unable to deliver closing message for tunnel 32075. Destroying anyway.
Apr 22 14:44:53 boulevard xl2tpd[28092]: control_finish: Peer requested tunnel 5666 twice, ignoring second one.
Apr 22 14:44:54 boulevard ipsec_setup: ...Openswan IPsec started
Apr 22 14:44:54 boulevard pluto: adjusting ipsec.d to /etc/ipsec.d
Apr 22 14:44:54 boulevard ipsec__plutorun: adjusting ipsec.d to /etc/ipsec.d
Apr 22 14:44:55 boulevard ipsec__plutorun: 002 added connection description «L2TP-PSK»
Apr 22 14:44:55 boulevard xl2tpd[28092]: Maximum retries exceeded for tunnel 18155.  Closing.
Apr 22 14:44:55 boulevard xl2tpd[28092]: Connection 8653 closed to 109.148.223.39, port 1701 (Timeout)
Apr 22 14:44:55 boulevard xl2tpd[28092]: Unable to deliver closing message for tunnel 14088. Destroying anyway.
Apr 22 14:44:55 boulevard xl2tpd[28092]: Can not find tunnel 23449 (refhim=0)
Apr 22 14:44:55 boulevard xl2tpd[28092]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 23449 Dumping.
Apr 22 14:44:55 boulevard xl2tpd[28092]: Can not find tunnel 43494 (refhim=0)
Apr 22 14:44:55 boulevard xl2tpd[28092]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 43494 Dumping.
Apr 22 14:44:55 boulevard xl2tpd[28092]: Can not find tunnel 43494 (refhim=0)
Apr 22 14:44:55 boulevard xl2tpd[28092]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 43494 Dumping.
Apr 22 14:44:55 boulevard xl2tpd[28092]: Can not find tunnel 23449 (refhim=0)
Apr 22 14:44:55 boulevard xl2tpd[28092]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 23449 Dumping.
Apr 22 14:44:55 boulevard xl2tpd[28092]: Can not find tunnel 55905 (refhim=0)
Apr 22 14:44:55 boulevard xl2tpd[28092]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 55905 Dumping.
Apr 22 14:44:55 boulevard xl2tpd[28092]: Can not find tunnel 9494 (refhim=0)
Apr 22 14:44:55 boulevard xl2tpd[28092]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 9494 Dumping.
Apr 22 14:44:55 boulevard xl2tpd[28092]: Can not find tunnel 44669 (refhim=0)

ip a: 

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN 
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
    inet6 ::1/128 scope host 
       valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP qlen 1000
    link/ether 38:60:77:2f:ad:3e brd ff:ff:ff:ff:ff:ff
    inet 188.120.238.209/20 brd 188.120.239.255 scope global eth0
    inet6 fe80::3a60:77ff:fe2f:ad3e/64 scope link 
       valid_lft forever preferred_lft forever
3: tun0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 100
    link/none 
    inet 10.0.141.1 peer 10.0.141.2/32 scope global tun0

uname -a : 

Linux boulevard.inpark.me 3.2.0-80-generic #116-Ubuntu SMP Mon Mar 23 17:11:03 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

На сервере обновленная позавчера Ubuntu 12.04. Клиенты - Оффтопик и роутеры Mikrotik

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

Попробуй добавить в /etc/xl2tpd/xl2tpd.conf
в [global] 

pppoptfile = /etc/ppp/options.xl2tpd
в [lns default] 
ip range = 10.0.0.2-10.0.0.254
length bit = yes
В /etc/ppp/options.xl2tpd 
receive-all

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

Всё сделал, но что-то не помогло

Apr 22 17:12:21 boulevard xl2tpd[3150]: setsockopt recvref[30]: Protocol not available
Apr 22 17:12:21 boulevard xl2tpd[3150]: This binary does not support kernel L2TP.
Apr 22 17:12:21 boulevard xl2tpd[3151]: xl2tpd version xl2tpd-1.3.1 started on boulevard.inpark.me PID:3151
Apr 22 17:12:21 boulevard xl2tpd[3151]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
Apr 22 17:12:21 boulevard xl2tpd[3151]: Forked by Scott Balmos and David Stipp, (C) 2001
Apr 22 17:12:21 boulevard xl2tpd[3151]: Inherited by Jeff McAdams, (C) 2002
Apr 22 17:12:21 boulevard xl2tpd[3151]: Forked again by Xelerance (http://www.xelerance.com) (C) 2006
Apr 22 17:12:21 boulevard xl2tpd[3151]: Listening on IP address 0.0.0.0, port 1701
Apr 22 17:12:28 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 5432 twice, ignoring second one.
Apr 22 17:12:28 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 2291 twice, ignoring second one.
Apr 22 17:12:34 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 46693.  Closing.
Apr 22 17:12:34 boulevard xl2tpd[3151]: Connection 6105 closed to 194.190.114.54, port 1701 (Timeout)
Apr 22 17:12:34 boulevard xl2tpd[3151]: Connection established to 194.190.114.54, 1701.  Local: 46693, Remote: 6105 (ref=0/0).  LNS session is 'default'
Apr 22 17:12:34 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 5432 twice, ignoring second one.
Apr 22 17:12:36 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 44081.  Closing.
Apr 22 17:12:36 boulevard xl2tpd[3151]: Connection 5432 closed to 213.141.130.34, port 1701 (Timeout)
Apr 22 17:12:36 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 9637 twice, ignoring second one.
Apr 22 17:12:38 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 2170.  Closing.
Apr 22 17:12:38 boulevard xl2tpd[3151]: Connection 2291 closed to 83.149.9.52, port 57482 (Timeout)
Apr 22 17:12:40 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 47991.  Closing.
Apr 22 17:12:40 boulevard xl2tpd[3151]: Connection 27197 closed to 95.78.169.87, port 1701 (Timeout)
Apr 22 17:12:40 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 2291 twice, ignoring second one.
Apr 22 17:12:40 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 11074 twice, ignoring second one.
Apr 22 17:12:40 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 9637 twice, ignoring second one.
Apr 22 17:12:40 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 8916 twice, ignoring second one.
Apr 22 17:12:42 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 13450.  Closing.
Apr 22 17:12:42 boulevard xl2tpd[3151]: Connection 9637 closed to 81.4.234.179, port 1701 (Timeout)
Apr 22 17:12:44 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 6670.  Closing.
Apr 22 17:12:44 boulevard xl2tpd[3151]: Connection 8819 closed to 89.188.119.130, port 1038 (Timeout)
Apr 22 17:12:44 boulevard xl2tpd[3151]: Unable to deliver closing message for tunnel 46693. Destroying anyway.
Apr 22 17:12:44 boulevard xl2tpd[3151]: Connection established to 213.141.130.34, 1701.  Local: 44081, Remote: 5432 (ref=0/0).  LNS session is 'default'
Apr 22 17:12:44 boulevard xl2tpd[3151]: Can not find tunnel 46693 (refhim=0)
Apr 22 17:12:44 boulevard xl2tpd[3151]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 46693 Dumping.
Apr 22 17:12:44 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 8916 twice, ignoring second one.
Apr 22 17:12:44 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 2046 twice, ignoring second one.
Apr 22 17:12:44 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 11074 twice, ignoring second one.
Apr 22 17:12:46 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 11115.  Closing.
Apr 22 17:12:46 boulevard xl2tpd[3151]: Connection 11074 closed to 83.149.8.159, port 30052 (Timeout)
Apr 22 17:12:46 boulevard xl2tpd[3151]: Unable to deliver closing message for tunnel 44081. Destroying anyway.
Apr 22 17:12:46 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 9637 twice, ignoring second one.
Apr 22 17:12:46 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 2046 twice, ignoring second one.
Apr 22 17:12:48 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 14790.  Closing.
Apr 22 17:12:48 boulevard xl2tpd[3151]: Connection 8916 closed to 86.182.89.125, port 1701 (Timeout)
Apr 22 17:12:48 boulevard xl2tpd[3151]: Unable to deliver closing message for tunnel 2170. Destroying anyway.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Maximum retries exceeded for tunnel 34502.  Closing.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Connection 5964 closed to 95.84.168.150, port 1701 (Timeout)
Apr 22 17:12:50 boulevard xl2tpd[3151]: Unable to deliver closing message for tunnel 47991. Destroying anyway.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Can not find tunnel 46693 (refhim=0)
Apr 22 17:12:50 boulevard xl2tpd[3151]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 46693 Dumping.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Can not find tunnel 44081 (refhim=0)
Apr 22 17:12:50 boulevard xl2tpd[3151]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 44081 Dumping.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Can not find tunnel 44081 (refhim=0)
Apr 22 17:12:50 boulevard xl2tpd[3151]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 44081 Dumping.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Can not find tunnel 44081 (refhim=0)
Apr 22 17:12:50 boulevard xl2tpd[3151]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 44081 Dumping.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Can not find tunnel 46693 (refhim=0)
Apr 22 17:12:50 boulevard xl2tpd[3151]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 46693 Dumping.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Can not find tunnel 2170 (refhim=0)
Apr 22 17:12:50 boulevard xl2tpd[3151]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 2170 Dumping.
Apr 22 17:12:50 boulevard xl2tpd[3151]: Can not find tunnel 2170 (refhim=0)
Apr 22 17:12:50 boulevard xl2tpd[3151]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 2170 Dumping.
Apr 22 17:12:50 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 590 twice, ignoring second one.
Apr 22 17:12:50 boulevard xl2tpd[3151]: control_finish: Peer requested tunnel 11074 twice, ignoring second one.

ip a

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN 
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
    inet6 ::1/128 scope host 
       valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP qlen 1000
    link/ether 38:60:77:2f:ad:3e brd ff:ff:ff:ff:ff:ff
    inet 188.120.238.209/20 brd 188.120.239.255 scope global eth0
    inet6 fe80::3a60:77ff:fe2f:ad3e/64 scope link 
       valid_lft forever preferred_lft forever
Dikar ★★
() автор топика
Ответ на: комментарий от Disova

Неа(

Кстати, «pppoptfile = /etc/ppp/options.xl2tpd» в [global] не парсится. Я вставил в [lns default] - это нормально?

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

Господа, неужели больше ни у кого нет идей?

Dikar ★★
() автор топика 
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 ★★★★★
()

Попробуй с этим конфигом /etc/xl2tpd/xl2tpd.conf 

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

[lns default]                          
ip range = 10.0.0.2-10.0.0.254         
local ip = 10.0.0.1                    
length bit = yes                      
refuse chap = yes                      
refuse pap = yes                       
require authentication = no            
ppp debug = yes                         
pppoptfile = /etc/ppp/options.xl2tpd

Если нет - покажи еще /etc/ipsec.secret и 

ipsec verify

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

Оффтопик это винда? В ней указывай использовать Microsoft CHAP(MS-CHAP v2)

Disova ★
()

Двухвечернее исследование дампов пакетов не выявило в трафике ничего некорректного, кроме того что клиенты в процессе согласования соединения на уровне l2tp почему-то не переходили к следующему после SCCRQ этапу, хотя ответы сервера были вполне корректны. Более вдумчивое разглядывание дампа показало наличие малообъяснимых задержек в ответах со стороны сервера, достигавших в снятых дампах от 2-х до 10 секунд.

xl2tpd однопоточный, и strace показал, что большую часть времени он проводит не в select/poll, как можно было ожидать, а в nanosleep!

Проблема оказалась в том, что в поставляемой с ubuntu12.04 версии xl2tpd ещё не исправлен следующий баг:

https://github.com/xelerance/xl2tpd/pull/15/files#diff-1113ea3793e29f98397a98...

В результате забытых скобочек sleep(2) выполнялся всегда при получении пакета SCCRQ с запросом на соединение, а не только в режиме отладки. И если клиенты подключались последовательно по одному (пока их первый раз настраивали) - это почти не вызывало проблем.

А после того как сервер перезагрузился все клиенты попытались установить соединение одновременно, в результате чего сервер никому из них не отвечал достаточно быстро, в результате чего они продолжали слать SCCRQ, отчего сервер только больше вызывал sleep, и те ответы, которые всё же доходили до клиентов, отбрасывались ими, поскольку приходили слишком поздно.

Помогла установка более новой версии из 14.04 в которой этот баг уже исправлен.

GPFault ★★
()
19 июня 2015 г.
29 июля 2015 г.
Вы не можете добавлять комментарии в эту тему. Тема перемещена в архив.
Admin