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 [email protected] 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 _______________________________________________ Users mailing list [email protected] https://lists.strongswan.org/mailman/listinfo/users
