[Vpn-help] Cisco VPN 3000 and shrew 2.1.5 windows client

oleduc at parc.com oleduc at parc.com
Mon Dec 14 17:31:38 CST 2009


Hello,

Like many people using shrew vpn client, I was hoping to have it working in order to make up for the lack of cisco 64bit vpn software. We are using IPsec vpn, xauth+psk authentication mode and our concentrator is configured to accept many different kind of IKE proposals. Our vpn config is not very original but still, there may be something that I am missing in the client config...

I am facing an issue that other users seems to have encountered. Users pass authentication but the session disconnects after a second or so. I tried on several windows platforms (xp-32 and win7-64) and it is the same problem everywhere.

Below are the log messages of respectively the shrew client and the cisco vpn 3000:

Shrew 2.1.5 vpn client logs:
09/12/14 14:48:22 ii : ipc client process thread begin ...
09/12/14 14:48:22 <A : peer config add message
09/12/14 14:48:22 DB : peer ref increment ( ref count = 1, obj count = 0 )
09/12/14 14:48:22 DB : peer added ( obj count = 1 )
09/12/14 14:48:22 ii : local address client_public_ip_add selected for peer
09/12/14 14:48:22 DB : peer ref increment ( ref count = 2, obj count = 1 )
09/12/14 14:48:22 DB : tunnel ref increment ( ref count = 1, obj count = 0 )
09/12/14 14:48:22 DB : tunnel added ( obj count = 1 )
09/12/14 14:48:22 <A : proposal config message
09/12/14 14:48:22 <A : proposal config message
09/12/14 14:48:22 <A : client config message
09/12/14 14:48:22 <A : xauth username message
09/12/14 14:48:22 <A : xauth password message
09/12/14 14:48:22 <A : local id 'group_key_id' message
09/12/14 14:48:22 <A : preshared key message
09/12/14 14:48:22 <A : peer tunnel enable message
09/12/14 14:48:22 DB : tunnel ref increment ( ref count = 2, obj count = 1 )
09/12/14 14:48:22 DB : new phase1 ( ISAKMP initiator )
09/12/14 14:48:22 DB : exchange type is aggressive
09/12/14 14:48:22 DB : client_public_ip_add:500 <-> vpn3000_client_public_ip_add:500
09/12/14 14:48:22 DB : 40ebe69914e77cf4:0000000000000000
09/12/14 14:48:22 DB : phase1 ref increment ( ref count = 1, obj count = 0 )
09/12/14 14:48:22 DB : phase1 added ( obj count = 1 )
09/12/14 14:48:22 >> : security association payload
09/12/14 14:48:22 >> : - proposal #1 payload
09/12/14 14:48:22 >> : -- transform #1 payload
09/12/14 14:48:22 >> : -- transform #2 payload
09/12/14 14:48:22 >> : -- transform #3 payload
09/12/14 14:48:22 >> : -- transform #4 payload
09/12/14 14:48:22 >> : -- transform #5 payload
09/12/14 14:48:22 >> : -- transform #6 payload
09/12/14 14:48:22 >> : -- transform #7 payload
09/12/14 14:48:22 >> : -- transform #8 payload
09/12/14 14:48:22 >> : -- transform #9 payload
09/12/14 14:48:22 >> : -- transform #10 payload
09/12/14 14:48:22 >> : -- transform #11 payload
09/12/14 14:48:22 >> : -- transform #12 payload
09/12/14 14:48:22 >> : -- transform #13 payload
09/12/14 14:48:22 >> : -- transform #14 payload
09/12/14 14:48:22 >> : -- transform #15 payload
09/12/14 14:48:22 >> : -- transform #16 payload
09/12/14 14:48:22 >> : -- transform #17 payload
09/12/14 14:48:22 >> : -- transform #18 payload
09/12/14 14:48:22 >> : key exchange payload
09/12/14 14:48:22 >> : nonce payload
09/12/14 14:48:22 >> : identification payload
09/12/14 14:48:22 >> : vendor id payload
09/12/14 14:48:22 ii : local supports XAUTH
09/12/14 14:48:22 >> : vendor id payload
09/12/14 14:48:22 ii : local supports FRAGMENTATION
09/12/14 14:48:22 >> : vendor id payload
09/12/14 14:48:22 ii : local is SHREW SOFT compatible
09/12/14 14:48:22 >> : vendor id payload
09/12/14 14:48:22 ii : local is NETSCREEN compatible
09/12/14 14:48:22 >> : vendor id payload
09/12/14 14:48:22 ii : local is SIDEWINDER compatible
09/12/14 14:48:22 >> : vendor id payload
09/12/14 14:48:22 ii : local is CISCO UNITY compatible
09/12/14 14:48:22 >= : cookies 40ebe69914e77cf4:0000000000000000
09/12/14 14:48:22 >= : message 00000000
09/12/14 14:48:22 -> : send IKE packet client_public_ip_add:500 -> vpn3000_client_public_ip_add:500 ( 1060 bytes )
09/12/14 14:48:22 DB : phase1 resend event scheduled ( ref count = 2 )
09/12/14 14:48:22 DB : phase1 ref decrement ( ref count = 1, obj count = 1 )
09/12/14 14:48:22 DB : tunnel ref increment ( ref count = 3, obj count = 1 )
09/12/14 14:48:22 <- : recv IKE packet vpn3000_client_public_ip_add:500 -> client_public_ip_add:500 ( 396 bytes )
09/12/14 14:48:22 DB : phase1 found
09/12/14 14:48:22 DB : phase1 ref increment ( ref count = 2, obj count = 1 )
09/12/14 14:48:22 ii : processing phase1 packet ( 396 bytes )
09/12/14 14:48:22 =< : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:22 =< : message 00000000
09/12/14 14:48:22 << : security association payload
09/12/14 14:48:22 << : - propsal #1 payload
09/12/14 14:48:22 << : -- transform #6 payload
09/12/14 14:48:22 ii : unmatched isakmp proposal/transform
09/12/14 14:48:22 ii : key length ( 128 != 256 )
09/12/14 14:48:22 ii : unmatched isakmp proposal/transform
09/12/14 14:48:22 ii : key length ( 128 != 256 )
09/12/14 14:48:22 ii : unmatched isakmp proposal/transform
09/12/14 14:48:22 ii : key length ( 128 != 192 )
09/12/14 14:48:22 ii : unmatched isakmp proposal/transform
09/12/14 14:48:22 ii : key length ( 128 != 192 )
09/12/14 14:48:22 ii : unmatched isakmp proposal/transform
09/12/14 14:48:22 ii : hash type ( hmac-sha != hmac-md5 )
09/12/14 14:48:22 ii : matched isakmp proposal #1 transform #6
09/12/14 14:48:22 ii : - transform    = ike
09/12/14 14:48:22 ii : - cipher type  = aes
09/12/14 14:48:22 ii : - key length   = 128 bits
09/12/14 14:48:22 ii : - hash type    = sha1
09/12/14 14:48:22 ii : - dh group     = modp-1024
09/12/14 14:48:22 ii : - auth type    = xauth-initiator-psk
09/12/14 14:48:22 ii : - life seconds = 86400
09/12/14 14:48:22 ii : - life kbytes  = 0
09/12/14 14:48:22 << : key exchange payload
09/12/14 14:48:22 << : nonce payload
09/12/14 14:48:22 << : identification payload
09/12/14 14:48:22 ii : phase1 id match
09/12/14 14:48:22 ii : received = ipv4-host vpn3000_client_public_ip_add
09/12/14 14:48:22 << : hash payload
09/12/14 14:48:22 << : vendor id payload
09/12/14 14:48:22 ii : peer is CISCO UNITY compatible
09/12/14 14:48:22 << : vendor id payload
09/12/14 14:48:22 ii : peer supports XAUTH
09/12/14 14:48:22 << : vendor id payload
09/12/14 14:48:22 ii : peer supports DPDv1
09/12/14 14:48:22 << : vendor id payload
09/12/14 14:48:22 ii : unknown vendor id ( 20 bytes )
09/12/14 14:48:22 0x : 4048b7d5 6ebce885 25e7de7f 00d6c2d3 c0000000
09/12/14 14:48:22 << : vendor id payload
09/12/14 14:48:22 ii : unknown vendor id ( 16 bytes )
09/12/14 14:48:22 0x : 55090407 dabe7c91 e93de153 93f89348
09/12/14 14:48:22 << : vendor id payload
09/12/14 14:48:22 ii : unknown vendor id ( 16 bytes )
09/12/14 14:48:22 0x : 1f07f70e aa6514d3 b0fa9654 2a500407
09/12/14 14:48:22 ii : nat-t is disabled locally
09/12/14 14:48:22 == : DH shared secret ( 128 bytes )
09/12/14 14:48:22 == : SETKEYID ( 20 bytes )
09/12/14 14:48:22 == : SETKEYID_d ( 20 bytes )
09/12/14 14:48:22 == : SETKEYID_a ( 20 bytes )
09/12/14 14:48:22 == : SETKEYID_e ( 20 bytes )
09/12/14 14:48:22 == : cipher key ( 16 bytes )
09/12/14 14:48:22 == : cipher iv ( 16 bytes )
09/12/14 14:48:22 == : phase1 hash_i ( computed ) ( 20 bytes )
09/12/14 14:48:22 >> : hash payload
09/12/14 14:48:22 >= : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:22 >= : message 00000000
09/12/14 14:48:22 >= : encrypt iv ( 16 bytes )
09/12/14 14:48:22 == : encrypt packet ( 52 bytes )
09/12/14 14:48:22 == : stored iv ( 16 bytes )
09/12/14 14:48:22 DB : phase1 resend event canceled ( ref count = 1 )
09/12/14 14:48:22 -> : send IKE packet client_public_ip_add:500 -> vpn3000_client_public_ip_add:500 ( 88 bytes )
09/12/14 14:48:22 == : phase1 hash_r ( computed ) ( 20 bytes )
09/12/14 14:48:22 == : phase1 hash_r ( received ) ( 20 bytes )
09/12/14 14:48:22 ii : phase1 sa established
09/12/14 14:48:22 ii : vpn3000_client_public_ip_add:500 <-> client_public_ip_add:500
09/12/14 14:48:22 ii : 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:22 ii : sending peer INITIAL-CONTACT notification
09/12/14 14:48:22 ii : - client_public_ip_add:500 -> vpn3000_client_public_ip_add:500
09/12/14 14:48:22 ii : - isakmp spi = 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:22 ii : - data size 0
09/12/14 14:48:22 >> : hash payload
09/12/14 14:48:22 >> : notification payload
09/12/14 14:48:22 == : new informational hash ( 20 bytes )
09/12/14 14:48:22 == : new informational iv ( 16 bytes )
09/12/14 14:48:22 >= : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:22 >= : message 231bb25f
09/12/14 14:48:22 >= : encrypt iv ( 16 bytes )
09/12/14 14:48:22 == : encrypt packet ( 80 bytes )
09/12/14 14:48:22 == : stored iv ( 16 bytes )
09/12/14 14:48:22 -> : send IKE packet client_public_ip_add:500 -> vpn3000_client_public_ip_add:500 ( 120 bytes )
09/12/14 14:48:22 DB : phase1 ref increment ( ref count = 2, obj count = 1 )
09/12/14 14:48:22 DB : phase1 ref increment ( ref count = 3, obj count = 1 )
09/12/14 14:48:22 DB : phase1 ref increment ( ref count = 4, obj count = 1 )
09/12/14 14:48:22 DB : phase2 not found
09/12/14 14:48:22 DB : phase1 ref decrement ( ref count = 3, obj count = 1 )
09/12/14 14:48:22 <- : recv IKE packet vpn3000_client_public_ip_add:500 -> client_public_ip_add:500 ( 108 bytes )
09/12/14 14:48:22 DB : phase1 found
09/12/14 14:48:22 DB : phase1 ref increment ( ref count = 4, obj count = 1 )
09/12/14 14:48:22 ii : processing config packet ( 108 bytes )
09/12/14 14:48:22 DB : config not found
09/12/14 14:48:22 DB : tunnel ref increment ( ref count = 4, obj count = 1 )
09/12/14 14:48:22 DB : config ref increment ( ref count = 1, obj count = 0 )
09/12/14 14:48:22 DB : config added ( obj count = 1 )
09/12/14 14:48:22 == : new config iv ( 16 bytes )
09/12/14 14:48:22 =< : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:22 =< : message da44436e
09/12/14 14:48:22 =< : decrypt iv ( 16 bytes )
09/12/14 14:48:22 == : decrypt packet ( 108 bytes )
09/12/14 14:48:22 <= : stored iv ( 16 bytes )
09/12/14 14:48:22 << : hash payload
09/12/14 14:48:22 << : attribute payload
09/12/14 14:48:22 == : configure hash_i ( computed ) ( 20 bytes )
09/12/14 14:48:22 == : configure hash_c ( computed ) ( 20 bytes )
09/12/14 14:48:22 ii : configure hash verified
09/12/14 14:48:22 ii : - xauth authentication type
09/12/14 14:48:22 ii : - xauth username
09/12/14 14:48:22 !! : warning, unhandled xauth attribute 32136
09/12/14 14:48:22 ii : - xauth passcode
09/12/14 14:48:22 ii : received basic xauth request - Enter Username and Password.
09/12/14 14:48:22 ii : - standard xauth username
09/12/14 14:48:22 ii : - standard xauth passcode
09/12/14 14:48:22 ii : sending xauth response for user_name
09/12/14 14:48:22 >> : hash payload
09/12/14 14:48:22 >> : attribute payload
09/12/14 14:48:22 == : new configure hash ( 20 bytes )
09/12/14 14:48:22 >= : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:22 >= : message da44436e
09/12/14 14:48:22 >= : encrypt iv ( 16 bytes )
09/12/14 14:48:22 == : encrypt packet ( 92 bytes )
09/12/14 14:48:22 == : stored iv ( 16 bytes )
09/12/14 14:48:22 -> : send IKE packet client_public_ip_add:500 -> vpn3000_client_public_ip_add:500 ( 120 bytes )
09/12/14 14:48:22 DB : config resend event scheduled ( ref count = 2 )
09/12/14 14:48:22 DB : config ref decrement ( ref count = 1, obj count = 1 )
09/12/14 14:48:22 DB : phase1 ref decrement ( ref count = 3, obj count = 1 )
09/12/14 14:48:25 <- : recv IKE packet vpn3000_client_public_ip_add:500 -> client_public_ip_add:500 ( 76 bytes )
09/12/14 14:48:25 DB : phase1 found
09/12/14 14:48:25 DB : phase1 ref increment ( ref count = 4, obj count = 1 )
09/12/14 14:48:25 ii : processing config packet ( 76 bytes )
09/12/14 14:48:25 DB : config found
09/12/14 14:48:25 DB : config ref increment ( ref count = 2, obj count = 1 )
09/12/14 14:48:25 == : new config iv ( 16 bytes )
09/12/14 14:48:25 =< : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:25 =< : message 1cce04f7
09/12/14 14:48:25 =< : decrypt iv ( 16 bytes )
09/12/14 14:48:25 == : decrypt packet ( 76 bytes )
09/12/14 14:48:25 <= : trimmed packet padding ( 12 bytes )
09/12/14 14:48:25 <= : stored iv ( 16 bytes )
09/12/14 14:48:25 << : hash payload
09/12/14 14:48:25 << : attribute payload
09/12/14 14:48:25 == : configure hash_i ( computed ) ( 20 bytes )
09/12/14 14:48:25 == : configure hash_c ( computed ) ( 20 bytes )
09/12/14 14:48:25 ii : configure hash verified
09/12/14 14:48:25 ii : received xauth result -
09/12/14 14:48:25 ii : user user_name authentication succeeded
09/12/14 14:48:25 ii : sending xauth acknowledge
09/12/14 14:48:25 >> : hash payload
09/12/14 14:48:25 >> : attribute payload
09/12/14 14:48:25 == : new configure hash ( 20 bytes )
09/12/14 14:48:25 >= : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:25 >= : message 1cce04f7
09/12/14 14:48:25 >= : encrypt iv ( 16 bytes )
09/12/14 14:48:25 == : encrypt packet ( 60 bytes )
09/12/14 14:48:25 == : stored iv ( 16 bytes )
09/12/14 14:48:25 DB : config resend event canceled ( ref count = 1 )
09/12/14 14:48:25 -> : send IKE packet client_public_ip_add:500 -> vpn3000_client_public_ip_add:500 ( 88 bytes )
09/12/14 14:48:25 DB : config resend event scheduled ( ref count = 2 )
09/12/14 14:48:25 ii : building config attribute list
09/12/14 14:48:25 ii : - IP4 Address
09/12/14 14:48:25 ii : - Address Expiry
09/12/14 14:48:25 ii : - IP4 Netamask
09/12/14 14:48:25 ii : - IP4 DNS Server
09/12/14 14:48:25 ii : - IP4 WINS Server
09/12/14 14:48:25 ii : - DNS Suffix
09/12/14 14:48:25 ii : - Split DNS Domain
09/12/14 14:48:25 ii : - IP4 Split Network Include
09/12/14 14:48:25 ii : - IP4 Split Network Exclude
09/12/14 14:48:25 ii : - Save Password
09/12/14 14:48:25 == : new config iv ( 16 bytes )
09/12/14 14:48:25 ii : sending config pull request
09/12/14 14:48:25 >> : hash payload
09/12/14 14:48:25 >> : attribute payload
09/12/14 14:48:25 == : new configure hash ( 20 bytes )
09/12/14 14:48:25 >= : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:25 >= : message 81d0b07d
09/12/14 14:48:25 >= : encrypt iv ( 16 bytes )
09/12/14 14:48:25 == : encrypt packet ( 100 bytes )
09/12/14 14:48:25 == : stored iv ( 16 bytes )
09/12/14 14:48:25 DB : config resend event canceled ( ref count = 1 )
09/12/14 14:48:25 -> : send IKE packet client_public_ip_add:500 -> vpn3000_client_public_ip_add:500 ( 136 bytes )
09/12/14 14:48:25 DB : config resend event scheduled ( ref count = 2 )
09/12/14 14:48:25 DB : config ref decrement ( ref count = 1, obj count = 1 )
09/12/14 14:48:25 DB : phase1 ref decrement ( ref count = 3, obj count = 1 )
09/12/14 14:48:26 <- : recv IKE packet vpn3000_client_public_ip_add:500 -> client_public_ip_add:500 ( 140 bytes )
09/12/14 14:48:26 DB : phase1 found
09/12/14 14:48:26 DB : phase1 ref increment ( ref count = 4, obj count = 1 )
09/12/14 14:48:26 ii : processing config packet ( 140 bytes )
09/12/14 14:48:26 DB : config found
09/12/14 14:48:26 DB : config ref increment ( ref count = 2, obj count = 1 )
09/12/14 14:48:26 =< : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:26 =< : message 81d0b07d
09/12/14 14:48:26 =< : decrypt iv ( 16 bytes )
09/12/14 14:48:26 == : decrypt packet ( 140 bytes )
09/12/14 14:48:26 <= : trimmed packet padding ( 10 bytes )
09/12/14 14:48:26 <= : stored iv ( 16 bytes )
09/12/14 14:48:26 << : hash payload
09/12/14 14:48:26 << : attribute payload
09/12/14 14:48:26 == : configure hash_i ( computed ) ( 20 bytes )
09/12/14 14:48:26 == : configure hash_c ( computed ) ( 20 bytes )
09/12/14 14:48:26 ii : configure hash verified
09/12/14 14:48:26 ii : received config pull response
09/12/14 14:48:26 ii : - IP4 Address = tunnel_ip_add
09/12/14 14:48:26 ii : - IP4 Netmask = 255.255.252.0
09/12/14 14:48:26 ii : - IP4 DNS Server = dns_ip
09/12/14 14:48:26 ii : - IP4 DNS Server = sec_dns_ip
09/12/14 14:48:26 ii : - IP4 WINS Server = wins_ip
09/12/14 14:48:26 ii : - IP4 WINS Server = sec_wins_ip
09/12/14 14:48:26 ii : - Save Password = 0
09/12/14 14:48:26 ii : - DNS Suffix = domain_name
09/12/14 14:48:26 DB : config resend event canceled ( ref count = 1 )
09/12/14 14:48:26 DB : config ref decrement ( ref count = 0, obj count = 1 )
09/12/14 14:48:26 DB : phase1 ref decrement ( ref count = 3, obj count = 1 )
09/12/14 14:48:29 ii : waiting for vnet to arrive ...
09/12/14 14:48:30 ii : VNET adapter MTU is 1520
09/12/14 14:48:30 ii : enabled adapter ROOT\VNET\0000
09/12/14 14:48:30 ii : creating NONE INBOUND policy ANY:vpn3000_client_public_ip_add:* -> ANY:client_public_ip_add:*
09/12/14 14:48:30 DB : policy ref increment ( ref count = 1, obj count = 0 )
09/12/14 14:48:30 DB : policy added ( obj count = 1 )
09/12/14 14:48:30 DB : policy ref decrement ( ref count = 0, obj count = 1 )
09/12/14 14:48:30 K> : send pfkey X_SPDADD UNSPEC message
09/12/14 14:48:30 ii : creating NONE OUTBOUND policy ANY:client_public_ip_add:* -> ANY:vpn3000_client_public_ip_add:*
09/12/14 14:48:30 K< : recv pfkey X_SPDADD UNSPEC message
09/12/14 14:48:30 DB : policy found
09/12/14 14:48:30 DB : policy ref increment ( ref count = 1, obj count = 1 )
09/12/14 14:48:30 DB : policy ref decrement ( ref count = 0, obj count = 1 )
09/12/14 14:48:30 ii : created NONE policy route for vpn3000_client_public_ip_add/32
09/12/14 14:48:30 DB : policy ref increment ( ref count = 1, obj count = 1 )
09/12/14 14:48:30 DB : policy added ( obj count = 2 )
09/12/14 14:48:30 DB : policy ref decrement ( ref count = 0, obj count = 2 )
09/12/14 14:48:30 K> : send pfkey X_SPDADD UNSPEC message
09/12/14 14:48:30 ii : creating IPSEC INBOUND policy ANY:0.0.0.0/0:* -> ANY:13.0.210.2:*
09/12/14 14:48:30 DB : policy ref increment ( ref count = 1, obj count = 2 )
09/12/14 14:48:30 DB : policy added ( obj count = 3 )
09/12/14 14:48:30 DB : policy ref decrement ( ref count = 0, obj count = 3 )
09/12/14 14:48:30 K> : send pfkey X_SPDADD UNSPEC message
09/12/14 14:48:30 ii : creating IPSEC OUTBOUND policy ANY:13.0.210.2:* -> ANY:0.0.0.0/0:*
09/12/14 14:48:30 K< : recv pfkey X_SPDADD UNSPEC message
09/12/14 14:48:30 DB : policy found
09/12/14 14:48:30 DB : policy ref increment ( ref count = 1, obj count = 3 )
09/12/14 14:48:30 ii : calling init phase2 for initial policy
09/12/14 14:48:30 DB : policy found
09/12/14 14:48:30 DB : policy ref increment ( ref count = 2, obj count = 3 )
09/12/14 14:48:30 DB : policy not found
09/12/14 14:48:30 !! : unable to locate inbound policy for init phase2
09/12/14 14:48:30 DB : policy ref decrement ( ref count = 1, obj count = 3 )
09/12/14 14:48:30 DB : policy ref decrement ( ref count = 0, obj count = 3 )
09/12/14 14:48:30 K< : recv pfkey X_SPDADD UNSPEC message
09/12/14 14:48:30 DB : policy found
09/12/14 14:48:30 DB : policy ref increment ( ref count = 1, obj count = 3 )
09/12/14 14:48:30 DB : policy ref decrement ( ref count = 0, obj count = 3 )
09/12/14 14:48:31 ii : created IPSEC policy route for 0.0.0.0
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 3 )
09/12/14 14:48:31 DB : policy added ( obj count = 4 )
09/12/14 14:48:31 DB : policy ref decrement ( ref count = 0, obj count = 4 )
09/12/14 14:48:31 K> : send pfkey X_SPDADD UNSPEC message
09/12/14 14:48:31 ii : split DNS bypassed ( no split domains defined )
09/12/14 14:48:31 K< : recv pfkey X_SPDADD UNSPEC message
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 4 )
09/12/14 14:48:31 DB : policy ref decrement ( ref count = 0, obj count = 4 )
09/12/14 14:48:31 K< : recv pfkey ACQUIRE UNSPEC message
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 4 )
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 4 )
09/12/14 14:48:31 DB : tunnel found
09/12/14 14:48:31 DB : tunnel ref increment ( ref count = 5, obj count = 1 )
09/12/14 14:48:31 DB : tunnel ref increment ( ref count = 6, obj count = 1 )
09/12/14 14:48:31 DB : new phase2 ( IPSEC initiator )
09/12/14 14:48:31 DB : phase2 ref increment ( ref count = 1, obj count = 0 )
09/12/14 14:48:31 DB : phase2 added ( obj count = 1 )
09/12/14 14:48:31 K> : send pfkey GETSPI ESP message
09/12/14 14:48:31 DB : phase2 ref decrement ( ref count = 0, obj count = 1 )
09/12/14 14:48:31 DB : tunnel ref decrement ( ref count = 5, obj count = 1 )
09/12/14 14:48:31 DB : policy ref decrement ( ref count = 0, obj count = 4 )
09/12/14 14:48:31 DB : policy ref decrement ( ref count = 0, obj count = 4 )
09/12/14 14:48:31 K< : recv pfkey GETSPI ESP message
09/12/14 14:48:31 DB : phase2 found
09/12/14 14:48:31 DB : phase2 ref increment ( ref count = 1, obj count = 1 )
09/12/14 14:48:31 ii : updated spi for 1 ipsec-esp proposal
09/12/14 14:48:31 DB : phase1 found
09/12/14 14:48:31 DB : phase1 ref increment ( ref count = 4, obj count = 1 )
09/12/14 14:48:31 >> : hash payload
09/12/14 14:48:31 >> : security association payload
09/12/14 14:48:31 >> : - proposal #1 payload
09/12/14 14:48:31 >> : -- transform #1 payload
09/12/14 14:48:31 >> : -- transform #2 payload
09/12/14 14:48:31 >> : -- transform #3 payload
09/12/14 14:48:31 >> : -- transform #4 payload
09/12/14 14:48:31 >> : -- transform #5 payload
09/12/14 14:48:31 >> : -- transform #6 payload
09/12/14 14:48:31 >> : -- transform #7 payload
09/12/14 14:48:31 >> : -- transform #8 payload
09/12/14 14:48:31 >> : -- transform #9 payload
09/12/14 14:48:31 >> : -- transform #10 payload
09/12/14 14:48:31 >> : -- transform #11 payload
09/12/14 14:48:31 >> : -- transform #12 payload
09/12/14 14:48:31 >> : -- transform #13 payload
09/12/14 14:48:31 >> : -- transform #14 payload
09/12/14 14:48:31 >> : -- transform #15 payload
09/12/14 14:48:31 >> : -- transform #16 payload
09/12/14 14:48:31 >> : -- transform #17 payload
09/12/14 14:48:31 >> : -- transform #18 payload
09/12/14 14:48:31 >> : nonce payload
09/12/14 14:48:31 >> : identification payload
09/12/14 14:48:31 >> : identification payload
09/12/14 14:48:31 == : phase2 hash_i ( input ) ( 632 bytes )
09/12/14 14:48:31 == : phase2 hash_i ( computed ) ( 20 bytes )
09/12/14 14:48:31 == : new phase2 iv ( 16 bytes )
09/12/14 14:48:31 >= : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:31 >= : message 54e036c9
09/12/14 14:48:31 >= : encrypt iv ( 16 bytes )
09/12/14 14:48:31 == : encrypt packet ( 680 bytes )
09/12/14 14:48:31 == : stored iv ( 16 bytes )
09/12/14 14:48:31 -> : send IKE packet client_public_ip_add:500 -> vpn3000_client_public_ip_add:500 ( 712 bytes )
09/12/14 14:48:31 DB : phase2 resend event scheduled ( ref count = 2 )
09/12/14 14:48:31 DB : phase1 ref decrement ( ref count = 3, obj count = 1 )
09/12/14 14:48:31 DB : phase2 ref decrement ( ref count = 1, obj count = 1 )
09/12/14 14:48:31 <- : recv IKE packet vpn3000_client_public_ip_add:500 -> client_public_ip_add:500 ( 92 bytes )
09/12/14 14:48:31 DB : phase1 found
09/12/14 14:48:31 DB : phase1 ref increment ( ref count = 4, obj count = 1 )
09/12/14 14:48:31 ii : processing informational packet ( 92 bytes )
09/12/14 14:48:31 == : new informational iv ( 16 bytes )
09/12/14 14:48:31 =< : cookies 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:31 =< : message 0d702407
09/12/14 14:48:31 =< : decrypt iv ( 16 bytes )
09/12/14 14:48:31 == : decrypt packet ( 92 bytes )
09/12/14 14:48:31 <= : trimmed packet padding ( 12 bytes )
09/12/14 14:48:31 <= : stored iv ( 16 bytes )
09/12/14 14:48:31 << : hash payload
09/12/14 14:48:31 << : delete payload
### Note: The disconnection happens around this point
09/12/14 14:48:31 == : informational hash_i ( computed ) ( 20 bytes )
09/12/14 14:48:31 == : informational hash_c ( received ) ( 20 bytes )
09/12/14 14:48:31 ii : informational hash verified
09/12/14 14:48:31 ii : received peer DELETE message
09/12/14 14:48:31 ii : - vpn3000_client_public_ip_add:500 -> client_public_ip_add:500
09/12/14 14:48:31 ii : - isakmp spi = 40ebe69914e77cf4:a0cea31adabf7c91
09/12/14 14:48:31 DB : phase1 found
09/12/14 14:48:31 DB : phase1 ref increment ( ref count = 5, obj count = 1 )
09/12/14 14:48:31 ii : cleanup, marked phase1 40ebe69914e77cf4:a0cea31adabf7c91 for removal
09/12/14 14:48:31 DB : phase1 soft event canceled ( ref count = 4 )
09/12/14 14:48:31 DB : phase1 hard event canceled ( ref count = 3 )
09/12/14 14:48:31 DB : phase1 dead event canceled ( ref count = 2 )
09/12/14 14:48:31 DB : config ref increment ( ref count = 1, obj count = 1 )
09/12/14 14:48:31 DB : config deleted ( obj count = 0 )
09/12/14 14:48:31 DB : tunnel ref decrement ( ref count = 4, obj count = 1 )
09/12/14 14:48:31 ii : phase1 removal before expire time
09/12/14 14:48:31 DB : phase1 not found
09/12/14 14:48:31 DB : phase1 ref decrement ( ref count = 1, obj count = 1 )
09/12/14 14:48:31 DB : phase1 deleted ( obj count = 0 )
09/12/14 14:48:31 DB : tunnel ref decrement ( ref count = 3, obj count = 1 )
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 4 )
09/12/14 14:48:31 ii : removing IPSEC INBOUND policy ANY:0.0.0.0/0:* -> ANY:13.0.210.2:*
09/12/14 14:48:31 K> : send pfkey X_SPDDELETE2 UNSPEC message
09/12/14 14:48:31 DB : policy ref decrement ( ref count = 0, obj count = 4 )
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 4 )
09/12/14 14:48:31 ii : removing IPSEC OUTBOUND policy ANY:13.0.210.2:* -> ANY:0.0.0.0/0:*
09/12/14 14:48:31 K> : send pfkey X_SPDDELETE2 UNSPEC message
09/12/14 14:48:31 DB : policy ref decrement ( ref count = 0, obj count = 4 )
09/12/14 14:48:31 K< : recv pfkey X_SPDDELETE2 UNSPEC message
09/12/14 14:48:31 ii : removed IPSEC policy route for ANY:0.0.0.0/0:*
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 4 )
09/12/14 14:48:31 ii : removing NONE INBOUND policy ANY:vpn3000_client_public_ip_add:* -> ANY:client_public_ip_add:*
09/12/14 14:48:31 K> : send pfkey X_SPDDELETE2 UNSPEC message
09/12/14 14:48:31 DB : policy ref decrement ( ref count = 0, obj count = 4 )
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 4 )
09/12/14 14:48:31 ii : removing NONE OUTBOUND policy ANY:client_public_ip_add:* -> ANY:vpn3000_client_public_ip_add:*
09/12/14 14:48:31 K> : send pfkey X_SPDDELETE2 UNSPEC message
09/12/14 14:48:31 DB : policy ref decrement ( ref count = 0, obj count = 4 )
09/12/14 14:48:31 ii : removed NONE policy route for ANY:vpn3000_client_public_ip_add:*
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 4 )
09/12/14 14:48:31 DB : policy deleted ( obj count = 3 )
09/12/14 14:48:31 K< : recv pfkey X_SPDDELETE2 UNSPEC message
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 3 )
09/12/14 14:48:31 DB : policy deleted ( obj count = 2 )
09/12/14 14:48:31 K< : recv pfkey X_SPDDELETE2 UNSPEC message
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 2 )
09/12/14 14:48:31 DB : policy deleted ( obj count = 1 )
09/12/14 14:48:31 K< : recv pfkey X_SPDDELETE2 UNSPEC message
09/12/14 14:48:31 DB : policy found
09/12/14 14:48:31 DB : policy ref increment ( ref count = 1, obj count = 1 )
09/12/14 14:48:31 DB : policy deleted ( obj count = 0 )
09/12/14 14:48:32 ii : disabled adapter ROOT\VNET\0000
09/12/14 14:48:32 DB : tunnel stats event canceled ( ref count = 2 )
09/12/14 14:48:32 DB : removing tunnel config references
09/12/14 14:48:32 DB : removing tunnel phase2 references
09/12/14 14:48:32 DB : phase2 ref increment ( ref count = 2, obj count = 1 )
09/12/14 14:48:32 DB : phase2 resend event canceled ( ref count = 1 )
09/12/14 14:48:32 ii : phase2 removal before expire time
09/12/14 14:48:32 DB : phase2 deleted ( obj count = 0 )
09/12/14 14:48:32 DB : tunnel ref decrement ( ref count = 1, obj count = 1 )
09/12/14 14:48:32 DB : removing tunnel phase1 references
09/12/14 14:48:32 DB : tunnel deleted ( obj count = 0 )
09/12/14 14:48:33 DB : peer ref decrement ( ref count = 1, obj count = 1 )
09/12/14 14:48:33 DB : removing all peer tunnel refrences
09/12/14 14:48:33 DB : peer deleted ( obj count = 0 )
09/12/14 14:48:33 ii : ipc client process thread exit ...

Cisco VPN 3000 logs:
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-14: RPT=4599: public_ip_address: Group [group_name] User [user_name] Authentication configured for SDI
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-19: RPT=24731: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: primary DNS = dns_ip
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-19: RPT=24732: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: secondary DNS = sec_dns_ip
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-19: RPT=24733: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: primary WINS = wins_ip
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-19: RPT=24734: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: secondary WINS = sec_wins_ip
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-19: RPT=24735: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: default domain = domain_name
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-19: RPT=24736: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: IP Compression = LZS
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-19: RPT=24737: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: Split Tunneling Policy = Disabled
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-78: RPT=9197: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: Browser Proxy Setting = 1
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-78: RPT=9198: public_ip_address: Group [group_name] User [user_name] IKEGetUserAttributes: Browser Proxy Bypass Local = 0
2009 Dec 14 14:48:25.180 PST -8:00 %IKE-5-52: RPT=1860: public_ip_address: Group [group_name] User [user_name] User (user_name) authenticated.
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-0: RPT=5511410: public_ip_address: Group [group_name] User [user_name] constructing blank hash
2009 Dec 14 14:48:25.180 PST -8:00 %IKEDBG-7-0: RPT=5511411: public_ip_address: Group [group_name] User [user_name] constructing qm hash
2009 Dec 14 14:48:25.190 PST -8:00 %IKE-6-130: RPT=300: public_ip_address: Group [group_name] User [user_name] Received unsupported transaction mode attribute: 5
2009 Dec 14 14:48:26.050 PST -8:00 %IKEDBG-7-31: RPT=300: public_ip_address: Group [group_name] User [user_name] Obtained IP addr (tunnel_ip_add) prior to initiating Mode Cfg (XAuth enabled)
2009 Dec 14 14:48:26.050 PST -8:00 %IKEDBG-7-32: RPT=300: public_ip_address: Group [group_name] User [user_name] Sending subnet mask (255.255.252.0) to remote client
2009 Dec 14 14:48:26.050 PST -8:00 %IKEDBG-7-0: RPT=5511412: public_ip_address: Group [group_name] User [user_name] constructing blank hash
2009 Dec 14 14:48:26.050 PST -8:00 %IKEDBG-7-20: RPT=1838: public_ip_address: Group [group_name] User [user_name] construct_cfg_set: default domain = domain_name
2009 Dec 14 14:48:26.050 PST -8:00 %IKEDBG-7-0: RPT=5511414: public_ip_address: Group [group_name] User [user_name] constructing qm hash
2009 Dec 14 14:48:31.220 PST -8:00 %IKEDBG-7-21: RPT=1809: public_ip_address: Group [group_name] User [user_name] Delay Quick Mode processing, Cert/Trans Exch/RM DSID in progress
2009 Dec 14 14:48:31.220 PST -8:00 %IKEDBG-7-65: RPT=613: public_ip_address: Group [group_name] User [user_name] IKE AM Responder FSM error history (struct &0x1ec20be8) <state>, <event>: AM_DONE, EV_ERROR AM_TM_PEND_QM, EV_TM_OK AM_TM_PEND_QM, NullEvent AM_TM_INIT_MODECFG_V6H, EV_SND_MSG_TO_TM
2009 Dec 14 14:48:31.220 PST -8:00 %IKEDBG-7-0: RPT=5511415: public_ip_address: Group [group_name] User [user_name] IKE SA AM:a0cea31a terminating: flags 0x01c1f001, refcnt 0, tuncnt 0
2009 Dec 14 14:48:31.220 PST -8:00 %IKEDBG-7-0: RPT=5511417: public_ip_address: Group [group_name] User [user_name] constructing blank hash

Any help, input would be much appreciated.




--
Olivier





More information about the vpn-help mailing list