Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
Community Member

DMVPN phase I fails when migrating from PSK to RSIG

I am currently is the process of migrating my DMVPN network from pre-share key to certificates. Most of the spokes have come up and are working without any issues but there are several that are not making it past phase I. I have included the isakmp debugging from the hub and one of the spokes that are failing. I see that the hub is going QM_IDLE after receiving the certificate from the spoke but it does not look like the spoke ever receives the cert from the hub. I suspect an issue with the ISP but it's not as simple as filtering 500 as all the messages except the cert seem to make it. If I move the spoke back to PSK it works fine. Has anyone seen this issue before and what was the resolution?        

DMVPN Hub
Oct  7 19:38:36.213: ISAKMP: local port 500, remote port 500
Oct  7 19:38:36.213: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 7F1AA7CC5920
Oct  7 19:38:36.213: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Oct  7 19:38:36.213: ISAKMP:(0):Old State = IKE_READY  New State = IKE_R_MM1
Oct  7 19:38:36.214: ISAKMP:(0): processing SA payload. message ID = 0
Oct  7 19:38:36.214: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Oct  7 19:38:36.214: ISAKMP (0): vendor ID is NAT-T RFC 3947
Oct  7 19:38:36.214: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch
Oct  7 19:38:36.214: ISAKMP (0): vendor ID is NAT-T v7
Oct  7 19:38:36.214: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID is NAT-T v3
Oct  7 19:38:36.214: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID is NAT-T v2
Oct  7 19:38:36.214: ISAKMP:(0):found peer pre-shared key matching 2.8.51.58
Oct  7 19:38:36.214: ISAKMP:(0): local preshared key found
Oct  7 19:38:36.214: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (R) MM_NO_STATE (peer 2.8.51.58)
Oct  7 19:38:36.214: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (R) MM_NO_STATE (peer 2.8.51.58)
Oct  7 19:38:36.214: ISAKMP:(0):Checking ISAKMP transform 1 against priority 5 policy
Oct  7 19:38:36.214: ISAKMP:      encryption 3DES-CBC
Oct  7 19:38:36.214: ISAKMP:      hash MD5
Oct  7 19:38:36.214: ISAKMP:      default group 1
Oct  7 19:38:36.214: ISAKMP:      auth RSA sig
Oct  7 19:38:36.214: ISAKMP:      life type in seconds
Oct  7 19:38:36.214: ISAKMP:      life duration (VPI) of  0x0 0x1 0x51 0x80
Oct  7 19:38:36.214: ISAKMP:(0):atts are acceptable. Next payload is 3
Oct  7 19:38:36.214: ISAKMP:(0):Acceptable atts:actual life: 0
Oct  7 19:38:36.214: ISAKMP:(0):Acceptable atts:life: 0
Oct  7 19:38:36.214: ISAKMP:(0):Fill atts in sa vpi_length:4
Oct  7 19:38:36.214: ISAKMP:(0):Fill atts in sa life_in_seconds:86400
Oct  7 19:38:36.214: ISAKMP:(0): IKE->PKI Start PKI Session state (R) MM_NO_STATE (peer 2.8.51.58)
Oct  7 19:38:36.214: ISAKMP:(0): PKI->IKE Started PKI Session state (R) MM_NO_STATE (peer 2.8.51.58)
Oct  7 19:38:36.214: ISAKMP:(0):Returning Actual lifetime: 86400
Oct  7 19:38:36.214: ISAKMP:(0)::Started lifetime timer: 86400.
Oct  7 19:38:36.214: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Oct  7 19:38:36.214: ISAKMP (0): vendor ID is NAT-T RFC 3947
Oct  7 19:38:36.214: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch
Oct  7 19:38:36.214: ISAKMP (0): vendor ID is NAT-T v7
Oct  7 19:38:36.214: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID is NAT-T v3
Oct  7 19:38:36.214: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
Oct  7 19:38:36.214: ISAKMP:(0): vendor ID is NAT-T v2
Oct  7 19:38:36.214: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Oct  7 19:38:36.214: ISAKMP:(0):Old State = IKE_R_MM1  New State = IKE_R_MM1
Oct  7 19:38:36.214: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
Oct  7 19:38:36.214: ISAKMP:(0): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) MM_SA_SETUP
Oct  7 19:38:36.214: ISAKMP:(0):Sending an IKE IPv4 Packet.
Oct  7 19:38:36.214: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Oct  7 19:38:36.214: ISAKMP:(0):Old State = IKE_R_MM1  New State = IKE_R_MM2
Oct  7 19:38:36.240: ISAKMP (0): received packet from 2.8.51.58 dport 500 sport 500 Global (R) MM_SA_SETUP
Oct  7 19:38:36.240: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Oct  7 19:38:36.240: ISAKMP:(0):Old State = IKE_R_MM2  New State = IKE_R_MM3
Oct  7 19:38:36.240: ISAKMP:(0): processing KE payload. message ID = 0
Oct  7 19:38:36.242: ISAKMP:(0): processing NONCE payload. message ID = 0
Oct  7 19:38:36.242: ISAKMP:(38618): processing CERT_REQ payload. message ID = 0
Oct  7 19:38:36.242: ISAKMP:(38618): peer wants a CT_X509_SIGNATURE cert
Oct  7 19:38:36.242: ISAKMP:(38618): peer wants cert issued by cn=Tetra Pak Root CA - G1
Oct  7 19:38:36.242: ISAKMP:(38618): processing vendor id payload
Oct  7 19:38:36.242: ISAKMP:(38618): vendor ID is DPD
Oct  7 19:38:36.242: ISAKMP:(38618): processing vendor id payload
Oct  7 19:38:36.242: ISAKMP:(38618): speaking to another IOS box!
Oct  7 19:38:36.242: ISAKMP:(38618): processing vendor id payload
Oct  7 19:38:36.242: ISAKMP:(38618): vendor ID seems Unity/DPD but major 209 mismatch
Oct  7 19:38:36.242: ISAKMP:(38618): vendor ID is XAUTH
Oct  7 19:38:36.242: ISAKMP:received payload type 20
Oct  7 19:38:36.242: ISAKMP (38618): His hash no match - this node outside NAT
Oct  7 19:38:36.242: ISAKMP:received payload type 20
Oct  7 19:38:36.242: ISAKMP (38618): No NAT Found for self or peer
Oct  7 19:38:36.242: ISAKMP:(38618):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Oct  7 19:38:36.242: ISAKMP:(38618):Old State = IKE_R_MM3  New State = IKE_R_MM3
Oct  7 19:38:36.243: ISAKMP:(38618): IKE->PKI Get configured TrustPoints state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.243: ISAKMP:(38618): PKI->IKE Got configured TrustPoints state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.243: ISAKMP:(38618): IKE->PKI Get IssuerNames state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.243: ISAKMP:(38618): PKI->IKE Got IssuerNames state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.243: ISAKMP (38618): constructing CERT_REQ for issuer cn=Tetra Pak Issuing NAD CA 01 - G1,dc=tp1,dc=ad1,dc=tetrapak,dc=com
Oct  7 19:38:36.243: ISAKMP:(38618): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Oct  7 19:38:36.243: ISAKMP:(38618):Sending an IKE IPv4 Packet.
Oct  7 19:38:36.243: ISAKMP:(38618):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Oct  7 19:38:36.243: ISAKMP:(38618):Old State = IKE_R_MM3  New State = IKE_R_MM4
Oct  7 19:38:36.484: ISAKMP (38618): received packet from 2.8.51.58 dport 500 sport 500 Global (R) MM_KEY_EXCH
Oct  7 19:38:36.484: ISAKMP:(38618):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Oct  7 19:38:36.484: ISAKMP:(38618):Old State = IKE_R_MM4  New State = IKE_R_MM5
Oct  7 19:38:36.484: ISAKMP:(38618): processing ID payload. message ID = 0
Oct  7 19:38:36.484: ISAKMP (38618): ID payload
        next-payload : 6
        type         : 2
        FQDN name    : lvrirt-s2s-01.nvv.net.company.com
        protocol     : 17
        port         : 500
        length       : 42
Oct  7 19:38:36.484: ISAKMP:(38618): processing CERT payload. message ID = 0
Oct  7 19:38:36.484: ISAKMP:(38618): processing a CT_X509_SIGNATURE cert
Oct  7 19:38:36.484: ISAKMP:(38618): IKE->PKI Add peer's certificate state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.485: ISAKMP:(38618): PKI->IKE Added peer's certificate state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.485: ISAKMP:(38618): IKE->PKI Get PeerCertificateChain state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.485: ISAKMP:(38618): PKI->IKE Got PeerCertificateChain state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.485: ISAKMP:(38618): peer's pubkey is cached
Oct  7 19:38:36.485: ISAKMP:(38618): IKE->PKI Validate certificate chain state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.485: ISAKMP:(38618): PKI->IKE Validate certificate chain state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.485: ISAKMP:(38618): Unable to get DN from certificate!
Oct  7 19:38:36.485: ISAKMP:(38618): processing SIG payload. message ID = 0
Oct  7 19:38:36.486: ISAKMP:received payload type 17
Oct  7 19:38:36.486: ISAKMP:(38618): processing NOTIFY INITIAL_CONTACT protocol 1
        spi 0, message ID = 0, sa = 0x7F1AA7CC5920
Oct  7 19:38:36.486: ISAKMP:(38618):SA authentication status:
        authenticated
Oct  7 19:38:36.486: ISAKMP:(38618):SA has been authenticated with 2.8.51.58
Oct  7 19:38:36.486: ISAKMP:(38618):SA authentication status:
        authenticated
Oct  7 19:38:36.486: ISAKMP:(38618): Process initial contact,
bring down existing phase 1 and 2 SA's with local 15.18.1.1 remote 2.8.51.58 remote port 500
Oct  7 19:38:36.486: ISAKMP:(38617):received initial contact, deleting SA
Oct  7 19:38:36.486: ISAKMP:(38617):peer does not do paranoid keepalives.
Oct  7 19:38:36.486: ISAKMP:(38617):deleting SA reason "Receive initial contact" state (R) QM_IDLE       (peer 2.8.51.58)
Oct  7 19:38:36.486: ISAKMP:(38618):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Oct  7 19:38:36.486: ISAKMP:(38618):Old State = IKE_R_MM5  New State = IKE_R_MM5
Oct  7 19:38:36.487: ISAKMP: set new node 2177251913 to QM_IDLE
Oct  7 19:38:36.487: ISAKMP:(38617): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) QM_IDLE
Oct  7 19:38:36.487: ISAKMP:(38617):Sending an IKE IPv4 Packet.
Oct  7 19:38:36.487: ISAKMP:(38617):purging node 2177251913
Oct  7 19:38:36.487: ISAKMP:(38617):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Oct  7 19:38:36.487: ISAKMP:(38617):Old State = IKE_P1_COMPLETE  New State = IKE_DEST_SA
Oct  7 19:38:36.487: ISAKMP:(38618): IKE->PKI Get self CertificateChain state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.487: ISAKMP:(38618): PKI->IKE Got self CertificateChain state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.487: ISAKMP:(38618): IKE->PKI Get SubjectName state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.487: ISAKMP:(38618): PKI->IKE Got SubjectName state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.487: ISAKMP:(38618):My ID configured as IPv4 Addr, but Addr not in Cert!
Oct  7 19:38:36.487: ISAKMP:(38618):Using FQDN as My ID
Oct  7 19:38:36.487: ISAKMP:(38618):SA is doing RSA signature authentication using id type ID_FQDN
Oct  7 19:38:36.487: ISAKMP (38618): ID payload
        next-payload : 6
        type         : 2
        FQDN name    : selurt-dmvpn-01.nvv.net.company.com
        protocol     : 17
        port         : 500
        length       : 44
Oct  7 19:38:36.487: ISAKMP:(38618):Total payload length: 44
Oct  7 19:38:36.487: ISAKMP:(38618): IKE->PKI Get CertificateChain to be sent to peer state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.488: ISAKMP:(38618): PKI->IKE Got CertificateChain to be sent to peer state (R) MM_KEY_EXCH (peer 2.8.51.58)
Oct  7 19:38:36.489: ISAKMP (38618): constructing CERT payload for hostname=selurt-dmvpn-01.nvv.net.company.com,serialNumber=4279180096
Oct  7 19:38:36.489: ISAKMP (38618): constructing CERT payload for cn=Tetra Pak Issuing NAD CA 01 - G1,dc=tp1,dc=ad1,dc=tetrapak,dc=com
Oct  7 19:38:36.489: ISAKMP:(38618): using the TP_NAD_CA trustpoint's keypair to sign
Oct  7 19:38:36.494: ISAKMP:(38618): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Oct  7 19:38:36.494: ISAKMP:(38618):Sending an IKE IPv4 Packet.
Oct  7 19:38:36.494: ISAKMP:(38618):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Oct  7 19:38:36.494: ISAKMP:(38618):Old State = IKE_R_MM5  New State = IKE_P1_COMPLETE
Oct  7 19:38:36.494: ISAKMP:(38617):deleting SA reason "Receive initial contact" state (R) QM_IDLE       (peer 2.8.51.58)
Oct  7 19:38:36.494: ISAKMP:(38617):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Oct  7 19:38:36.494: ISAKMP:(38617):Old State = IKE_DEST_SA  New State = IKE_DEST_SA
Oct  7 19:38:36.494: ISAKMP:(38618):IKE_DPD is enabled, initializing timers
Oct  7 19:38:36.494: ISAKMP:(38618): IKE->PKI End PKI Session state (R) QM_IDLE       (peer 2.8.51.58)
Oct  7 19:38:36.494: ISAKMP:(38618): PKI->IKE Ended PKI session state (R) QM_IDLE       (peer 2.8.51.58)
Oct  7 19:38:36.494: ISAKMP:(38618):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
selurt-dmvpn-01#
Oct  7 19:38:36.494: ISAKMP:(38618):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE
selurt-dmvpn-01#
Oct  7 19:38:46.492: ISAKMP (38618): received packet from 2.8.51.58 dport 500 sport 500 Global (R) QM_IDLE
Oct  7 19:38:46.492: ISAKMP:(38618): phase 1 packet is a duplicate of a previous packet.
Oct  7 19:38:46.492: ISAKMP:(38618): retransmitting due to retransmit phase 1
Oct  7 19:38:46.992: ISAKMP:(38618): retransmitting phase 1 QM_IDLE      ...
Oct  7 19:38:46.992: ISAKMP (38618): incrementing error counter on sa, attempt 1 of 5: retransmit phase 1
Oct  7 19:38:46.992: ISAKMP:(38618): retransmitting phase 1 QM_IDLE
Oct  7 19:38:46.992: ISAKMP:(38618): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) QM_IDLE
selurt-dmvpn-01#
Oct  7 19:38:46.992: ISAKMP:(38618):Sending an IKE IPv4 Packet.
selurt-dmvpn-01#
Oct  7 19:38:56.481: ISAKMP (38618): received packet from 2.8.51.58 dport 500 sport 500 Global (R) QM_IDLE
Oct  7 19:38:56.481: ISAKMP:(38618): phase 1 packet is a duplicate of a previous packet.
Oct  7 19:38:56.481: ISAKMP:(38618): retransmitting due to retransmit phase 1
Oct  7 19:38:56.981: ISAKMP:(38618): retransmitting phase 1 QM_IDLE      ...
Oct  7 19:38:56.981: ISAKMP (38618): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Oct  7 19:38:56.981: ISAKMP:(38618): retransmitting phase 1 QM_IDLE
Oct  7 19:38:56.981: ISAKMP:(38618): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) QM_IDLE
selurt-dmvpn-01#
Oct  7 19:38:56.981: ISAKMP:(38618):Sending an IKE IPv4 Packet.
selurt-dmvpn-01#
Oct  7 19:39:06.481: ISAKMP (38618): received packet from 2.8.51.58 dport 500 sport 500 Global (R) QM_IDLE
Oct  7 19:39:06.481: ISAKMP:(38618): phase 1 packet is a duplicate of a previous packet.
Oct  7 19:39:06.481: ISAKMP:(38618): retransmitting due to retransmit phase 1
Oct  7 19:39:06.981: ISAKMP:(38618): retransmitting phase 1 QM_IDLE      ...
Oct  7 19:39:06.981: ISAKMP (38618): incrementing error counter on sa, attempt 3 of 5: retransmit phase 1
Oct  7 19:39:06.981: ISAKMP:(38618): retransmitting phase 1 QM_IDLE
Oct  7 19:39:06.981: ISAKMP:(38618): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) QM_IDLE
selurt-dmvpn-01#
Oct  7 19:39:06.981: ISAKMP:(38618):Sending an IKE IPv4 Packet.
selurt-dmvpn-01#
Oct  7 19:39:09.880: ISAKMP:(38616):purging SA., sa=7F1AA7721158, delme=7F1AA7721158
selurt-dmvpn-01#
Oct  7 19:39:16.481: ISAKMP (38618): received packet from 2.8.51.58 dport 500 sport 500 Global (R) QM_IDLE
Oct  7 19:39:16.481: ISAKMP:(38618): phase 1 packet is a duplicate of a previous packet.
Oct  7 19:39:16.481: ISAKMP:(38618): retransmitting due to retransmit phase 1
Oct  7 19:39:16.980: ISAKMP:(38618): retransmitting phase 1 QM_IDLE      ...
Oct  7 19:39:16.980: ISAKMP (38618): incrementing error counter on sa, attempt 4 of 5: retransmit phase 1
Oct  7 19:39:16.980: ISAKMP:(38618): retransmitting phase 1 QM_IDLE
Oct  7 19:39:16.980: ISAKMP:(38618): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) QM_IDLE
selurt-dmvpn-01#
Oct  7 19:39:16.980: ISAKMP:(38618):Sending an IKE IPv4 Packet.
selurt-dmvpn-01#
Oct  7 19:39:26.481: ISAKMP (38618): received packet from 2.8.51.58 dport 500 sport 500 Global (R) QM_IDLE
Oct  7 19:39:26.482: ISAKMP:(38618): phase 1 packet is a duplicate of a previous packet.
Oct  7 19:39:26.482: ISAKMP:(38618): retransmitting due to retransmit phase 1
Oct  7 19:39:26.981: ISAKMP:(38618): retransmitting phase 1 QM_IDLE      ...
Oct  7 19:39:26.981: ISAKMP (38618): incrementing error counter on sa, attempt 5 of 5: retransmit phase 1
Oct  7 19:39:26.981: ISAKMP:(38618): retransmitting phase 1 QM_IDLE
Oct  7 19:39:26.981: ISAKMP:(38618): sending packet to 2.8.51.58 my_port 500 peer_port 500 (R) QM_IDLE
selurt-dmvpn-01#
Oct  7 19:39:26.981: ISAKMP:(38618):Sending an IKE IPv4 Packet.
selurt-dmvpn-01#
Oct  7 19:39:36.493: ISAKMP:(38617):purging SA., sa=7F1AA79AD9E0, delme=7F1AA79AD9E0

DMVPN Spoke
Oct  7 19:38:36.181: ISAKMP:(0): SA request profile is (NULL)
Oct  7 19:38:36.181: ISAKMP: Created a peer struct for 15.18.1.1, peer port 500
Oct  7 19:38:36.181: ISAKMP: New peer created peer = 0x2B1F480C peer_handle = 0x80001DF4
Oct  7 19:38:36.181: ISAKMP: Locking peer struct 0x2B1F480C, refcount 1 for isakmp_initiator
Oct  7 19:38:36.181: ISAKMP: local port 500, remote port 500
Oct  7 19:38:36.181: ISAKMP: set new node 0 to QM_IDLE
Oct  7 19:38:36.181: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 2B16C9FC
Oct  7 19:38:36.181: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
Oct  7 19:38:36.181: ISAKMP:(0):found peer pre-shared key matching 15.18.1.1
Oct  7 19:38:36.181: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer 15.18.1.1)
Oct  7 19:38:36.181: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer 15.18.1.1)
Oct  7 19:38:36.181: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
Oct  7 19:38:36.181: ISAKMP:(0): constructed NAT-T vendor-07 ID
Oct  7 19:38:36.181: ISAKMP:(0): constructed NAT-T vendor-03 ID
Oct  7 19:38:36.181: ISAKMP:(0): constructed NAT-T vendor-02 ID
Oct  7 19:38:36.181: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
Oct  7 19:38:36.181: ISAKMP:(0):Old State = IKE_READY  New State = IKE_I_MM1
Oct  7 19:38:36.181: ISAKMP:(0): beginning Main Mode exchange
Oct  7 19:38:36.181: ISAKMP:(0): sending packet to 15.18.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
Oct  7 19:38:36.181: ISAKMP:(0):Sending an IKE IPv4 Packet.
Oct  7 19:38:36.205: ISAKMP (0): received packet from 15.18.1.1 dport 500 sport 500 Global (I) MM_NO_STATE
Oct  7 19:38:36.205: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Oct  7 19:38:36.205: ISAKMP:(0):Old State = IKE_I_MM1  New State = IKE_I_MM2
Oct  7 19:38:36.205: ISAKMP:(0): processing SA payload. message ID = 0
Oct  7 19:38:36.205: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.205: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Oct  7 19:38:36.205: ISAKMP (0): vendor ID is NAT-T RFC 3947
Oct  7 19:38:36.205: ISAKMP:(0):found peer pre-shared key matching 15.18.1.1
Oct  7 19:38:36.205: ISAKMP:(0): local preshared key found
Oct  7 19:38:36.205: ISAKMP : Scanning profiles for xauth ...
Oct  7 19:38:36.205: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer 15.18.1.1)
Oct  7 19:38:36.205: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer 15.18.1.1)
Oct  7 19:38:36.205: ISAKMP:(0):Checking ISAKMP transform 1 against priority 5 policy
Oct  7 19:38:36.205: ISAKMP:      encryption 3DES-CBC
Oct  7 19:38:36.205: ISAKMP:      hash MD5
Oct  7 19:38:36.205: ISAKMP:      default group 1
Oct  7 19:38:36.205: ISAKMP:      auth RSA sig
Oct  7 19:38:36.205: ISAKMP:      life type in seconds
Oct  7 19:38:36.205: ISAKMP:      life duration (VPI) of  0x0 0x1 0x51 0x80
Oct  7 19:38:36.205: ISAKMP:(0):atts are acceptable. Next payload is 0
Oct  7 19:38:36.205: ISAKMP:(0):Acceptable atts:actual life: 0
Oct  7 19:38:36.205: ISAKMP:(0):Acceptable atts:life: 0
Oct  7 19:38:36.205: ISAKMP:(0):Fill atts in sa vpi_length:4
Oct  7 19:38:36.205: ISAKMP:(0):Fill atts in sa life_in_seconds:86400
Oct  7 19:38:36.205: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer 15.18.1.1)
Oct  7 19:38:36.205: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer 15.18.1.1)
Oct  7 19:38:36.205: ISAKMP:(0):Returning Actual lifetime: 86400
Oct  7 19:38:36.205: ISAKMP:(0)::Started lifetime timer: 86400.
Oct  7 19:38:36.205: ISAKMP:(0): processing vendor id payload
Oct  7 19:38:36.205: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Oct  7 19:38:36.205: ISAKMP (0): vendor ID is NAT-T RFC 3947
Oct  7 19:38:36.205: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Oct  7 19:38:36.205: ISAKMP:(0):Old State = IKE_I_MM2  New State = IKE_I_MM2
Oct  7 19:38:36.209: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer 15.18.1.1)
Oct  7 19:38:36.209: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer 15.18.1.1)
Oct  7 19:38:36.209: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer 15.18.1.1)
Oct  7 19:38:36.209: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer 15.18.1.1)
Oct  7 19:38:36.209: ISAKMP (0): constructing CERT_REQ for issuer cn=Tetra Pak Root CA - G1
Oct  7 19:38:36.209: ISAKMP:(0): sending packet to 15.18.1.1 my_port 500 peer_port 500 (I) MM_SA_SETUP
Oct  7 19:38:36.209: ISAKMP:(0):Sending an IKE IPv4 Packet.
Oct  7 19:38:36.209: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Oct  7 19:38:36.209: ISAKMP:(0):Old State = IKE_I_MM2  New State = IKE_I_MM3
Oct  7 19:38:36.233: ISAKMP (0): received packet from 15.18.1.1 dport 500 sport 500 Global (I) MM_SA_SETUP
Oct  7 19:38:36.233: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Oct  7 19:38:36.233: ISAKMP:(0):Old State = IKE_I_MM3  New State = IKE_I_MM4
Oct  7 19:38:36.233: ISAKMP:(0): processing KE payload. message ID = 0
Oct  7 19:38:36.245: ISAKMP:(0): processing NONCE payload. message ID = 0
Oct  7 19:38:36.245: ISAKMP:(8329): processing CERT_REQ payload. message ID = 0
Oct  7 19:38:36.245: ISAKMP:(8329): peer wants a CT_X509_SIGNATURE cert
Oct  7 19:38:36.245: ISAKMP:(8329): peer wants cert issued by cn=Tetra Pak Issuing NAD CA 01 - G1,dc=tp1,dc=ad1,dc=tetrapak,dc=com
Oct  7 19:38:36.249:  Choosing trustpoint TP_NAD_CA as issuer
Oct  7 19:38:36.249: ISAKMP:(8329): processing vendor id payload
Oct  7 19:38:36.249: ISAKMP:(8329): vendor ID is Unity
Oct  7 19:38:36.249: ISAKMP:(8329): processing vendor id payload
Oct  7 19:38:36.249: ISAKMP:(8329): vendor ID is DPD
Oct  7 19:38:36.249: ISAKMP:(8329): processing vendor id payload
Oct  7 19:38:36.249: ISAKMP:(8329): speaking to another IOS box!
Oct  7 19:38:36.249: ISAKMP:received payload type 20
Oct  7 19:38:36.249: ISAKMP (8329): His hash no match - this node outside NAT
Oct  7 19:38:36.249: ISAKMP:received payload type 20
Oct  7 19:38:36.249: ISAKMP (8329): No NAT Found for self or peer
Oct  7 19:38:36.249: ISAKMP:(8329):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Oct  7 19:38:36.249: ISAKMP:(8329):Old State = IKE_I_MM4  New State = IKE_I_MM4
Oct  7 19:38:36.249: ISAKMP:(8329):Send initial contact
Oct  7 19:38:36.249: ISAKMP:(8329): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer 15.18.1.1)
Oct  7 19:38:36.249: ISAKMP:(8329): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer 15.18.1.1)
Oct  7 19:38:36.249: ISAKMP:(8329): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer 15.18.1.1)
Oct  7 19:38:36.249: ISAKMP:(8329): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer 15.18.1.1)
Oct  7 19:38:36.249: ISAKMP:(8329):My ID configured as IPv4 Addr, but Addr not in Cert!
Oct  7 19:38:36.249: ISAKMP:(8329):Using FQDN as My ID
Oct  7 19:38:36.249: ISAKMP:(8329):SA is doing RSA signature authentication using id type ID_FQDN
Oct  7 19:38:36.249: ISAKMP (8329): ID payload
        next-payload : 6
        type         : 2
        FQDN name    : lvrirt-s2s-01.nvv.net.company.com
        protocol     : 17
        port         : 500
        length       : 42
Oct  7 19:38:36.249: ISAKMP:(8329):Total payload length: 42
Oct  7 19:38:36.249: ISAKMP:(8329): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer 15.18.1.1)
Oct  7 19:38:36.253: ISAKMP:(8329): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer 15.18.1.1)
Oct  7 19:38:36.253: ISAKMP (8329): constructing CERT payload for hostname=lvrirt-s2s-01.nvv.net.company.com,serialNumber=FCZ163860KW
Oct  7 19:38:36.253: ISKAMP: growing send buffer from 1024 to 3072
Oct  7 19:38:36.253: ISAKMP:(8329): using the TP_NAD_CA trustpoint's keypair to sign
Oct  7 19:38:36.449: ISAKMP:(8329): sending packet to 15.18.1.1 my_port 500 peer_port 500 (I) MM_KEY_EXCH
Oct  7 19:38:36.449: ISAKMP:(8329):Sending an IKE IPv4 Packet.
Oct  7 19:38:36.449: ISAKMP:(8329):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Oct  7 19:38:36.449: ISAKMP:(8329):Old State = IKE_I_MM4  New State = IKE_I_MM5
Oct  7 19:38:36.481: ISAKMP (8328): received packet from 15.18.1.1 dport 500 sport 500 Global (I) MM_NO_STATE
Oct  7 19:38:46.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH...
Oct  7 19:38:46.449: ISAKMP (8329): incrementing error counter on sa, attempt 1 of 5: retransmit phase 1
Oct  7 19:38:46.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH
Oct  7 19:38:46.449: ISAKMP:(8329): sending packet to 15.18.1.1 my_port 500 peer_port 500 (I) MM_KEY_EXCH
Oct  7 19:38:46.449: ISAKMP:(8329):Sending an IKE IPv4 Packet.
Oct  7 19:38:54.709: ISAKMP:(8327):purging node 1841056658
Oct  7 19:38:54.709: ISAKMP:(8327):purging node -57107868
Oct  7 19:38:56.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH...
Oct  7 19:38:56.449: ISAKMP (8329): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Oct  7 19:38:56.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH
Oct  7 19:38:56.449: ISAKMP:(8329): sending packet to 15.18.1.1 my_port 500 peer_port 500 (I) MM_KEY_EXCH
Oct  7 19:38:56.449: ISAKMP:(8329):Sending an IKE IPv4 Packet.
Oct  7 19:39:04.709: ISAKMP:(8327):purging SA., sa=3169E824, delme=3169E824
Oct  7 19:39:06.181: ISAKMP: set new node 0 to QM_IDLE
Oct  7 19:39:06.181: ISAKMP:(8329):SA is still budding. Attached new ipsec request to it. (local 2.8.51.58, remote 15.18.1.1)
Oct  7 19:39:06.181: ISAKMP: Error while processing SA request: Failed to initialize SA
Oct  7 19:39:06.181: ISAKMP: Error while processing KMI message 0, error 2.
Oct  7 19:39:06.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH...
Oct  7 19:39:06.449: ISAKMP (8329): incrementing error counter on sa, attempt 3 of 5: retransmit phase 1
Oct  7 19:39:06.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH
Oct  7 19:39:06.449: ISAKMP:(8329): sending packet to 15.18.1.1 my_port 500 peer_port 500 (I) MM_KEY_EXCH
Oct  7 19:39:06.449: ISAKMP:(8329):Sending an IKE IPv4 Packet.
Oct  7 19:39:10.261: ISAKMP:(8328):purging node -1445247076
Oct  7 19:39:16.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH...
Oct  7 19:39:16.449: ISAKMP (8329): incrementing error counter on sa, attempt 4 of 5: retransmit phase 1
Oct  7 19:39:16.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH
Oct  7 19:39:16.449: ISAKMP:(8329): sending packet to 15.18.1.1 my_port 500 peer_port 500 (I) MM_KEY_EXCH
Oct  7 19:39:16.449: ISAKMP:(8329):Sending an IKE IPv4 Packet.
Oct  7 19:39:20.261: ISAKMP:(8328):purging SA., sa=2AD85BD0, delme=2AD85BD0
Oct  7 19:39:26.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH...
Oct  7 19:39:26.449: ISAKMP (8329): incrementing error counter on sa, attempt 5 of 5: retransmit phase 1
Oct  7 19:39:26.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH
Oct  7 19:39:26.449: ISAKMP:(8329): sending packet to 15.18.1.1 my_port 500 peer_port 500 (I) MM_KEY_EXCH
Oct  7 19:39:26.449: ISAKMP:(8329):Sending an IKE IPv4 Packet.
Oct  7 19:39:36.449: ISAKMP:(8329): retransmitting phase 1 MM_KEY_EXCH...
Oct  7 19:39:36.449: ISAKMP:(8329):peer does not do paranoid keepalives.
Oct  7 19:39:36.449: ISAKMP:(8329):deleting SA reason "Death by retransmission P1" state (I) MM_KEY_EXCH (peer 15.18.1.1)
Oct  7 19:39:36.449: ISAKMP:(8329):deleting SA reason "Death by retransmission P1" state (I) MM_KEY_EXCH (peer 15.18.1.1)

1 ACCEPTED SOLUTION

Accepted Solutions
Cisco Employee

DMVPN phase I fails when migrating from PSK to RSIG

Mike,

Hub sends its cert but spoke never recives that, this is typically a problem with fragmentation handling in transit networks.

Sniff both end you control and check whether you're not missing any fragments on spoke end.

Could be as simple as an MTU problem on your end or could be something in the path attempting reassambly.

Multiple ways to go, check your end, if fragments are missing in transit - start investigating with ISP(s).

M.

7 REPLIES
Cisco Employee

DMVPN phase I fails when migrating from PSK to RSIG

Mike,

Hub sends its cert but spoke never recives that, this is typically a problem with fragmentation handling in transit networks.

Sniff both end you control and check whether you're not missing any fragments on spoke end.

Could be as simple as an MTU problem on your end or could be something in the path attempting reassambly.

Multiple ways to go, check your end, if fragments are missing in transit - start investigating with ISP(s).

M.

Community Member

DMVPN phase I fails when migrating from PSK to RSIG

Marcin,

Thanks, it looks like the fragments are getting lost in transit. I'll need to convince the ISP to resolve the issue.

/Mike

Cisco Employee

DMVPN phase I fails when migrating from PSK to RSIG

Mike,

If you're not in production yet, lower the hub's physical interface's MTU to something like 1300 bytes. It might be a question of double fragmentation, in which case you might be able to work it around, while it's being looked into.

M.

Community Member

DMVPN phase I fails when migrating from PSK to RSIG

Marcen,

Unfortunately it's already a production network so I am at the mercy of the ISP. Thanks for the suggestion.

/MIke

Cisco Employee

DMVPN phase I fails when migrating from PSK to RSIG

Mike,

Another possibility

IF you're willing to try IKEv2 between failing spokes and hub

http://www.cisco.com/en/US/docs/ios-xml/ios/security/a1/sec-cr-c3.html#wp3510722946

You can make fragmentation on IKE level instead of IP...

There's a similar command for IKEv1 but AFAIU it does not work with DMVPN.

M.

Community Member

DMVPN phase I fails when migrating from PSK to RSIG

Marcin,

Very insteresting. Is it possible to run both IKEV1 and IKEV2 spokes on the same DMVPN hub? I would assume that I would need to create another tunnel interface to support the V2 Clients. I could then migrate all of my existing spokes to V2.

/Mike

Cisco Employee

DMVPN phase I fails when migrating from PSK to RSIG

Mike,

What we had problems before is mixing v1 and v2 on same source interfaces. It was just not working.

1) Use different source interface for v1 and v2

2) Move hub to 15.3(3)M  (AFAIR)

But you're right for most setups there is a problem to share same source interface for v1 and v2.

M.

905
Views
0
Helpful
7
Replies
CreatePlease to create content