L2L VPN negotiations fail from remote end

Jouni Forss · ‎06-01-2011

Hi,

We have a problem with an excisting L2L VPN connection.

The connection has to this day served only connections originating in one direction. Meaning only one end initiates the connections. This has worked normally so far. Now the third party behind the L2L VPN also wants to access some recourses trough the L2L VPN and because of that also initiates the connections.

This is where we face our problem.

For some reason the remote end cant bring up the L2L VPN where as we can (and the second party in our end ofcourse)

The connection was originally on a Cisco 6509 WS-SVC-IPSEC-1 module

For the tests in new equipment we moved the connection to a Cisco 7609 with SPA-IPSEC-2G module

The remote end uses Checkpoint FW1 R70 (or something like that. I'm not familiar with Checkpoints)

With both equipment the problem remains.

We did the tests today and i took some debug messages on our end with "debug crypto isakmp" and "debug crypto isakmp error" enabled. I also enable the "debug crypto condition peer ipv4 x.x.x.x" for the debugs as there are several other connections on the same device.

This is what the debug shows (Remote end IP replaced with x.x.x.x):

Jun 1 2011 07:20:58.062 UTC: ISAKMP: local port 500, remote port 500
Jun 1 2011 07:20:58.062 UTC: insert sa successfully sa = 207E7B00
Jun 1 2011 07:20:58.062 UTC: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jun 1 2011 07:20:58.062 UTC: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_MM1

Jun 1 2011 07:20:58.062 UTC: ISAKMP:(0): processing SA payload. message ID = 0
Jun 1 2011 07:20:58.062 UTC: ISAKMP:(0): processing vendor id payload
Jun 1 2011 07:20:58.062 UTC: ISAKMP:(0): vendor ID seems Unity/DPD but major 175 mismatch
Jun 1 2011 07:20:58.062 UTC: ISAKMP:(0):found peer pre-shared key matching x.x.x.x
Jun 1 2011 07:20:58.062 UTC: ISAKMP:(0): local preshared key found
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0): Authentication by xauth preshared
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      encryption 3DES-CBC
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      hash SHA
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      auth pre-share
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      default group 2
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      life type in seconds
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      life duration (VPI) of 0x0 0x0 0x70 0x80
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):Encryption algorithm offered does not match policy!
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):atts are not acceptable. Next payload is 0
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):Checking ISAKMP transform 1 against priority 2 policy
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      encryption 3DES-CBC
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      hash SHA
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      auth pre-share
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      default group 2
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      life type in seconds
Jun 1 2011 07:20:58.066 UTC: ISAKMP:      life duration (VPI) of 0x0 0x0 0x70 0x80
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):atts are acceptable. Next payload is 0
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0): processing vendor id payload
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0): vendor ID seems Unity/DPD but major 175 mismatch
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM1

Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0): sending packet to x.x.x.x my_port 500 peer_port 500 (R) MM_SA_SETUP
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Jun 1 2011 07:20:58.066 UTC: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM2

Jun 1 2011 07:20:58.082 UTC: ISAKMP (0): received packet from x.x.x.x dport 500 sport 500 Global (R) MM_SA_SETUP
Jun 1 2011 07:20:58.082 UTC: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jun 1 2011 07:20:58.082 UTC: ISAKMP:(0):Old State = IKE_R_MM2 New State = IKE_R_MM3

Jun 1 2011 07:20:58.082 UTC: ISAKMP:(0): processing KE payload. message ID = 0
Jun 1 2011 07:20:58.082 UTC: ISAKMP:(0): processing NONCE payload. message ID = 0
Jun 1 2011 07:20:58.082 UTC: ISAKMP:(0):found peer pre-shared key matching x.x.x.x
Jun 1 2011 07:20:58.082 UTC: ISAKMP:(78418):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jun 1 2011 07:20:58.082 UTC: ISAKMP:(78418):Old State = IKE_R_MM3 New State = IKE_R_MM3

Jun 1 2011 07:20:58.086 UTC: ISAKMP:(78418): sending packet to x.x.x.x my_port 500 peer_port 500 (R) MM_KEY_EXCH
Jun 1 2011 07:20:58.086 UTC: ISAKMP:(78418):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Jun 1 2011 07:20:58.086 UTC: ISAKMP:(78418):Old State = IKE_R_MM3 New State = IKE_R_MM4

Jun 1 2011 07:20:58.102 UTC: ISAKMP (78418): received packet from x.x.x.x dport 500 sport 500 Global (R) MM_KEY_EXCH
Jun 1 2011 07:20:58.102 UTC: %CRYPTO-4-IKMP_BAD_MESSAGE: IKE message from x.x.x.x failed its sanity check or is malformed
Jun 1 2011 07:20:58.102 UTC: ISAKMP (0:78418): incrementing error counter on sa, attempt 1 of 5: PAYLOAD_MALFORMED
Jun 1 2011 07:20:58.102 UTC: ISAKMP:(78418): sending packet to x.x.x.x my_port 500 peer_port 500 (R) MM_KEY_EXCH
Jun 1 2011 07:20:58.102 UTC: ISAKMP (0:78418): incrementing error counter on sa, attempt 2 of 5: reset_retransmission
Jun 1 2011 07:20:59.118 UTC: ISAKMP:(78418): retransmitting phase 1 MM_KEY_EXCH...
Jun 1 2011 07:20:59.118 UTC: ISAKMP (0:78418): incrementing error counter on sa, attempt 3 of 5: retransmit phase 1
Jun 1 2011 07:20:59.118 UTC: ISAKMP:(78418): no outgoing phase 1 packet to retransmit. MM_KEY_EXCH
Jun 1 2011 07:20:59.118 UTC: ISAKMP:(78418):peer does not do paranoid keepalives.

Jun 1 2011 07:20:59.118 UTC: ISAKMP:(78418):deleting SA reason "Death by retransmission P1" state (R) MM_KEY_EXCH (peer x.x.x.x)
Jun 1 2011 07:20:59.118 UTC: ISAKMP:(78418):deleting SA reason "Death by retransmission P1" state (R) MM_KEY_EXCH (peer x.x.x.x)
Jun 1 2011 07:20:59.118 UTC: ISAKMP:(78418):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Jun 1 2011 07:20:59.118 UTC: ISAKMP:(78418):Old State = IKE_R_MM4 New State = IKE_DEST_SA

To my eye it seems that the attributes/parameters for Phase 1 are ok on both ends (have to be since the connection forms normally when the traffic is initiated from our side) but somewhere along the way the negotiations stop because our end gets a malformed packet during the negotiations? Does this mean the remote end is somehow faulty? Is there some compatibility problem with the VPN devices in question? or its the sign of some known problem with VPN connections?

So far I have not found any explanation to what is causing this.

Any help would be greatly appriciated. If you need any additional information, please ask.

- Jouni

Istvan Matyasovszki · ‎06-02-2011

Hi Jouni,

The first thing that comes to mind when seeing the debugs you've collected is that

the pre-shared keys are mismatched. 

As based on your description the issue only manifests itself
when the IKE Phase 1 is initiated by the remote peer, i wold say
the pre-shared key to peer IP address mappings were not correctly
defined. So the first thing I'd try is removing the relevant 
pre-shared keys and then add them back making sure the peer IPs
are correctly mapped to them. 

When adding back the keys, add the clear text form not the encrypted one,
let the local subsystem encrypt the keys.

Hope this helps

Istvan

Jouni Forss · ‎06-08-2011

Hi,

It doesnt seem to be about the PSK as we could initiate the VPN connection from our end on both VPN platforms we have. I dont think it should go up at all if the PSK dont match?

Also we changed the PSK to a very simple one while testing and it didnt change the situation and debug in anyway whatsoever. Also we changed it back to the original which also didnt change anything.

To me this seems more like some problem with the VPN devices in question or they have just configured it wrong somehow on their end. We have never had same kind of problem during the 3 years I've worked in the local ISP.

Were going to try changing the networks configured in the encryption domain as they seem really strange when the connection is active. I mean when our end user has brought up the L2L VPN and the remote also initiates connections, I can see with the "show crypto session remote " command 2 connections listed? Even though I guess I should only see 1 connection and several SAs?

fgasimzade · ‎06-08-2011

It can probably be different IPSEC implementation, I am not sure though, try upgrading your IOS

ronaldo.luciano · ‎11-11-2016

Hi Jouni Forss,

Do you happen to find the solution to this? We are experiencing exact same issue on one of our VPN connection.

Istvan Matyasovszki · ‎06-08-2011

Hi,

In my message, i was actually pointing to pre-shared key to peer IP address mappings.

So if we look at the Phase 1 negotiation the sequence of events is this :

1) We send our pre-shared key

Jun 1 2011 07:20:58.082 UTC: ISAKMP:(0):found peer pre-shared key matching x.x.x.x
Jun 1 2011 07:20:58.082 UTC: ISAKMP:(78418):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jun 1 2011 07:20:58.082 UTC: ISAKMP:(78418):Old State = IKE_R_MM3 New State = IKE_R_MM3

Jun 1 2011 07:20:58.086 UTC: ISAKMP:(78418): sending packet to x.x.x.x my_port 500 peer_port 500 (R) MM_KEY_EXCH

2) We receive the peer's pre shared key and the IKE state machine throws and error regarding the

received message.

Jun 1 2011 07:20:58.102 UTC: ISAKMP (78418): received packet from x.x.x.x dport 500 sport 500 Global (R) MM_KEY_EXCH

Jun 1 2011 07:20:58.102 UTC: %CRYPTO-4-IKMP_BAD_MESSAGE: IKE message from x.x.x.x failed its sanity check or is malformed

If it has been validated that the pre-shared key to peer IP mappings are fine then the interpretation is that

the message itself is corrupted. So basically the process that checks component payload types and the sum

of the individual lengths on the received message, fails.

3). Then, we retransmit our key two more times :

Jun 1 2011 07:20:58.102 UTC: ISAKMP (0:78418): incrementing error counter on sa, attempt 1 of 5: PAYLOAD_MALFORMED

Jun 1 2011 07:20:58.102 UTC: ISAKMP:(78418): sending packet to x.x.x.x my_port 500 peer_port 500 (R) MM_KEY_EXCH

Jun 1 2011 07:20:58.102 UTC: ISAKMP (0:78418): incrementing error counter on sa, attempt 2 of 5: reset_retransmission

Jun 1 2011 07:20:59.118 UTC: ISAKMP:(78418): retransmitting phase 1 MM_KEY_EXCH...

Jun 1 2011 07:20:59.118 UTC: ISAKMP (0:78418): incrementing error counter on sa, attempt 3 of 5: retransmit phase 1

And there seems to be nothing coming back from the peer.

Could you please share your ipsec configuration from the 7609 ? Are you running crypto connect or vrf mode ?

Istvan

Alejandro Aceituno canal · ‎06-09-2015

Check your configuration. You will have an isakmp profile under the tunnel configuration with the right isakmp configuration, match identity and keyring psk key. But you will have in the router configuration an unused isakmp profile, with the same match id but a wrong keyring and wrong psk key. This unused isakmp profile will be before in your router configuration.

For inbound connections, IOS looks for a matching isakmp profile, but this may not be that configured under the tunnel interface. This looks for a match id in the isakmp profiles in the same order these are in the configuration. Dont match the incoming traffic with the tunnel and the isakmp profile based on the source ip address and the tunnel destination ip address. This is why if the same peer id is in several isakmp profiles this may match on a wrong configuration.

For outbound, this use always the isakmp profile configured under the tunnel interface. So will use always the right configuration.

This is why this works on outbound, but dont works on inbound.

Br

Alex.