[strongSwan] PSK Windows Vista/7 to NATted strongswan problems
Germán Salvador
gsalvador at zitralia.com
Thu Jul 21 17:33:23 CEST 2011
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
>> 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
>>
>>
>> _______________________________________________
>> Users mailing list
>> Users at lists.strongswan.org
>> https://lists.strongswan.org/mailman/listinfo/users
>
More information about the Users
mailing list