Thanks Andreas, Well, It seems that I was using different 172* nets in the client and server when capturing the logs. But I have tried again using the correct networks, and the problem is still the same, with almost an identical pluto and windows log.
Germán > Hello Germán, > > IKEv1 Main Mode is successful but Vista has a problem with its Quick > Mode policies and fails. Did you correctly define the subnet > 172.16.247.0/24 that you want to connect to on the Windows box? > > Regards > > Andreas > > On 07/21/2011 02:36 PM, Germán Salvador wrote: >> 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 > _______________________________________________ Users mailing list [email protected] https://lists.strongswan.org/mailman/listinfo/users
