Posts Tagged ‘Troubleshooting’

MM_WAIT_MSG4 is the stage where the firewall that initiated the tunnel is sending its pre-shared key hash to the receiver. This is NOT the stage that actually checks to see if the pre-shared keys match, it only exchanges the hashes for them.

The Initiator will stay at MSG4 until it gets a PSK back from its peer. If the receiver is missing a tunnel group or PSK the initiator will stay at MM_WAIT_MSG4

If the tunnel has to pass through a firewall to reach both end points you might have problems with the way traffic is passed through that middle firewall.

The tunnel can sometimes get stuck here due to incompatible vendor types. Try to get both devices on a modern version of software to try to eliminate any vendor mismatch issues.

This can sometimes fail due to mismatched ASA versions (rare).

Recently I had this problem pop up and I wanted to deconstruct the debug message leading up to the problem

! — Tunnel initiated - OK lets go!
Jun 10 2010 17:36:05: %ASA-7-715077: Pitcher: received a key acquire message, spi 0×0
Jun 10 2010 17:36:05: %ASA-5-713041: IP = 233.22.22.233, IKE Initiator: New Phase 1, Intf Inside_Network, IKE Peer 233.22.22.233  local Proxy Address 192.168.245.120, remote Proxy Address 10.3.10.122,  Crypto map (MAP-VPN)
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing ISAKMP SA payload
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing NAT-Traversal VID ver 02 payload
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing NAT-Traversal VID ver 03 payload
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing Fragmentation VID + extended capabilities payload
Jun 10 2010 17:36:05: %ASA-7-713236: IP = 233.22.22.233, IKE_DECODE SENDING Message (msgid=0) with payloads : HDR + SA (1) + VENDOR (13) + VENDOR (13) + VENDOR (13) + NONE (0) total length : 148
Jun 10 2010 17:36:05: %ASA-7-713236: IP = 233.22.22.233, IKE_DECODE RECEIVED Message (msgid=0) with payloads : HDR + SA (1) + VENDOR (13) + NONE (0) total length : 108
Jun 10 2010 17:36:05: %ASA-7-715047: IP = 233.22.22.233, processing SA payload
Jun 10 2010 17:36:05: %ASA-7-713906: IP = 233.22.22.233, Oakley proposal is acceptable
! — At this point the firewall’s have agreed on the same ISAKMP proposals
Jun 10 2010 17:36:05: %ASA-7-715047: IP = 233.22.22.233, processing VID payload
Jun 10 2010 17:36:05: %ASA-7-715049: IP = 233.22.22.233, Received Fragmentation VID
Jun 10 2010 17:36:05: %ASA-7-715064: IP = 233.22.22.233, IKE Peer included IKE fragmentation capability flags:  Main Mode:        True  Aggressive Mode:True
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing ke payload
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing nonce payload
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing Cisco Unity VID payload
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing xauth V6 VID payload
Jun 10 2010 17:36:05: %ASA-7-715048: IP = 233.22.22.233, Send IOS VID
Jun 10 2010 17:36:05: %ASA-7-715038: IP = 233.22.22.233, Constructing ASA spoofing IOS Vendor ID payload (version: 1.0.0, capabilities: 20000001)
Jun 10 2010 17:36:05: %ASA-7-715046: IP = 233.22.22.233, constructing VID payload
Jun 10 2010 17:36:05: %ASA-7-715048: IP = 233.22.22.233, Send Altiga/Cisco VPN3000/Cisco ASA GW VID
Jun 10 2010 17:36:05: %ASA-7-713236: IP = 233.22.22.233, IKE_DECODE SENDING Message (msgid=0) with payloads : HDR + KE (4) + NONCE (10) + VENDOR (13) + VENDOR (13) + VENDOR (13) + VENDOR (13) + NONE (0) total length : 256

! — All the syslogs above happened in the same second. All of a sudden things slowed down. 5 seconds passed which made me concerned already.

Jun 10 2010 17:36:10: %ASA-7-715077: Pitcher: received a key acquire message, spi 0×0
! — Wait, what? A new key acquire message, this isn’t right…
Jun 10 2010 17:36:10: %ASA-6-713219: IP = 233.22.22.233, Queuing KEY-ACQUIRE messages to be processed when P1 SA is complete.
Jun 10 2010 17:36:13: %ASA-7-713236: IP = 233.22.22.233, IKE_DECODE RESENDING Message (msgid=0) with payloads : HDR + KE (4) + NONCE (10) + VENDOR (13) + VENDOR (13) + VENDOR (13) + VENDOR (13) + NONE (0) total length : 256
! — Resending the payload? That’s not a good sign…
Jun 10 2010 17:36:13: %ASA-7-713236: IP = 233.22.22.233, IKE_DECODE RECEIVED Message (msgid=0) with payloads : HDR + NOTIFY (11) + NONE (0) total length :68
Jun 10 2010 17:36:13: %ASA-7-713236: IP = 233.22.22.233, IKE_DECODE RECEIVED Message (msgid=0) with payloads : HDR + NOTIFY (11) + NONE (0) total length :68
Jun 10 2010 17:36:13: %ASA-5-713904: IP = 233.22.22.233, Received an un-encrypted INVALID_COOKIE notify message, dropping
! — un-encrypted cookie? Why did the other side send us an un-encrypted packet? Could it be because the other side doesn’t have any information for this peer??
Jun 10 2010 17:36:13: %ASA-4-713903: IP = 233.22.22.233, Information Exchange processing failed
Jun 10 17:36:13 [IKEv1]: IP = 233.22.22.233, Information Exchange processing failed

The ultimate reason why this tunnel didn’t form is because the other side had the wrong Peer IP defined for the tunnel-group/pre-shared key. So when this side sent its isakmp proposals the other side only checked if it had a crypto map statement for this peer, it didn’t check if it had a tunnel-group defined. When they tried to exchange the pre-shared keys the remote end realized it doesn’t have any pre-shared key for this peer and just stopped responding. When this side tried to send another packet the remote end sent some cookie over which of course was not encrypted because it doesn’t have the right peer IP to do the encryption with. The debugs above are from an ASA 8.0.4 code connecting to a Cisco VPN concentrator running unknown code.

I have found this page to be handy from time to time:

http://www.cisco.com/en/US/products/ps6120/products_tech_note09186a00807e0aca.shtml

ISAKMP (IKE Phase 1) Negotiations States

The MM_WAIT_MSG state can be an excellent clue into why a tunnel is not forming. If your firewall is hanging at a specific state review this graph below to find where along the path the VPN is failing.

Graph source: tunnelsup.com

 

These are the possible ISAKMP negotiation states on an ASA firewall. ISAKMP stands for: The Internet Security Association and Key Management Protocol

ASA ISAKMP STATES

• MM_WAIT_MSG2 Initiator
  Initial DH public key sent to responder. Awaiting initial contact reply from other side.
  Initiator sends encr/hash/dh ike policy details to create initial contact. Initiator will wait at MM_WAIT_MSG2 until it hears back from its peer. If stuck here it usually means the other end is not responding. This could be due to no route to the far end or the far end does not have ISAKMP enabled on the outside or the far end is down.

• MM_WAIT_MSG3 Receiver
  Receiver is sending back its IKE policy to the initiator.
  Initiator sends encr/hash/dh ike policy details to create initial contact. Initiator will wait at MM_WAIT_MSG2 until it hears back from its peer. Hang ups here may also be due to mismatch device vendors, a router with a firewall in the way, or even ASA version mismatches.

• MM_WAIT_MSG4 Initiator
  Initiator is sending the Pre-Shared-Key hash to its peer.
  Initiator sends a hash of its PSK. Initiator will stay at MSG4 until it gets a PSK back from its peer. If the receiver is missing a tunnel group or PSK the initiator will stay at MM_WAIT_MSG4
  

• MM_WAIT_MSG5 Receiver
  Receiver is sending its PSK hash to its peer.
  Receiver does not yet check if PSK hashes match. If receiver has a tunnel-group and PSK configured for this peer it will send the PSK hash to the peer. If PSKs don’t match, receiver will stay at MM_WAIT_MSG5. I have also seen the tunnel stop here when NAT-T was on when it needed to be turned off.
  

• MM_WAIT_MSG6 Initiator
  Initiator checks if PSK hashes match.
  If PSK keys match, Initiator becomes MM_ACTIVE and lets receiver know of match. If PSK doesn’t match, initiator stays at MM_WAIT_MSG6. I have also seen the tunnel stop here when NAT-T was on when it needed to be turned off.
  However, if the state goes to MSG6 then the ISAKMP gets reset that means phase 1 finished but phase 2 failed. Check that IPSEC settings match in phase 2 to get the tunnel to stay at MM_ACTIVE.

• AM_ACTIVE / MM_ACTIVE
  The ISAKMP negotiations are complete. Phase 1 has successfully completed.

PIX ISAKMP STATES

• MM_NO_STATE

ISAKMP SA has been created but nothing else has happened yet.

• MM_SA_SETUP

The peers have agreed on parameters for the ISAKMP SA.

• MM_KEY_EXCH

The peers have exchanged Diffie-Hellman public keys and have generated a shared secret. The I SAKMP SA remains unauthenticated.

• MM_KEY_AUTH

The ISAKMP SA has been authenticated. If the router initiated this exchange, this state trans itions immediately to QM_IDLE and a Quick mode exchange begins.

• AG_NO_STATE

The ISAKMP SA has been created but nothing else has happened yet.

• AG_INIT_EXCH

The peers have done the first exchange in Aggressive mode but the SA is not authenticated.

• AG_AUTH

The ISAKMP SA has been authenticated. If the router initiated this exchange, this state transitions immediately to QM_IDLE and a Quick mode exchange begins.

• QM_IDLE

The ISAKMP negotiations are complete. Phase 1 successfully completed. It remains authenticated with its peer and may be used for subsequent Quick mode exchanges.

 

But what is the difference between MM and AM?

Main mode vs Aggressive mode. Here is a image taken from Cisco’s website to show the difference.

As you can see the Main mode is the same as the flowchart at the top of the page. Aggressive mode only uses 4 steps to establish the tunnel.

 

Errors With ISAKMP Or Phase 1 Establishing

A very common problem is phase 1 not establishing correctly.

• Verify ISAKMP parameters match exactly.
• Verify pre-shared-keys match exactly.
• Check that each side has a route to the peer address that you are trying to form a tunnel with.
• Verify ISAKMP is enabled on the outside interfaces.
• Is ESP traffic permitted in through the outside interface?
• Is UDP port 500 open on the outside ACL?
• Some situations require that UDP port 4500 is open for the outside.

Debugs And Show Commands

To gain more info on where the problem might be, try these show commands and debugs.

• show crypto isakmp sa

Showing status of ISAKMP negotiations

• show crypto ipsec sa [peer 1.1.1.1]

Show status of IPSEC tunnels

• show log
• debug crypto isakmp
• debug crypto ipsec
• debug crypto condition peer 1.1.1.1

Knowing where to look for problems

VPN problems are usually very easy to fix once you know where the problem is at. Understand that VPN tunnels are a multi-step process. Knowing this you should be able to step through the tunnel being built to find where it got hung up at and stopped working.

• Tunnel isn’t even trying to start

ISAKMP/IPSEC isn’t enabled or applied to an interface. VPN ACL isn’t catching any interesting traffic to fire up the tunnel. Routes/NAT’s are misdirecting traffic out the wrong interface.

• ISAKMP Phase 1 doesn’t complete all the way.

There are lots of reasons why ISAKMP Phase 1 won’t fully establish. Look over some of the common reasons here.

• Phase 1 establishes but Phase 2 doesn’t fully establish

It is possible that the Phase 2 IPSEC attributes don’t match but this usually indicates a malformed Phase 1.

• Phase 1 and 2 establish but traffic still isn’t getting there

Remember, the VPN tunnel is just in charge of getting the secure line open. Networking rules still apply. Check routes/ACL’s/NAT’s etc.