|
Author
|
Topic: VPN debugs
|
Smeans
unregistered
|
posted February 18, 2011 01:27 PM
I know I mentioned this before with a link, but here is a little labbing that will hopefully help someone out.
Although many experienced network engineers troubleshoot without the somewhat cryptic Cisco device debugs, it is a hallmark of certification testing. With that in mind, I’ve decided to lab up common problems with debugs turned on.
I have to stress that for these debugs to make sense in any way you first need a solid grasp of how IPsec and particularly IKE works. Not just the phases, but what is included in each exchange during those phases.
First, I’m doing a simple site to site tunnel between a router and an ASA. Error #1 is a mismatched IKE proposal. The Router is using 3des, ASA is using aes. The router’s output doesn’t come right out and tell us this, it just tells us we are using main mode and the pre-shared keys match. Other than that we just know that we get no further than MM1 (first message of first exchange).
*Feb 18 17:59:50.119: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
*Feb 18 17:59:50.119: ISAKMP:(0):found peer pre-shared key matching 24.234.3.100
*Feb 18 17:59:50.119: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1
*Feb 18 17:59:50.123: ISAKMP:(0): beginning Main Mode exchange
*Feb 18 17:59:50.123: ISAKMP:(0): sending packet to 24.234.3.100 my_port 500 peer_port 500 (I) MM_NO_STATE
*Feb 18 17:59:50.123: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Feb 18 17:59:50.123: ISAKMP (0:0): received packet from 24.234.3.100 dport 500 sport 500 Global (I) MM_NO_STATE
*Feb 18 17:59:50.123: ISAKMP:(0):Notify has no hash. Rejected.
*Feb 18 17:59:50.123: ISAKMP (0:0): Unknown Input IKE_MESG_FROM_PEER, IKE_INFO_NOTIFY: state = IKE_I_MM1
*Feb 18 17:59:50.123: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_INFO_NOTIFY
*Feb 18 17:59:50.123: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM1
*Feb 18 17:59:50.123: %CRYPTO-6-IKMP_MODE_FAILURE: Processing of Informational mode failed with peer at 24.234.3.100
Well, knowing that the first exchange is IKE proposals we can check the hashes and encryption values. I’m going to fix this, and then mismatch the transform sets. Now we get a lot further. We go from IKE MM6 (last message in main mode exchange, comes from the other side) to Quick mode. But, we get the message that can be tough to spot in a big debug. Proposal not chosen. Easy to figure out with context (knowing we got past main mode) but if you received just this line in a question it would be a bit tricky unless you had seen this many times before.
*Feb 18 18:23:23.435: ISAKMP:(1002):Old State = IKE_I_MM6 New State = IKE_P1_COMPLETE
*Feb 18 18:23:23.435: ISAKMP:(1002):beginning Quick Mode exchange, M-ID of -84678876
*Feb 18 18:23:23.443: ISAKMP (0:1002): received packet from 24.234.3.100 dport 500 sport 500 Global (I) QM_IDLE
*Feb 18 18:23:23.443: ISAKMP: set new node 224984723 to QM_IDLE
*Feb 18 18:23:23.443: ISAKMP:(1002): processing HASH payload. message ID = 224984723
*Feb 18 18:23:23.443: ISAKMP:(1002): processing NOTIFY PROPOSAL_NOT_CHOSEN protocol 3
It’s worth noting for the real world that the ASA debugs are a lot more informative as long as you turn on greater than default debugs. For instance with the mismatched SA above and debug level 150 turned on we get (and I’m cherry picking messages here, output is verbose):
Feb 18 18:48:51 [IKEv1]: Group = 24.234.3.3, IP = 24.234.3.3, PHASE 1 COMPLETED
Feb 18 18:48:51 [IKEv1]: Group = 24.234.3.3, IP = 24.234.3.3, IKE Remote Peer configured for crypto map: VPN
Feb 18 18:48:51 [IKEv1 DEBUG]: Group = 24.234.3.3, IP = 24.234.3.3, processing IPSec SA payload
Feb 18 18:48:51 [IKEv1]: Group = 24.234.3.3, IP = 24.234.3.3, All IPSec SA proposals found unacceptable!
Site to site tunnel debugs aren’t THAT bad, but lots of the more complicated debug problems involve remote access. So, I’m going to set up a router as an Easy VPN server and another as a hardware client. Now we not only have the standard MM/QM messages, but also AG mode, XUATH and IKE MODE stuff to worry about.
In the first example I’m debugging from the client and have don’t a mismatched isakmp policy. Crazily enough the AM goes through and the connection is made. The reason is shown with a show crypto isakmp sa, EZ VPN has a TON of default ike policies and one of these was chosen. The take home message as far as debugs go here is that the ike policy is carried in the AG_INIT_EXCH.
*Feb 18 19:50:19.459: ISAKMP:(0): beginning Aggressive Mode exchange
*Feb 18 19:50:19.459: ISAKMP:(0): sending packet to 24.234.100.3 my_port 500 peer_port 500 (I) AG_INIT_EXCH
*Feb 18 19:50:19.927: ISAKMP:(0):Checking ISAKMP transform 1 against priority 65515 policy
*Feb 18 19:50:19.927: ISAKMP: encryption AES-CBC
*Feb 18 19:50:19.927: ISAKMP: keylength of 128
*Feb 18 19:50:19.927: ISAKMP: hash SHA
*Feb 18 19:50:19.927: ISAKMP: default group 2
*Feb 18 19:50:19.927: ISAKMP: auth XAUTHInitPreShared
*Feb 18 19:50:19.927: ISAKMP: life type in seconds
*Feb 18 19:50:19.927: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Feb 18 19:50:19.927: ISAKMP:(0):atts are acceptable. Next payload is 0
R4#sho crypto isakmp policy
Global IKE policy
Protection suite of priority 5
encryption algorithm: Three key triple DES
hash algorithm: Secure Hash Standard
authentication method: Pre-Shared Key
Diffie-Hellman group: #2 (1024 bit)
lifetime: 86400 seconds, no volume limit
Default protection suite
encryption algorithm: DES - Data Encryption Standard (56 bit keys).
hash algorithm: Secure Hash Standard
authentication method: Rivest-Shamir-Adleman Signature
Diffie-Hellman group: #1 (768 bit)
lifetime: 86400 seconds, no volume limit
EZVPN IKE policy
Protection suite of priority 65515
encryption algorithm: AES - Advanced Encryption Standard (128 bit keys).
hash algorithm: Secure Hash Standard
authentication method:
Diffie-Hellman group: #2 (1024 bit)
lifetime: 2147483 seconds, no volume limit
Next up I have a mismatched username/password in the client configuration. This one is pretty easy, we can see the xauth conversion go on and then:
*Feb 18 19:50:20.303: ISAKMP: XAUTH_STATUS_V2 XAUTH-FAIL
*Feb 18 19:50:20.307: ISAKMP:(1003):deleting SA reason "XAUTH fail" state (I) CONF_XAUTH (peer 24.234.100.3)
When the username and password is corrected, the connection is made. Now, I’m going to correct the username/password and mismatch the ezvpn group’s key. Note that this output is not complete as with the others:
*Feb 18 20:00:18.239: ISAKMP:(0):Checking ISAKMP transform 1 against priority 65515 policy
*Feb 18 20:00:18.239: ISAKMP: encryption AES-CBC
*Feb 18 20:00:18.243: ISAKMP: keylength of 128
*Feb 18 20:00:18.243: ISAKMP: hash SHA
*Feb 18 20:00:18.243: ISAKMP: default group 2
*Feb 18 20:00:18.243: ISAKMP: auth XAUTHInitPreShared
*Feb 18 20:00:18.243: ISAKMP: life type in seconds
*Feb 18 20:00:18.243: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Feb 18 20:00:18.243: ISAKMP:(0):atts are acceptable. Next payload is 0
*Feb 18 20:00:18.291: ISAKMP (0:1004): Unknown Input IKE_MESG_FROM_PEER, IKE_AM_EXCH: state = IKE_I_AM1
*Feb 18 20:00:18.291: ISAKMP:(1004):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
*Feb 18 20:00:18.291: ISAKMP:(1004):Old State = IKE_I_AM1 New State = IKE_I_AM1
*Feb 18 20:00:18.295: %CRYPTO-6-IKMP_MODE_FAILURE: Processing of Aggressive mode failed with peer at 24.234.100.3
*Feb 18 20:00:27.771: ISAKMP:(1004): retransmitting phase 1 AG_INIT_EXCH...
Ok, so here it’s not so clear what is going on by the debugs. We do the AG_INIT_EXCH but get a message back from the peer that isn’t understood. We do see that our state doesn’t change, we’re stuck in IKE_I_AM1 and then AG_INIT_EXCH happens again. To solve this problem you really need to know what goes on in the aggressive mode initial exchange. In the very first packet you send over everything. That means your ike proposals, DH public info, certs or PSKs and so on. If the other side accepts, he sends back a reply with everything needed. The last message is an acknowledgement.
Well, we can see above that the ike proposal was accepted but we never saw xauth, meaning we never finished aggressive mode. That narrows it down quite a bit, and we should find the bad group key in short order.
IP: Logged
|
|
Pushkar Bhatkoti
Brainiac
Member # 23144
Member Rated:
|
posted February 18, 2011 11:18 PM
Nice one steve.
Posts: 860 | From: Sydney/Australia | Registered: Sep 2007
| IP: Logged
|
|
|
UBBFriend: Email this page to someone!
Printer-friendly view of this topic