Friday, December 12, 2014

Certification based Cisco IPSec VPN Down Caused by 'signature invalid'

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.
IKE Phase Messages - IMG


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:

No comments:

Post a Comment

NetSec Youtube Videos