Troubleshooting Steps
Before looking at some possible reasons of tunnel failure, it is worth examining the debug of a successful Remote Access VPN tunnel build-up process. Remote Access VPN Client uses Aggressive Mode negotiation (three packets exchange instead of six packets for Main Mode in the case of LAN-to-LAN tunnels) to build up the tunnel with the VPN Concentrator. Example 8-1 shows the default event log on the VPN Concentrator for a successful phase I Aggressive Mode negotiation.
Example 8-1. Default Event Log on VPN 3000 Concentrator for the Aggressive Mode Negotiation
! Shows the VPN Client IP Address, mode supported, and Fragmentation Capabilities
1 06/20/2005 10:39:28.760 SEV=5 IKEDBG/64 RPT=7 172.16.172.119
IKE Peer included IKE fragmentation capability flags:
Main Mode: False
Aggressive Mode: True
! Shows the Group and User Authentication Status
3 06/20/2005 10:39:33.670 SEV=4 IKE/52 RPT=3 172.16.172.119
Group [mygroup] User [myuser]
User (myuser) authenticated.
! Provides the VPN Client OS and Client Version information
4 06/20/2005 10:39:33.700 SEV=5 IKE/184 RPT=3 172.16.172.119
Group [mygroup] User [myuser]
Client Type: WinNT
Client Application Version: 4.0.5 (B)
! Shows the connection Type
6 06/20/2005 10:39:34.560 SEV=4 AUTH/22 RPT=6 172.16.172.119
User [myuser] Group [mygroup] connected, Session Type: IPsec
! Shows the Aggressive Mode Status Completed Successfully
7 06/20/2005 10:39:34.560 SEV=4 IKE/119 RPT=6 172.16.172.119
Group [mygroup] User [myuser]
PHASE 1 COMPLETED
Once phase 1 is established, phase 2 negotiation starts. A successful phase 2 (Quick Mode) is shown in example 8-2.
Example 8-2. Default Event Messages For Working Client on VPN 3000 Concentrator with Quick Mode
! Shows the IP address assigned by the VPN Concentrator to the VPN Client
8 06/20/2005 10:39:34.570 SEV=5 IKE/25 RPT=3 172.16.172.119
Group [mygroup] User [myuser]
Received remote Proxy Host data in ID Payload:
Address 10.1.1.40, Protocol 0, Port 0
! Local and Remote Proxies are the networks that will be encrypted by the IPSec
tunnel.
! All Zeros Indicate, all traffic will go through the tunnel, hence no Split
Tunneling
11 06/20/2005 10:39:34.570 SEV=5 IKE/34 RPT=4 172.16.172.119
Group [mygroup] User [myuser]
Received local IP Proxy Subnet data in ID Payload:
Address 0.0.0.0, CAsk 0.0.0.0, Protocol 0, Port 0
! Shows the locally Matched IPsec SA
14 06/20/2005 10:39:34.570 SEV=5 IKE/66 RPT=4 172.16.172.119
Group [mygroup] User [myuser]
IKE Remote Peer configured for SA: ESP-3DES-MD5
! Shows the negotiated Phase 2 Re-Key Interval
15 06/20/2005 10:39:34.570 SEV=5 IKE/75 RPT=3 172.16.172.119
Group [mygroup] User [myuser]
Overriding Initiator's IPsec rekeying duration from 2147483 to 28800 seconds
! Shows Inbound and Outbound SPIs
17 06/20/2005 10:39:34.580 SEV=4 IKE/49 RPT=6 172.16.172.119
Group [mygroup] User [myuser]
Security negotiation complete for User (myuser)
Responder, Inbound SPI = 0x1999168f, Outbound SPI = 0xa3bd8da1
! Shows User and GroupQuick Mode Completed Successfully
20 06/20/2005 10:39:34.580 SEV=4 IKE/120 RPT=6 172.16.172.119
Group [mygroup] User [myuser]
PHASE 2 COMPLETED (msgid=d2d8d26a)
! Finally shows that Network Access Control (NAC) is disabled
21 06/20/2005 10:39:34.580 SEV=4 NAC/27 RPT=3
NAC is disabled for peer - PUB_IP:172.16.172.119, PRV_IP:10.1.1.40
To analyze the Remote Access VPN establishment efficiently, and quickly, you must analyze the log on both the VPN 3000 Concentrator and the VPN Client. Example 8-3 shows the phase 1 establishment on the VPN Client using Aggressive mode.
Example 8-3. Phase 1 Establishment for Aggressive Mode Negotiation on VPN Client
! The following lines indicate that the VPN Client Environment is fine.
453 12:16:26.937 06/20/05 Sev=Info/4 CM/0x63100002
Begin connection process
! Following lines indicates that Microsoft IPsec server is stopped successfully
454 12:16:26.968 06/20/05 Sev=Info/4 CVPND/0xE3400001
Microsoft IPsec Policy Agent service stopped successfully
! Showing the Interface Used for the Connection
455 12:16:26.968 06/20/05 Sev=Info/4 CM/0x63100004
Establish secure connection using Ethernet
.
.
.
! Shows the VPN Concentrator IP address the VPN Client is trying to establish VPN
! connection
457 12:16:27.968 06/20/05 Sev=Info/6 IKE/0x6300003B
Attempting to establish a connection with 172.16.172.119.
! This is the 1st packet in Aggressive Mode sent by the VPN Client
458 12:16:27.968 06/20/05 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK AG (SA, KE, NON, ID, VID(Xauth), VID(dpd), VID(Nat-T),
VID(Frag), VID(Unity)) to 172.16.172.119
! Following line indicates that IPSec Driver has successfully started
459 12:16:27.968 06/20/05 Sev=Info/4 IPSEC/0x63700008
IPsec driver successfully started
! Following is the 2nd message sent by the VPN VPN Concentrator, which is received
! by the VPN Client
463 12:16:28.125 06/20/05 Sev=Info/4 IKE/0x63000014
RECEIVING <<< ISAKMP OAK AG (SA, KE, NON, ID, HASH, VID(Unity), VID(Xauth),
VID(dpd), VID(Frag), VID(?), VID(?)) from 172.16.172.119
! The following message shows that VPN Concentrator is Cisco-Unity compliant
464 12:16:28.125 06/20/05 Sev=Info/5 IKE/0x63000001
Peer is a Cisco-Unity compliant peer
! Shows that the Peer Supports Extended Authentication
465 12:16:28.125 06/20/05 Sev=Info/5 IKE/0x63000001
Peer supports XAUTH
! Shows that the Peer Supports Dead Peer Detection (DPD)
466 12:16:28.125 06/20/05 Sev=Info/5 IKE/0x63000001
Peer supports DPD
! IKE Packet Fragmentation is supported.
467 12:16:28.125 06/20/05 Sev=Info/5 IKE/0x63000001
Peer supports IKE fragmentation payloads
! The Peer Supports Delete with Reason Messages
468 12:16:28.125 06/20/05 Sev=Info/5 IKE/0x63000001
Peer supports DWR Code and DWR Text
! The 3rd message which is the final message in Aggressive mode is sent by the
VPNClient.
470 12:16:28.125 06/20/05 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK AG *(HASH, NOTIFY:STATUS_INITIAL_CONTACT, VID(?),
VID(Unity)) to 172.16.172.119
! UDP Port Number Used for IKEPort 500 (Not NAT-T) as shown by the local and remote
! port which is 0x01F4 in Hex.
471 12:16:28.125 06/20/05 Sev=Info/4 IKE/0x63000083
IKE Port in use - Local Port = 0x01F4, Remote Port = 0x01F4
! The following line shows the IKE Aggressive Mode Complete
472 12:16:28.125 06/20/05 Sev=Info/4 CM/0x6310000E
Established Phase 1 SA. 1 Crypto Active IKE SA, 0 User Authenticated IKE SA in the
system
In a Remote Access VPN connection, right after the phase 1 establishment, X-auth and mode configuration take place as shown in Example 8-4. This happens when the IP address assignment, DNS server IP address, and so on are assigned to the VPN Client.
Example 8-4. X-Auth and Mode Configuration Messages After Phase 1 Establishment
! Shows VPN client received Username/Password Prompt from VPN Concentrator
474 12:16:28.125 06/20/05 Sev=Info/4IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 172.16.172.119
! Username/Password prompt is presented to the user here
475 12:16:28.125 06/20/05 Sev=Info/4CM/0x63100015
Launch xAuth application
! Users entered username/password is sent to the VPN Concentrator
477 12:16:30.687 06/20/05 Sev=Info/4IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 172.16.172.119
! Received Authentication Acknowledgement from the VPN Concentrator
479 12:16:30.984 06/20/05 Sev=Info/4IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 172.16.172.119
! VPN Client is sending Authentication Acknowledgement back to the VPN Concentrator
480 12:16:30.984 06/20/05 Sev=Info/4IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 172.16.172.119
! Show user authentication is successful
481 12:16:30.984 06/20/05 Sev=Info/4CM/0x6310000E
Established Phase 1 SA. 1 Crypto Active IKE SA, 1 User Authenticated IKE SA in
the system
! VPN Client is sending firewall status to the VPN Concentrator
483 12:16:31.000 06/20/05 Sev=Info/5IKE/0x6300005D
Firewall Policy: Product=Cisco Systems Integrated Client, Capability= (Centralized
Protection Policy).
484 12:16:31.000 06/20/05 Sev=Info/4IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 172.16.172.119
! Receiving Mode Config Attributes from the VPN 3000 Concentrator
486 12:16:31.859 06/20/05 Sev=Info/4IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 172.16.172.119
! Tunnel Assigned IP Address from the VPN Concentrator to the VPN Client
487 12:16:31.859 06/20/05 Sev=Info/5IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_ADDRESS: , value = 10.1.1.40
! Tunnel Assigned Subnet CAsk is shown below
488 12:16:31.859 06/20/05 Sev=Info/5IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_NETCASK: , value = 255.255.255.0
! Following lines show if the Password Allowed to Be Stored Locally. Value 0x00000000
! means NO
489 12:16:31.859 06/20/05 Sev=Info/5IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SAVEPWD: , value = 0x00000000
! Number of Entries in the Split Tunnel List. In this log it shows 2.
490 12:16:31.859 06/20/05 Sev=Info/5IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SPLIT_INCLUDE (# of split_nets), value =
0x00000002
! Detail of all Networks in the Split List
491 12:16:31.859 06/20/05 Sev=Info/5IKE/0x6300000F
SPLIT_NET #1
subnet = 10.1.1.0
CAsk = 255.255.255.0
protocol = 0
src port = 0
dest port=0
! Perfect Forward Secrecy (Disabled) as the value is set to 0x00000000
493 12:16:31.859 06/20/05 Sev=Info/5IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_PFS: , value = 0x00000000
! Peer version information is shown here
494 12:16:31.859 06/20/05 Sev=Info/5IKE/0x6300000E
MODE_CFG_REPLY: Attribute = APPLICATION_VERSION, value = Cisco Systems, Inc./VPN
3000 Concentrator Version 4.7.Rel built by vmurphy on CAr 10 2005 12:35:39
After the successful X-Auth and mode-config of the VPN connection, phase 2 negotiation (Quick Mode) starts as shown in Example 8-5.
Example 8-5. Shows a Successful Quick Mode Negotiation (Phase II) on VPN Client
! Quick Mode Starts here. Sending Quick Mode Message 1
497 12:16:31.875 06/20/05 Sev=Info/4IKE/0x63000013
SENDING >>> ISAKMP OAK QM *(HASH, SA, NON, ID, ID) to 172.16.172.119
! Received IKE Notify message from the VPN Concentrator
500 12:16:31.890 06/20/05 Sev=Info/4IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:STATUS_RESP_LIFETIME) from
172.16.172.119
! Received Quick Mode Message 2 from the VPN Concentrator
504 12:16:31.890 06/20/05 Sev=Info/4IKE/0x63000014
RECEIVING <<< ISAKMP OAK QM *(HASH, SA, NON, ID, ID, NOTIFY:STATUS_RESP_LIFETIME)
from 172.16.172.119
! Sending Quick Mode Message 3 as shown below
506 12:16:31.890 06/20/05 Sev=Info/4IKE/0x63000013
SENDING >>> ISAKMP OAK QM *(HASH) to 172.16.172.119
507 12:16:31.890 06/20/05 Sev=Info/5IKE/0x63000059
! Loading SPIs here
Loading IPsec SA (MsgID=D335FB24 OUTBOUND SPI = 0x448FCE67 INBOUND SPI = 0x26DCA8D9)
! Non-VPN Routing Table
510 12:16:31.937 06/20/05 Sev=Info/5CVPND/0x63400013
Destination NetCAsk Gateway Interface Metric
0.0.0.0 0.0.0.0 172.16.172.119 172.16.172.119 20
127.0.0.0 255.0.0.0 127.0.0.1 127.0.0.1 1
172.16.172.119 255.255.255.255 127.0.0.1 127.0.0.1 20
! Virtual Adapter Enabled with the Tunnel Assigned Address
511 12:16:32.562 06/20/05 Sev=Info/4CM/0x63100034
The Virtual Adapter was enabled:
IP=10.1.1.40/255.255.255.0
DNS=0.0.0.0,0.0.0.0
WINS=0.0.0.0,0.0.0.0
DoMain=
Split DNS Names=
! Routing Table post VPN, Repeated for All Subnets in the Network List
512 12:16:32.562 06/20/05 Sev=Info/5CVPND/0x63400013
Destination NetCAsk Gateway Interface Metric
0.0.0.0 0.0.0.0 172.16.172.119 172.16.172.119 20
10.1.1.0 255.255.255.0 10.1.1.40 10.1.1.40 10
10.1.1.40 255.255.255.255 127.0.0.1 127.0.0.1 10
10.255.255.255 255.255.255.255 10.1.1.40 10.1.1.40 10
127.0.0.0 255.0.0.0 127.0.0.1 127.0.0.1 1
172.16.172.119 255.255.255.255 127.0.0.1 127.0.0.1 20
! Virtual Adapter is Added
514 12:16:32.609 06/20/05 Sev=Info/6CM/0x63100036
The routing table was updated for the Virtual Adapter
! Locally Assigned and Tunnel Assigned Addresses
516 12:16:32.953 06/20/05 Sev=Info/4CM/0x63100038
Address watch added for 172.16.172.119. Current hostname: rail, Current
address(es): 10.1.1.40, 172.16.172.119.
! Tunnel Assigned Address to the Virtual Adapter
522 12:16:33.015 06/20/05 Sev=Info/4IPSEC/0x6370002E
Assigned VA private interface addr 10.1.1.40
After becoming comfortable with the sequence of events that takes place for a successful Remote Access VPN connection, examine the possible causes of tunnel failure as listed in the following sections:
VPN Client cannot connect
VPN Client can connect but Tunnel is not passing traffic
VPN Client can connect but users cannot access Internet
VPN Client can connect but users cannot access local LAN
Details on the above listed items follow in the following sections.