06-23-2013 06:03 AM
Hi,
I am trying to establish VPN session to Cisco ASA 5525X firewall running 9.1.1 through Cisco VPN Client. Although AnyConnect is the way forward, still the legacy method would need to be supported for some time as this is part of a migration. I tried two VPN users (authenticated through AD) on two client machines running Windows 7 64-bit and Cisco VPN Client 5.0.07.0440. Both the users are successfull establishing a session from one machine to the ASA but not the other. On entering wrong credentails, the login pop-up appears immediately. On correct username/password combination, the following VPN client log messages are generated and the session drops i.e. "Not connected." in the status bar. The PCF file is the same across both client machines.
Cisco Systems VPN Client Version 5.0.07.0440
Copyright (C) 1998-2010 Cisco Systems, Inc. All Rights Reserved.
Client Type(s): Windows, WinNT
Running on: 6.1.7601 Service Pack 1
119 22:49:16.933 06/23/13 Sev=Info/6 IKE/0x6300003B
Attempting to establish a connection with 203.99.111.44.
120 22:49:16.939 06/23/13 Sev=Info/4 IKE/0x63000001
Starting IKE Phase 1 Negotiation
121 22:49:16.942 06/23/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK AG (SA, KE, NON, ID, VID(Xauth), VID(dpd), VID(Frag), VID(Nat-T), VID(Unity)) to 203.99.111.44
122 22:49:16.973 06/23/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
123 22:49:16.973 06/23/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK AG (SA, KE, NON, ID, HASH, VID(Unity), VID(Xauth), VID(dpd), VID(Nat-T), NAT-D, NAT-D, VID(Frag), VID(?)) from 203.99.111.44
124 22:49:16.974 06/23/13 Sev=Info/5 IKE/0x63000001
Peer is a Cisco-Unity compliant peer
125 22:49:16.974 06/23/13 Sev=Info/5 IKE/0x63000001
Peer supports XAUTH
126 22:49:16.974 06/23/13 Sev=Info/5 IKE/0x63000001
Peer supports DPD
127 22:49:16.974 06/23/13 Sev=Info/5 IKE/0x63000001
Peer supports NAT-T
128 22:49:16.974 06/23/13 Sev=Info/5 IKE/0x63000001
Peer supports IKE fragmentation payloads
129 22:49:16.977 06/23/13 Sev=Info/6 IKE/0x63000001
IOS Vendor ID Contruction successful
130 22:49:16.977 06/23/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK AG *(HASH, NOTIFY:STATUS_INITIAL_CONTACT, NAT-D, NAT-D, VID(?), VID(Unity)) to 203.99.111.44
131 22:49:16.977 06/23/13 Sev=Info/6 IKE/0x63000055
Sent a keepalive on the IPSec SA
132 22:49:16.977 06/23/13 Sev=Info/4 IKE/0x63000083
IKE Port in use - Local Port = 0xCA7C, Remote Port = 0x1194
133 22:49:16.977 06/23/13 Sev=Info/5 IKE/0x63000072
Automatic NAT Detection Status:
Remote end is NOT behind a NAT device
This end IS behind a NAT device
134 22:49:17.000 06/23/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
135 22:49:17.000 06/23/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 203.99.111.44
136 22:49:17.211 06/23/13 Sev=Info/4 IPSEC/0x63700008
IPSec driver successfully started
137 22:49:17.211 06/23/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
138 22:49:23.207 06/23/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 203.99.111.44
139 22:49:23.393 06/23/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
140 22:49:23.393 06/23/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 203.99.111.44
141 22:49:23.393 06/23/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 203.99.111.44
142 22:49:23.401 06/23/13 Sev=Info/5 IKE/0x6300005E
Client sending a firewall request to concentrator
143 22:49:23.401 06/23/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 203.99.111.44
144 22:49:23.427 06/23/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
145 22:49:23.427 06/23/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 203.99.111.44
146 22:49:23.427 06/23/13 Sev=Info/5 IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_ADDRESS: , value = 10.2.193.69
147 22:49:23.427 06/23/13 Sev=Info/5 IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_DNS(1): , value = 10.2.5.2
148 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_DNS(2): , value = 10.1.5.2
149 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SAVEPWD: , value = 0x00000000
150 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SPLIT_INCLUDE (# of split_nets), value = 0x00000001
151 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x6300000F
SPLIT_NET #1
subnet = 10.0.0.0
mask = 255.0.0.0
protocol = 0
src port = 0
dest port=0
152 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x6300000E
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_DEFDOMAIN: , value = example.org
153 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_PFS: , value = 0x00000000
154 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x6300000E
MODE_CFG_REPLY: Attribute = APPLICATION_VERSION, value = Cisco Systems, Inc ASA5525 Version 9.1(1) built by builders on Wed 28-Nov-12 11:15 PST
155 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SMARTCARD_REMOVAL_DISCONNECT: , value = 0x00000001
156 22:49:23.428 06/23/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = Received and using NAT-T port number , value = 0x00001194
157 22:49:23.445 06/23/13 Sev=Info/4 IKE/0x63000056
Received a key request from Driver: Local IP = 10.2.193.69, GW IP = 203.99.111.44, Remote IP = 0.0.0.0
158 22:49:23.445 06/23/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK QM *(HASH, SA, NON, ID, ID) to 203.99.111.44
159 22:49:23.477 06/23/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
160 22:49:23.477 06/23/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:STATUS_RESP_LIFETIME) from 203.99.111.44
161 22:49:23.477 06/23/13 Sev=Info/5 IKE/0x63000045
RESPONDER-LIFETIME notify has value of 86400 seconds
162 22:49:23.477 06/23/13 Sev=Info/5 IKE/0x63000047
This SA has already been alive for 7 seconds, setting expiry to 86393 seconds from now
163 22:49:23.477 06/23/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
164 22:49:23.477 06/23/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:NO_PROPOSAL_CHOSEN) from 203.99.111.44
165 22:49:23.478 06/23/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to 203.99.111.44
166 22:49:23.478 06/23/13 Sev=Info/4 IKE/0x63000049
Discarding IPsec SA negotiation, MsgID=F3E3C530
167 22:49:23.478 06/23/13 Sev=Info/4 IKE/0x63000017
Marking IKE SA for deletion (I_Cookie=CD65262E1C3808E4 R_Cookie=912AE160ADADEE65) reason = DEL_REASON_IKE_NEG_FAILED
168 22:49:23.478 06/23/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
169 22:49:23.479 06/23/13 Sev=Info/4 IKE/0x63000058
Received an ISAKMP message for a non-active SA, I_Cookie=CD65262E1C3808E4 R_Cookie=912AE160ADADEE65
170 22:49:23.479 06/23/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(Dropped) from 203.99.111.44
171 22:49:24.310 06/23/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
172 22:49:26.838 06/23/13 Sev=Info/4 IKE/0x6300004B
Discarding IKE SA negotiation (I_Cookie=CD65262E1C3808E4 R_Cookie=912AE160ADADEE65) reason = DEL_REASON_IKE_NEG_FAILED
173 22:49:26.849 06/23/13 Sev=Info/4 IKE/0x63000001
IKE received signal to terminate VPN connection
174 22:49:26.855 06/23/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
175 22:49:26.855 06/23/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
176 22:49:26.855 06/23/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
177 22:49:26.855 06/23/13 Sev=Info/4 IPSEC/0x6370000A
IPSec driver successfully stopped
Any ideas why the second Windows 7 client is not working ?
Regards,
Rick.
Solved! Go to Solution.
06-23-2013 09:21 AM
Rick
Thanks for the additional output. It does show the xauth authentication step, which is good to see. But it does not offer much clarity about what is causing the problem.
My attention is drawn to a couple of message from the logs which are consistent in both sessions for which you have posted logs.
32 00:36:08.178 06/24/13 Sev=Info/5 IKE/0x6300005E
Client sending a firewall request to concentrator
I am not sure that we see any response to this but it makes me wonder if this is somehow involved in the problem. Is it possible that there is any difference in firewall setup and operation between the two clients?
I also am interested in this series of messages
48 00:36:08.210 06/24/13 Sev=Info/4 IKE/0x63000056
Received a key request from Driver: Local IP = 10.2.193.69, GW IP = 203.99.111.44, Remote IP = 0.0.0.0
I am not sure why the Driver is doing a key request at this point, and I wonder why the remote IP is 0.0.0.0?
It is followed by a packet in which the ASA provides the value of the SA lifetime - which would seem to be on the track toward successful connection. which is followed by
55 00:36:08.350 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
56 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:NO_PROPOSAL_CHOSEN) from 203.99.111.44
in which the ASA indicates that no proposal was chosen. So it appears that the ASA is not happy about something.
If we are not finding indications from the client that identify the problem then perhaps we need to look at the ASA. Are any log messages generated on the ASA during this attempt to establish VPN that might show us the problem? Would it be feasible to run debugs on the ASA during a test from this machine?
HTH
Rick
06-23-2013 07:06 AM
Rick
It seems from messages 146 through 156 that negotiation was successful and the client is receiving parameters from the ASA. But I do not see anything in the log messages that indicates the authentication process. I wonder if anything else happened that is not reflected in these logs? I would suggest that you check the logging setting in the client, make sure that all categories are set to high, and run the test again and post the complete log output from the client.
Through message 162 the messages seem to indicate that processes are headed toward a successful connection. Then message 164 says that no proposal was chosen (coming from the ASA). So I wonder if something is going on with the ASA. Are there any log messages from the ASA when this happens? Is it feasible to run debug on the ASA during this test?
HTH
Rick
06-23-2013 07:53 AM
Thanks Rick, the following output is generated when Log Settings are set to all High.
Cisco Systems VPN Client Version 5.0.07.0440
Copyright (C) 1998-2010 Cisco Systems, Inc. All Rights Reserved.
Client Type(s): Windows, WinNT
Running on: 6.1.7601 Service Pack 1
1 00:36:00.051 06/24/13 Sev=Info/4 CM/0x63100002
Begin connection process
2 00:36:00.098 06/24/13 Sev=Info/4 CM/0x63100004
Establish secure connection
3 00:36:00.098 06/24/13 Sev=Info/4 CM/0x63100024
Attempt connection with server "203.99.111.44"
4 00:36:00.098 06/24/13 Sev=Info/6 IKE/0x6300003B
Attempting to establish a connection with 203.99.111.44.
5 00:36:00.098 06/24/13 Sev=Info/4 IKE/0x63000001
Starting IKE Phase 1 Negotiation
6 00:36:00.113 06/24/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK AG (SA, KE, NON, ID, VID(Xauth), VID(dpd), VID(Frag), VID(Nat-T), VID(Unity)) to 203.99.111.44
7 00:36:00.113 06/24/13 Sev=Info/4 IPSEC/0x63700008
IPSec driver successfully started
8 00:36:00.113 06/24/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
9 00:36:00.144 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
10 00:36:00.144 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK AG (SA, KE, NON, ID, HASH, VID(Unity), VID(Xauth), VID(dpd), VID(Nat-T), NAT-D, NAT-D, VID(Frag), VID(?)) from 203.99.111.44
11 00:36:00.144 06/24/13 Sev=Info/5 IKE/0x63000001
Peer is a Cisco-Unity compliant peer
12 00:36:00.144 06/24/13 Sev=Info/5 IKE/0x63000001
Peer supports XAUTH
13 00:36:00.144 06/24/13 Sev=Info/5 IKE/0x63000001
Peer supports DPD
14 00:36:00.144 06/24/13 Sev=Info/5 IKE/0x63000001
Peer supports NAT-T
15 00:36:00.144 06/24/13 Sev=Info/5 IKE/0x63000001
Peer supports IKE fragmentation payloads
16 00:36:00.144 06/24/13 Sev=Info/6 IKE/0x63000001
IOS Vendor ID Contruction successful
17 00:36:00.144 06/24/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK AG *(HASH, NOTIFY:STATUS_INITIAL_CONTACT, NAT-D, NAT-D, VID(?), VID(Unity)) to 203.99.111.44
18 00:36:00.144 06/24/13 Sev=Info/6 IKE/0x63000055
Sent a keepalive on the IPSec SA
19 00:36:00.144 06/24/13 Sev=Info/4 IKE/0x63000083
IKE Port in use - Local Port = 0xE953, Remote Port = 0x1194
20 00:36:00.144 06/24/13 Sev=Info/5 IKE/0x63000072
Automatic NAT Detection Status:
Remote end is NOT behind a NAT device
This end IS behind a NAT device
21 00:36:00.144 06/24/13 Sev=Info/4 CM/0x6310000E
Established Phase 1 SA. 1 Crypto Active IKE SA, 0 User Authenticated IKE SA in the system
22 00:36:00.160 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
23 00:36:00.160 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 203.99.111.44
24 00:36:00.160 06/24/13 Sev=Info/4 CM/0x63100015
Launch xAuth application
25 00:36:00.176 06/24/13 Sev=Info/6 GUI/0x63B00012
Authentication request attributes is 6h.
26 00:36:08.038 06/24/13 Sev=Info/4 CM/0x63100017
xAuth application returned
27 00:36:08.038 06/24/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 203.99.111.44
28 00:36:08.163 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
29 00:36:08.163 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 203.99.111.44
30 00:36:08.163 06/24/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 203.99.111.44
31 00:36:08.163 06/24/13 Sev=Info/4 CM/0x6310000E
Established Phase 1 SA. 1 Crypto Active IKE SA, 1 User Authenticated IKE SA in the system
32 00:36:08.178 06/24/13 Sev=Info/5 IKE/0x6300005E
Client sending a firewall request to concentrator
33 00:36:08.178 06/24/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 203.99.111.44
34 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
35 00:36:08.194 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 203.99.111.44
36 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_ADDRESS: , value = 10.2.193.69
37 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_DNS(1): , value = 10.2.5.2
38 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_DNS(2): , value = 10.1.5.2
39 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SAVEPWD: , value = 0x00000000
40 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SPLIT_INCLUDE (# of split_nets), value = 0x00000001
41 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300000F
SPLIT_NET #1
subnet = 10.0.0.0
mask = 255.0.0.0
protocol = 0
src port = 0
dest port=0
42 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300000E
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_DEFDOMAIN: , value = example.org
43 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_PFS: , value = 0x00000000
44 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300000E
MODE_CFG_REPLY: Attribute = APPLICATION_VERSION, value = Cisco Systems, Inc ASA5525 Version 9.1(1) built by builders on Wed 28-Nov-12 11:15 PST
45 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SMARTCARD_REMOVAL_DISCONNECT: , value = 0x00000001
46 00:36:08.194 06/24/13 Sev=Info/5 IKE/0x6300000D
MODE_CFG_REPLY: Attribute = Received and using NAT-T port number , value = 0x00001194
47 00:36:08.194 06/24/13 Sev=Info/4 CM/0x63100019
Mode Config data received
48 00:36:08.210 06/24/13 Sev=Info/4 IKE/0x63000056
Received a key request from Driver: Local IP = 10.2.193.69, GW IP = 203.99.111.44, Remote IP = 0.0.0.0
49 00:36:08.210 06/24/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK QM *(HASH, SA, NON, ID, ID) to 203.99.111.44
50 00:36:08.256 06/24/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
51 00:36:08.350 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
52 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:STATUS_RESP_LIFETIME) from 203.99.111.44
53 00:36:08.350 06/24/13 Sev=Info/5 IKE/0x63000045
RESPONDER-LIFETIME notify has value of 86400 seconds
54 00:36:08.350 06/24/13 Sev=Info/5 IKE/0x63000047
This SA has already been alive for 8 seconds, setting expiry to 86392 seconds from now
55 00:36:08.350 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
56 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:NO_PROPOSAL_CHOSEN) from 203.99.111.44
57 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to 203.99.111.44
58 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000049
Discarding IPsec SA negotiation, MsgID=F6670759
59 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000017
Marking IKE SA for deletion (I_Cookie=3F8BF9480B75C4A2 R_Cookie=A8A3F19D035B6D01) reason = DEL_REASON_IKE_NEG_FAILED
60 00:36:08.350 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
61 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000058
Received an ISAKMP message for a non-active SA, I_Cookie=3F8BF9480B75C4A2 R_Cookie=A8A3F19D035B6D01
62 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(Dropped) from 203.99.111.44
63 00:36:10.955 06/24/13 Sev=Info/6 CVPND/0x63400006
Service reports: "Running".
64 00:36:11.860 06/24/13 Sev=Info/4 IKE/0x6300004B
Discarding IKE SA negotiation (I_Cookie=3F8BF9480B75C4A2 R_Cookie=A8A3F19D035B6D01) reason = DEL_REASON_IKE_NEG_FAILED
65 00:36:11.860 06/24/13 Sev=Info/4 CM/0x63100012
Phase 1 SA deleted before first Phase 2 SA is up cause by "DEL_REASON_IKE_NEG_FAILED". 0 Crypto Active IKE SA, 0 User Authenticated IKE SA in the system
66 00:36:11.860 06/24/13 Sev=Info/5 CM/0x63100025
Initializing CVPNDrv
67 00:36:11.860 06/24/13 Sev=Info/6 CM/0x63100046
Set tunnel established flag in registry to 0.
68 00:36:11.860 06/24/13 Sev=Info/4 IKE/0x63000001
IKE received signal to terminate VPN connection
69 00:36:11.876 06/24/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
70 00:36:11.876 06/24/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
71 00:36:11.876 06/24/13 Sev=Info/4 IPSEC/0x63700014
Deleted all keys
72 00:36:11.876 06/24/13 Sev=Info/4 IPSEC/0x6370000A
IPSec driver successfully stopped
Regards,
Rick.
06-23-2013 09:21 AM
Rick
Thanks for the additional output. It does show the xauth authentication step, which is good to see. But it does not offer much clarity about what is causing the problem.
My attention is drawn to a couple of message from the logs which are consistent in both sessions for which you have posted logs.
32 00:36:08.178 06/24/13 Sev=Info/5 IKE/0x6300005E
Client sending a firewall request to concentrator
I am not sure that we see any response to this but it makes me wonder if this is somehow involved in the problem. Is it possible that there is any difference in firewall setup and operation between the two clients?
I also am interested in this series of messages
48 00:36:08.210 06/24/13 Sev=Info/4 IKE/0x63000056
Received a key request from Driver: Local IP = 10.2.193.69, GW IP = 203.99.111.44, Remote IP = 0.0.0.0
I am not sure why the Driver is doing a key request at this point, and I wonder why the remote IP is 0.0.0.0?
It is followed by a packet in which the ASA provides the value of the SA lifetime - which would seem to be on the track toward successful connection. which is followed by
55 00:36:08.350 06/24/13 Sev=Info/5 IKE/0x6300002F
Received ISAKMP packet: peer = 203.99.111.44
56 00:36:08.350 06/24/13 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:NO_PROPOSAL_CHOSEN) from 203.99.111.44
in which the ASA indicates that no proposal was chosen. So it appears that the ASA is not happy about something.
If we are not finding indications from the client that identify the problem then perhaps we need to look at the ASA. Are any log messages generated on the ASA during this attempt to establish VPN that might show us the problem? Would it be feasible to run debugs on the ASA during a test from this machine?
HTH
Rick
06-25-2013 12:00 AM
Thanks Rick, much appreciate your replies. Yes you are right the ASA was not happy about something and that something was "crypto dynamic-map Internet_dyn_map 20 set nat-t-disable" being configured. This was configured on the old firewall ASA5540 running 7.2.4 and we didn't had any issues. With the new ASA5525X running 9.1 and migrated config, it didn't like it. Removed the line and it worked.
Thanks,
Rick.
06-25-2013 07:00 AM
Rick
I am glad that my suggestion pointed you toward the problem. I am glad that you have solved it. Thanks for posting back to the forum to tell us that you have solved it. And thanks for using the rating system to mark the question as answered. It makes the forum more useful when people can read a question and can know that a solution was found. Your marking has contributed to this process.
HTH
Rick
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide