[strongSwan] PSK Windows Vista/7 to NATted strongswan problems
Andreas Steffen
andreas.steffen at strongswan.org
Thu Jul 21 15:20:33 CEST 2011
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
--
======================================================================
Andreas Steffen andreas.steffen at strongswan.org
strongSwan - the Linux VPN Solution! www.strongswan.org
Institute for Internet Technologies and Applications
University of Applied Sciences Rapperswil
CH-8640 Rapperswil (Switzerland)
===========================================================[ITA-HSR]==
More information about the Users
mailing list