[strongSwan] L2TP over IPSec-PSK tunnel not stable in-time
Martin Lambev
fsh3mve at gmail.com
Wed May 30 04:13:02 CEST 2012
Hello StrongSwan guys,
I have very strange problem and I do not know how to debug properly and find the solution, so I count on your advice.
I building a server running PPTP, L2TP service with various clients - iOS, MAC and Windows connect to it.
But over RANDOM times L2TP connection is vanished ( sometimes 15 minutes, an hour, or and more) iOS and Mac OS X clients get disconnected and the reason is:
in the client log "Serial link appears to be disconnected." and message box to the user: "you were disconnected because PPP server is not responding"
Usual cause of this error is when PPPOE connection of ADSL is disconnected and reinitiated ( this cloud happen not more that 2 times a week, especially if there is P2P traffic).
What I observe is that this happens no mater if the client is idle or actively using the tunnel, and PPPOE connection is the same one.
Why I'm thinking that this is related to StrongSwan? I do not have much knowledge and experience using IPSec, that's why I need your assistance.
I make exactly same test set up with openswan ( same ipsec.conf with required changes for openswan to work), and can hold connection for days with no PPP server is not responding errors, but I have other issues with openswan regarding windows cleints. So I'm looking for solution?
SERVER _IP_50.31.*.*<->INTERNET<->ADSL_MODEM<->IP_182.240.29.154_BUFFALO-WHR-HP-54G-WIRELSS-ROUTER_INTERNAL_IP_1.1.1.1<|>IP_1.1.1.252_MAC_OS_X_Snow_Leopard_client
WHR-HP-G54 is running tomato firmware. MacOS X - Snow Leopard 10.6.8 + latest updates.
Server is CentOS 6.2 x64 Linux updated and strongSwan U4.6.3/K2.6.32-220.17.1.el6.x86_64, I try to use EPEL repo build but can't connect behind NAT, so I had to compile form source:
StrongSwan is compiled with that following options:
./configure --sysconfdir=/etc --prefix=/usr --libexecdir=/usr/lib \
--enable-openssl \
--enable-agent \
--enable-gcrypt \
--enable-integrity-test \
--enable-openssl \
--enable-nat-transport \
--enable-eap-identity \
--enable-eap-radius \
--enable-eap-md5 \
--enable-integrity-test \
--enable-cisco-quirks \
--enable-radattr \
--enable-dhcp \
--enable-eap-md5 \
--enable-blowfish \
--enable-eap-mschapv2 \
--enable-eap-aka \
--enable-eap-aka-3gpp2
My strongswan configuration:
# ipsec.conf - strongSwan IPsec configuration file
# basic configuration
config setup
#plutodebug=all
# crlcheckinterval=600
# strictcrlpolicy=yes
# cachecrls=yes
keep_alive=20s #Put this to force KA packages
nat_traversal=yes
charonstart=no
plutostart=yes
virtual_private=%v4:10.0.0.0/8,%v4:192.168.0.0/16,%v4:172.16.0.0/12
# Add connections here.
# I comment this out to be sure that it's not DPD related
#conn %default
# dpddelay=30
# dpdtimeout=120
# dpdaction=clear
conn WIN-L2TP-PSK-NAT
rightsubnet=vhost:%no,%priv
leftprotoport=17/%any
rightprotoport=17/1701
also=L2TP-PSK-noNAT
conn APPLE-L2TP-PSK-NAT
rightsubnet=vhost:%no,%priv
forceencaps=yes
leftprotoport=17/1701
rightprotoport=17/%any
also=L2TP-PSK-noNAT
conn L2TP-PSK-noNAT
keyexchange=ikev1
authby=secret
pfs=no
auto=add
rekey=no
type=tunnel
keyingtries=3
left=50.31.240.127
leftnexthop=%defaultroute
right=%any
rightsubnetwithin=0.0.0.0/0
Strongswan log:
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: received Vendor ID payload [RFC 3947]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [4df37928e9fc4fd1b3262170d515c662]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [8f8d83826d246b6fc7a8a6a428c11de8]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [439b59f8ba676c4c7737ae22eab8f582]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [4d1e0e136deafa34c4f3ea9f02ec7285]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [80d0bb3def54565ee84645d4c85ce3ee]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [9909b64eed937c6573de52ace952fa6b]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
May 29 17:01:49 msvpn pluto[28754]: packet from 182.240.29.154:500: received Vendor ID payload [Dead Peer Detection]
May 29 17:01:49 msvpn pluto[28754]: "L2TP-PSK-noNAT"[11] 182.240.29.154 #29: responding to Main Mode from unknown peer 182.240.29.154
May 29 17:01:49 msvpn pluto[28754]: "L2TP-PSK-noNAT"[11] 182.240.29.154 #29: NAT-Traversal: Result using RFC 3947: peer is NATed
May 29 17:01:49 msvpn pluto[28754]: "L2TP-PSK-noNAT"[11] 182.240.29.154 #29: ignoring informational payload, type IPSEC_INITIAL_CONTACT
May 29 17:01:49 msvpn pluto[28754]: "L2TP-PSK-noNAT"[11] 182.240.29.154 #29: Peer ID is ID_IPV4_ADDR: '1.1.1.252'
May 29 17:01:49 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154 #29: deleting connection "L2TP-PSK-noNAT" instance with peer 182.240.29.154 {isakmp=#0/ipsec=#0}
May 29 17:01:49 msvpn pluto[28754]: | NAT-T: new mapping 182.240.29.154:500/4500)
May 29 17:01:49 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sent MR3, ISAKMP SA established
May 29 17:01:50 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #30: NAT-Traversal: received 2 NAT-OA. using first, ignoring others
May 29 17:01:50 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #30: responding to Quick Mode
May 29 17:01:51 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #30: Dead Peer Detection (RFC 3706) enabled
May 29 17:01:51 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #30: IPsec SA established {ESP=>0x00b83a5b <0xc1050de2 NATOA=1.1.1.252}
May 29 17:01:51 msvpn pluto[28754]: 192.168.100.1 appeared on ppp0
May 29 17:01:51 msvpn pluto[28754]: 192.168.100.1 disappeared from ppp0
May 29 17:01:51 msvpn pluto[28754]: 192.168.100.1 appeared on ppp0
May 29 17:01:51 msvpn pluto[28754]: interface ppp0 activated
May 29 17:49:51 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[16] 182.240.29.154:4500 #31: NAT-Traversal: received 2 NAT-OA. using first, ignoring others
May 29 17:49:51 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[16] 182.240.29.154:4500 #31: responding to Quick Mode
May 29 17:49:51 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[16] 182.240.29.154:4500 #31: cannot install eroute -- it is in use for "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #30
May 29 17:49:51 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[16] 182.240.29.154:4500: deleting connection "APPLE-L2TP-PSK-NAT" instance with peer 182.240.29.154 {isakmp=#0/ipsec=#0}
May 29 17:49:54 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:49:54 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:49:57 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:49:57 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:50:00 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:50:00 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:50:03 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:50:03 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:50:06 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:50:06 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:50:09 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:50:09 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:50:12 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:50:12 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:50:15 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:50:15 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:50:18 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xdff2e28f (perhaps this is a duplicated packet)
May 29 17:50:18 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: sending encrypted notification INVALID_MESSAGE_ID to 182.240.29.154:4500
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: received Vendor ID payload [RFC 3947]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [4df37928e9fc4fd1b3262170d515c662]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [8f8d83826d246b6fc7a8a6a428c11de8]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [439b59f8ba676c4c7737ae22eab8f582]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [4d1e0e136deafa34c4f3ea9f02ec7285]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [80d0bb3def54565ee84645d4c85ce3ee]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [9909b64eed937c6573de52ace952fa6b]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
May 29 17:55:49 msvpn pluto[28754]: packet from 182.240.29.154:4500: received Vendor ID payload [Dead Peer Detection]
May 29 17:55:49 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #32: responding to Main Mode from unknown peer 182.240.29.154:4500
May 29 17:55:49 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #32: NAT-Traversal: Result using RFC 3947: peer is NATed
May 29 17:55:49 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #32: Peer ID is ID_IPV4_ADDR: '1.1.1.252'
May 29 17:55:49 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #32: sent MR3, ISAKMP SA established
May 29 17:55:54 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500 #29: received Delete SA payload: deleting ISAKMP State #29
May 29 17:55:54 msvpn pluto[28754]: "L2TP-PSK-noNAT"[12] 182.240.29.154:4500: deleting connection "L2TP-PSK-noNAT" instance with peer 182.240.29.154 {isakmp=#0/ipsec=#0}
May 29 18:01:51 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #30: IPsec SA expired (--dontrekey)
May 29 18:01:51 msvpn pluto[28754]: deleting policy 182.240.29.154/32[udp/63505] === 50.31.*.*/32[udp/l2tp] fwd failed, not found
May 29 18:01:52 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[17] 182.240.29.154:4500 #33: NAT-Traversal: received 2 NAT-OA. using first, ignoring others
May 29 18:01:52 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[17] 182.240.29.154:4500 #33: responding to Quick Mode
May 29 18:01:52 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[17] 182.240.29.154:4500 #33: Dead Peer Detection (RFC 3706) enabled
May 29 18:01:52 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[17] 182.240.29.154:4500 #33: IPsec SA established {ESP=>0x0714c753 <0xcdf1a4da NATOA=1.1.1.252}
May 29 18:01:52 msvpn pluto[28754]: interface ppp0 deactivated
May 29 18:01:52 msvpn pluto[28754]: interface ppp0 deleted
May 29 18:07:11 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #32: received Delete SA(0x0714c753) payload: deleting IPSEC State #33
May 29 18:07:11 msvpn pluto[28754]: deleting policy 182.240.29.154/32[udp/63505] === 50.31.*.*/32[udp/l2tp] fwd failed, not found
May 29 18:07:11 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #32: deleting connection "APPLE-L2TP-PSK-NAT" instance with peer 182.240.29.154 {isakmp=#0/ipsec=#0}
May 29 18:07:11 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500 #32: received Delete SA payload: deleting ISAKMP State #32
May 29 18:07:11 msvpn pluto[28754]: "APPLE-L2TP-PSK-NAT"[15] 182.240.29.154:4500: deleting connection "APPLE-L2TP-PSK-NAT" instance with peer 182.240.29.154 {isakmp=#0/ipsec=#0}
Accel-pppd ppp+l2tp server log:
[2012-05-29 17:01:50]: info: : recv [L2TP tid=0 sid=0 Ns=0 Nr=0 <Message-Type Start-Ctrl-Conn-Request> <Protocol-Version 256> <Framing-Capabilities 3> <Host-Name > <Assigned-Tunnel-ID 154> <Recv-Window-Size 4>]
[2012-05-29 17:01:50]: info: : send [L2TP tid=154 sid=0 Ns=0 Nr=1 <Message-Type Start-Ctrl-Conn-Reply> <Protocol-Version 256> <Host-Name accel-ppp> <Framing-Capabilities 3> <Assigned-Tunnel-ID 1> <Vendor-Name accel-ppp>]
[2012-05-29 17:01:51]: info: : recv [L2TP tid=1 sid=0 Ns=1 Nr=1 <Message-Type Start-Ctrl-Conn-Connected>]
[2012-05-29 17:01:51]: info: : recv [L2TP tid=1 sid=0 Ns=2 Nr=1 <Message-Type Incoming-Call-Request> <Assigned-Session-ID 27332> <Call-Serial-Number 1>]
[2012-05-29 17:01:51]: info: : send [L2TP tid=154 sid=27332 Ns=1 Nr=3 <Message-Type Incoming-Call-Reply> <Assigned-Session-ID 1>]
[2012-05-29 17:01:51]: info: : recv [L2TP tid=1 sid=1 Ns=3 Nr=2 <Message-Type Incoming-Call-Connected> <TX-Speed 1000000> <Framing-Type 3>]
[2012-05-29 17:01:51]: info: ppp0: connect: ppp0 <--> l2tp(182.240.29.154)
[2012-05-29 17:01:51]: debug: ppp0: lcp_layer_init
[2012-05-29 17:01:51]: debug: ppp0: auth_layer_init
[2012-05-29 17:01:51]: debug: ppp0: ccp_layer_init
[2012-05-29 17:01:51]: debug: ppp0: ipcp_layer_init
[2012-05-29 17:01:51]: debug: ppp0: ipv6cp_layer_init
[2012-05-29 17:01:51]: debug: ppp0: ppp established
[2012-05-29 17:01:51]: debug: ppp0: lcp_layer_start
[2012-05-29 17:01:51]: info: ppp0: send [LCP ConfReq id=1 <auth MSCHAP-v2> <magic 2463b9ea> <mru 1400>]
[2012-05-29 17:01:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=2 Nr=4]
[2012-05-29 17:01:51]: info: ppp0: recv [LCP ConfReq id=1 < 2 6 0 0 0 0 > <magic 24b2c03b> <pcomp> <accomp>]
[2012-05-29 17:01:51]: info: ppp0: send [LCP ConfRej id=1 < 2 6 0 0 0 0 > <pcomp> <accomp>]
[2012-05-29 17:01:51]: info: ppp0: recv [LCP ConfAck id=1 <auth MSCHAP-v2> <magic 2463b9ea> <mru 1400>]
[2012-05-29 17:01:51]: info: ppp0: recv [LCP ConfReq id=2 <magic 24b2c03b>]
[2012-05-29 17:01:51]: info: ppp0: send [LCP ConfAck id=2 ]
[2012-05-29 17:01:51]: debug: ppp0: lcp_layer_started
[2012-05-29 17:01:51]: debug: ppp0: auth_layer_start
[2012-05-29 17:01:51]: info: ppp0: send [MSCHAP-v2 Challenge id=1 <1e167a1d7d46ada03286ca5789f397>]
[2012-05-29 17:01:51]: debug: ppp0: recv [LCP EchoReq id=0 <magic 3bc0b224>]
[2012-05-29 17:01:51]: debug: ppp0: send [LCP EchoRep id=0 <magic eab96324>]
[2012-05-29 17:01:51]: info: ppp0: recv [MSCHAP-v2 Response id=1 <a36ad570bcc26c2363136b638f92237>, <91fcd698c7ed38a1c8ee14b8068be57eac2c98d2481298>, F=0, name="user"]
[2012-05-29 17:01:51]: info: ppp0: send [RADIUS(1) Access-Request id=1 <User-Name "user"> <NAS-Identifier "accel-pppd"> <NAS-IP-Address 127.0.0.1> <NAS-Port 0> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "182.240.29.154"> <Called-Station-Id "50.31.*.*"><Microsoft MS-CHAP-Challenge ><Microsoft MS-CHAP2-Response >]
[2012-05-29 17:01:51]: info: ppp0: recv [RADIUS(1) Access-Accept id=1 <Framed-Protocol PPP> <Framed-Compression Van-Jacobson-TCP-IP><Microsoft MS-CHAP2-Success ><Microsoft MS-MPPE-Recv-Key ><Microsoft MS-MPPE-Send-Key ><Microsoft MS-MPPE-Encryption-Policy 1><Microsoft MS-MPPE-Encryption-Type 6>]
[2012-05-29 17:01:51]: info: ppp0: send [MSCHAP-v2 Success id=1 "S=B51F7D00C1E48A4167AFEDEDB9C63906B7956BAA M=Authentication successed"]
[2012-05-29 17:01:51]: debug: ppp0: auth_layer_started
[2012-05-29 17:01:51]: debug: ppp0: ccp_layer_start
[2012-05-29 17:01:51]: debug: ppp0: ipcp_layer_start
[2012-05-29 17:01:51]: info: ppp0: send [IPCP ConfReq id=1 <addr 192.168.100.1>]
[2012-05-29 17:01:51]: debug: ppp0: ipv6cp_layer_start
[2012-05-29 17:01:51]: info: ppp0: user: authentication successed
[2012-05-29 17:01:51]: info: ppp0: recv [IPCP ConfReq id=1 <addr 0.0.0.0> <dns1 0.0.0.0> <dns2 0.0.0.0>]
[2012-05-29 17:01:51]: info: ppp0: send [IPCP ConfNak id=1 <addr 192.168.100.38> <dns1 208.67.222.222> <dns2 8.8.8.8>]
[2012-05-29 17:01:51]: warn: ppp0: IPV6CP: discarding packet
[2012-05-29 17:01:51]: info: ppp0: send [LCP ProtoRej id=3 <8057>]
[2012-05-29 17:01:51]: info: ppp0: recv [IPCP ConfAck id=1 <addr 192.168.100.1>]
[2012-05-29 17:01:51]: info: ppp0: recv [IPCP ConfReq id=2 <addr 192.168.100.38> <dns1 208.67.222.222> <dns2 8.8.8.8>]
[2012-05-29 17:01:51]: info: ppp0: send [IPCP ConfAck id=2]
[2012-05-29 17:01:51]: debug: ppp0: ipcp_layer_started
[2012-05-29 17:01:51]: info: ppp0: send [RADIUS(1) Accounting-Request id=1 <User-Name "user"> <NAS-Identifier "accel-pppd"> <NAS-IP-Address 127.0.0.1> <NAS-Port 0> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "182.240.29.154"> <Called-Station-Id "50.31.*.*"> <Acct-Status-Type Start> <Acct-Authentic RADIUS> <Acct-Session-Id "0040de0f535563e2"> <Acct-Session-Time 0> <Acct-Input-Octets 0> <Acct-Output-Octets 0> <Acct-Input-Packets 0> <Acct-Output-Packets 0> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 192.168.100.38>]
[2012-05-29 17:01:51]: info: ppp0: recv [RADIUS(1) Accounting-Response id=1]
[2012-05-29 17:01:51]: debug: ppp0: l2tp: ppp started
[2012-05-29 17:02:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=2 Nr=4 <Message-Type Hello>]
[2012-05-29 17:03:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=3 Nr=4 <Message-Type Hello>]
[2012-05-29 17:04:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=4 Nr=4 <Message-Type Hello>]
[2012-05-29 17:05:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=5 Nr=4 <Message-Type Hello>]
[2012-05-29 17:06:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=6 Nr=4 <Message-Type Hello>]
[2012-05-29 17:07:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=7 Nr=4 <Message-Type Hello>]
[2012-05-29 17:08:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=8 Nr=4 <Message-Type Hello>]
[2012-05-29 17:09:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=9 Nr=4 <Message-Type Hello>]
[2012-05-29 17:10:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=10 Nr=4 <Message-Type Hello>]
[2012-05-29 17:11:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=11 Nr=4 <Message-Type Hello>]
[2012-05-29 17:12:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=12 Nr=4 <Message-Type Hello>]
[2012-05-29 17:13:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=13 Nr=4 <Message-Type Hello>]
[2012-05-29 17:14:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=14 Nr=4 <Message-Type Hello>]
[2012-05-29 17:15:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=15 Nr=4 <Message-Type Hello>]
[2012-05-29 17:16:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=16 Nr=4 <Message-Type Hello>]
[2012-05-29 17:17:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=17 Nr=4 <Message-Type Hello>]
[2012-05-29 17:18:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=18 Nr=4 <Message-Type Hello>]
[2012-05-29 17:19:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=19 Nr=4 <Message-Type Hello>]
[2012-05-29 17:20:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=20 Nr=4 <Message-Type Hello>]
[2012-05-29 17:21:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=21 Nr=4 <Message-Type Hello>]
[2012-05-29 17:22:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=22 Nr=4 <Message-Type Hello>]
[2012-05-29 17:23:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=23 Nr=4 <Message-Type Hello>]
[2012-05-29 17:24:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=24 Nr=4 <Message-Type Hello>]
[2012-05-29 17:25:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=25 Nr=4 <Message-Type Hello>]
[2012-05-29 17:26:51]: debug: ppp0: recv [LCP EchoReq id=1 <magic 3bc0b224>]
[2012-05-29 17:26:51]: debug: ppp0: send [LCP EchoRep id=1 <magic eab96324>]
[2012-05-29 17:26:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=26 Nr=4 <Message-Type Hello>]
[2012-05-29 17:27:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=27 Nr=4 <Message-Type Hello>]
[2012-05-29 17:28:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=28 Nr=4 <Message-Type Hello>]
[2012-05-29 17:29:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=29 Nr=4 <Message-Type Hello>]
[2012-05-29 17:30:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=30 Nr=4 <Message-Type Hello>]
[2012-05-29 17:31:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=31 Nr=4 <Message-Type Hello>]
[2012-05-29 17:32:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=32 Nr=4 <Message-Type Hello>]
[2012-05-29 17:33:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=33 Nr=4 <Message-Type Hello>]
[2012-05-29 17:34:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=34 Nr=4 <Message-Type Hello>]
[2012-05-29 17:35:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=35 Nr=4 <Message-Type Hello>]
[2012-05-29 17:36:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=36 Nr=4 <Message-Type Hello>]
[2012-05-29 17:37:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=37 Nr=4 <Message-Type Hello>]
[2012-05-29 17:38:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=38 Nr=4 <Message-Type Hello>]
[2012-05-29 17:39:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=39 Nr=4 <Message-Type Hello>]
[2012-05-29 17:40:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=40 Nr=4 <Message-Type Hello>]
[2012-05-29 17:41:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=41 Nr=4 <Message-Type Hello>]
[2012-05-29 17:42:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=42 Nr=4 <Message-Type Hello>]
[2012-05-29 17:43:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=43 Nr=4 <Message-Type Hello>]
[2012-05-29 17:44:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=44 Nr=4 <Message-Type Hello>]
[2012-05-29 17:45:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=45 Nr=4 <Message-Type Hello>]
[2012-05-29 17:46:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=46 Nr=4 <Message-Type Hello>]
[2012-05-29 17:47:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=47 Nr=4 <Message-Type Hello>]
[2012-05-29 17:48:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=48 Nr=4 <Message-Type Hello>]
[2012-05-29 17:49:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=49 Nr=4 <Message-Type Hello>]
[2012-05-29 17:50:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=50 Nr=4 <Message-Type Hello>]
[2012-05-29 17:51:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=51 Nr=4 <Message-Type Hello>]
[2012-05-29 17:52:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=52 Nr=4 <Message-Type Hello>]
[2012-05-29 17:53:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=53 Nr=4 <Message-Type Hello>]
[2012-05-29 17:54:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=54 Nr=4 <Message-Type Hello>]
[2012-05-29 17:55:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=55 Nr=4 <Message-Type Hello>]
[2012-05-29 17:56:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=56 Nr=4 <Message-Type Hello>]
[2012-05-29 17:57:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=57 Nr=4 <Message-Type Hello>]
[2012-05-29 17:58:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=58 Nr=4 <Message-Type Hello>]
[2012-05-29 17:59:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=59 Nr=4 <Message-Type Hello>]
[2012-05-29 18:00:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=60 Nr=4 <Message-Type Hello>]
[2012-05-29 18:01:51]: debug: ppp0: send [L2TP tid=154 sid=0 Ns=61 Nr=4 <Message-Type Hello>]
[2012-05-29 18:01:51]: warn: l2tp: sendto: Operation not permitted
[2012-05-29 18:01:51]: debug: ppp0: ppp_terminate
[2012-05-29 18:01:51]: info: ppp0: send [RADIUS(1) Accounting-Request id=1 <User-Name "user"> <NAS-Identifier "accel-pppd"> <NAS-IP-Address 127.0.0.1> <NAS-Port 0> <NAS-Port-Type Virtual> <Service-Type Framed-User> <Framed-Protocol PPP> <Calling-Station-Id "182.240.29.154"> <Called-Station-Id "50.31.*.*"> <Acct-Status-Type Stop> <Acct-Authentic RADIUS> <Acct-Session-Id "0040de0f535563e2"> <Acct-Session-Time 3600> <Acct-Input-Octets 1088279> <Acct-Output-Octets 10808550> <Acct-Input-Packets 12610> <Acct-Output-Packets 12660> <Acct-Input-Gigawords 0> <Acct-Output-Gigawords 0> <Framed-IP-Address 192.168.100.38> <Acct-Terminate-Cause User-Request>]
[2012-05-29 18:01:52]: info: ppp0: recv [RADIUS(1) Accounting-Response id=1]
[2012-05-29 18:01:52]: debug: ppp0: lcp_layer_free
[2012-05-29 18:01:52]: debug: ppp0: auth_layer_free
[2012-05-29 18:01:52]: debug: ppp0: ccp_layer_free
[2012-05-29 18:01:52]: debug: ppp0: ipcp_layer_free
[2012-05-29 18:01:52]: debug: ppp0: ipv6cp_layer_free
[2012-05-29 18:01:52]: debug: ppp0: ppp destablished
[2012-05-29 18:01:52]: debug: ppp0: l2tp: ppp finished
[2012-05-29 18:01:52]: info: ppp0: disconnected
MacOS X Snow Leopard - Client log:
5/29/12 5:01:49 PM pppd[92868] pppd 2.4.2 (Apple version 412.5) started by user, uid 501
5/29/12 5:01:49 PM pppd[92868] L2TP connecting to server '50.31.*.*' (50.31.*.*)...
5/29/12 5:01:49 PM pppd[92868] IPSec connection started
5/29/12 5:01:50 PM pppd[92868] IPSec connection established
5/29/12 5:01:51 PM pppd[92868] L2TP connection established.
5/29/12 5:01:51 PM pppd[92868] Connect: ppp0 <--> socket[34:18]
5/29/12 5:01:52 PM pppd[92868] local IP address 192.168.100.38
5/29/12 5:01:52 PM pppd[92868] remote IP address 192.168.100.1
5/29/12 5:01:52 PM pppd[92868] primary DNS address 208.67.222.222
5/29/12 5:01:52 PM pppd[92868] secondary DNS address 8.8.8.8
5/29/12 5:01:52 PM pppd[92868] l2tp_wait_input: Address added. previous interface setting (name: en1, address: 1.1.1.252), current interface setting (name: ppp0, family: PPP, address: 192.168.100.38, subnet: 255.255.255.0, destination: 192.168.100.1).
5/29/12 6:07:11 PM pppd[92868] Serial link appears to be disconnected.
5/29/12 6:07:11 PM pppd[92868] Connection terminated.
5/29/12 6:07:11 PM pppd[92868] L2TP disconnecting...
5/29/12 6:07:11 PM pppd[92868] L2TP disconnected
If you can advise me how can I solve this issue pealse help!
Best Regards,
Martin
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20120530/7b5da189/attachment.html>
More information about the Users
mailing list