[Openswan Users] openswan - xl2tpd problem
onno frank
onnoklm at hotmail.com
Sun Sep 9 09:27:08 EDT 2007
Hi,
I seem to be having some strange problem that ive been wrestling about for
quite some time now. It seems through the logs that all is ok, but the
windows vpn connection dialogue just stays, until it gives a timeout error.
I hope you may be able to shed some light onto it.
Thanks.
Here are the logs:
ipsec_setup: Starting Openswan IPsec U2.4.9/K2.6.22-gentoo-r5...
[ ok ]
Sep 9 15:22:51 bravo ipsec__plutorun: Starting Pluto subsystem...
Sep 9 15:22:52 bravo pluto[10159]: Starting Pluto (Openswan Version 2.4.9
PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR; Vendor ID OE_]{vKgCoOI)
Sep 9 15:22:52 bravo pluto[10159]: Setting NAT-Traversal port-4500 floating
to on
Sep 9 15:22:52 bravo pluto[10159]: port floating activation criteria
nat_t=1/port_fload=1
Sep 9 15:22:52 bravo pluto[10159]: including NAT-Traversal patch (Version
0.6c)
Sep 9 15:22:52 bravo pluto[10159]: ike_alg_register_enc(): Activating
OAKLEY_AES_CBC: Ok (ret=0)
Sep 9 15:22:52 bravo pluto[10159]: starting up 1 cryptographic helpers
Sep 9 15:22:52 bravo pluto[10159]: started helper pid=10163 (fd:6)
Sep 9 15:22:52 bravo pluto[10159]: Using NETKEY IPsec interface code on
2.6.22-gentoo-r5
Sep 9 15:22:52 bravo ipsec_setup: ...Openswan IPsec started
Sep 9 15:22:57 bravo pluto[10159]: Changing to directory
'/etc/ipsec/ipsec.d/cacerts'
Sep 9 15:22:57 bravo pluto[10159]: loaded CA cert file 'ca-cert.pem' (867
bytes)
Sep 9 15:22:57 bravo pluto[10159]: Could not change to directory
'/etc/ipsec/ipsec.d/aacerts'
Sep 9 15:22:57 bravo pluto[10159]: Could not change to directory
'/etc/ipsec/ipsec.d/ocspcerts'
Sep 9 15:22:57 bravo pluto[10159]: Could not change to directory
'/etc/ipsec/ipsec.d/crls'
Sep 9 15:22:57 bravo pluto[10159]: loaded host cert file
'/etc/ipsec/ipsec.d/certs/gateway.cert' (2900 bytes)
Sep 9 15:22:57 bravo pluto[10159]: added connection description
"roadwarrior-l2tp"
Sep 9 15:22:57 bravo pluto[10159]: loaded host cert file
'/etc/ipsec/ipsec.d/certs/gateway.cert' (2900 bytes)
Sep 9 15:22:57 bravo pluto[10159]: added connection description
"roadwarrior"
Sep 9 15:22:57 bravo pluto[10159]: loaded host cert file
'/etc/ipsec/ipsec.d/certs/gateway.cert' (2900 bytes)
Sep 9 15:22:57 bravo pluto[10159]: added connection description
"roadwarrior-l2tp-oldwin"
Sep 9 15:22:57 bravo pluto[10159]: loaded host cert file
'/etc/ipsec/ipsec.d/certs/gateway.cert' (2900 bytes)
Sep 9 15:22:57 bravo pluto[10159]: added connection description
"macintosh-l2tp"
Sep 9 15:22:57 bravo pluto[10159]: loaded host cert file
'/etc/ipsec/ipsec.d/certs/gateway.cert' (2900 bytes)
Sep 9 15:22:57 bravo pluto[10159]: added connection description
"roadwarrior-l2tp-updatedwin"
Sep 9 15:22:57 bravo pluto[10159]: listening for IKE messages
Sep 9 15:22:57 bravo pluto[10159]: adding interface tun0/tun0 10.11.0.2:500
Sep 9 15:22:57 bravo pluto[10159]: adding interface tun0/tun0
10.11.0.2:4500
Sep 9 15:22:57 bravo pluto[10159]: adding interface eth0/eth0
87.106.180.178:500
Sep 9 15:22:57 bravo pluto[10159]: adding interface eth0/eth0
87.106.180.178:4500
Sep 9 15:22:57 bravo pluto[10159]: adding interface lo/lo 127.0.0.1:500
Sep 9 15:22:57 bravo pluto[10159]: adding interface lo/lo 127.0.0.1:4500
Sep 9 15:22:57 bravo pluto[10159]: adding interface lo/lo ::1:500
Sep 9 15:22:57 bravo pluto[10159]: loading secrets from
"/etc/ipsec/ipsec.secrets"
Sep 9 15:22:57 bravo pluto[10159]: loaded private key file
'/etc/ipsec/ipsec.d/private/ca-key.pem' (887 bytes)
Sep 9 15:22:57 bravo pluto[10159]: loaded private key file
'/etc/ipsec/ipsec.d/private/gateway.key' (887 bytes)
Sep 9 15:23:07 bravo pluto[10159]: packet from 88.28.141.152:500: ignoring
Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000004]
Sep 9 15:23:07 bravo pluto[10159]: packet from 88.28.141.152:500: ignoring
Vendor ID payload [FRAGMENTATION]
Sep 9 15:23:07 bravo pluto[10159]: packet from 88.28.141.152:500: received
Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] method set to=106
Sep 9 15:23:07 bravo pluto[10159]: packet from 88.28.141.152:500: ignoring
Vendor ID payload [Vid-Initial-Contact]
Sep 9 15:23:07 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
responding to Main Mode from unknown peer 88.28.141.152
Sep 9 15:23:07 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Sep 9 15:23:07 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
STATE_MAIN_R1: sent MR1, expecting MI2
Sep 9 15:23:08 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike-02/03: no NAT
detected
Sep 9 15:23:08 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Sep 9 15:23:08 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
STATE_MAIN_R2: sent MR2, expecting MI3
Sep 9 15:23:09 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
discarding duplicate packet; already STATE_MAIN_R2
Sep 9 15:23:09 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
Main mode peer ID is ID_DER_ASN1_DN: 'O=IntelectIT, CN=Phillipp Cohrs'
Sep 9 15:23:09 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
no crl from issuer "CN=VPN CA, O=IntelectIT" found (strict=no)
Sep 9 15:23:09 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
I am sending my cert
Sep 9 15:23:09 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Sep 9 15:23:09 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_RSA_SIG
cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp2048}
Sep 9 15:23:10 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
retransmitting in response to duplicate packet; already STATE_MAIN_R3
Sep 9 15:23:10 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #2:
responding to Quick Mode {msgid:14ab56ef}
Sep 9 15:23:10 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #2:
transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
Sep 9 15:23:10 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #2:
STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
Sep 9 15:23:11 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #2:
next payload type of ISAKMP Hash Payload has an unknown value: 215
Sep 9 15:23:11 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #2:
malformed payload in packet
Sep 9 15:23:11 bravo pluto[10159]: | payload malformed after IV
Sep 9 15:23:11 bravo pluto[10159]: | 85 da d0 2b a7 fd 30 7b
Sep 9 15:23:11 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #2:
sending notification PAYLOAD_MALFORMED to 88.28.141.152:500
Sep 9 15:23:11 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #2:
transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Sep 9 15:23:11 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #2:
STATE_QUICK_R2: IPsec SA established {ESP=>0x21856f84 <0xe61561eb
xfrm=3DES_0-HMAC_MD5 NATD=none DPD=none}
Sep 9 15:23:11 bravo xl2tpd[5684]: network_thread: recv packet from
88.28.141.152, size = 99, tunnel = 0, call = 0 ref=0 refhim=0
Sep 9 15:23:11 bravo xl2tpd[5684]: get_call: allocating new tunnel for host
88.28.141.152, port 1701.
Sep 9 15:23:11 bravo xl2tpd[5684]: handle_avps: handling avp's for tunnel
51378, call 2769
Sep 9 15:23:11 bravo xl2tpd[5684]: message_type_avp: message type 1
(Start-Control-Connection-Request)
Sep 9 15:23:11 bravo xl2tpd[5684]: protocol_version_avp: peer is using
version 1, revision 0.
Sep 9 15:23:11 bravo xl2tpd[5684]: framing_caps_avp: supported peer frames:
sync
Sep 9 15:23:11 bravo xl2tpd[5684]: bearer_caps_avp: supported peer bearers:
Sep 9 15:23:11 bravo xl2tpd[5684]: firmware_rev_avp: peer reports firmware
version 1280 (0x0500)
Sep 9 15:23:11 bravo xl2tpd[5684]: hostname_avp: peer reports hostname
'laptop'
Sep 9 15:23:11 bravo xl2tpd[5684]: vendor_avp: peer reports vendor
'Microsoft'
Sep 9 15:23:11 bravo xl2tpd[5684]: assigned_tunnel_avp: using peer's tunnel
45
Sep 9 15:23:11 bravo xl2tpd[5684]: receive_window_size_avp: peer wants RWS
of 8. Will use flow control.
Sep 9 15:23:11 bravo xl2tpd[5684]: control_finish: message type is
Start-Control-Connection-Request(1). Tunnel is 45, call is 0.
Sep 9 15:23:11 bravo xl2tpd[5684]: control_finish: sending SCCRP
Sep 9 15:23:13 bravo xl2tpd[5684]: network_thread: recv packet from
88.28.141.152, size = 99, tunnel = 0, call = 0 ref=0 refhim=0
Sep 9 15:23:13 bravo xl2tpd[5684]: get_call: allocating new tunnel for host
88.28.141.152, port 1701.
Sep 9 15:23:13 bravo xl2tpd[5684]: handle_avps: handling avp's for tunnel
56777, call 5387312
Sep 9 15:23:13 bravo xl2tpd[5684]: message_type_avp: message type 1
(Start-Control-Connection-Request)
Sep 9 15:23:13 bravo xl2tpd[5684]: protocol_version_avp: peer is using
version 1, revision 0.
Sep 9 15:23:13 bravo xl2tpd[5684]: framing_caps_avp: supported peer frames:
sync
Sep 9 15:23:13 bravo xl2tpd[5684]: bearer_caps_avp: supported peer bearers:
Sep 9 15:23:13 bravo xl2tpd[5684]: firmware_rev_avp: peer reports firmware
version 1280 (0x0500)
Sep 9 15:23:13 bravo xl2tpd[5684]: hostname_avp: peer reports hostname
'laptop'
Sep 9 15:23:13 bravo xl2tpd[5684]: vendor_avp: peer reports vendor
'Microsoft'
Sep 9 15:23:13 bravo xl2tpd[5684]: assigned_tunnel_avp: using peer's tunnel
45
Sep 9 15:23:13 bravo xl2tpd[5684]: receive_window_size_avp: peer wants RWS
of 8. Will use flow control.
Sep 9 15:23:13 bravo xl2tpd[5684]: control_finish: message type is
Start-Control-Connection-Request(1). Tunnel is 45, call is 0.
Sep 9 15:23:13 bravo xl2tpd[5684]: control_finish: Peer requested tunnel 45
twice, ignoring second one.
Sep 9 15:23:13 bravo xl2tpd[5684]: build_fdset: closing down tunnel 56777
Sep 9 15:23:14 bravo xl2tpd[5684]: network_thread: recv packet from
88.28.141.152, size = 99, tunnel = 0, call = 0 ref=0 refhim=0
Sep 9 15:23:14 bravo xl2tpd[5684]: get_call: allocating new tunnel for host
88.28.141.152, port 1701.
Sep 9 15:23:14 bravo xl2tpd[5684]: handle_avps: handling avp's for tunnel
27588, call 5387312
Sep 9 15:23:14 bravo xl2tpd[5684]: message_type_avp: message type 1
(Start-Control-Connection-Request)
Sep 9 15:23:14 bravo xl2tpd[5684]: protocol_version_avp: peer is using
version 1, revision 0.
Sep 9 15:23:14 bravo xl2tpd[5684]: framing_caps_avp: supported peer frames:
sync
Sep 9 15:23:14 bravo xl2tpd[5684]: bearer_caps_avp: supported peer bearers:
Sep 9 15:23:14 bravo xl2tpd[5684]: firmware_rev_avp: peer reports firmware
version 1280 (0x0500)
Sep 9 15:23:14 bravo xl2tpd[5684]: hostname_avp: peer reports hostname
'laptop'
Sep 9 15:23:14 bravo xl2tpd[5684]: vendor_avp: peer reports vendor
'Microsoft'
Sep 9 15:23:14 bravo xl2tpd[5684]: assigned_tunnel_avp: using peer's tunnel
45
Sep 9 15:23:14 bravo xl2tpd[5684]: receive_window_size_avp: peer wants RWS
of 8. Will use flow control.
Sep 9 15:23:14 bravo xl2tpd[5684]: control_finish: message type is
Start-Control-Connection-Request(1). Tunnel is 45, call is 0.
Sep 9 15:23:14 bravo xl2tpd[5684]: control_finish: Peer requested tunnel 45
twice, ignoring second one.
Sep 9 15:23:14 bravo xl2tpd[5684]: build_fdset: closing down tunnel 27588
Sep 9 15:23:18 bravo xl2tpd[5684]: network_thread: recv packet from
88.28.141.152, size = 99, tunnel = 0, call = 0 ref=0 refhim=0
Sep 9 15:23:18 bravo xl2tpd[5684]: get_call: allocating new tunnel for host
88.28.141.152, port 1701.
Sep 9 15:23:18 bravo xl2tpd[5684]: handle_avps: handling avp's for tunnel
49855, call 51322
Sep 9 15:23:18 bravo xl2tpd[5684]: message_type_avp: message type 1
(Start-Control-Connection-Request)
Sep 9 15:23:18 bravo xl2tpd[5684]: protocol_version_avp: peer is using
version 1, revision 0.
Sep 9 15:23:18 bravo xl2tpd[5684]: framing_caps_avp: supported peer frames:
sync
Sep 9 15:23:18 bravo xl2tpd[5684]: bearer_caps_avp: supported peer bearers:
Sep 9 15:23:18 bravo xl2tpd[5684]: firmware_rev_avp: peer reports firmware
version 1280 (0x0500)
Sep 9 15:23:18 bravo xl2tpd[5684]: hostname_avp: peer reports hostname
'laptop'
Sep 9 15:23:18 bravo xl2tpd[5684]: vendor_avp: peer reports vendor
'Microsoft'
Sep 9 15:23:18 bravo xl2tpd[5684]: assigned_tunnel_avp: using peer's tunnel
45
Sep 9 15:23:18 bravo xl2tpd[5684]: receive_window_size_avp: peer wants RWS
of 8. Will use flow control.
Sep 9 15:23:18 bravo xl2tpd[5684]: control_finish: message type is
Start-Control-Connection-Request(1). Tunnel is 45, call is 0.
Sep 9 15:23:18 bravo xl2tpd[5684]: control_finish: Peer requested tunnel 45
twice, ignoring second one.
Sep 9 15:23:18 bravo xl2tpd[5684]: build_fdset: closing down tunnel 49855
Sep 9 15:23:18 bravo xl2tpd[5684]: Maximum retries exceeded for tunnel
51378. Closing.
Sep 9 15:23:18 bravo xl2tpd[5684]: build_fdset: closing down tunnel 51378
Sep 9 15:23:18 bravo xl2tpd[5684]: Connection 45 closed to 88.28.141.152,
port 1701 (Timeout)
Sep 9 15:23:23 bravo xl2tpd[5684]: Unable to deliver closing message for
tunnel 51378. Destroying anyway.
Sep 9 15:23:23 bravo xl2tpd[5684]: build_fdset: closing down tunnel 51378
Sep 9 15:23:26 bravo xl2tpd[5684]: network_thread: recv packet from
88.28.141.152, size = 99, tunnel = 0, call = 0 ref=0 refhim=0
Sep 9 15:23:26 bravo xl2tpd[5684]: get_call: allocating new tunnel for host
88.28.141.152, port 1701.
Sep 9 15:23:26 bravo xl2tpd[5684]: handle_avps: handling avp's for tunnel
23346, call 36370
Sep 9 15:23:26 bravo xl2tpd[5684]: message_type_avp: message type 1
(Start-Control-Connection-Request)
Sep 9 15:23:26 bravo xl2tpd[5684]: protocol_version_avp: peer is using
version 1, revision 0.
Sep 9 15:23:26 bravo xl2tpd[5684]: framing_caps_avp: supported peer frames:
sync
Sep 9 15:23:26 bravo xl2tpd[5684]: bearer_caps_avp: supported peer bearers:
Sep 9 15:23:26 bravo xl2tpd[5684]: firmware_rev_avp: peer reports firmware
version 1280 (0x0500)
Sep 9 15:23:26 bravo xl2tpd[5684]: hostname_avp: peer reports hostname
'laptop'
Sep 9 15:23:26 bravo xl2tpd[5684]: vendor_avp: peer reports vendor
'Microsoft'
Sep 9 15:23:26 bravo xl2tpd[5684]: assigned_tunnel_avp: using peer's tunnel
45
Sep 9 15:23:26 bravo xl2tpd[5684]: receive_window_size_avp: peer wants RWS
of 8. Will use flow control.
Sep 9 15:23:26 bravo xl2tpd[5684]: control_finish: message type is
Start-Control-Connection-Request(1). Tunnel is 45, call is 0.
Sep 9 15:23:26 bravo xl2tpd[5684]: control_finish: sending SCCRP
Sep 9 15:23:33 bravo xl2tpd[5684]: Maximum retries exceeded for tunnel
23346. Closing.
Sep 9 15:23:33 bravo xl2tpd[5684]: build_fdset: closing down tunnel 23346
Sep 9 15:23:33 bravo xl2tpd[5684]: Connection 45 closed to 88.28.141.152,
port 1701 (Timeout)
Sep 9 15:23:36 bravo xl2tpd[5684]: network_thread: recv packet from
88.28.141.152, size = 99, tunnel = 0, call = 0 ref=0 refhim=0
Sep 9 15:23:36 bravo xl2tpd[5684]: get_call: allocating new tunnel for host
88.28.141.152, port 1701.
Sep 9 15:23:36 bravo xl2tpd[5684]: handle_avps: handling avp's for tunnel
56628, call 5388624
Sep 9 15:23:36 bravo xl2tpd[5684]: message_type_avp: message type 1
(Start-Control-Connection-Request)
Sep 9 15:23:36 bravo xl2tpd[5684]: protocol_version_avp: peer is using
version 1, revision 0.
Sep 9 15:23:36 bravo xl2tpd[5684]: framing_caps_avp: supported peer frames:
sync
Sep 9 15:23:36 bravo xl2tpd[5684]: bearer_caps_avp: supported peer bearers:
Sep 9 15:23:36 bravo xl2tpd[5684]: firmware_rev_avp: peer reports firmware
version 1280 (0x0500)
Sep 9 15:23:36 bravo xl2tpd[5684]: hostname_avp: peer reports hostname
'laptop'
Sep 9 15:23:36 bravo xl2tpd[5684]: vendor_avp: peer reports vendor
'Microsoft'
Sep 9 15:23:36 bravo xl2tpd[5684]: assigned_tunnel_avp: using peer's tunnel
45
Sep 9 15:23:36 bravo xl2tpd[5684]: receive_window_size_avp: peer wants RWS
of 8. Will use flow control.
Sep 9 15:23:36 bravo xl2tpd[5684]: control_finish: message type is
Start-Control-Connection-Request(1). Tunnel is 45, call is 0.
Sep 9 15:23:36 bravo xl2tpd[5684]: control_finish: Peer requested tunnel 45
twice, ignoring second one.
Sep 9 15:23:36 bravo xl2tpd[5684]: build_fdset: closing down tunnel 56628
Sep 9 15:23:38 bravo xl2tpd[5684]: Unable to deliver closing message for
tunnel 23346. Destroying anyway.
Sep 9 15:23:38 bravo xl2tpd[5684]: build_fdset: closing down tunnel 23346
Sep 9 15:23:46 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
received Delete SA(0x21856f84) payload: deleting IPSEC State #2
Sep 9 15:23:46 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
received and ignored informational message
Sep 9 15:23:47 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152 #1:
received Delete SA payload: deleting ISAKMP State #1
Sep 9 15:23:47 bravo pluto[10159]: "roadwarrior-l2tp"[1] 88.28.141.152:
deleting connection "roadwarrior-l2tp" instance with peer 88.28.141.152
{isakmp=#0/ipsec=#0}
Sep 9 15:23:47 bravo pluto[10159]: packet from 88.28.141.152:500: received
and ignored informational message
Sep 9 15:23:49 bravo pluto[10159]: ERROR: asynchronous network error report
on eth0 (sport=500) for message to 88.28.141.152 port 500, complainant
87.106.180.178: No route to host [errno 113, origin ICMP type 3 code 1 (not
authenticated)]
Sep 9 15:23:49 bravo pluto[10159]: ERROR: asynchronous network error report
on eth0 (sport=500) for message to 88.28.141.152 port 500, complainant
87.106.180.178: No route to host [errno 113, origin ICMP type 3 code 1 (not
authenticated)]
-------------------------------------
And ipsec barf
_________________________________________________________________
Don't just search. Find. Check out the new MSN Search!
http://search.msn.com/
More information about the Users
mailing list