DMVPN with IPsec generating "IKMP_MODE_FAILURE" on spoke router?

[Lost & Found]

Hi,

I do have a Dmvpn with ipsec profile and it is generating a lot of logs related to %CRYPTO-6-IKMP_MODE_FAILURE Processing of Main mode failed with peer at x.x.x.x (multiple peer ip address) on some of my spoke router. Note, That my connection to hub is stable for more that a week.

From the peer address, I have located that it's another spoke site. Since this is a dmpn it also build a Ipsec tunnel to secure the connection between spoke to spoke right? But is it normal to see this logs though from other sites I cannot see this logs.

CRYPTO-4-IKMP_NO_SA -> Negotiation with the remote peer has failed, so there is a configuration mismatch between local and remote sites. Verify attributes at both sides.

During my testing, I'm able to see that I'm able to reach the spoke 2 LAN from Spoke 1 LAN segment. Does this mean that I'm having issue building the Ipsec or it it required since I still able to connect from spoke 1 to spoke 2.?

Example logs:

Spoke 1:

Trace route:

xxxxxxx#trace <SPOKE 2 LAN> source <SPOKE1 LAN>
1 172.x.x.x [AS x] 156 msec * * <---- HUB
2 172.x.x.x [AS x] 752 msec 764 msec * <---- Spoke 2

xxxxxx#sh crypto isakmp sa | i 112.x.x.x
112.x.x.x 201.x.x.x MM_NO_STATE 2121 ACTIVE (deleted)
112.x.x.x 201.x.x.x MM_NO_STATE 2116 ACTIVE (deleted)

xxxxxx#sh dmvpn | i 112
1 112.x.x.x 172.24.194.54 UP 00:12:37 D <--- Dynamic

Logs:
Feb 17 08:24:13 GMT: %CRYPTO-4-IKMP_NO_SA: IKE message from x.x.x has no SA and is not an initialization offer
Feb 17 08:24:13 GMT: %CRYPTO-6-IKMP_MODE_FAILURE: Processing of Main mode failed with peer at 58.x.x.x
Feb 17 08:25:13 GMT: %CRYPTO-6-IKMP_MODE_FAILURE: Processing of Main mode failed with peer at 112.x.x.x
Feb 17 08:26:13 GMT: %CRYPTO-6-IKMP_MODE_FAILURE: Processing of Main mode failed with peer at 112.x.x.x
Feb 17 08:27:25 GMT: %CRYPTO-6-IKMP_MODE_FAILURE: Processing of Main mode failed with peer at 126.x.x.x

Config:
interface Tun100
bandwidth 2000
<>
no ip redirects
ip mtu 1400
ip pim nbma-mode
ip pim sparse-mode
ip nat outside
ip nhrp group 2M
ip nhrp map multicast xxxxx
ip nhrp map xxx xxxx
ip nhrp network-id 2x
ip nhrp holdtime 500
ip nhrp nhs xxxx
ip nhrp shortcut
ip nhrp redirect
ip virtual-reassembly in
ip tcp adjust-mss 1360
qos pre-classify
tunnel source xxxx
tunnel mode gre multipoint
tunnel key xx
tunnel vrf xxx
tunnel protection ipsec profile xxx shared

Spoke 2:

xxxxx#sh crypto isakmp sa | i x.x.x.x
112.x.x.x 201.x.x.x QM_IDLE 4798 ACTIVE <---- OK?
116.x.x.x 201.x.x.x MM_NO_STATE 4777 ACTIVE (deleted)

Logs:
No logs related to Spoke 1

Thanks

[Georg Pauwen]

Hello,

the log messages ' %CRYPTO-6-IKMP_MODE_FAILURE: Processing of Main mode failed with peer' imply that the phase 1 policy does not match on both sides. Can you post the output of 'show run | inc crypto isakmp' from both sides ?

[Lost & Found]

Hi George, heres the sample config.

Spoke1:

hostnamexxx#show run | inc crypto isakmp
crypto isakmp policy 1
crypto isakmp policy 10
crypto isakmp keepalive 10
crypto isakmp peer address 165.225.110.18 vrf PUBLIC
crypto isakmp peer address 165.225.116.18 vrf PUBLIC
crypto isakmp profile CRYPTO_MT
crypto isakmp profile CRYPTO_GS

hostnamexxx#sh run | sec policy 1
crypto isakmp policy 1
encr aes 256
group 5
!
crypto isakmp policy 10
encr 3des
hash md5
authentication pre-share
group 2
!
hostnamexxx#sh run | sec profile CRYPTO_MT
crypto isakmp profile CRYPTO_MT
vrf PUBLIC
match identity host <rd>.xxx.com PUBLIC
!
hostnamexxx#sh run | sec profile CRYPTO_GS
crypto isakmp profile CRYPTO_GS
vrf PUBLIC
ca trust-point ciscopki
match identity host domain xxx.com
!
crypto ipsec profile CRYPTO_GS
set transform-set TRANS_CRYPTO_GS
set isakmp-profile CRYPTO_GS

Spoke2:

hostnamexxx#show run | inc crypto isakmp
crypto isakmp policy 1
crypto isakmp keepalive 10
crypto isakmp profile CRYPTO_MT
crypto isakmp profile CRYPTO_GS

hostnamexxx#sh run | sec policy 1
crypto isakmp policy 1
encr aes 256
group 5
1
hostnamexxx#sh run | sec profile CRYPTO_MT
crypto isakmp profile CRYPTO_MT
vrf PUBLIC
match identity host <rd>.xxx.com PUBLIC
!
hostnamexxx#sh run | sec profile CRYPTO_GS
crypto isakmp profile CRYPTO_GS
vrf PUBLIC
ca trust-point ciscopki
match identity host domain xxx.com
!
crypto ipsec profile CRYPTO_GS
set transform-set TRANS_CRYPTO_GS
set isakmp-profile CRYPTO_GS

[Lost & Found]

Should all of the spoke site should build an IPsec tunnel in order to communicate. Though, Right now there no major issue. It just this logs %CRYPTO-6-IKMP_MODE_FAILURE:  is continuously generating some logs. 

[Georg Pauwen]

Hello,

your DMVPN does not necessarily need IPSec, but it is highly recommended since you are sending data over the public Internet.

Either way, if you just want to get rid of the message in your syslog, you can configure the below:

logging discriminator CRYPTO_DROP severity drops 6 facility drops CRYPTO mnemonics drops IKMP_MODE_FAILURE

logging buffered discriminator CRYPTO_DROP 100000
logging console discriminator CRYPTO_DROP
logging monitor discriminator CRYPTO_DROP

[Lost & Found]

Hi George, 

Thanks for your response. But I would like to verify why this logs is generated? If there's there failure from another spoke site with Ike phase 1 policy.. means the spoke-to-spoke communication is building an IPsec tunnel?

Another, thing. Why the ipsec on the other spoke 2 is ok while the spoke 1 isakmp is not?

Spoke 1:

xxxxxx#sh crypto isakmp sa | i 112.x.x.x
112.x.x.x 201.x.x.x MM_NO_STATE 2121 ACTIVE (deleted)
112.x.x.x 201.x.x.x MM_NO_STATE 2116 ACTIVE (deleted)

Spoke 2:

xxxxx#sh crypto isakmp sa | i x.x.x.x
112.x.x.x 201.x.x.x QM_IDLE 4798 ACTIVE <---- OK?
116.x.x.x 201.x.x.x MM_NO_STATE 4777 ACTIVE (deleted)

[Georg Pauwen]

Hello,

it is unclear from the information you have provided what you have configured. Post the full running configuration of the hub and the spoke that generates the message...

[Lost & Found]

Here's the sample of the debug output:

Feb 17 13:40:16 GMT: ISAKMP: local port 500, remote port 500
Feb 17 13:40:16 GMT: ISAKMP: set new node 0 to QM_IDLE
Feb 17 13:40:16 GMT: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 8F7D9A54
Feb 17 13:40:16 GMT: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
Feb 17 13:40:16 GMT: ISAKMP:(0):Profile has no keyring, aborting key search
Feb 17 13:40:16 GMT: ISAKMP:(0):Profile has no keyring, aborting host key search
Feb 17 13:40:16 GMT: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
Feb 17 13:40:16 GMT: ISAKMP:(0): constructed NAT-T vendor-07 ID
Feb 17 13:40:16 GMT: ISAKMP:(0): constructed NAT-T vendor-03 ID
Feb 17 13:40:16 GMT: ISAKMP:(0): constructed NAT-T vendor-02 ID
Feb 17 13:40:16 GMT: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
Feb 17 13:40:16 GMT: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1

Feb 17 13:40:16 GMT: ISAKMP:(0): beginning Main Mode exchange
Feb 17 13:40:16 GMT: ISAKMP:(0): sending packet to x.x.x.x my_port 500 peer_port 500 (I) MM_NO_STATE
Feb 17 13:40:16 GMT: ISAKMP:(0):Sending an IKE IPv4 Packet.
Feb 17 13:40:16 GMT: ISAKMP (0): received packet from x.x.x.x dport 500 sport 500 INTERNET (I) MM_NO_STATE
Feb 17 13:40:16 GMT: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Feb 17 13:40:16 GMT: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2

Feb 17 13:40:16 GMT: ISAKMP:(0): processing SA payload. message ID = 0
Feb 17 13:40:16 GMT: ISAKMP:(0): processing vendor id payload
Feb 17 13:40:16 GMT: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Feb 17 13:40:16 GMT: ISAKMP (0): vendor ID is NAT-T RFC 3947
Feb 17 13:40:16 GMT: ISAKMP:(0):Profile has no keyring, aborting key search
Feb 17 13:40:16 GMT: ISAKMP:(0):Profile has no keyring, aborting host key search
Feb 17 13:40:16 GMT: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy
Feb 17 13:40:16 GMT: ISAKMP: encryption AES-CBC
Feb 17 13:40:16 GMT: ISAKMP: keylength of 256
Feb 17 13:40:16 GMT: ISAKMP: hash SHA
Feb 17 13:40:16 GMT: ISAKMP: default group 5
Feb 17 13:40:16 GMT: ISAKMP: auth RSA sig
Feb 17 13:40:16 GMT: ISAKMP: life type in seconds
Feb 17 13:40:16 GMT: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80
Feb 17 13:40:16 GMT: ISAKMP:(0):atts are acceptable. Next payload is 0
Feb 17 13:40:16 GMT: ISAKMP:(0):Acceptable atts:actual life: 0
Feb 17 13:40:16 GMT: ISAKMP:(0):Acceptable atts:life: 0
Feb 17 13:40:16 GMT: ISAKMP:(0):Fill atts in sa vpi_length:4
Feb 17 13:40:16 GMT: ISAKMP:(0):Fill atts in sa life_in_seconds:86400
Feb 17 13:40:16 GMT: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0):Returning Actual lifetime: 86400
Feb 17 13:40:16 GMT: ISAKMP:(0)::Started lifetime timer: 86400.

Feb 17 13:40:16 GMT: ISAKMP:(0): processing vendor id payload
Feb 17 13:40:16 GMT: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Feb 17 13:40:16 GMT: ISAKMP (0): vendor ID is NAT-T RFC 3947
Feb 17 13:40:16 GMT: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Feb 17 13:40:16 GMT: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2

Feb 17 13:40:16 GMT: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP (0): constructing CERT_REQ for issuer cn=j201rc04
Feb 17 13:40:16 GMT: ISAKMP:(0): sending packet to x.x.x.x my_port 500 peer_port 500 (I) MM_SA_SETUP
Feb 17 13:40:16 GMT: ISAKMP:(0):Sending an IKE IPv4 Packet.
Feb 17 13:40:16 GMT: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Feb 17 13:40:16 GMT: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3

Feb 17 13:40:16 GMT: ISAKMP (0): received packet from x.x.x.x dport 500 sport 500 INTERNET (I) MM_SA_SETUP
Feb 17 13:40:16 GMT: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Feb 17 13:40:16 GMT: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4

Feb 17 13:40:16 GMT: ISAKMP:(0): processing KE payload. message ID = 0
Feb 17 13:40:16 GMT: ISAKMP:(0): processing NONCE payload. message ID = 0
Feb 17 13:40:16 GMT: ISAKMP:(2015): processing vendor id payload
Feb 17 13:40:16 GMT: ISAKMP:(2015): vendor ID is Unity
Feb 17 13:40:16 GMT: ISAKMP:(2015): processing vendor id payload
Feb 17 13:40:16 GMT: ISAKMP:(2015): vendor ID is DPD
Feb 17 13:40:16 GMT: ISAKMP:(2015): processing vendor id payload
Feb 17 13:40:16 GMT: ISAKMP:(2015): speaking to another IOS box!
Feb 17 13:40:16 GMT: ISAKMP:received payload type 20
Feb 17 13:40:16 GMT: ISAKMP (2015): His hash no match - this node outside NAT
Feb 17 13:40:16 GMT: ISAKMP:received payload type 20
Feb 17 13:40:16 GMT: ISAKMP (2015): No NAT Found for self or peer
Feb 17 13:40:16 GMT: ISAKMP:(2015):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Feb 17 13:40:16 GMT: ISAKMP:(2015):Old State = IKE_I_MM4 New State = IKE_I_MM4

Feb 17 13:40:16 GMT: ISAKMP:(2015):Send initial contact
Feb 17 13:40:16 GMT: ISAKMP:(2015): processing CERT_REQ payload.
Feb 17 13:40:16 GMT: ISAKMP:(2015): peer wants a CT_X509_SIGNATURE cert
Feb 17 13:40:16 GMT: ISAKMP:(2015): peer wants cert issued by cn=j201rc04
Feb 17 13:40:16 GMT: ISAKMP:(2015): processing CERT_REQ payload.
Feb 17 13:40:16 GMT: ISAKMP:(2015): peer wants a CT_X509_SIGNATURE cert
Feb 17 13:40:16 GMT: ISAKMP:(2015): peer wants cert issued by cn=cvo-sdp-pki
Feb 17 13:40:16 GMT: ISAKMP:(2015): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(2015): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(2015): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(2015): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(2015):My ID configured as IPv4 Addr, but Addr not in Cert!
Feb 17 13:40:16 GMT: ISAKMP:(2015):Using FQDN as My ID
Feb 17 13:40:16 GMT: ISAKMP:(2015):SA is doing RSA signature authentication using id type ID_FQDN
Feb 17 13:40:16 GMT: ISAKMP (2015): ID payload
next-payload : 6
type : 2
FQDN name : hostnamexxx
protocol : 17
port : 500
length : 22
Feb 17 13:40:16 GMT: ISAKMP:(2015):Total payload length: 22
Feb 17 13:40:16 GMT: ISAKMP:(2015): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP:(2015): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer x.x.x.x)
Feb 17 13:40:16 GMT: ISAKMP (2015): constructing CERT payload for hostname=joco-pa8897rz1.jci.com,cn=a8897r01
Feb 17 13:40:16 GMT: ISAKMP:(2015): using the IOSPKI trustpoint's keypair to sign
Feb 17 13:40:16 GMT: ISAKMP:(2015): sending packet to x.x.x.x my_port 500 peer_port 500 (I) MM_KEY_EXCH
Feb 17 13:40:16 GMT: ISAKMP:(2015):Sending an IKE IPv4 Packet.
Feb 17 13:40:16 GMT: ISAKMP:(2015):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Feb 17 13:40:16 GMT: ISAKMP:(2015):Old State = IKE_I_MM4 New State = IKE_I_MM5

Feb 17 13:40:17 GMT: ISAKMP (2012): received packet from x.x.x.x dport 500 sport 500 INTERNET (I) MM_NO_STATE
Feb 17 13:40:17 GMT: ISAKMP:(2008):purging SA., sa=8F28E6D0, delme=8F28E6D0
Feb 17 13:40:17 GMT: ISAKMP (2015): received packet from x.x.x.x dport 500 sport 500 INTERNET (I) MM_KEY_EXCH
Feb 17 13:40:17 GMT: ISAKMP:(2015): processing ID payload. message ID = 0
Feb 17 13:40:17 GMT: ISAKMP (2015): ID payload
next-payload : 6
type : 2
FQDN name : hostnamexxx
protocol : 17
port : 500
length : 22
Feb 17 13:40:17 GMT: ISAKMP:(2015):Expected CRYPTO_GS profile doesn't match, aborting exchange
Feb 17 13:40:17 GMT: ISAKMP (2015): FSM action returned error: 2
Feb 17 13:40:17 GMT: ISAKMP:(2015):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Feb 17 13:40:17 GMT: ISAKMP:(2015):Old State = IKE_I_MM5 New State = IKE_I_MM6

hostnamexxx#
Feb 17 13:40:17 GMT: %CRYPTO-6-IKMP_MODE_FAILURE: Processing of Main mode failed with peer at x.x.x.x
Feb 17 13:40:17 GMT: ISAKMP:(2015):peer does not do paranoid keepalives.

Feb 17 13:40:17 GMT: ISAKMP:(2015):deleting SA reason "IKMP_ERR_NO_RETRANS" state (I) MM_KEY_EXCH (peer x.x.x.x)
Feb 17 13:40:17 GMT: ISAKMP:(2015):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Feb 17 13:40:17 GMT: ISAKMP:(2015):Old State = IKE_I_MM6 New State = IKE_I_MM6

Feb 17 13:40:17 GMT: ISAKMP:(2015):peer does not do paranoid keepalives.

Feb 17 13:40:17 GMT: ISAKMP (2015): FSM action returned error: 2
Feb 17 13:40:17 GMT: ISAKMP:(2015):Input = IKE_MESG_INTERNAL, IKE_PROCESS_ERROR
Feb 17 13:40:17 GMT: ISAKMP:(2015):Old State = IKE_I_MM6 New State = IKE_I_MM5

Feb 17 13:40:17 GMT: ISAKMP:(2015):deleting SA reason "IKMP_ERR_NO_RETRANS" state (I) MM_KEY_EXCH (peer x.x.x.x)
Feb 17 13:40:17 GMT: ISAKMP:(2015):deleting node 1239526262 error FALSE reason "IKE deleted"
Feb 17 13:40:17 GMT: ISAKMP:(2015): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer x.x.x.x)
Feb 17 13:40:17 GMT: ISAKMP:(2015): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer x.x.x.x)
Feb 17 13:40:17 GMT: ISAKMP:(2015):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Feb 17 13:40:17 GMT: ISAKMP:(2015):Old State = IKE_I_MM5 New State = IKE_DEST_SA

[Georg Pauwen]

Hello,

post the full running configurations (sh run) of both the hub and the spoke. The debug output indicates that the IPSec profile CRYPTO_GS does not match...