[strongSwan] PSK Windows Vista/7 to NATted strongswan problems
Germán Salvador
gsalvador at zitralia.com
Thu Jul 21 14:36:43 CEST 2011
Hello,
I have done my best trying to diagnose some IPSec connection problems,
but I think I am stuck. Can someone plase have a look on this and tell
me if there is something obviously wrong?
What I am trying to do is to set up a IPSec connection coming from a
non-natted Windows Vista or 7 client to a strongswan server located
behind a NAT gateway. I'm using PSK, as certificates are not desirable
in this specific environment.
The server, client configuration and some logs are below. Please note that:
- I am also testing the same server configuration using another
strongswan from a linux box as a client and it works fine.
- The same server configuration, without leftid, works from the windows
client when the server is not NATted.
- The windows connect script works fine when the server is not natted.
I am aware that Windows by default doesn't allow IPSec to NATTed severs,
but I have done what I've read it is needed:
- In the windows registry, I have
HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\PolicyAgent\AssumeUDPEncapsulationContextOnSendRule
= 2
- I have also set "netsh advfirewall set global ipsec ipsecthroughnat
serverandclientbehindnat"
Thanks in advance,
German Salvador
Server configuration:
-----------------------------
config setup
plutodebug=control
charondebug=all
nat_traversal=yes
charonstart=no
plutostart=yes
conn %default
left=%defaultroute
leftsubnet=172.16.247.128/24
leftid=@1.2.3.4
right=%any
rightsubnetwithin=0.0.0.0/0
auto=add
conn vista_psk
authby=secret
pfs=no
Client connection script
-----------------------------
set MYIP=5.6.7.8
set REMOTEIP=1.2.3.4
netsh advfirewall consec add rule ^
name=TESTRULE ^
endpoint1=%MYIP%/32 endpoint2=172.16.155.0/255.255.255.0 ^
action=requireinrequireout ^
mode=tunnel ^
localtunnelendpoint=%MYIP% remotetunnelendpoint=%REMOTEIP% ^
auth1=computerpsk ^
auth1psk=donttellany1 ^
qmsecmethods=AH:SHA1+ESP:SHA1-3DES+60min+100000kb
pause
ping -n 5 172.16.155.135
pause
netsh advfirewall consec delete rule name=TESTRULE
Pluto log:
------------
Jul 21 13:31:38 svpn ipsec_starter[3361]: Starting strongSwan 4.4.1
IPsec [starter]...
Jul 21 13:31:38 svpn pluto[3375]: Starting IKEv1 pluto daemon
(strongSwan 4.4.1) THREADS SMARTCARD VENDORID
Jul 21 13:31:38 svpn pluto[3375]: plugin 'test-vectors' failed to load:
/usr/lib/ipsec/plugins/libstrongswan-test-vectors.so: cannot open shared
object file: No such file or directory
Jul 21 13:31:38 svpn pluto[3375]: attr-sql plugin: database URI not set
Jul 21 13:31:38 svpn pluto[3375]: plugin 'attr-sql': failed to load -
attr_sql_plugin_create returned NULL
Jul 21 13:31:38 svpn pluto[3375]: loaded plugins: curl ldap aes des sha1
sha2 md5 random x509 pubkey pkcs1 pgp dnskey pem openssl hmac gmp xauth
attr resolve
Jul 21 13:31:38 svpn pluto[3375]: | inserting event EVENT_REINIT_SECRET,
timeout in 3600 seconds
Jul 21 13:31:38 svpn pluto[3375]: including NAT-Traversal patch
(Version 0.6c)
Jul 21 13:31:38 svpn pluto[3375]: | pkcs11 module
'/usr/lib/opensc-pkcs11.so' loading...
Jul 21 13:31:38 svpn pluto[3375]: failed to load pkcs11 module
'/usr/lib/opensc-pkcs11.so'
Jul 21 13:31:38 svpn pluto[3375]: Using Linux 2.6 IPsec interface code
Jul 21 13:31:38 svpn ipsec_starter[3374]: pluto (3375) started after 20 ms
Jul 21 13:31:38 svpn pluto[3375]: loading ca certificates from
'/etc/ipsec.d/cacerts'
Jul 21 13:31:38 svpn pluto[3375]: loading aa certificates from
'/etc/ipsec.d/aacerts'
Jul 21 13:31:38 svpn pluto[3375]: loading ocsp certificates from
'/etc/ipsec.d/ocspcerts'
Jul 21 13:31:38 svpn pluto[3375]: Changing to directory '/etc/ipsec.d/crls'
Jul 21 13:31:38 svpn pluto[3375]: loading attribute certificates from
'/etc/ipsec.d/acerts'
Jul 21 13:31:38 svpn pluto[3375]: | inserting event EVENT_LOG_DAILY,
timeout in 37702 seconds
Jul 21 13:31:38 svpn pluto[3375]: | next event EVENT_REINIT_SECRET in
3600 seconds
Jul 21 13:31:38 svpn pluto[3375]: |
Jul 21 13:31:38 svpn pluto[3375]: | *received whack message
Jul 21 13:31:38 svpn pluto[3375]: listening for IKE messages
Jul 21 13:31:38 svpn pluto[3375]: | found lo with address 127.0.0.1
Jul 21 13:31:38 svpn pluto[3375]: | found eth0 with address 192.168.0.41
Jul 21 13:31:38 svpn pluto[3375]: | found eth1 with address 172.16.247.128
Jul 21 13:31:38 svpn pluto[3375]: adding interface eth1/eth1
172.16.247.128:500
Jul 21 13:31:38 svpn pluto[3375]: adding interface eth1/eth1
172.16.247.128:4500
Jul 21 13:31:38 svpn pluto[3375]: adding interface eth0/eth0
192.168.0.41:500
Jul 21 13:31:38 svpn pluto[3375]: adding interface eth0/eth0
192.168.0.41:4500
Jul 21 13:31:38 svpn pluto[3375]: adding interface lo/lo 127.0.0.1:500
Jul 21 13:31:38 svpn pluto[3375]: adding interface lo/lo 127.0.0.1:4500
Jul 21 13:31:38 svpn pluto[3375]: | found lo with address
0000:0000:0000:0000:0000:0000:0000:0001
Jul 21 13:31:38 svpn pluto[3375]: adding interface lo/lo ::1:500
Jul 21 13:31:38 svpn pluto[3375]: loading secrets from "/etc/ipsec.secrets"
Jul 21 13:31:38 svpn pluto[3375]: loaded PSK secret for %any
Jul 21 13:31:38 svpn pluto[3375]: | next event EVENT_REINIT_SECRET in
3600 seconds
Jul 21 13:31:38 svpn pluto[3375]: |
Jul 21 13:31:38 svpn pluto[3375]: | *received whack message
Jul 21 13:31:38 svpn pluto[3375]: | from whack: got
--esp=aes128-sha1,3des-sha1
Jul 21 13:31:38 svpn pluto[3375]: | esp proposal: AES_CBC_128/HMAC_SHA1,
3DES_CBC/HMAC_SHA1,
Jul 21 13:31:38 svpn pluto[3375]: | from whack: got
--ike=aes128-sha1-modp2048,3des-sha1-modp1536
Jul 21 13:31:38 svpn pluto[3375]: | ike proposal:
AES_CBC_128/HMAC_SHA1/MODP_2048, 3DES_CBC/HMAC_SHA1/MODP_1536,
Jul 21 13:31:38 svpn pluto[3375]: added connection description "vista_psk"
Jul 21 13:31:38 svpn pluto[3375]: |
172.16.247.0/24===192.168.0.41[1.2.3.4]---192.168.0.13...%any[%any]==={0.0.0.0/0}
Jul 21 13:31:38 svpn pluto[3375]: | ike_life: 10800s; ipsec_life: 3600s;
rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 3; policy:
PSK+ENCRYPT+TUNNEL
Jul 21 13:31:38 svpn pluto[3375]: | next event EVENT_REINIT_SECRET in
3600 seconds
Jul 21 13:32:32 svpn pluto[3375]: |
Jul 21 13:32:32 svpn pluto[3375]: | *received 268 bytes from 5.6.7.8:500
on eth0
Jul 21 13:32:32 svpn pluto[3375]: packet from 5.6.7.8:500: received
Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000005]
Jul 21 13:32:32 svpn pluto[3375]: packet from 5.6.7.8:500: received
Vendor ID payload [RFC 3947]
Jul 21 13:32:32 svpn pluto[3375]: packet from 5.6.7.8:500: ignoring
Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
Jul 21 13:32:32 svpn pluto[3375]: packet from 5.6.7.8:500: ignoring
Vendor ID payload [FRAGMENTATION]
Jul 21 13:32:32 svpn pluto[3375]: packet from 5.6.7.8:500: ignoring
Vendor ID payload [MS-Negotiation Discovery Capable]
Jul 21 13:32:32 svpn pluto[3375]: packet from 5.6.7.8:500: ignoring
Vendor ID payload [Vid-Initial-Contact]
Jul 21 13:32:32 svpn pluto[3375]: packet from 5.6.7.8:500: ignoring
Vendor ID payload [IKE CGA version 1]
Jul 21 13:32:32 svpn pluto[3375]: | preparse_isakmp_policy: peer
requests PSK authentication
Jul 21 13:32:32 svpn pluto[3375]: | instantiated "vista_psk" for 5.6.7.8
Jul 21 13:32:32 svpn pluto[3375]: | creating state object #1 at 0xb8f558e0
Jul 21 13:32:32 svpn pluto[3375]: | ICOOKIE: e8 21 b3 83 4e 2c d1 af
Jul 21 13:32:32 svpn pluto[3375]: | RCOOKIE: 1a 44 bd 34 e9 5d 05 4a
Jul 21 13:32:32 svpn pluto[3375]: | peer: 4d d1 18 90
Jul 21 13:32:32 svpn pluto[3375]: | state hash entry 17
Jul 21 13:32:32 svpn pluto[3375]: | inserting event EVENT_SO_DISCARD,
timeout in 0 seconds for #1
Jul 21 13:32:32 svpn pluto[3375]: "vista_psk"[1] 5.6.7.8 #1: responding
to Main Mode from unknown peer 5.6.7.8
Jul 21 13:32:32 svpn pluto[3375]: | inserting event EVENT_RETRANSMIT,
timeout in 10 seconds for #1
Jul 21 13:32:32 svpn pluto[3375]: | next event EVENT_RETRANSMIT in 10
seconds for #1
Jul 21 13:32:33 svpn pluto[3375]: |
Jul 21 13:32:33 svpn pluto[3375]: | *received 260 bytes from 5.6.7.8:500
on eth0
Jul 21 13:32:33 svpn pluto[3375]: | ICOOKIE: e8 21 b3 83 4e 2c d1 af
Jul 21 13:32:33 svpn pluto[3375]: | RCOOKIE: 1a 44 bd 34 e9 5d 05 4a
Jul 21 13:32:33 svpn pluto[3375]: | peer: 4d d1 18 90
Jul 21 13:32:33 svpn pluto[3375]: | state hash entry 17
Jul 21 13:32:33 svpn pluto[3375]: | state object #1 found, in STATE_MAIN_R1
Jul 21 13:32:33 svpn pluto[3375]: "vista_psk"[1] 5.6.7.8 #1:
NAT-Traversal: Result using RFC 3947: i am NATed
Jul 21 13:32:33 svpn pluto[3375]: | inserting event
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Jul 21 13:32:33 svpn pluto[3375]: | inserting event EVENT_RETRANSMIT,
timeout in 10 seconds for #1
Jul 21 13:32:33 svpn pluto[3375]: | next event EVENT_RETRANSMIT in 10
seconds for #1
Jul 21 13:32:33 svpn pluto[3375]: |
Jul 21 13:32:33 svpn pluto[3375]: | *received 76 bytes from 5.6.7.8:4500
on eth0
Jul 21 13:32:33 svpn pluto[3375]: | ICOOKIE: e8 21 b3 83 4e 2c d1 af
Jul 21 13:32:33 svpn pluto[3375]: | RCOOKIE: 1a 44 bd 34 e9 5d 05 4a
Jul 21 13:32:33 svpn pluto[3375]: | peer: 4d d1 18 90
Jul 21 13:32:33 svpn pluto[3375]: | state hash entry 17
Jul 21 13:32:33 svpn pluto[3375]: | state object #1 found, in STATE_MAIN_R2
Jul 21 13:32:33 svpn pluto[3375]: "vista_psk"[1] 5.6.7.8 #1: Peer ID is
ID_IPV4_ADDR: '5.6.7.8'
Jul 21 13:32:33 svpn pluto[3375]: | peer CA: %none
Jul 21 13:32:33 svpn pluto[3375]: | current connection is a full match
-- no need to look further
Jul 21 13:32:33 svpn pluto[3375]: | offered CA: %none
Jul 21 13:32:33 svpn pluto[3375]: | NAT-T: new mapping 5.6.7.8:500/4500)
Jul 21 13:32:33 svpn pluto[3375]: | inserting event EVENT_SA_REPLACE,
timeout in 10530 seconds for #1
Jul 21 13:32:33 svpn pluto[3375]: "vista_psk"[1] 5.6.7.8:4500 #1: sent
MR3, ISAKMP SA established
Jul 21 13:32:33 svpn pluto[3375]: | next event EVENT_NAT_T_KEEPALIVE in
20 seconds
Jul 21 13:32:34 svpn pluto[3375]: |
Jul 21 13:32:34 svpn pluto[3375]: | *received 92 bytes from 5.6.7.8:4500
on eth0
Jul 21 13:32:34 svpn pluto[3375]: | ICOOKIE: e8 21 b3 83 4e 2c d1 af
Jul 21 13:32:34 svpn pluto[3375]: | RCOOKIE: 1a 44 bd 34 e9 5d 05 4a
Jul 21 13:32:34 svpn pluto[3375]: | peer: 4d d1 18 90
Jul 21 13:32:34 svpn pluto[3375]: | state hash entry 17
Jul 21 13:32:34 svpn pluto[3375]: | state object #1 found, in STATE_MAIN_R3
Jul 21 13:32:34 svpn pluto[3375]: | ICOOKIE: e8 21 b3 83 4e 2c d1 af
Jul 21 13:32:34 svpn pluto[3375]: | RCOOKIE: 1a 44 bd 34 e9 5d 05 4a
Jul 21 13:32:34 svpn pluto[3375]: | peer: 4d d1 18 90
Jul 21 13:32:34 svpn pluto[3375]: | state hash entry 17
Jul 21 13:32:34 svpn pluto[3375]: | state object #1 found, in STATE_MAIN_R3
Jul 21 13:32:34 svpn pluto[3375]: "vista_psk"[1] 5.6.7.8:4500 #1:
received Delete SA payload: deleting ISAKMP State #1
Jul 21 13:32:34 svpn pluto[3375]: | ICOOKIE: e8 21 b3 83 4e 2c d1 af
Jul 21 13:32:34 svpn pluto[3375]: | RCOOKIE: 1a 44 bd 34 e9 5d 05 4a
Jul 21 13:32:34 svpn pluto[3375]: | peer: 4d d1 18 90
Jul 21 13:32:34 svpn pluto[3375]: | state hash entry 17
Jul 21 13:32:34 svpn pluto[3375]: "vista_psk"[1] 5.6.7.8:4500: deleting
connection "vista_psk" instance with peer 5.6.7.8 {isakmp=#0/ipsec=#0}
Jul 21 13:32:34 svpn pluto[3375]: | next event EVENT_NAT_T_KEEPALIVE in
19 seconds
Jul 21 13:32:49 svpn pluto[3375]: |
Jul 21 13:32:49 svpn pluto[3375]: | *received whack message
Jul 21 13:32:49 svpn pluto[3375]: shutting down
I have also captured some IKE debugging information on Windows, using
WFPUtil, the is the most interesting info I have there:
...
[1]04C0.01C0::07/21/2011-11:51:48.614 [ikeext]
[1]04C0.01C0::07/21/2011-11:51:48.614 [ikeext]Received IKE Acquire
Acquire context 28
Local address: 5.6.7.8
Remote address: 1.2.3.4
Mode: Tunnel Mode
Filter ID: 0x8000000000000037
Remote Port: 0x0000
Flags: 0x00000000
[1]04C0.01C0::07/21/2011-11:51:48.614 [ikeext]
[1]04C0.01C0::07/21/2011-11:51:48.614 [ikeext]Received AUTHIP Acquire
Acquire context 28
Local address: 5.6.7.8
Remote address: 1.2.3.4
Mode: Tunnel Mode
Filter ID: 0x8000000000000037
Remote Port: 0x0000
Flags: 0x00000000
[1]04C0.1600::07/21/2011-11:51:48.615 [ikeext]Processing acquire with
ipsec context 28, keyMod 0
[1]04C0.1600::07/21/2011-11:51:48.615 [ikeext]QM localAddr: 5.6.7.8.0
Protocol 0
[1]04C0.1600::07/21/2011-11:51:48.615 [ikeext]QM peerAddr:
172.16.155.0.0 Mask 255.255.255.0 Protocol 0
[1]04C0.1600::07/21/2011-11:51:48.615 [ikeext]Acquire flags 1
[1]04C0.1600::07/21/2011-11:51:48.615 [ikeext]Peer State 0
[1]04C0.1600::07/21/2011-11:51:48.615 [ikeext]IkeBeginMMInitiator:
Setting acquire 022E9E70 as prime acquire for MM SA 022F11E8
[1]04C0.1600::07/21/2011-11:51:48.615 [ikeext]Looking up MM policy for IKE
[0]04C0.12BC::07/21/2011-11:51:48.616 [ikeext]Processing acquire with
ipsec context 28, keyMod 1
[0]04C0.12BC::07/21/2011-11:51:48.616 [ikeext]QM localAddr: 5.6.7.8.0
Protocol 0
[0]04C0.12BC::07/21/2011-11:51:48.616 [ikeext]QM peerAddr:
172.16.155.0.0 Mask 255.255.255.0 Protocol 0
[0]04C0.12BC::07/21/2011-11:51:48.616 [ikeext]Acquire flags 1
[1]04C0.1600::07/21/2011-11:51:48.617 [ikeext]Policy
GUID: {b52d17d4-7a36-4372-a398-71813a09b6d9}
LUID: 0x8000000000000038
Name: {B347B547-1B04-47AF-A625-47300D2E59C7}:TESTRULE
Description: (null)
Flags: 0x00000000
Provider: <unspecified>
Provider data:
Type: IKE Main Mode
Soft expiry: 0
InitiatorImpersonationType: None
Auth methods: 1
-- 0 --
Type: Preshared Key
Key:
00000000 ** ** ** ** ** ** ** **-** ** ** **
donttellany1
Proposals: 2
-- 0 --
Cipher algorithm:
Type: AES-128
Key length: 0
Rounds: 0
Integrity algorithm:
Type: SHA1
Max lifetime (sec): 28800
DH group: 2
QM limit: 0
-- 1 --
Cipher algorithm:
Type: 3DES
Key length: 0
Rounds: 0
Integrity algorithm:
Type: SHA1
Max lifetime (sec): 28800
DH group: 2
QM limit: 0
Flags: 0x00000000
MaxDynamicFilters: 0
[1]04C0.1600::07/21/2011-11:51:48.617 [ikeext]Construct IKEHeader
[1]04C0.1600::07/21/2011-11:51:48.617 [ikeext]Initializing Kerberos SSPI
[1]04C0.1600::07/21/2011-11:51:48.617 [user]IkeFindAuthConfig failed
with Windows error 87(ERROR_INVALID_PARAMETER)
[1]04C0.1600::07/21/2011-11:51:48.617 [user]IkeFindAuthConfig failed
with HRESULT 0x80070057(ERROR_INVALID_PARAMETER)
[1]04C0.1600::07/21/2011-11:51:48.617 [user]IkeDetermineSspiInfo failed
with HRESULT 0x80070057(ERROR_INVALID_PARAMETER)
[1]04C0.1600::07/21/2011-11:51:48.617 [user]IkeCreateSspiIke failed with
HRESULT 0x80070057(ERROR_INVALID_PARAMETER)
[1]04C0.1600::07/21/2011-11:51:48.617 [ikeext]WFP free sspi 022E97E8
[1]04C0.1600::07/21/2011-11:51:48.617 [user]IkeGetSspiContext failed
with HRESULT 0x80070057(ERROR_INVALID_PARAMETER)
[1]04C0.1600::07/21/2011-11:51:48.617 [ikeext]Construct SA
[0]04C0.12BC::07/21/2011-11:51:48.617 [ikeext]FwpmFilterEnum0 returned
no matching filters
[0]04C0.12BC::07/21/2011-11:51:48.617 [user]IkeMatchFwpmFilter failed
with Windows error 13825(ERROR_IPSEC_IKE_NO_POLICY)
[0]04C0.12BC::07/21/2011-11:51:48.617 [user]IkeMatchFwpmFilter failed
with HRESULT 0x80073601(ERROR_IPSEC_IKE_NO_POLICY)
[0]04C0.12BC::07/21/2011-11:51:48.617 [user]IkeFindQMPolicy failed with
HRESULT 0x80073601(ERROR_IPSEC_IKE_NO_POLICY)
[0]04C0.12BC::07/21/2011-11:51:48.617 [ikeext]Completing Acquire for
ipsec context 28
[1]04C0.1600::07/21/2011-11:51:48.617 [ikeext]AUTHIP keying module is
not enabled for traffic
[1]04C0.1600::07/21/2011-11:51:48.617 [ikeext]IKE not sending
co-existence Vendor ID
[1]04C0.1600::07/21/2011-11:51:48.617 [ikeext]Construct VENDOR type MS
NT5 ISAKMPOAKLEY
[0]04C0.12BC::07/21/2011-11:51:48.617 [ikeext]IkeFreeAcquireContext:
Freeing acquire 022E9DA0
[0]04C0.12BC::07/21/2011-11:51:48.617 [user]IkeProcessAcquireDispatch
failed with HRESULT 0x80073601(ERROR_IPSEC_IKE_NO_POLICY)
[1]04C0.1600::07/21/2011-11:51:48.618 [ikeext]Construct VENDOR type RFC
3947
[1]04C0.1600::07/21/2011-11:51:48.618 [ikeext]Construct VENDOR type
draft-ietf-ipsec-nat-t-ike-02
[1]04C0.1600::07/21/2011-11:51:48.618 [ikeext]Construct VENDOR type
FRAGMENTATION
[1]04C0.1600::07/21/2011-11:51:48.618 [ikeext]Construct VENDOR type
MS-Negotiation Discovery Capable
[1]04C0.1600::07/21/2011-11:51:48.618 [ikeext]Construct VENDOR type
Vid-Initial-Contact
[1]04C0.1600::07/21/2011-11:51:48.618 [ikeext]Construct VENDOR type IKE
CGA version 1
[1]04C0.1600::07/21/2011-11:51:48.619 [ikeext]
[1]04C0.1600::07/21/2011-11:51:48.619 [ikeext]Sending Packet
[1]04C0.1600::07/21/2011-11:51:48.619 [ikeext]iCookie e821b3834e2cd1af
rCookie 0000000000000000
[1]04C0.1600::07/21/2011-11:51:48.619 [ikeext]Exchange type: IKE Main
Mode Length 268 NextPayload SA Flags 0 Messid 0x00000000
[1]04C0.1600::07/21/2011-11:51:48.619 [ikeext]Local Address: 5.6.7.8.500
Protocol 0
[1]04C0.1600::07/21/2011-11:51:48.619 [ikeext]Peer Address: 1.2.3.4.500
Protocol 0
[1]04C0.1600::07/21/2011-11:51:48.619 [ikeext]Global IF index epoch (18)
higher than cache epoch (0). Obtaining IF index from stack.
[1]04C0.1600::07/21/2011-11:51:48.619 [ikeext]Created new TimerContext
022E9DA0, type 0
[0]04C0.1600::07/21/2011-11:51:49.257 [ikeext]
[0]04C0.1600::07/21/2011-11:51:49.257 [ikeext]Received packet
[0]04C0.1600::07/21/2011-11:51:49.257 [ikeext]Local Address: 5.6.7.8.500
Protocol 0
[0]04C0.1600::07/21/2011-11:51:49.257 [ikeext]Peer Address: 1.2.3.4.500
Protocol 0
[0]04C0.1600::07/21/2011-11:51:49.257 [ikeext]iCookie e821b3834e2cd1af
rCookie 1a44bd34e95d054a
[0]04C0.1600::07/21/2011-11:51:49.257 [ikeext]Exchange type: IKE Main
Mode Length 160 NextPayload SA Flags 0 Messid 0x00000000
[0]04C0.1600::07/21/2011-11:51:49.257 [ikeext]mmSa: 0x022F11E8
[0]04C0.1600::07/21/2011-11:51:49.257 [ikeext]Process Payload VENDOR ID,
SA 022F11E8
[0]04C0.1600::07/21/2011-11:51:49.259 [ikeext]Process Payload VENDOR ID,
SA 022F11E8
[0]04C0.1600::07/21/2011-11:51:49.259 [ikeext]Process Payload VENDOR ID,
SA 022F11E8
[0]04C0.1600::07/21/2011-11:51:49.260 [ikeext]Process Payload VENDOR ID,
SA 022F11E8
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]Received Vendor ID type:
RFC 3947
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]Process Payload SA, SA
022F11E8
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]MM transform num: 1
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]OAK_ENCR_ALG: 7
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]OAK_KEY_LENGTH: 128
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]OAK_HASH_ALG: 2
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]OAK_GROUP_DESC: 2
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]OAK_AUTH_METHOD: 1
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]OAK_LIFE_TYPE: 1
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]OAK_LIFE_DUR: 28800
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]Accepted proposal. Trans: 1
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]Ignoring port float.
Incoming packet not on 4500
[0]04C0.1600::07/21/2011-11:51:49.261 [ikeext]Construct IKEHeader
[0]04C0.1600::07/21/2011-11:51:49.331 [ikeext]Construct KE
[0]04C0.1600::07/21/2011-11:51:49.331 [ikeext]Construct NONCE
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]Construct NatDisc
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]Construct NatDisc
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]Sending Packet
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]iCookie e821b3834e2cd1af
rCookie 1a44bd34e95d054a
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]Exchange type: IKE Main
Mode Length 260 NextPayload KE Flags 0 Messid 0x00000000
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]Local Address: 5.6.7.8.500
Protocol 0
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]Peer Address: 1.2.3.4.500
Protocol 0
[0]04C0.1600::07/21/2011-11:51:49.332 [ikeext]Updating TimerContext
022E9DA0
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Received packet
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Local Address: 5.6.7.8.500
Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Peer Address: 1.2.3.4.500
Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]iCookie e821b3834e2cd1af
rCookie 1a44bd34e95d054a
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Exchange type: IKE Main
Mode Length 228 NextPayload KE Flags 0 Messid 0x00000000
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]mmSa: 0x022F11E8
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Process Payload KE, SA
022F11E8
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Process Payload NONCE, SA
022F11E8
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Process Payload NATDISC,
SA 022F11E8
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Process Payload NATDISC,
SA 022F11E8
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Ignoring port float.
Incoming packet not on 4500
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Construct IKEHeader
[1]04C0.1600::07/21/2011-11:51:50.077 [ikeext]Peer behind NAT
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]Construct MM ID
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]Construct HASH
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]Sending Packet
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]iCookie e821b3834e2cd1af
rCookie 1a44bd34e95d054a
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]Exchange type: IKE Main
Mode Length 76 NextPayload ID Flags 1 Messid 0x00000000
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]Local Address:
5.6.7.8.4500 Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]Peer Address: 1.2.3.4.4500
Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.103 [ikeext]Updating TimerContext
022E9DA0
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Received packet
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Local Address:
5.6.7.8.4500 Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Peer Address: 1.2.3.4.4500
Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]iCookie e821b3834e2cd1af
rCookie 1a44bd34e95d054a
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Exchange type: IKE Main
Mode Length 76 NextPayload ID Flags 1 Messid 0x00000000
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]mmSa: 0x022F11E8
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Process Payload MM ID, SA
022F11E8
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Process Payload HASH, SA
022F11E8
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Destroying TimerContext
022E9DA0, type 0
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]TimerContext 022E9DA0, Old
ref 2
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]TimerContext 022E9DA0, Old
ref 1
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Freeing TimerContext 022E9DA0
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Scheduling MM lifetime
expiry for SA 022F11E8, secs 28800
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Created new TimerContext
022E9DA0, type 3
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Ignoring port float.
Negotiation already on 4500
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Construct IKEHeader
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]Looking up QM policy for IKE
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]QM localAddr: 5.6.7.8.0
Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.417 [ikeext]QM peerAddr:
172.16.155.0.0 Mask 255.255.255.0 Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.418 [ikeext]Policy
GUID: {0b36f95a-c126-410b-953a-b4e105173aaa}
LUID: 0x8000000000000037
Name: {B347B547-1B04-47AF-A625-47300D2E59C7}:TESTRULE
Description: (null)
Flags: 0x00000000
Provider: <unspecified>
Provider data:
Type: IKE Quick Mode Tunnel
Proposals: 1
-- 0 --
Lifetime:
Seconds: 3600
Kilobytes: 100000
Packets: 2147483647
PFS group: None
SA transforms: 2
-- 0 --
Type: AH
Type: SHA1
Config: HMAC-SHA1-96
Crypto module: <unspecified>
-- 1 --
Type: ESP-Auth & Cipher
Auth transform:
Type: SHA1
Config: HMAC-SHA1-96
Crypto module: <unspecified>
Cipher transform:
Type: 3DES
Config: CBC-3DES
Crypto module: <unspecified>
Flags: 0x00000000
Local tunnelEndpoint: 5.6.7.8
Remote tunnelEndpoint: 1.2.3.4
Normal idle timeout (seconds): 300
Idle timeout in case of failover (seconds): 60
[1]04C0.1600::07/21/2011-11:51:50.418 [ikeext]Create QMSA: qmSA 021FDE40
messId 1
[1]04C0.1600::07/21/2011-11:51:50.418 [ikeext]IkeBeginQMInitiator:
acquire 022E9E70 being handed off to QM 021FDE40
[1]04C0.1600::07/21/2011-11:51:50.418 [ikeext]GetSpi
SA context 28
Local address: 5.6.7.8
Remote address: 1.2.3.4
Mode: Tunnel Mode
Filter ID: 0x8000000000000037
Remote Port: 0x0000
UDP Encapsulation:
Local port: 4500
Remote port: 4500
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Got SPI from BFE 3318039952
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Local address: 5.6.7.8.0
Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Peer address:
172.16.155.0.0 Mask 255.255.255.0 Protocol 0
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Construct IKEHeader
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Construct HASH
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Construct SA
[1]04C0.1600::07/21/2011-11:51:50.419
[user]IkeConstructQMProposalInitiator failed with Windows error
13861(ERROR_IPSEC_IKE_INVALID_POLICY)
[1]04C0.1600::07/21/2011-11:51:50.419
[user]IkeConstructQMProposalInitiator failed with HRESULT
0x80073625(ERROR_IPSEC_IKE_INVALID_POLICY)
[1]04C0.1600::07/21/2011-11:51:50.419 [user]IkeConstructQMSA failed with
HRESULT 0x80073625(ERROR_IPSEC_IKE_INVALID_POLICY)
[1]04C0.1600::07/21/2011-11:51:50.419 [user]IkeConstructOakQMInitiator
failed with HRESULT 0x80073625(ERROR_IPSEC_IKE_INVALID_POLICY)
[1]04C0.1600::07/21/2011-11:51:50.419 [user]IkeConstructQM failed with
HRESULT 0x80073625(ERROR_IPSEC_IKE_INVALID_POLICY)
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]QM done. Cleaning up qmSa
021FDE40. Error 13861(ERROR_IPSEC_IKE_INVALID_POLICY)
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Completing Acquire for
ipsec context 28
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]IkeFreeAcquireContext:
Freeing acquire 022E9E70
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]IKE diagnostic event:
Event Header:
Timestamp: 1601-01-01T00:00:00.000Z
Flags: 0x00000100
IP version field set
IP version: IPv4
IP protocol: 0
Local address: 0.0.0.0
Remote address: 0.0.0.0
Local Port: 0
Remote Port: 0
Application ID:
User SID: <invalid>
Failure type: IKE/Authip Quick Mode Failure
Type specific info:
Failure error code:0x00003625
Directiva no válida
Failure point: Local
Keying module type: Ike
QM State: Initial state, no QM packets sent
QM SA role: Initiator
Mode: Tunnel Mode
Local Subnet:
IPv4 Addr & Mask: 5.6.7.8/255.255.255.255
Remote Subnet:
IPv4 Addr & Mask: 172.16.155.0/255.255.255.0
QM Filter ID: 0x00000000000111e8
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]SendNotify: mmSa 022F11E8
cookie 83b321e8 state 6 messId 1
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Error code
13861(ERROR_IPSEC_IKE_INVALID_POLICY) doesnt map to any RFC notify type
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]NOT sending any notify
[1]04C0.1600::07/21/2011-11:51:50.419 [ikeext]Deleting QM. MM: 022F11E8
QM: 021FDE40
More information about the Users
mailing list