Symptom:
Recently, I were troubleshooting a IPSec VPN using Certificate issue. One IPSec VPN router got rebooted then IPSec tunnel was not able to be re-build. It tested fine with pre-share key. But when change back to certificate, ISAKMP authentication failure with ‘signature invalid‘ error.
Dec 12 21:44:33.558: ISAKMP (0): received packet from 3.1.1.1 dport 500 sport 500 Global (N) NEW SA
Dec 12 21:44:33.558: ISAKMP: Created a peer struct for 3.1.1.1, peer port 500
Dec 12 21:44:33.558: ISAKMP: New peer created peer = 0x28677D80 peer_handle = 0x80000008
Dec 12 21:44:33.558: ISAKMP: Locking peer struct 0x28677D80, refcount 1 for crypto_isakmp_process_block
Dec 12 21:44:33.558: ISAKMP: local port 500, remote port 500
Dec 12 21:44:33.558: ISAKMP:(0):insert sa successfully sa = 295FC4D0
Dec 12 21:44:33.558: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Dec 12 21:44:33.558: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_MM1
Dec 12 21:44:33.558: ISAKMP:(0): processing SA payload. message ID = 0
Dec 12 21:44:33.558: ISAKMP:(0): processing vendor id payload
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Dec 12 21:44:33.558: ISAKMP (0): vendor ID is NAT-T RFC 3947
Dec 12 21:44:33.558: ISAKMP:(0): processing vendor id payload
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch
Dec 12 21:44:33.558: ISAKMP (0): vendor ID is NAT-T v7
Dec 12 21:44:33.558: ISAKMP:(0): processing vendor id payload
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID is NAT-T v3
Dec 12 21:44:33.558: ISAKMP:(0): processing vendor id payload
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID is NAT-T v2
Dec 12 21:44:33.558: ISAKMP:(0):found peer pre-shared key matching 3.1.1.1
Dec 12 21:44:33.558: ISAKMP:(0): local preshared key found
Dec 12 21:44:33.558: ISAKMP : Scanning profiles for xauth …
Dec 12 21:44:33.558: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (R) MM_NO_STATE (peer 3.1.1.1)
Dec 12 21:44:33.558: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (R) MM_NO_STATE (peer 3.1.1.1)
Dec 12 21:44:33.558: ISAKMP:(0):Checking ISAKMP transform 1 against priority 5 policy
Dec 12 21:44:33.558: ISAKMP: encryption 3DES-CBC
Dec 12 21:44:33.558: ISAKMP: hash MD5
Dec 12 21:44:33.558: ISAKMP: default group 2
Dec 12 21:44:33.558: ISAKMP: auth RSA sig
Dec 12 21:44:33.558: ISAKMP: life type in seconds
Dec 12 21:44:33.558: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80
Dec 12 21:44:33.558: ISAKMP:(0):atts are acceptable. Next payload is 3
Dec 12 21:44:33.558: ISAKMP:(0):Acceptable atts:actual life: 0
Dec 12 21:44:33.558: ISAKMP:(0):Acceptable atts:life: 0
Dec 12 21:44:33.558: ISAKMP:(0):Fill atts in sa vpi_length:4
Dec 12 21:44:33.558: ISAKMP:(0):Fill atts in sa life_in_seconds:86400
Dec 12 21:44:33.558: ISAKMP:(0): IKE->PKI Start PKI Session state (R) MM_NO_STATE (peer 3.1.1.1)
Dec 12 21:44:33.558: ISAKMP:(0): PKI->IKE Started PKI Session state (R) MM_NO_STATE (peer 3.1.1.1)
Dec 12 21:44:33.558: ISAKMP:(0):Returning Actual lifetime: 86400
Dec 12 21:44:33.558: ISAKMP:(0)::Started lifetime timer: 86400.
Dec 12 21:44:33.558: ISAKMP:(0): processing vendor id payload
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Dec 12 21:44:33.558: ISAKMP (0): vendor ID is NAT-T RFC 3947
Dec 12 21:44:33.558: ISAKMP:(0): processing vendor id payload
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch
Dec 12 21:44:33.558: ISAKMP (0): vendor ID is NAT-T v7
Dec 12 21:44:33.558: ISAKMP:(0): processing vendor id payload
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID is NAT-T v3
Dec 12 21:44:33.558: ISAKMP:(0): processing vendor id payload
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
Dec 12 21:44:33.558: ISAKMP:(0): vendor ID is NAT-T v2
Dec 12 21:44:33.558: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Dec 12 21:44:33.558: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM1
Dec 12 21:44:33.562: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
Dec 12 21:44:33.562: ISAKMP:(0): sending packet to 3.1.1.1 my_port 500 peer_port 500 (R) MM_SA_SETUP
Dec 12 21:44:33.562: ISAKMP:(0):Sending an IKE IPv4 Packet.
Dec 12 21:44:33.562: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Dec 12 21:44:33.562: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM2
Dec 12 21:44:33.594: ISAKMP (0): received packet from 3.1.1.1 dport 500 sport 500 Global (R) MM_SA_SETUP
Dec 12 21:44:33.594: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Dec 12 21:44:33.594: ISAKMP:(0):Old State = IKE_R_MM2 New State = IKE_R_MM3
Dec 12 21:44:33.594: ISAKMP:(0): processing KE payload. message ID = 0
Dec 12 21:44:33.622: ISAKMP:(0): processing NONCE payload. message ID = 0
Dec 12 21:44:33.622: ISAKMP:(1007): processing CERT_REQ payload. message ID = 0
Dec 12 21:44:33.622: ISAKMP:(1007): peer wants a CT_X509_SIGNATURE cert
Dec 12 21:44:33.622: ISAKMP:(1007): peer wants cert issued by cn=VeriSign Class 3 Secure Server CA – G3,ou=Terms of use at https://www.verisign.com/rpa (c)10,ou=VeriSign Trust Network
Dec 12 21:44:33.622: Choosing trustpoint Verisign2014 as issuer
Dec 12 21:44:33.622: ISAKMP:(1007): processing vendor id payload
Dec 12 21:44:33.622: ISAKMP:(1007): vendor ID is DPD
Dec 12 21:44:33.622: ISAKMP:(1007): processing vendor id payload
Dec 12 21:44:33.622: ISAKMP:(1007): speaking to another IOS box!
Dec 12 21:44:33.622: ISAKMP:(1007): processing vendor id payload
Dec 12 21:44:33.622: ISAKMP:(1007): vendor ID seems Unity/DPD but major 237 mismatch
Dec 12 21:44:33.622: ISAKMP:(1007): vendor ID is XAUTH
Dec 12 21:44:33.622: ISAKMP:received payload type 20
Dec 12 21:44:33.622: ISAKMP (1007): His hash no match – this node outside NAT
Dec 12 21:44:33.622: ISAKMP:received payload type 20
Dec 12 21:44:33.622: ISAKMP (1007): No NAT Found for self or peer
Dec 12 21:44:33.622: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Dec 12 21:44:33.622: ISAKMP:(1007):Old State = IKE_R_MM3 New State = IKE_R_MM3
Dec 12 21:44:33.622: ISAKMP:(1007): IKE->PKI Get configured TrustPoints state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.622: ISAKMP:(1007): PKI->IKE Got configured TrustPoints state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.622: ISAKMP:(1007): IKE->PKI Get IssuerNames state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.622: ISAKMP:(1007): PKI->IKE Got IssuerNames state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.622: ISAKMP (1007): constructing CERT_REQ for issuer cn=VeriSign Class 3 Secure Server CA – G3,ou=Terms of use at https://www.verisign.com/rpa (c)10,ou=VeriSign Trust Network,o=VeriSign, Inc.,c=US
Dec 12 21:44:33.622: ISAKMP:(1007): sending packet to 3.1.1.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Dec 12 21:44:33.622: ISAKMP:(1007):Sending an IKE IPv4 Packet.
Dec 12 21:44:33.622: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Dec 12 21:44:33.622: ISAKMP:(1007):Old State = IKE_R_MM3 New State = IKE_R_MM4
Dec 12 21:44:33.986: ISAKMP (1007): received packet from 3.1.1.1 dport 500 sport 500 Global (R) MM_KEY_EXCH
Dec 12 21:44:33.986: ISAKMP:(1007):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Dec 12 21:44:33.986: ISAKMP:(1007):Old State = IKE_R_MM4 New State = IKE_R_MM5
Dec 12 21:44:33.986: ISAKMP:(1007): processing ID payload. message ID = 0
Dec 12 21:44:33.986: ISAKMP (1007): ID payload
next-payload : 6
type : 2
FQDN name : V-DMZ.ge.com
protocol : 17
port : 500
length : 27
Dec 12 21:44:33.986: ISAKMP:(0):: peer matches *none* of the profiles
Dec 12 21:44:33.986: ISAKMP:(1007): processing CERT payload. message ID = 0
Dec 12 21:44:33.986: ISAKMP:(1007): processing a CT_X509_SIGNATURE cert
Dec 12 21:44:33.986: ISAKMP:(1007): IKE->PKI Add peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.990: ISAKMP:(1007): PKI->IKE Added peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.990: ISAKMP:(1007): IKE->PKI Get PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.990: ISAKMP:(1007): PKI->IKE Got PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.990: ISAKMP:(1007): peer’s pubkey is cached
Dec 12 21:44:33.990: ISAKMP:(1007): IKE->PKI Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.990: ISAKMP:(1007): PKI->IKE Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:33.990: ISAKMP:(0):: peer matches *none* of the profiles
Dec 12 21:44:33.990: ISAKMP:(1007): processing SIG payload. message ID = 0
Dec 12 21:44:33.998: ISAKMP:(1007): signature invalid!
Dec 12 21:44:33.998: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Dec 12 21:44:33.998: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM5
Dec 12 21:44:34.002: ISAKMP (1007): incrementing error counter on sa, attempt 1 of 5: reset_retransmission
Dec 12 21:44:34.002: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_ERROR
Dec 12 21:44:34.002: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM4
Dec 12 21:44:35.002: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH…
Dec 12 21:44:35.002: ISAKMP (1007): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Dec 12 21:44:35.002: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH
Dec 12 21:44:35.002: ISAKMP:(1007): sending packet to 3.1.1.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Dec 12 21:44:35.002: ISAKMP:(1007):Sending an IKE IPv4 Packet.
Dec 12 21:44:43.986: ISAKMP (1007): received packet from 3.1.1.1 dport 500 sport 500 Global (R) MM_KEY_EXCH
Dec 12 21:44:43.986: ISAKMP:(1007):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Dec 12 21:44:43.986: ISAKMP:(1007):Old State = IKE_R_MM4 New State = IKE_R_MM5
Dec 12 21:44:43.986: ISAKMP:(1007): processing CERT payload. message ID = 0
Dec 12 21:44:43.986: ISAKMP:(1007): processing a CT_X509_SIGNATURE cert
Dec 12 21:44:43.986: ISAKMP:(1007): IKE->PKI Add peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:43.986: ISAKMP:(1007): PKI->IKE Added peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:43.986: ISAKMP:(1007): IKE->PKI Get PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:43.986: ISAKMP:(1007): PKI->IKE Got PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:43.986: ISAKMP:(1007): peer’s pubkey is cached
Dec 12 21:44:43.990: ISAKMP:(1007): IKE->PKI Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)attempt to reset validated peer object for session 1
Dec 12 21:44:43.998: ISAKMP:(1007): PKI->IKE Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:44.022: ISAKMP:(0):: peer matches *none* of the profiles
Dec 12 21:44:44.022: ISAKMP:(1007): processing SIG payload. message ID = 0
Dec 12 21:44:44.030: ISAKMP:(1007): signature invalid!
Dec 12 21:44:44.030: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Dec 12 21:44:44.030: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM5
Dec 12 21:44:44.030: ISAKMP (1007): incrementing error counter on sa, attempt 1 of 5: reset_retransmission
Dec 12 21:44:44.030: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_ERROR
Dec 12 21:44:44.030: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM4
Dec 12 21:44:45.030: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH…
Dec 12 21:44:45.030: ISAKMP (1007): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Dec 12 21:44:45.030: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH
Dec 12 21:44:45.030: ISAKMP:(1007): sending packet to 3.1.1.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Dec 12 21:44:45.030: ISAKMP:(1007):Sending an IKE IPv4 Packet.
Dec 12 21:44:53.986: ISAKMP (1007): received packet from 3.1.1.1 dport 500 sport 500 Global (R) MM_KEY_EXCH
Dec 12 21:44:53.986: ISAKMP:(1007):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Dec 12 21:44:53.986: ISAKMP:(1007):Old State = IKE_R_MM4 New State = IKE_R_MM5
Dec 12 21:44:53.986: ISAKMP:(1007): processing CERT payload. message ID = 0
Dec 12 21:44:53.986: ISAKMP:(1007): processing a CT_X509_SIGNATURE cert
Dec 12 21:44:53.986: ISAKMP:(1007): IKE->PKI Add peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:53.986: ISAKMP:(1007): PKI->IKE Added peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:53.986: ISAKMP:(1007): IKE->PKI Get PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:53.986: ISAKMP:(1007): PKI->IKE Got PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:53.986: ISAKMP:(1007): peer’s pubkey is cached
Dec 12 21:44:53.986: ISAKMP:(1007): IKE->PKI Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:53.986: ISAKMP:(1007): PKI->IKE Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:44:54.010: ISAKMP:(0):: peer matches *none* of the profiles
Dec 12 21:44:54.010: ISAKMP:(1007): processing SIG payload. message ID = 0
Dec 12 21:44:54.018: ISAKMP:(1007): signature invalid!
Dec 12 21:44:54.018: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Dec 12 21:44:54.018: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM5
Dec 12 21:44:54.018: ISAKMP (1007): incrementing error counter on sa, attempt 1 of 5: reset_retransmission
Dec 12 21:44:54.018: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_ERROR
Dec 12 21:44:54.018: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM4
Dec 12 21:44:55.018: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH…
Dec 12 21:44:55.018: ISAKMP (1007): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Dec 12 21:44:55.018: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH
Dec 12 21:44:55.018: ISAKMP:(1007): sending packet to 3.1.1.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Dec 12 21:44:55.018: ISAKMP:(1007):Sending an IKE IPv4 Packet.
Dec 12 21:45:03.986: ISAKMP (1007): received packet from 3.1.1.1 dport 500 sport 500 Global (R) MM_KEY_EXCH
Dec 12 21:45:03.986: ISAKMP:(1007):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Dec 12 21:45:03.986: ISAKMP:(1007):Old State = IKE_R_MM4 New State = IKE_R_MM5
Dec 12 21:45:03.986: ISAKMP:(1007): processing CERT payload. message ID = 0
Dec 12 21:45:03.986: ISAKMP:(1007): processing a CT_X509_SIGNATURE cert
Dec 12 21:45:03.986: ISAKMP:(1007): IKE->PKI Add peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:03.986: ISAKMP:(1007): PKI->IKE Added peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:03.986: ISAKMP:(1007): IKE->PKI Get PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:03.986: ISAKMP:(1007): PKI->IKE Got PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:03.986: ISAKMP:(1007): peer’s pubkey is cached
Dec 12 21:45:03.986: ISAKMP:(1007): IKE->PKI Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:03.986: ISAKMP:(1007): PKI->IKE Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:04.010: ISAKMP:(0):: peer matches *none* of the profiles
Dec 12 21:45:04.010: ISAKMP:(1007): processing SIG payload. message ID = 0
Dec 12 21:45:04.018: ISAKMP:(1007): signature invalid!
Dec 12 21:45:04.018: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Dec 12 21:45:04.018: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM5
Dec 12 21:45:04.018: ISAKMP (1007): incrementing error counter on sa, attempt 1 of 5: reset_retransmission
Dec 12 21:45:04.018: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_ERROR
Dec 12 21:45:04.018: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM4
Dec 12 21:45:05.018: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH…
Dec 12 21:45:05.018: ISAKMP (1007): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Dec 12 21:45:05.018: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH
Dec 12 21:45:05.018: ISAKMP:(1007): sending packet to 3.1.1.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Dec 12 21:45:05.018: ISAKMP:(1007):Sending an IKE IPv4 Packet.
Dec 12 21:45:13.986: ISAKMP (1007): received packet from 3.1.1.1 dport 500 sport 500 Global (R) MM_KEY_EXCH
Dec 12 21:45:13.986: ISAKMP:(1007):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Dec 12 21:45:13.986: ISAKMP:(1007):Old State = IKE_R_MM4 New State = IKE_R_MM5
Dec 12 21:45:13.986: ISAKMP:(1007): processing CERT payload. message ID = 0
Dec 12 21:45:13.986: ISAKMP:(1007): processing a CT_X509_SIGNATURE cert
Dec 12 21:45:13.986: ISAKMP:(1007): IKE->PKI Add peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:13.986: ISAKMP:(1007): PKI->IKE Added peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:13.986: ISAKMP:(1007): IKE->PKI Get PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:13.986: ISAKMP:(1007): PKI->IKE Got PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:13.986: ISAKMP:(1007): peer’s pubkey is cached
Dec 12 21:45:13.986: ISAKMP:(1007): IKE->PKI Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:13.986: ISAKMP:(1007): PKI->IKE Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:14.010: ISAKMP:(0):: peer matches *none* of the profiles
Dec 12 21:45:14.010: ISAKMP:(1007): processing SIG payload. message ID = 0
Dec 12 21:45:14.018: ISAKMP:(1007): signature invalid!
Dec 12 21:45:14.018: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Dec 12 21:45:14.018: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM5
Dec 12 21:45:14.018: ISAKMP (1007): incrementing error counter on sa, attempt 1 of 5: reset_retransmission
Dec 12 21:45:14.018: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_ERROR
Dec 12 21:45:14.018: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM4
Dec 12 21:45:15.018: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH…
Dec 12 21:45:15.018: ISAKMP (1007): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Dec 12 21:45:15.018: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH
Dec 12 21:45:15.018: ISAKMP:(1007): sending packet to 3.1.1.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Dec 12 21:45:15.018: ISAKMP:(1007):Sending an IKE IPv4 Packet.
Dec 12 21:45:23.986: ISAKMP (1007): received packet from 3.1.1.1 dport 500 sport 500 Global (R) MM_KEY_EXCH
Dec 12 21:45:23.986: ISAKMP:(1007):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Dec 12 21:45:23.986: ISAKMP:(1007):Old State = IKE_R_MM4 New State = IKE_R_MM5
Dec 12 21:45:23.986: ISAKMP:(1007): processing CERT payload. message ID = 0
Dec 12 21:45:23.986: ISAKMP:(1007): processing a CT_X509_SIGNATURE cert
Dec 12 21:45:23.986: ISAKMP:(1007): IKE->PKI Add peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:23.986: ISAKMP:(1007): PKI->IKE Added peer’s certificate state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:23.986: ISAKMP:(1007): IKE->PKI Get PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:23.986: ISAKMP:(1007): PKI->IKE Got PeerCertificateChain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:23.986: ISAKMP:(1007): peer’s pubkey is cached
Dec 12 21:45:23.986: ISAKMP:(1007): IKE->PKI Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:23.986: ISAKMP:(1007): PKI->IKE Validate certificate chain state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:24.010: ISAKMP:(0):: peer matches *none* of the profiles
Dec 12 21:45:24.010: ISAKMP:(1007): processing SIG payload. message ID = 0
Dec 12 21:45:24.018: ISAKMP:(1007): signature invalid!
Dec 12 21:45:24.018: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Dec 12 21:45:24.018: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM5
Dec 12 21:45:24.018: ISAKMP (1007): incrementing error counter on sa, attempt 1 of 5: reset_retransmission
Dec 12 21:45:24.018: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PROCESS_ERROR
Dec 12 21:45:24.018: ISAKMP:(1007):Old State = IKE_R_MM5 New State = IKE_R_MM4
Dec 12 21:45:25.018: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH…
Dec 12 21:45:25.018: ISAKMP (1007): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Dec 12 21:45:25.018: ISAKMP:(1007): retransmitting phase 1 MM_KEY_EXCH
Dec 12 21:45:25.018: ISAKMP:(1007): sending packet to 3.1.1.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Dec 12 21:45:25.018: ISAKMP:(1007):Sending an IKE IPv4 Packet.
Dec 12 21:45:48.558: ISAKMP: quick mode timer expired.
Dec 12 21:45:48.558: ISAKMP:(1007):src 3.1.1.1 dst 6.4.2.1, SA is not authenticated
Dec 12 21:45:48.558: ISAKMP:(1007):peer does not do paranoid keepalives.
Dec 12 21:45:48.558: ISAKMP:(1007):deleting SA reason “QM_TIMER expired” state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:48.558: ISAKMP:(1007):deleting SA reason “QM_TIMER expired” state (R) MM_KEY_EXCH (peer 3.1.1.1)
Dec 12 21:45:48.558: ISAKMP: Unlocking peer struct 0x28677D80 for isadb_mark_sa_deleted(), count 0
Dec 12 21:45:48.558: ISAKMP: Deleting peer node by peer_reap for 3.1.1.1: 28677D80
Dec 12 21:45:48.558: ISAKMP:(1007): IKE->PKI End PKI Session state (R) MM_NO_STATE (peer 3.1.1.1)
Dec 12 21:45:48.558: ISAKMP:(1007): PKI->IKE Ended PKI Session state (R) MM_NO_STATE (peer 3.1.1.1)
Dec 12 21:45:48.558: ISAKMP:(1007):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Dec 12 21:45:48.558: ISAKMP:(1007):Old State = IKE_R_MM4 New State = IKE_DEST_SA
The regular phases and key exchange processes will go through following MM states:IKE_R_MM1
–>IKE_R_MM2
–> IKE_R_MM3
–> IKE_R_MM4
–> IKE_R_MM5
–> IKE_R_MM6
–> QM_IDLE
In this case, this router only got through IKE_R_MM5 indicating that the fifth message in the IKE exchange has been sent. From Cisco doc Understanding IOS IPSec and IKE debugs – IKEv1 Main Mode, it shows MM5 includes following information:
- Local identity information.
- Key
Here is a diagram for PSK based tunnel MM MSGs and Packet flow diagram from tunnelsup.com.
I tried to import certificate downloaded from the account of Verisign, but failed. It looks like CSR key has been changed.
v-dmz(config)#crypto pki import Verisign2014 certificate
Enter the base 64 encoded certificate.
End with a blank line or the word “quit” on a line by itself
—–BEGIN CERTIFICATE—–
MIIFezCCBGOgAwIBAgIQOu6c5mp+mIhLjQbkjOhWbzANBgkqhkiG9w0BAQUFADCB
tTELMAkGA1UEBhMCVVMxFzAVBgNVBAoTDlZlcmlTaWduLCBJbmMuMR8wHQYDVQQL
ExZWZXJpU2lnbiBUcnVzdCBOZXR3b3JrMTswOQYDVQQLEzJUZXJtcyBvZiB1c2Ug
YXQgaHR0cHM6Ly93d3cudmVyaXNpZ24uY29tL3JwYSAoYykxMDEvMC0GA1UEAxMm
VmVyaVNpZ24gQ2xhc3MgMyBTZWN1cmUgU2VydmVyIENBIC0gRzMwHhcNMTQwMzEz
MDAwMDAwWhcNMTcwMzEyMjM1OTU5WjCBtTELMAkGA1UEBhMCQ0ExEDAOBgNVBAgM
B29udGFyaW8xEDAOBgNVBAcMB21hcmtoYW0xLzAtBgNVBAoMJkdpZXNlY2tlICYg
RGV2cmllbnQgc3lzdGVtcyBjYW5hZGEgaW5jMTMwMQYDVQQLFCpUZXJtcyBvZiB1
c2UgYXQgd3d3LnZlcmlzaWduLmNvbS9ycGEgKGMpMDUxHDAaBgNVBAMME1YtRE1a
LU1UTy5naS1kZS5jb20wggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQCS
glKd+PNESJvcuQAbGiuqYLJJSJ/eFKcTpfMKpJ+Cv8C89Gs4NTtYdCNRl1NyHI0l
wx8Ayho0x1t6GbBtksP6AUn6n2xUZxKSL1q53TkijfO6kgrU6MmDcoN5Y+6MvXPE
DkPvRbJIZW8ziZTR1ux8Z//SljzkA3lGdQRG7lOvFCcTeK3mLznjOhwpfAwRMXKL
EXRrEzFT8X3WP7XMbpuaWr6eOEDzBxzuFJO+23KsZD3peZmKRr/1krAUJo6B/qn8
uxsW+9GOB6x1UmZ/3Wgrk3VFVV0rPzOSBNNjTH5CvzfA1BKAe/An4UfS5lUqNlAu
FD+ImIUtQ+Po1797DPvHAgMBAAGjggGDMIIBfzAeBgNVHREEFzAVghNWLURNWi1N
VE8uZ2ktZGUuY29tMAkGA1UdEwQCMAAwDgYDVR0PAQH/BAQDAgWgMEUGA1UdHwQ+
MDwwOqA4oDaGNGh0dHA6Ly9TVlJTZWN1cmUtRzMtY3JsLnZlcmlzaWduLmNvbS9T
VlJTZWN1cmVHMy5jcmwwQwYDVR0gBDwwOjA4BgpghkgBhvhFAQc2MCowKAYIKwYB
BQUHAgEWHGh0dHBzOi8vd3d3LnZlcmlzaWduLmNvbS9jcHMwHQYDVR0lBBYwFAYI
KwYBBQUHAwEGCCsGAQUFBwMCMB8GA1UdIwQYMBaAFA1EXBZTRMGCfh0gqyX0AWPY
vnmlMHYGCCsGAQUFBwEBBGowaDAkBggrBgEFBQcwAYYYaHR0cDovL29jc3AudmVy
aXNpZ24uY29tMEAGCCsGAQUFBzAChjRodHRwOi8vU1ZSU2VjdXJlLUczLWFpYS52
ZXJpc2lnbi5jb20vU1ZSU2VjdXJlRzMuY2VyMA0GCSqGSIb3DQEBBQUAA4IBAQAE
wPoi1ngHcmG/s9RtH4V0JLMIohhOoj2gJJ+1jUgsA8lRk4xkfhCdq85SI6kZPHV1
/D3Eie4lUzNxp+9cVmt8zX68OrhXmTdFLRwdholOq4r+V7P3acSJDlC2hdbw5w6V
7CcWM3sE5eAWAG7LAoiXv1VfpiY4vV1oDLNbEc9QprFamyDvP0ugH+xVuutDmINz
Z6Ec6N4wc16XqsczRuEAJkJ5K+Q9n7SrVNcB9KXWy03C6V+1zdiTPGGi8BU/VSbu
Kuym5kWFdDU5RhCVxyOi1AFt+TzKLe2CNJrS1jFMF+77YtGbCuJxZ0Z9yWs2pqzO
GsemGCEY0zAu+VlSWZz2
—–END CERTIFICATE—–
Cannot import certificate –
Certificate does not contain router’s General Purpose public key
for trust point Verisign2014
% Failed to parse or verify imported certificate
Solution:
Could not find out why ‘signature invalid’. It may relate the certificate file crashed itself. But re-generated CSR and re-imported it again follow the previous post resolved this issue.
Reference:
- Understanding IOS IPSec and IKE debugs – IKEv1 Main Mode
- ASA IPsec and IKE debugs (IKEv1 Main Mode) Troubleshooting TechNote
- ISAKMP (IKE Phase 1) Status Messages MM_WAIT_MSG#