Hi,
I'm having a few issues where by my OpenL2TP / IPSEC setup is disconnect
after anywhere between 2 and ~45 minutes with a Error 809 in Windows 7. I
know this is normally to do with NAT-T devices but I've already set the
registry key entry mentioned in the Microsoft KB ().
The strange thing is that the initial connection works fine. I was
wondering if anyone could point me towards a solution, or means of finding
one! I've been looking at the debug output from connections without any
real luck.
I've included my config and some log output below.
Regards,
Adam
/etc/openl2tp.conf - ran with /usr/sbin/openl2tpd -D -c /etc/openl2tpd.conf
-p ipsec.so
tunnel profile modify profile_name=default \
our_udp_port=1701
ppp profile modify profile_name=default \
auth_eap=no \
auth_pap=no \
auth_none=yes \
auth_chap=yes \
auth_mschapv1=yes \
idle_timeout=1800 \
auth_mschapv2=yes \
local_ipaddr=10.20.30.40 \
dns_ipaddr_pri=10.44.16.130 \
ip_pool_name=default
/etc/ippool.conf
pool create pool_name=default
pool address add pool_name=default first_addr=10.20.30.40 num_addrs=41
netmask=255.255.0.0
pool address reserve pool_name=default first_addr=10.20.30.40 num_addrs=1
Relevant log (hopefully...)
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FUNC: tunl 63931: allocated
context using profile 'default', created by network request
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: tunl 63931: setting up
ipsec SPD entry for a2c1082/1701 - 51958928/1701
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: RX: tunl 63931/0:
len=132 ns/nr=0/0, our ns/nr=0/0, peer ns/nr=0/0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: peer
ns/nr is 0/0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: DATA: RX: tunl 63931/0: rcv
132 bytes from peer 81.149.137.40, packet ns/nr 0/0 type 0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: update nr
from 0 to 1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVP: tunl 63931: SCCRQ
message decode of 112 bytes started
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: PROTOCOL_VERSION:
ver=1 rev=0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: FRAMING_CAP: cap=1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: BEARER_CAP: cap=0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: FIRMWARE_VERSION:
revision=1537
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: HOST_NAME: name=
remote-2530p.engineering.Clearswift.org
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: VENDOR_NAME:
name=Microsoft
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: TUNNEL_ID: id=2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: RX_WINDOW_SIZE:
size=8
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931: SCCRQ
received from peer 2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FSM: CCE(63931) event
SCCRQ_ACCEPT in state IDLE
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931: adjust
tx_window_size: peer=8, ours=10
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVP: tunl 63931: building
SCCRP message, 9 AVPs
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931: sending
SCCRP to peer 2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: queuing
tx packet, type 2, len 152, ns/nr 0/1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: update ns
to 1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: adding
packet to ackq, type 2, len 152, ns/nr 0/1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: DATA: TX: tunl 63931/0:
send 152 bytes to peer 81.149.137.40, packet ns/nr 0/1 type 2, retry 0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FSM: CCE(63931) state
change: IDLE --> WAITCTLCONN
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: RX: tunl 63931/0:
len=20 ns/nr=1/1, our ns/nr=1/1, peer ns/nr=0/0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: peer
ns/nr is 1/1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: pkt 0/1
is acked by nr 1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: DATA: RX: tunl 63931/0: rcv
20 bytes from peer 81.149.137.40, packet ns/nr 1/1 type 0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: update nr
from 1 to 2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVP: tunl 63931: SCCCN
message decode of 0 bytes started
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931: SCCCN
received from peer 2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FSM: CCE(63931) event
SCCCN_ACCEPT in state WAITCTLCONN
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FUNC: tunl 63931 up
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FSM: CCE(63931) state
change: WAITCTLCONN --> ESTABLISHED
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: RX: tunl 63931/0:
len=70 ns/nr=2/1, our ns/nr=1/2, peer ns/nr=1/1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: peer
ns/nr is 2/1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: DATA: RX: tunl 63931/0: rcv
70 bytes from peer 81.149.137.40, packet ns/nr 2/1 type 0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: update nr
from 2 to 3
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVP: tunl 63931: ICRQ
message decode of 50 bytes started
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: SESSION_ID: id=1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA:
CALL_SERIAL_NUMBER: value=0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: BEARER_TYPE: type=2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931/0: ICRQ
received from peer 2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: 63931/9712: creating UNIX
pppd context
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: 63931/9712: using ppp
profile 'default'
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FSM: LNIC(63931/9712) event
ICRQ_ACCEPT in state IDLE
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVP: tunl 63931: building
ICRP message, 2 AVPs
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931/9712:
sending ICRP to peer 2/1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: queuing
tx packet, type 11, len 28, ns/nr 1/3
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: update ns
to 2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: adding
packet to ackq, type 11, len 28, ns/nr 1/3
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: DATA: TX: tunl 63931/1:
send 28 bytes to peer 81.149.137.40, packet ns/nr 1/3 type 11, retry 0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FSM: LNIC(63931/9712) state
change: IDLE --> WAITCONNECT
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: RX: tunl 63931/9712:
len=48 ns/nr=3/2, our ns/nr=2/3, peer ns/nr=2/1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: peer
ns/nr is 3/2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: pkt 1/3
is acked by nr 2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: DATA: RX: tunl 63931/9712:
rcv 48 bytes from peer 81.149.137.40, packet ns/nr 3/2 type 0
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: update nr
from 3 to 4
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVP: tunl 63931: ICCN
message decode of 28 bytes started
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: TX_CONNECT_SPEED:
value=54000000
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: FRAMING_TYPE:
type=1
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: AVPDATA: PROXY_AUTH_TYPE:
value=4
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931/9712:
ICCN received from peer 2
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FSM: LNIC(63931/9712) event
ICCN_ACCEPT in state WAITCONNECT
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: 63931/9712: starting UNIX
pppd
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: sess 63931/9712: spawned
pppd pid=10349
Apr 9 09:58:27 openl2tp_host openl2tpd[24609]: FSM: LNIC(63931/9712) state
change: WAITCONNECT --> ESTABLISHED
Apr 9 09:58:27 openl2tp_host openl2tpd[10349]: sess 63931/9712: pppd
10.20.30.40: ms-dns 10.44.16.130 debug kdebug 7 noipdefault plugin
ippool.so ippool_name default ippool_debug 1 sync refuse-eap refuse-pap
idle 1800 nodetach local noauth noaccomp nopcomp nobsdcomp nodeflate
nopredictor1 novj novjccomp noendpoint nomp plugin pppol2tp.so plugin
openl2tp.so pppol2tp 21 pppol2tp_lns_mode pppol2tp_tunnel_id 63931
pppol2tp_session_id 9712 pppol2tp_debug_mask 15
Apr 9 09:58:27 openl2tp_host pppd[10349]: Plugin ippool.so loaded.
Apr 9 09:58:27 openl2tp_host pppd[10349]: Plugin pppol2tp.so loaded.
Apr 9 09:58:27 openl2tp_host pppd[10349]: Plugin openl2tp.so loaded.
Apr 9 09:58:27 openl2tp_host pppd[10349]: Enabling LCP snooping
Apr 9 09:58:27 openl2tp_host pppd[10349]: pppd 2.4.5 started by root, uid 0
Apr 9 09:58:27 openl2tp_host pppd[10349]: using channel 69
Apr 9 09:58:27 openl2tp_host pppd[10349]: Using interface ppp2
Apr 9 09:58:27 openl2tp_host pppd[10349]: Connect: ppp2 <-->
Apr 9 09:58:27 openl2tp_host pppd[10349]: PPPoL2TP options: lnsmode tid
63931 sid 9712 debugmask 15
Apr 9 09:58:27 openl2tp_host pppd[10349]: sent [LCP ConfReq id=0x1
<asyncmap 0x0> <magic 0x9b6c95fd>]
Apr 9 09:58:27 openl2tp_host pppd[10349]: rcvd [LCP ConfReq id=0x0 <mru
1400> <magic 0x57a04e0a> <pcomp> <accomp> <callback CBCP>]
Apr 9 09:58:27 openl2tp_host pppd[10349]: sent [LCP ConfRej id=0x0
<callback CBCP>]
Apr 9 09:58:27 openl2tp_host pppd[10349]: Found option type 0d; len 3
Apr 9 09:58:27 openl2tp_host pppd[10349]: rcvd [LCP ConfReq id=0x1 <mru
1400> <magic 0x57a04e0a> <pcomp> <accomp>]
Apr 9 09:58:27 openl2tp_host pppd[10349]: sent [LCP ConfAck id=0x1 <mru
1400> <magic 0x57a04e0a> <pcomp> <accomp>]
Apr 9 09:58:27 openl2tp_host pppd[10349]: Found option type 01; len 4
Apr 9 09:58:27 openl2tp_host pppd[10349]: Found option type 05; len 6
Apr 9 09:58:27 openl2tp_host pppd[10349]: Found option type 07; len 2
Apr 9 09:58:27 openl2tp_host pppd[10349]: Found option type 08; len 2
Apr 9 09:58:28 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: send zlb
ack, ns/nr=2/4
Apr 9 09:58:30 openl2tp_host pppd[10349]: sent [LCP ConfReq id=0x1
<asyncmap 0x0> <magic 0x9b6c95fd>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: rcvd [LCP ConfAck id=0x1
<asyncmap 0x0> <magic 0x9b6c95fd>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: Found option type 02; len 6
Apr 9 09:58:30 openl2tp_host pppd[10349]: Found ACCM of 00000000 (incoming)
Apr 9 09:58:30 openl2tp_host pppd[10349]: Found option type 05; len 6
Apr 9 09:58:30 openl2tp_host pppd[10349]: PPPoL2TP options: lnsmode tid
63931 sid 9712 debugmask 15
Apr 9 09:58:30 openl2tp_host pppd[10349]: Using explicit local address
10.20.30.40
Apr 9 09:58:30 openl2tp_host pppd[10349]: Allocated address 10.20.30.43
from pool default
Apr 9 09:58:30 openl2tp_host pppd[10349]: sent [IPCP ConfReq id=0x1 <addr
10.20.30.40>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: rcvd [LCP Ident id=0x2
magic=0x57a04e0a "MSRASV5.20"]
Apr 9 09:58:30 openl2tp_host pppd[10349]: rcvd [LCP Ident id=0x3
magic=0x57a04e0a "MSRAS-0-REMOTE-2530P"]
Apr 9 09:58:30 openl2tp_host pppd[10349]: rcvd [LCP Ident id=0x4
magic=0x57a04e0a
"\37777777606k\37777777714\37777777662\37777777676,*K\37777777627\37777777646\37777777663\37777777702<\37777777612
\37777777724"]
Apr 9 09:58:30 openl2tp_host pppd[10349]: rcvd [IPCP ConfReq id=0x5 <addr
0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns2 0.0.0.0> <ms-wins
0.0.0.0>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: sent [IPCP ConfRej id=0x5
<ms-wins 0.0.0.0> <ms-wins 0.0.0.0>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: rcvd [IPCP ConfAck id=0x1 <addr
10.20.30.40>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: rcvd [IPCP ConfReq id=0x6 <addr
0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: sent [IPCP ConfNak id=0x6 <addr
10.20.30.43> <ms-dns1 10.44.16.130> <ms-dns2 10.44.16.130>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: rcvd [IPCP ConfReq id=0x7 <addr
10.20.30.43> <ms-dns1 10.44.16.130> <ms-dns2 10.44.16.130>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: sent [IPCP ConfAck id=0x7 <addr
10.20.30.43> <ms-dns1 10.44.16.130> <ms-dns2 10.44.16.130>]
Apr 9 09:58:30 openl2tp_host pppd[10349]: local IP address 10.20.30.40
Apr 9 09:58:30 openl2tp_host pppd[10349]: remote IP address 10.20.30.43
Apr 9 09:58:30 openl2tp_host pppd[10349]: openl2tp send: sent
PPP_UPDOWN_IND, 52 bytes
Apr 9 09:58:30 openl2tp_host openl2tpd[24609]: FUNC: tunl 63931/9712:
using interface ppp2
<snip>
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: retry
failure
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: FSM: CCE(63931) event
XPRT_DOWN in state ESTABLISHED
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: AVP: tunl 63931: building
STOPCCN message, 3 AVPs
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931: sending
STOPCCN to peer 2
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: queuing
tx packet, type 4, len 38, ns/nr 3/5
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: tx window
closed
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: FUNC: tunl 63931 down
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: FUNC: tunl 63931: starting
cleanup timer
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: FSM: CCE(63931) state
change: ESTABLISHED --> CLOSING
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: FSM: LNIC(63931/9712) event
CLOSE_REQ in state ESTABLISHED
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: AVP: tunl 63931: building
CDN message, 3 AVPs
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: PROTO: tunl 63931/9712:
sending CDN to peer 2/1
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: queuing
tx packet, type 14, len 36, ns/nr 3/5
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: tx window
closed
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: 63931/9712: stopping unix
pppd pid 10349
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: 63931/9712: cleaning UNIX
pppd context
Apr 9 10:02:36 openl2tp_host openl2tpd[24609]: FSM: LNIC(63931/9712) state
change: ESTABLISHED --> IDLE
Apr 9 10:02:36 openl2tp_host pppd[10349]: Terminating on signal 15
Apr 9 10:02:36 openl2tp_host pppd[10349]: Freed address 10.20.30.43 to
pool default
Apr 9 10:02:36 openl2tp_host pppd[10349]: openl2tp send: sent
PPP_UPDOWN_IND, 52 bytes
Apr 9 10:02:36 openl2tp_host pppd[10349]: Connect time 4.1 minutes.
Apr 9 10:02:36 openl2tp_host pppd[10349]: Sent 10605 bytes, received 18932
bytes.
Apr 9 10:02:36 openl2tp_host pppd[10349]: PPPoL2TP options: lnsmode tid
63931 sid 9712 debugmask 15
Apr 9 10:02:36 openl2tp_host pppd[10349]: sent [LCP TermReq id=0x2 "User
request"]
Apr 9 10:02:37 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: set retry
interval to 2
Apr 9 10:02:37 openl2tp_host openl2tpd[24609]: XPRT: tunl 63931: retry
failure
Apr 9 10:02:37 openl2tp_host openl2tpd[24609]: FSM: CCE(63931) event
XPRT_DOWN in state CLOSING
Apr 9 10:02:39 openl2tp_host pppd[10349]: sent [LCP TermReq id=0x3 "User
request"]
Apr 9 10:02:42 openl2tp_host pppd[10349]: Connection terminated.
Apr 9 10:02:42 openl2tp_host pppd[10349]: Modem hangup
Apr 9 10:02:42 openl2tp_host pppd[10349]: ippool: Exiting. Releasing any
allocated IP addresses.
Apr 9 10:02:42 openl2tp_host pppd[10349]: Exit.
------------------------------------------------------------------------------
Precog is a next-generation analytics platform capable of advanced
analytics on semi-structured data. The platform includes APIs for building
apps and a phenomenal toolset for data science. Developers can use
our toolset for easy data analysis & visualization. Get a free account!
http://www2.precog.com/precogplatform/slashdotnewsletter
_______________________________________________
Openl2tp-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/openl2tp-users
