06-04-2018 03:03 AM - edited 03-08-2019 03:14 PM
Hello everyone,
I am managing a DMVPN infrastructure with two Hubs and around a thousand of Spokes.
There is approximatively all Spokes "Tunnel 2" going to Hub2 UP and running well.
I had move the HUB1 from a datacenter to another and since, i have around 70% of the Spokes "Tunnel 1" that are coming backed.
For thoses who are not working fine i've investigate many days and found that there is an issue on IKE phase 1 just after MM_5. This is not going to MM_6 SA Authenticated.
If i'm configuring the Spoke With a Pre-share key, all the phases goes well and the tunnel is UP.
There is no issue around UDP 500 / UDP 4500 blocked trafic as i've made some capture trafic and able to see the trames going through. (And like i said if i use a preshare key the tunnel goes UP).
I've tried to delete and renew the trustpoint with new CA and new receiving a new Certificate but still...
So...
I'm having a HUB with the following configuration :
#show crypto isakmp policy Global IKE policy Protection suite of priority 1 encryption algorithm: AES - Advanced Encryption Standard (256 bit keys). hash algorithm: Secure Hash Standard authentication method: Pre-Shared Key Diffie-Hellman group: #2 (1024 bit) lifetime: 86400 seconds, no volume limit Protection suite of priority 2 encryption algorithm: AES - Advanced Encryption Standard (256 bit keys). hash algorithm: Secure Hash Standard authentication method: Pre-Shared Key Diffie-Hellman group: #2 (1024 bit) lifetime: 86400 seconds, no volume limit Protection suite of priority 3 encryption algorithm: AES - Advanced Encryption Standard (256 bit keys). hash algorithm: Secure Hash Standard authentication method: Rivest-Shamir-Adleman Signature Diffie-Hellman group: #1 (768 bit) lifetime: 86400 seconds, no volume limit Protection suite of priority 10 encryption algorithm: AES - Advanced Encryption Standard (256 bit keys). hash algorithm: Secure Hash Standard authentication method: Pre-Shared Key Diffie-Hellman group: #2 (1024 bit) lifetime: 28800 seconds, no volume limit Protection suite of priority 20 encryption algorithm: DES - Data Encryption Standard (56 bit keys). hash algorithm: Secure Hash Standard authentication method: Rivest-Shamir-Adleman Signature Diffie-Hellman group: #1 (768 bit) lifetime: 86400 seconds, no volume limit Protection suite of priority 42 encryption algorithm: AES - Advanced Encryption Standard (256 bit keys). hash algorithm: Secure Hash Standard authentication method: Pre-Shared Key Diffie-Hellman group: #2 (1024 bit) lifetime: 86400 seconds, no volume limit
And Spokes with this configuration :
#show crypto isakmp policy Global IKE policy Protection suite of priority 1 encryption algorithm: AES - Advanced Encryption Standard (256 bit keys). hash algorithm: Secure Hash Standard authentication method: Rivest-Shamir-Adleman Signature Diffie-Hellman group: #1 (768 bit) lifetime: 86400 seconds, no volume limit
So the Policy 1 pf the Spoke Match the Policy 3 of the HUB.
If i do a "show crypto pki certificates verbose" on the Spoke, i can see that the certificate is valide and active.
If i enable "debug dmvpn all all" on the spokes i have no indication on any certificate error or ISAKMP error.
I'm staying here for the moment in my explaination. I will provide some configuration lines and debug lines to help you help me in the resolution.
Hope you'll be able to help me it's quite annoying !
Thanks a lot in advance.
Best,
06-04-2018 04:04 AM
Hello,
post the full configs of the hub and a non-working spoke...
06-04-2018 06:59 AM - edited 06-04-2018 07:24 AM
HUB01
! version 15.5 no service pad service tcp-keepalives-in service tcp-keepalives-out service timestamps debug datetime localtime show-timezone service timestamps log datetime msec localtime show-timezone service password-encryption no platform punt-keepalive disable-kernel-core ! hostname HUB01 ! boot-start-marker boot system flash bootflash:asr1001x-universalk9.03.15.01.S.155-2.S1-std.SPA.bin boot system flash bootflash:asr1001x-universalk9.03.13.02.S.154-3.S2-ext.SPA.bin boot-end-marker ! ! vrf definition Mgmt-intf ! address-family ipv4 exit-address-family ! address-family ipv6 exit-address-family ! security authentication failure rate 10 log security passwords min-length 6 logging buffered 256000 no logging console enable secret 5 XX ! aaa new-model ! ! aaa group server radius radius1 server X.X.X.X attribute nas-port none ! aaa authentication login default local ! ! ! ! ! aaa session-id common clock timezone GMT 0 0 no ip source-route no ip gratuitous-arps ! ! ! ! ! ! ! ! ! no ip bootp server ip domain name XX.XX ip name-server 8.8.8.8 ! ! ! ! ! ! ! ! ! ! subscriber templating ! multilink bundle-name authenticated ! ! ! ! ! ! ! ! crypto pki trustpoint X.X.X.X enrollment mode ra enrollment url http://X.X.X.X:P/certsrv/mscep/mscep.dll revocation-check none ! ! crypto pki certificate chain X.X.X.X certificate XX XX quit certificate ca XX XX quit archive path tftp://X.X.X.X/Hub01_ASR1001-X_Config_ write-memory time-period 720 spanning-tree extend system-id ! username XX privilege 15 password 7 XX ! redundancy mode none ! ! ! ! ! ! ip ssh maxstartups 5 ip ssh time-out 60 ip ssh authentication-retries 4 ip ssh logging events ip ssh version 2 ip ssh pubkey-chain username X key-hash ssh-rsa XX lldp run ! ! ! ! ! ! ! crypto isakmp policy 1 encr aes 256 authentication pre-share group 2 ! crypto isakmp policy 2 encr aes 256 authentication pre-share group 2 ! crypto isakmp policy 3 encr aes 256 ! crypto isakmp policy 10 encr aes 256 authentication pre-share group 2 lifetime 28800 ! crypto isakmp policy 20 ! crypto isakmp policy 42 encr aes 256 authentication pre-share group 2 crypto isakmp invalid-spi-recovery crypto isakmp keepalive 120 ! ! ! crypto ipsec transform-set CLIENT_SET esp-aes 256 esp-sha-hmac mode tunnel crypto ipsec transform-set trans2 esp-3des esp-md5-hmac mode tunnel crypto ipsec transform-set trans1 esp-aes 256 esp-md5-hmac mode transport require crypto ipsec transform-set trans3 esp-aes 256 esp-sha-hmac mode tunnel crypto ipsec transform-set trans4 esp-aes 256 esp-sha-hmac mode tunnel crypto ipsec nat-transparency spi-matching ! crypto ipsec profile VPNCLIENT set transform-set CLIENT_SET ! ! crypto ipsec profile vpnprof set transform-set trans1 ! ! crypto dynamic-map VPNCLIENT 100 set transform-set CLIENT_SET ! ! ! ! ! ! ! ! ! ! interface Loopback1 no ip address shutdown ! interface Tunnel1 bandwidth 50000 ip address 10.243.31.254 255.255.224.0 no ip redirects ip mtu 1300 ip nat inside ip hello-interval eigrp 1 30 ip hold-time eigrp 1 90 ip nhrp authentication XX ip nhrp map multicast dynamic ip nhrp network-id XX ip nhrp holdtime 360 ip nhrp registration no-unique ip nhrp redirect ip summary-address eigrp 1 10.241.0.0 255.255.0.0 ip tcp adjust-mss 1260 delay 1200 tunnel source GigabitEthernet0/0/0 tunnel mode gre multipoint tunnel key XX tunnel path-mtu-discovery tunnel protection ipsec profile vpnprof ip virtual-reassembly no ip virtual-reassembly-out ! interface TenGigabitEthernet0/0/0 no ip address shutdown ! interface TenGigabitEthernet0/0/1 no ip address shutdown ! interface GigabitEthernet0/0/0 description Public Interface ip address XX XX ip mtu 1480 ip nat outside ip access-group WANInterface in ip tcp adjust-mss 1440 negotiation auto crypto map VPN crypto ipsec fragmentation after-encryption ip virtual-reassembly ip virtual-reassembly-out ! interface GigabitEthernet0/0/1 description Private LAN ip address X.X.X.X 255.255.255.0 ip nat inside ip access-group LANInterface in negotiation auto ip virtual-reassembly ! interface GigabitEthernet0/0/2 ip address X.X.X.X 255.255.255.0 ip nat inside ip access-group XX in negotiation auto ip virtual-reassembly ! interface GigabitEthernet0/0/3 no ip address shutdown negotiation auto ! interface GigabitEthernet0/0/4 no ip address shutdown negotiation auto ! interface GigabitEthernet0/0/5 no ip address shutdown negotiation auto ! interface GigabitEthernet0 vrf forwarding Mgmt-intf no ip address shutdown negotiation auto ! interface Virtual-Template1 type tunnel ip unnumbered GigabitEthernet0/0/0 tunnel mode ipsec ipv4 tunnel protection ipsec profile VPNCLIENT ip virtual-reassembly ! ! router eigrp 1 distribute-list EIGRP_distribute out network X 0.0.31.255 network X 0.0.0.255 redistribute static passive-interface default no passive-interface Tunnel1 no eigrp log-neighbor-changes no eigrp log-neighbor-warnings ! ip nat log translations syslog ip nat translation timeout 120 ip nat translation tcp-timeout 120 ip nat translation udp-timeout 60 ip nat translation max-entries 1000000 ip nat inside source list NAT_Internet interface GigabitEthernet0/0/0 overload ip forward-protocol nd ! no ip http server no ip http secure-server ! ! ! ip radius source-interface GigabitEthernet0/0/1 no logging trap ! ! ! ! radius-server attribute 4 X radius-server host X timeout 120 retransmit 4 key 7 XX ! radius server RadiusMaster ! ! control-plane ! ! ! ! ! ! ! ! ! ! line con 0 length 0 stopbits 1 line aux 0 stopbits 1 line vty 0 4 access-class 1 in exec-timeout 30 0 transport input ssh ! ntp server 3.be.pool.ntp.org minpoll 10 ! end
Spoke
version 15.1 no service pad service timestamps debug datetime localtime service timestamps log datetime localtime service password-encryption ! hostname SPOKE_1255 ! boot-start-marker boot-end-marker ! ! logging buffered 64000 no logging console enable secret 5 XX ! aaa new-model ! ! aaa authentication login default local ! ! ! ! ! aaa session-id common ! memory-size iomem 10 clock timezone GMT 0 0 clock summer-time GMT+1 recurring last Sun Mar 0:00 last Sun Oct 0:00 crypto pki token default removal timeout 0 ! crypto pki trustpoint hub02.X.X:P enrollment mode ra enrollment url http://hub02.X.X:P/certsrv/mscep/mscep.dll revocation-check crl none ! crypto pki trustpoint hub01.X.X:P enrollment mode ra enrollment url http://hub01.X.X:P/certsrv/mscep/mscep.dll revocation-check crl none ! ! crypto pki certificate chain hub02.X.X:PP certificate XX XX quit certificate ca XX XX quit crypto pki certificate chain hub01.X.X:PP certificate X XX quit certificate ca XX XX quit ip source-route ! ! ! ! ! ip cef ip domain name X.X ip inspect name FW ftp timeout 3600 ip inspect name FW h323 timeout 3600 ip inspect name FW http timeout 3600 ip inspect name FW rcmd timeout 3600 ip inspect name FW realaudio timeout 3600 ip inspect name FW smtp timeout 3600 ip inspect name FW sqlnet timeout 3600 ip inspect name FW streamworks timeout 3600 ip inspect name FW tcp timeout 3600 ip inspect name FW tftp timeout 30 ip inspect name FW udp timeout 15 ip inspect name FW dns ip inspect name FW vdolive timeout 3600 no ipv6 cef ! ! multilink bundle-name authenticated ! ! username XX password 7 XX ! ! ! ! ip ssh time-out 60 ip ssh version 2 ! ! crypto isakmp policy 1 encr aes 256 crypto isakmp keepalive 120 ! ! crypto ipsec transform-set trans1 esp-aes 256 esp-md5-hmac mode transport require ! crypto ipsec profile vpnprof1 set security-association idle-time 120 set transform-set trans1 ! crypto ipsec profile vpnprof2 set security-association idle-time 120 set transform-set trans1 ! ! ! ! ! ! interface Loopback1 ip address 1.1.5.235 255.255.255.255 ip nat inside ip virtual-reassembly in ip tcp adjust-mss 1452 ! interface Tunnel1 bandwidth 1000 ip address 10.243.4.235 255.255.224.0 no ip redirects ip mtu 1400 ip nat outside ip nhrp authentication XX ip nhrp map 10.243.31.254 HUB01_IP ip nhrp map multicast HUB01_IP ip nhrp network-id XX ip nhrp holdtime 600 ip nhrp nhs 10.243.31.254 ip virtual-reassembly in ip tcp adjust-mss 1360 delay 1000 tunnel source FastEthernet4 tunnel mode gre multipoint tunnel key XX tunnel protection ipsec profile vpnprof1 shared ! interface Tunnel2 bandwidth 1000 ip address 10.243.36.235 255.255.224.0 no ip redirects ip mtu 1400 ip nat outside ip nhrp authentication XX ip nhrp map 10.243.63.254 HUB02_IP ip nhrp map multicast HUB02_IP ip nhrp network-id XX ip nhrp holdtime 600 ip nhrp nhs 10.243.63.254 ip virtual-reassembly in ip tcp adjust-mss 1360 delay 1100 tunnel source FastEthernet4 tunnel mode gre multipoint tunnel key XX tunnel protection ipsec profile vpnprof2 shared ! interface FastEthernet0 spanning-tree portfast ! interface FastEthernet1 spanning-tree portfast ! interface FastEthernet2 spanning-tree portfast ! interface FastEthernet3 spanning-tree portfast ! interface FastEthernet4 ip address dhcp ip access-group Filter_OUT in ip nat outside ip virtual-reassembly in duplex auto speed auto ! interface Vlan1 description ***Local LAN*** ip address 172.20.0.1 255.255.0.0 ip access-group Filter_IN in ip nat inside ip inspect FW in ip virtual-reassembly in ! ! router eigrp 1 distribute-list Distribute out Tunnel1 distribute-list Distribute out Tunnel2 network X 0.0.31.255 network X 0.0.31.255 redistribute static offset-list 10 in 10 Tunnel2 passive-interface default no passive-interface Tunnel1 no passive-interface Tunnel2 ! ip forward-protocol nd no ip http server no ip http secure-server ! ! ip dns server ip nat inside source list NAT_Internet interface FastEthernet4 overload ip route 0.0.0.0 0.0.0.0 dhcp ! ip access-list standard Distribute permit 10.89.204.0 0.0.1.255 ! ip access-list extended Filter_IN permit ip 172.20.0.0 0.0.255.255 10.242.0.0 0.0.255.255 permit ip 172.20.0.0 0.0.255.255 10.240.0.0 0.0.0.255 permit ip 172.20.0.0 0.0.255.255 10.241.0.0 0.0.0.255 permit ip 172.20.0.0 0.0.255.255 10.244.255.0 0.0.0.255 permit ip 172.20.0.0 0.0.255.255 10.244.254.0 0.0.0.255 deny ip 172.20.0.0 0.0.255.255 10.0.0.0 0.255.255.255 permit ip 172.20.0.0 0.0.255.255 any permit gre 172.20.0.0 0.0.255.255 any permit esp 172.20.0.0 0.0.255.255 any ip access-list extended Filter_OUT permit ip host HUB01 any permit icmp any any unreachable permit icmp any any echo-reply permit icmp any any packet-too-big permit icmp any any time-exceeded permit icmp any any traceroute permit icmp any any administratively-prohibited permit icmp any any echo permit tcp any any eq 22 permit udp any any eq bootpc permit udp any eq domain any permit gre any any permit ip host HUB02 any permit esp host HUB01 any ip access-list extended NAT_Internal permit ip 172.20.0.0 0.0.255.255 10.0.0.0 0.255.255.255 ip access-list extended NAT_Internet deny ip 172.20.0.0 0.0.255.255 10.0.0.0 0.255.255.255 permit ip 172.20.0.0 0.0.255.255 any ! logging esm config no cdp run ! ! ! ! route-map NAT_Internal permit 10 match ip address NAT_Internal ! ! ! control-plane ! ! line con 0 logging synchronous no modem enable line aux 0 line vty 0 4 logging synchronous transport input ssh ! ntp server 10.243.31.254 ntp server 10.243.63.254 end
06-04-2018 07:16 AM
Debug Spoke (debug dmvpn all all)
Jun 1 10:29:24: IPSEC-IFC MGRE/Tu1[shared]: Checking tunnel status. Jun 1 10:29:24: IPSEC-IFC MGRE/Tu1[shared]: tunnel coming up Jun 1 10:29:24: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:29:24: CRYPTO_SS(TUNNEL SEC): Application started listening Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared]: Socket 87C36B58 for HUB01_IP not open or does not exist Jun 1 10:29:25: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:29:25: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:29:25: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:29:25: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:29:25: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:29:25: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:29:25: ISAKMP: New peer created peer = 0x8847D7E0 peer_handle = 0x8000644D Jun 1 10:29:25: ISAKMP: Locking peer struct 0x8847D7E0, refcount 1 for isakmp_initiator Jun 1 10:29:25: ISAKMP: local port 500, remote port 500 Jun 1 10:29:25: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:29:25: ISAKMP:(0):insert sa successfully sa = 87BF14CC Jun 1 10:29:25: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:29:25: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:29:25: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:29:25: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:29:25: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:29:25: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:29:25: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:29:25: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:29:25: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:29:25: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:29:25: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:29:25: %SYS-5-CONFIG_I: Configured from console by admin on vty0 ( ) Jun 1 10:29:25: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:29:25: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:29:25: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:29:25: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:29:25: ISAKMP:(0): processing vendor id payload Jun 1 10:29:25: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:29:25: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:29:25: ISAKMP : Scanning profiles for xauth ... Jun 1 10:29:25: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:29:25: ISAKMP: encryption AES-CBC Jun 1 10:29:25: ISAKMP: keylength of 256 Jun 1 10:29:25: ISAKMP: hash SHA Jun 1 10:29:25: ISAKMP: default group 1 Jun 1 10:29:25: ISAKMP: auth RSA sig Jun 1 10:29:25: ISAKMP: life type in seconds Jun 1 10:29:25: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:29:25: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:29:25: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:29:25: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:29:25: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:29:25: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:29:25: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:29:25: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:29:25: ISAKMP:(0): processing vendor id payload Jun 1 10:29:25: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:29:25: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:29:25: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:29:25: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:29:25: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:25: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:29:25: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:29:25: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:29:25: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:29:25: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:29:25: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:29:25: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:29:25: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:29:25: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:29:25: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:29:25: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:29:25: ISAKMP:(2111): processing CERT_REQ payload. message ID = 0 Jun 1 10:29:25: ISAKMP:(2111): peer wants a CT_X509_SIGNATURE cert Jun 1 10:29:25: ISAKMP:(2111): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:29:25: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:29:25: ISAKMP:(2111): processing vendor id payload Jun 1 10:29:25: ISAKMP:(2111): vendor ID is Unity Jun 1 10:29:25: ISAKMP:(2111): processing vendor id payload Jun 1 10:29:25: ISAKMP:(2111): vendor ID is DPD Jun 1 10:29:25: ISAKMP:(2111): processing vendor id payload Jun 1 10:29:25: ISAKMP:(2111): speaking to another IOS box! Jun 1 10:29:25: ISAKMP:received payload type 20 Jun 1 10:29:25: ISAKMP (2111): NAT found, both nodes inside NAT Jun 1 10:29:25: ISAKMP:received payload type 20 Jun 1 10:29:25: ISAKMP (2111): My hash no match - this node inside NAT Jun 1 10:29:25: ISAKMP:(2111):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:29:25: ISAKMP:(2111):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:29:25: ISAKMP:(2111):Send initial contact Jun 1 10:29:25: ISAKMP:(2111): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(2111): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(2111): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(2111): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(2111):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:29:25: ISAKMP:(2111):Using FQDN as My ID Jun 1 10:29:25: ISAKMP:(2111):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:29:25: ISAKMP (2111): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:29:25: ISAKMP:(2111):Total payload length: 25 Jun 1 10:29:25: ISAKMP:(2111): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:25: ISAKMP:(2111): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:25: ISAKMP (2111): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:29:25: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:29:25: ISAKMP:(2111): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:29:25: ISAKMP:(2111): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:29:25: ISAKMP:(2111):Sending an IKE IPv4 Packet. Jun 1 10:29:25: ISAKMP:(2111):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:29:25: ISAKMP:(2111):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:29:25: ISAKMP (0): received packet from HUB01_IP dport 4500 sport 4500 Global (N) NEW SA SPOKE_0268# Jun 1 10:29:25: %CRYPTO-4-IKMP_NO_SA: IKE message from HUB01_IP has no SA and is not an initialization offer Jun 1 10:29:26: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:26: %LINK-3-UPDOWN: Interface Tunnel1, changed state to up Jun 1 10:29:26: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:26: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 80 < 1000 Jun 1 10:29:26: IPSEC-IFC MGRE/Tu1[shared]: tunnel coming up Jun 1 10:29:26: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:29:26: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:29:26: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:29:26: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:26: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Socket is already open. Ignoring. SPOKE_0268# Jun 1 10:29:26: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel1, changed state to up SPOKE_0268# Jun 1 10:29:27: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:29:27: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:27: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 284 < 1000 SPOKE_0268# Jun 1 10:29:31: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:32: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 608 < 1000 Jun 1 10:29:32: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 608 < 1000 Jun 1 10:29:32: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:32: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:29:32: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:29:32: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:29:32: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:29:32: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:29:32: ISAKMP:(2111):peer does not do paranoid keepalives. Jun 1 10:29:32: ISAKMP:(2111):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:32: ISAKMP:(2111):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:32: ISAKMP: Unlocking peer struct 0x8847D7E0 for isadb_mark_sa_deleted(), count 0 Jun 1 10:29:32: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 8847D7E0 Jun 1 10:29:32: ISAKMP:(2111):deleting node -779529369 error FALSE reason "IKE deleted" Jun 1 10:29:32: ISAKMP:(2111): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:32: ISAKMP:(2111): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:32: ISAKMP:(2111):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:29:32: ISAKMP:(2111):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:29:32: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared]: Socket 87454954 for HUB01_IP not open or does not exist Jun 1 10:29:39: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:29:39: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:29:39: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:29:39: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:29:39: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:29:39: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:29:39: ISAKMP: New peer created peer = 0x87C36B58 peer_handle = 0x8000644F Jun 1 10:29:39: ISAKMP: Locking peer struct 0x87C36B58, refcount 1 for isakmp_initiator Jun 1 10:29:39: ISAKMP: local port 500, remote port 500 Jun 1 10:29:39: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:29:39: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87BF0498 Jun 1 10:29:39: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:29:39: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:29:39: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:29:39: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:29:39: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:29:39: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:29:39: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:29:39: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:29:39: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:29:39: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:29:39: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:29:39: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:29:39: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:29:39: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:29:39: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:29:39: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:29:39: ISAKMP:(0): processing vendor id payload Jun 1 10:29:39: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:29:39: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:29:39: ISAKMP : Scanning profiles for xauth ... Jun 1 10:29:39: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:29:39: ISAKMP: encryption AES-CBC Jun 1 10:29:39: ISAKMP: keylength of 256 Jun 1 10:29:39: ISAKMP: hash SHA Jun 1 10:29:39: ISAKMP: default group 1 Jun 1 10:29:39: ISAKMP: auth RSA sig Jun 1 10:29:39: ISAKMP: life type in seconds Jun 1 10:29:39: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:29:39: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:29:39: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:29:39: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:29:39: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:29:39: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:29:39: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:29:39: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:29:39: ISAKMP:(0): processing vendor id payload Jun 1 10:29:39: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:29:39: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:29:39: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:29:39: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:29:39: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:39: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:29:39: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:29:39: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:29:39: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:29:39: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:29:39: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:29:39: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:29:39: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:29:39: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:29:39: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:29:39: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:29:39: ISAKMP:(2112): processing CERT_REQ payload. message ID = 0 Jun 1 10:29:39: ISAKMP:(2112): peer wants a CT_X509_SIGNATURE cert Jun 1 10:29:39: ISAKMP:(2112): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:29:39: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:29:39: ISAKMP:(2112): processing vendor id payload Jun 1 10:29:39: ISAKMP:(2112): vendor ID is Unity Jun 1 10:29:39: ISAKMP:(2112): processing vendor id payload Jun 1 10:29:39: ISAKMP:(2112): vendor ID is DPD Jun 1 10:29:39: ISAKMP:(2112): processing vendor id payload Jun 1 10:29:39: ISAKMP:(2112): speaking to another IOS box! Jun 1 10:29:39: ISAKMP:received payload type 20 Jun 1 10:29:39: ISAKMP (2112): NAT found, both nodes inside NAT Jun 1 10:29:39: ISAKMP:received payload type 20 Jun 1 10:29:39: ISAKMP (2112): My hash no match - this node inside NAT Jun 1 10:29:39: ISAKMP:(2112):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:29:39: ISAKMP:(2112):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:29:39: ISAKMP:(2112):Send initial contact Jun 1 10:29:39: ISAKMP:(2112): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(2112): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(2112): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(2112): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(2112):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:29:39: ISAKMP:(2112):Using FQDN as My ID Jun 1 10:29:39: ISAKMP:(2112):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:29:39: ISAKMP (2112): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:29:39: ISAKMP:(2112):Total payload length: 25 Jun 1 10:29:39: ISAKMP:(2112): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:39: ISAKMP:(2112): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:39: ISAKMP (2112): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:29:39: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:29:39: ISAKMP:(2112): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:29:39: ISAKMP:(2112): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:29:39: ISAKMP:(2112):Sending an IKE IPv4 Packet. Jun 1 10:29:39: ISAKMP:(2112):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:29:39: ISAKMP:(2112):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:29:39: ISAKMP (2111): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:29:40: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 SPOKE_0268# Jun 1 10:29:41: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 916 < 1000 Jun 1 10:29:41: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 916 < 1000 SPOKE_0268# Jun 1 10:29:42: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 SPOKE_0268# Jun 1 10:29:44: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 SPOKE_0268# Jun 1 10:29:45: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:29:45: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 536 < 1000 Jun 1 10:29:45: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 536 < 1000 Jun 1 10:29:46: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:29:46: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:29:46: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:29:46: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:29:46: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:29:46: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:29:46: ISAKMP:(2112):peer does not do paranoid keepalives. Jun 1 10:29:46: ISAKMP:(2112):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:46: ISAKMP:(2111):peer does not do paranoid keepalives. Jun 1 10:29:46: ISAKMP:(2112):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:46: ISAKMP: Unlocking peer struct 0x87C36B58 for isadb_mark_sa_deleted(), count 0 Jun 1 10:29:46: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 87C36B58 Jun 1 10:29:46: ISAKMP:(2112):deleting node 104430948 error FALSE reason "IKE deleted" Jun 1 10:29:46: ISAKMP:(2112): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:46: ISAKMP:(2112): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:46: ISAKMP:(2112):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:29:46: ISAKMP:(2112):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:29:46: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared]: Socket 87C36B58 for HUB01_IP not open or does not exist Jun 1 10:29:51: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:29:51: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:29:51: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:29:51: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:29:51: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:29:51: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:29:51: ISAKMP: New peer created peer = 0x87F130E8 peer_handle = 0x80006451 Jun 1 10:29:51: ISAKMP: Locking peer struct 0x87F130E8, refcount 1 for isakmp_initiator Jun 1 10:29:51: ISAKMP: local port 500, remote port 500 Jun 1 10:29:51: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:29:51: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87B3DC10 Jun 1 10:29:51: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:29:51: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:29:51: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:29:51: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:29:51: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:29:51: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:29:51: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:29:51: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:29:51: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:29:51: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:29:51: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:51: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:29:51: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:29:51: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:29:51: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:29:51: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:29:51: ISAKMP:(0): processing vendor id payload Jun 1 10:29:51: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:29:51: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:29:51: ISAKMP : Scanning profiles for xauth ... Jun 1 10:29:51: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:29:51: ISAKMP: encryption AES-CBC Jun 1 10:29:51: ISAKMP: keylength of 256 Jun 1 10:29:51: ISAKMP: hash SHA Jun 1 10:29:51: ISAKMP: default group 1 Jun 1 10:29:51: ISAKMP: auth RSA sig Jun 1 10:29:51: ISAKMP: life type in seconds Jun 1 10:29:51: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:29:51: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:29:51: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:29:51: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:29:51: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:29:51: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:29:51: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:29:51: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:29:51: ISAKMP:(0): processing vendor id payload Jun 1 10:29:51: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:29:51: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:29:51: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:29:51: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:29:51: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:29:51: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:29:51: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:29:51: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:29:51: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:29:51: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:29:51: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:29:51: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:29:51: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:29:51: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:29:51: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:29:51: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:29:51: ISAKMP:(2113): processing CERT_REQ payload. message ID = 0 Jun 1 10:29:51: ISAKMP:(2113): peer wants a CT_X509_SIGNATURE cert Jun 1 10:29:51: ISAKMP:(2113): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:29:51: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:29:51: ISAKMP:(2113): processing vendor id payload Jun 1 10:29:51: ISAKMP:(2113): vendor ID is Unity Jun 1 10:29:51: ISAKMP:(2113): processing vendor id payload Jun 1 10:29:51: ISAKMP:(2113): vendor ID is DPD Jun 1 10:29:51: ISAKMP:(2113): processing vendor id payload Jun 1 10:29:51: ISAKMP:(2113): speaking to another IOS box! Jun 1 10:29:51: ISAKMP:received payload type 20 Jun 1 10:29:51: ISAKMP (2113): NAT found, both nodes inside NAT Jun 1 10:29:51: ISAKMP:received payload type 20 Jun 1 10:29:51: ISAKMP (2113): My hash no match - this node inside NAT Jun 1 10:29:51: ISAKMP:(2113):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:29:51: ISAKMP:(2113):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:29:51: ISAKMP:(2113):Send initial contact Jun 1 10:29:51: ISAKMP:(2113): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(2113): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(2113): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(2113): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(2113):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:29:51: ISAKMP:(2113):Using FQDN as My ID Jun 1 10:29:51: ISAKMP:(2113):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:29:51: ISAKMP (2113): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:29:51: ISAKMP:(2113):Total payload length: 25 Jun 1 10:29:51: ISAKMP:(2113): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:51: ISAKMP:(2113): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:51: ISAKMP (2113): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:29:51: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:29:51: ISAKMP:(2113): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:29:51: ISAKMP:(2113): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:29:51: ISAKMP:(2113):Sending an IKE IPv4 Packet. Jun 1 10:29:51: ISAKMP:(2113):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:29:51: ISAKMP:(2113):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:29:51: ISAKMP (2112): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:29:52: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 SPOKE_0268# Jun 1 10:29:54: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:54: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 92 < 1000 Jun 1 10:29:54: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 92 < 1000 Jun 1 10:29:54: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 488 < 1000 Jun 1 10:29:54: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 488 < 1000 SPOKE_0268# Jun 1 10:29:57: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:58: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:29:58: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:29:58: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:29:58: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:29:58: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:29:58: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:29:58: ISAKMP:(2113):peer does not do paranoid keepalives. Jun 1 10:29:58: ISAKMP:(2113):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:58: ISAKMP:(2112):peer does not do paranoid keepalives. Jun 1 10:29:58: ISAKMP:(2111):peer does not do paranoid keepalives. Jun 1 10:29:58: ISAKMP:(2113):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:29:58: ISAKMP: Unlocking peer struct 0x87F130E8 for isadb_mark_sa_deleted(), count 0 Jun 1 10:29:58: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 87F130E8 Jun 1 10:29:58: ISAKMP:(2113):deleting node 1779760591 error FALSE reason "IKE deleted" Jun 1 10:29:58: ISAKMP:(2113): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:58: ISAKMP:(2113): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:29:58: ISAKMP:(2113):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:29:58: ISAKMP:(2113):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:29:58: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 8763F940 Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared]: Socket 8763F940 for HUB01_IP not open or does not exist Jun 1 10:30:05: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:30:05: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:05: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:30:05: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:30:05: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:30:05: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:30:05: ISAKMP: New peer created peer = 0x87454954 peer_handle = 0x80006453 Jun 1 10:30:05: ISAKMP: Locking peer struct 0x87454954, refcount 1 for isakmp_initiator Jun 1 10:30:05: ISAKMP: local port 500, remote port 500 Jun 1 10:30:05: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:30:05: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87D82C70 Jun 1 10:30:05: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:30:05: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:30:05: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:30:05: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:30:05: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:30:05: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:30:05: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:30:05: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:30:05: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:30:05: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:30:05: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 8763F940 Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:30:05: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:30:05: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:05: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:30:05: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:30:05: ISAKMP:(0): processing vendor id payload Jun 1 10:30:05: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:05: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:05: ISAKMP : Scanning profiles for xauth ... Jun 1 10:30:05: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:30:05: ISAKMP: encryption AES-CBC Jun 1 10:30:05: ISAKMP: keylength of 256 Jun 1 10:30:05: ISAKMP: hash SHA Jun 1 10:30:05: ISAKMP: default group 1 Jun 1 10:30:05: ISAKMP: auth RSA sig Jun 1 10:30:05: ISAKMP: life type in seconds Jun 1 10:30:05: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:30:05: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:30:05: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:30:05: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:30:05: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:30:05: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:30:05: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:30:05: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:30:05: ISAKMP:(0): processing vendor id payload Jun 1 10:30:05: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:05: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:05: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:05: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:30:05: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:05: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:05: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:30:05: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:30:05: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:05: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:30:05: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:30:05: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:30:05: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:05: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:30:05: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:30:05: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:30:05: ISAKMP:(2114): processing CERT_REQ payload. message ID = 0 Jun 1 10:30:05: ISAKMP:(2114): peer wants a CT_X509_SIGNATURE cert Jun 1 10:30:05: ISAKMP:(2114): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:05: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:30:05: ISAKMP:(2114): processing vendor id payload Jun 1 10:30:05: ISAKMP:(2114): vendor ID is Unity Jun 1 10:30:05: ISAKMP:(2114): processing vendor id payload Jun 1 10:30:05: ISAKMP:(2114): vendor ID is DPD Jun 1 10:30:05: ISAKMP:(2114): processing vendor id payload Jun 1 10:30:05: ISAKMP:(2114): speaking to another IOS box! Jun 1 10:30:05: ISAKMP:received payload type 20 Jun 1 10:30:05: ISAKMP (2114): NAT found, both nodes inside NAT Jun 1 10:30:05: ISAKMP:received payload type 20 Jun 1 10:30:05: ISAKMP (2114): My hash no match - this node inside NAT Jun 1 10:30:05: ISAKMP:(2114):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:05: ISAKMP:(2114):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:30:05: ISAKMP:(2114):Send initial contact Jun 1 10:30:05: ISAKMP:(2114): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(2114): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(2114): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(2114): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(2114):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:30:05: ISAKMP:(2114):Using FQDN as My ID Jun 1 10:30:05: ISAKMP:(2114):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:30:05: ISAKMP (2114): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:30:05: ISAKMP:(2114):Total payload length: 25 Jun 1 10:30:05: ISAKMP:(2114): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:05: ISAKMP:(2114): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:05: ISAKMP (2114): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:30:05: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:30:05: ISAKMP:(2114): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:30:05: ISAKMP:(2114): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:30:05: ISAKMP:(2114):Sending an IKE IPv4 Packet. Jun 1 10:30:05: ISAKMP:(2114):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:30:05: ISAKMP:(2114):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:30:05: ISAKMP (2113): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:30:05: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 8763F940 SPOKE_0268# Jun 1 10:30:07: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 8763F940 SPOKE_0268# Jun 1 10:30:08: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 SPOKE_0268# Jun 1 10:30:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 8763F940 Jun 1 10:30:11: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 8763F940 Jun 1 10:30:11: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:30:11: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:30:11: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:30:11: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:30:11: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:11: ISAKMP:(2114):peer does not do paranoid keepalives. Jun 1 10:30:11: ISAKMP:(2114):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:11: ISAKMP:(2113):peer does not do paranoid keepalives. Jun 1 10:30:11: ISAKMP:(2112):peer does not do paranoid keepalives. Jun 1 10:30:11: ISAKMP:(2111):peer does not do paranoid keepalives. Jun 1 10:30:11: ISAKMP:(2114):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:11: ISAKMP: Unlocking peer struct 0x87454954 for isadb_mark_sa_deleted(), count 0 Jun 1 10:30:11: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 87454954 Jun 1 10:30:11: ISAKMP:(2114):deleting node -1692886380 error FALSE reason "IKE deleted" Jun 1 10:30:11: ISAKMP:(2114): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:11: ISAKMP:(2114): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:11: ISAKMP:(2114):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:30:11: ISAKMP:(2114):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:30:11: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared]: Socket 87454954 for HUB01_IP not open or does not exist Jun 1 10:30:18: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:30:18: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:18: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:30:18: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:30:18: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:30:18: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:30:18: ISAKMP: New peer created peer = 0x8763F940 peer_handle = 0x80006455 Jun 1 10:30:18: ISAKMP: Locking peer struct 0x8763F940, refcount 1 for isakmp_initiator Jun 1 10:30:18: ISAKMP: local port 500, remote port 500 Jun 1 10:30:18: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:30:18: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87A9F57C Jun 1 10:30:18: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:30:18: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:30:18: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:30:18: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:30:18: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:30:18: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:30:18: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:30:18: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:30:18: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:30:18: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:30:18: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:18: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:30:18: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:30:18: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:18: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:30:18: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:30:18: ISAKMP:(0): processing vendor id payload Jun 1 10:30:18: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:18: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:18: ISAKMP : Scanning profiles for xauth ... Jun 1 10:30:18: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:30:18: ISAKMP: encryption AES-CBC Jun 1 10:30:18: ISAKMP: keylength of 256 Jun 1 10:30:18: ISAKMP: hash SHA Jun 1 10:30:18: ISAKMP: default group 1 Jun 1 10:30:18: ISAKMP: auth RSA sig Jun 1 10:30:18: ISAKMP: life type in seconds Jun 1 10:30:18: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:30:18: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:30:18: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:30:18: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:30:18: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:30:18: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:30:18: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:30:18: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:30:18: ISAKMP:(0): processing vendor id payload Jun 1 10:30:18: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:18: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:18: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:18: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:30:18: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:18: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:18: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:30:18: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:30:18: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:18: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:30:18: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:30:18: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:30:18: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:18: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:30:18: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:30:18: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:30:18: ISAKMP:(2115): processing CERT_REQ payload. message ID = 0 Jun 1 10:30:18: ISAKMP:(2115): peer wants a CT_X509_SIGNATURE cert Jun 1 10:30:18: ISAKMP:(2115): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:18: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:30:18: ISAKMP:(2115): processing vendor id payload Jun 1 10:30:18: ISAKMP:(2115): vendor ID is Unity Jun 1 10:30:18: ISAKMP:(2115): processing vendor id payload Jun 1 10:30:18: ISAKMP:(2115): vendor ID is DPD Jun 1 10:30:18: ISAKMP:(2115): processing vendor id payload Jun 1 10:30:18: ISAKMP:(2115): speaking to another IOS box! Jun 1 10:30:18: ISAKMP:received payload type 20 Jun 1 10:30:18: ISAKMP (2115): NAT found, both nodes inside NAT Jun 1 10:30:18: ISAKMP:received payload type 20 Jun 1 10:30:18: ISAKMP (2115): My hash no match - this node inside NAT Jun 1 10:30:18: ISAKMP:(2115):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:18: ISAKMP:(2115):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:30:18: ISAKMP:(2115):Send initial contact Jun 1 10:30:18: ISAKMP:(2115): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(2115): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(2115): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(2115): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(2115):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:30:18: ISAKMP:(2115):Using FQDN as My ID Jun 1 10:30:18: ISAKMP:(2115):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:30:18: ISAKMP (2115): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:30:18: ISAKMP:(2115):Total payload length: 25 Jun 1 10:30:18: ISAKMP:(2115): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:18: ISAKMP:(2115): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:18: ISAKMP (2115): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:30:18: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:30:18: ISAKMP:(2115): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:30:18: ISAKMP:(2115): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:30:18: ISAKMP:(2115):Sending an IKE IPv4 Packet. Jun 1 10:30:18: ISAKMP:(2115):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:30:18: ISAKMP:(2115):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:30:18: ISAKMP (2114): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:30:19: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 SPOKE_0268# Jun 1 10:30:21: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 SPOKE_0268# Jun 1 10:30:22: ISAKMP:(2111):purging node -779529369 Jun 1 10:30:22: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 SPOKE_0268# Jun 1 10:30:24: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:30:24: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:24: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 412 < 1000 Jun 1 10:30:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:30:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:30:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:30:25: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:30:25: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:25: ISAKMP:(2115):peer does not do paranoid keepalives. Jun 1 10:30:25: ISAKMP:(2115):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:25: ISAKMP:(2114):peer does not do paranoid keepalives. Jun 1 10:30:25: ISAKMP:(2113):peer does not do paranoid keepalives. Jun 1 10:30:25: ISAKMP:(2112):peer does not do paranoid keepalives. Jun 1 10:30:25: ISAKMP:(2111):peer does not do paranoid keepalives. Jun 1 10:30:25: ISAKMP:(2115):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:25: ISAKMP: Unlocking peer struct 0x8763F940 for isadb_mark_sa_deleted(), count 0 SPOKE_0268# Jun 1 10:30:25: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 8763F940 Jun 1 10:30:25: ISAKMP:(2115):deleting node -680561793 error FALSE reason "IKE deleted" Jun 1 10:30:25: ISAKMP:(2115): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:25: ISAKMP:(2115): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:25: ISAKMP:(2115):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:30:25: ISAKMP:(2115):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:30:25: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared]: Socket 87C36B58 for HUB01_IP not open or does not exist Jun 1 10:30:31: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:30:31: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:31: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:30:31: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:30:31: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:30:31: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:30:31: ISAKMP: New peer created peer = 0x8763F940 peer_handle = 0x80006457 Jun 1 10:30:31: ISAKMP: Locking peer struct 0x8763F940, refcount 1 for isakmp_initiator Jun 1 10:30:31: ISAKMP: local port 500, remote port 500 Jun 1 10:30:31: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:30:31: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87C638F4 Jun 1 10:30:31: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:30:31: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:30:31: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:30:31: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:30:31: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:30:31: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:30:31: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:30:31: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:30:31: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:30:31: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:30:31: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:30:31: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:30:31: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:30:31: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:31: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:30:31: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:30:31: ISAKMP:(0): processing vendor id payload Jun 1 10:30:31: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:31: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:31: ISAKMP : Scanning profiles for xauth ... Jun 1 10:30:31: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:30:31: ISAKMP: encryption AES-CBC Jun 1 10:30:31: ISAKMP: keylength of 256 Jun 1 10:30:31: ISAKMP: hash SHA Jun 1 10:30:31: ISAKMP: default group 1 Jun 1 10:30:31: ISAKMP: auth RSA sig Jun 1 10:30:31: ISAKMP: life type in seconds Jun 1 10:30:31: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:30:31: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:30:31: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:30:31: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:30:31: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:30:31: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:30:31: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:30:31: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:30:31: ISAKMP:(0): processing vendor id payload Jun 1 10:30:31: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:31: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:31: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:31: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:30:31: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:31: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:31: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:30:31: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:30:31: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:31: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:30:31: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:30:31: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:30:31: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:31: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:30:31: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:30:31: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:30:31: ISAKMP:(2116): processing CERT_REQ payload. message ID = 0 Jun 1 10:30:31: ISAKMP:(2116): peer wants a CT_X509_SIGNATURE cert Jun 1 10:30:31: ISAKMP:(2116): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:31: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:30:31: ISAKMP:(2116): processing vendor id payload Jun 1 10:30:31: ISAKMP:(2116): vendor ID is Unity Jun 1 10:30:31: ISAKMP:(2116): processing vendor id payload Jun 1 10:30:31: ISAKMP:(2116): vendor ID is DPD Jun 1 10:30:31: ISAKMP:(2116): processing vendor id payload Jun 1 10:30:31: ISAKMP:(2116): speaking to another IOS box! Jun 1 10:30:31: ISAKMP:received payload type 20 Jun 1 10:30:31: ISAKMP (2116): NAT found, both nodes inside NAT Jun 1 10:30:31: ISAKMP:received payload type 20 Jun 1 10:30:31: ISAKMP (2116): My hash no match - this node inside NAT Jun 1 10:30:31: ISAKMP:(2116):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:31: ISAKMP:(2116):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:30:31: ISAKMP:(2116):Send initial contact Jun 1 10:30:31: ISAKMP:(2116): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(2116): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(2116): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(2116): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(2116):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:30:31: ISAKMP:(2116):Using FQDN as My ID Jun 1 10:30:31: ISAKMP:(2116):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:30:31: ISAKMP (2116): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:30:31: ISAKMP:(2116):Total payload length: 25 Jun 1 10:30:31: ISAKMP:(2116): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:31: ISAKMP:(2116): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:31: ISAKMP (2116): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:30:31: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:30:31: ISAKMP:(2116): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:30:31: ISAKMP:(2116): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:30:31: ISAKMP:(2116):Sending an IKE IPv4 Packet. Jun 1 10:30:31: ISAKMP:(2116):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:30:31: ISAKMP:(2116):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:30:31: ISAKMP (2115): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:30:32: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:30:32: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 240 < 1000 Jun 1 10:30:32: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 240 < 1000 SPOKE_0268# Jun 1 10:30:32: ISAKMP:(2111):purging SA., sa=87BF14CC, delme=87BF14CC SPOKE_0268# Jun 1 10:30:34: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:30:34: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 280 < 1000 Jun 1 10:30:34: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 280 < 1000 SPOKE_0268# Jun 1 10:30:36: IPSEC-IFC MGRE/Tu2[shared](SRC_IP/188.65.206.34): connection lookup returned 87D3CB04 Jun 1 10:30:36: ISAKMP:(2112):purging node 104430948 Jun 1 10:30:36: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 SPOKE_0268# Jun 1 10:30:37: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:30:37: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 876 < 1000 Jun 1 10:30:38: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:30:38: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:30:38: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:30:38: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:30:38: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:30:38: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:38: ISAKMP:(2116):peer does not do paranoid keepalives. Jun 1 10:30:38: ISAKMP:(2116):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:38: ISAKMP:(2115):peer does not do paranoid keepalives. Jun 1 10:30:38: ISAKMP:(2114):peer does not do paranoid keepalives. Jun 1 10:30:38: ISAKMP:(2113):peer does not do paranoid keepalives. Jun 1 10:30:38: ISAKMP:(2112):peer does not do paranoid keepalives. Jun 1 10:30:38: ISAKMP:(2116):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:38: ISAKMP: Unlocking peer struct 0x8763F940 for isadb_mark_sa_deleted(), count 0 Jun 1 10:30:38: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 8763F940 Jun 1 10:30:38: ISAKMP:(2116):deleting node 283939560 error FALSE reason "IKE deleted" Jun 1 10:30:38: ISAKMP:(2116): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:38: ISAKMP:(2116): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:38: ISAKMP:(2116):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:30:38: ISAKMP:(2116):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:30:38: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared]: Socket 87454954 for HUB01_IP not open or does not exist Jun 1 10:30:43: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:30:43: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:43: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:30:43: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:30:43: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:30:43: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:30:43: ISAKMP: New peer created peer = 0x87898B00 peer_handle = 0x80006459 Jun 1 10:30:43: ISAKMP: Locking peer struct 0x87898B00, refcount 1 for isakmp_initiator Jun 1 10:30:43: ISAKMP: local port 500, remote port 500 Jun 1 10:30:43: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:30:43: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87BF1428 Jun 1 10:30:43: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:30:43: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:30:43: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:30:43: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:30:43: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:30:43: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:30:43: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:30:43: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:30:43: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:30:43: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:30:43: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:43: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:30:43: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:30:43: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:43: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:30:43: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:30:43: ISAKMP:(0): processing vendor id payload Jun 1 10:30:43: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:43: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:43: ISAKMP : Scanning profiles for xauth ... Jun 1 10:30:43: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:30:43: ISAKMP: encryption AES-CBC Jun 1 10:30:43: ISAKMP: keylength of 256 Jun 1 10:30:43: ISAKMP: hash SHA Jun 1 10:30:43: ISAKMP: default group 1 Jun 1 10:30:43: ISAKMP: auth RSA sig Jun 1 10:30:43: ISAKMP: life type in seconds Jun 1 10:30:43: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:30:43: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:30:43: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:30:43: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:30:43: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:30:43: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:30:43: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:30:43: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:30:43: ISAKMP:(0): processing vendor id payload Jun 1 10:30:43: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:43: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:43: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:43: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:30:43: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:43: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:43: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:43: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:30:43: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:30:43: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:43: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:30:43: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:30:43: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:30:43: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:43: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:30:43: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:30:44: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:30:44: ISAKMP:(2117): processing CERT_REQ payload. message ID = 0 Jun 1 10:30:44: ISAKMP:(2117): peer wants a CT_X509_SIGNATURE cert Jun 1 10:30:44: ISAKMP:(2117): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:44: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:30:44: ISAKMP:(2117): processing vendor id payload Jun 1 10:30:44: ISAKMP:(2117): vendor ID is Unity Jun 1 10:30:44: ISAKMP:(2117): processing vendor id payload Jun 1 10:30:44: ISAKMP:(2117): vendor ID is DPD Jun 1 10:30:44: ISAKMP:(2117): processing vendor id payload Jun 1 10:30:44: ISAKMP:(2117): speaking to another IOS box! Jun 1 10:30:44: ISAKMP:received payload type 20 Jun 1 10:30:44: ISAKMP (2117): NAT found, both nodes inside NAT Jun 1 10:30:44: ISAKMP:received payload type 20 Jun 1 10:30:44: ISAKMP (2117): My hash no match - this node inside NAT Jun 1 10:30:44: ISAKMP:(2117):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:44: ISAKMP:(2117):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:30:44: ISAKMP:(2117):Send initial contact Jun 1 10:30:44: ISAKMP:(2117): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:44: ISAKMP:(2117): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:44: ISAKMP:(2117): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:44: ISAKMP:(2117): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:44: ISAKMP:(2117):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:30:44: ISAKMP:(2117):Using FQDN as My ID Jun 1 10:30:44: ISAKMP:(2117):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:30:44: ISAKMP (2117): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:30:44: ISAKMP:(2117):Total payload length: 25 Jun 1 10:30:44: ISAKMP:(2117): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:44: ISAKMP:(2117): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:44: ISAKMP (2117): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:30:44: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:30:44: ISAKMP:(2117): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:30:44: ISAKMP:(2117): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:30:44: ISAKMP:(2117):Sending an IKE IPv4 Packet. Jun 1 10:30:44: ISAKMP:(2117):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:30:44: ISAKMP:(2117):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:30:44: ISAKMP (2116): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:30:44: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:30:44: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:44: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 500 < 1000 SPOKE_0268# Jun 1 10:30:45: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:30:46: ISAKMP:(2112):purging SA., sa=87BF0498, delme=87BF0498 Jun 1 10:30:46: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:46: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 648 < 1000 SPOKE_0268# Jun 1 10:30:48: ISAKMP:(2113):purging node 1779760591 Jun 1 10:30:49: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 SPOKE_0268# Jun 1 10:30:50: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 768 < 1000 Jun 1 10:30:50: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 768 < 1000 Jun 1 10:30:50: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:30:50: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:30:50: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:30:50: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:30:50: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:30:50: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:50: ISAKMP:(2117):peer does not do paranoid keepalives. Jun 1 10:30:50: ISAKMP:(2117):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:50: ISAKMP:(2116):peer does not do paranoid keepalives. Jun 1 10:30:50: ISAKMP:(2115):peer does not do paranoid keepalives. Jun 1 10:30:50: ISAKMP:(2114):peer does not do paranoid keepalives. Jun 1 10:30:50: ISAKMP:(2113):peer does not do paranoid keepalives. Jun 1 10:30:50: ISAKMP:(2117):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:50: ISAKMP: Unlocking peer struct 0x87898B00 for isadb_mark_sa_deleted(), count 0 Jun 1 10:30:50: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 87898B00 Jun 1 10:30:50: ISAKMP:(2117):deleting node 1162453125 error FALSE reason "IKE deleted" Jun 1 10:30:50: ISAKMP:(2117): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:50: ISAKMP:(2117): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:50: ISAKMP:(2117):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL SPOKE_0268# Jun 1 10:30:50: ISAKMP:(2117):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:30:50: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared]: Socket 87C36B58 for HUB01_IP not open or does not exist Jun 1 10:30:57: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:30:57: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:30:57: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:30:57: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:30:57: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:30:57: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:30:57: ISAKMP: New peer created peer = 0x8847D7E0 peer_handle = 0x8000645B Jun 1 10:30:57: ISAKMP: Locking peer struct 0x8847D7E0, refcount 1 for isakmp_initiator Jun 1 10:30:57: ISAKMP: local port 500, remote port 500 Jun 1 10:30:57: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:30:57: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87BF0498 Jun 1 10:30:57: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:30:57: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:30:57: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:30:57: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:30:57: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:30:57: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:30:57: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:30:57: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:30:57: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:30:57: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:30:57: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:30:57: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:30:57: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:30:57: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:57: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:30:57: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:30:57: ISAKMP:(0): processing vendor id payload Jun 1 10:30:57: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:57: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:57: ISAKMP : Scanning profiles for xauth ... Jun 1 10:30:57: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:30:57: ISAKMP: encryption AES-CBC Jun 1 10:30:57: ISAKMP: keylength of 256 Jun 1 10:30:57: ISAKMP: hash SHA Jun 1 10:30:57: ISAKMP: default group 1 Jun 1 10:30:57: ISAKMP: auth RSA sig Jun 1 10:30:57: ISAKMP: life type in seconds Jun 1 10:30:57: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:30:57: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:30:57: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:30:57: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:30:57: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:30:57: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:30:57: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:30:57: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:30:57: ISAKMP:(0): processing vendor id payload Jun 1 10:30:57: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:30:57: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:30:57: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:57: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:30:57: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:30:57: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:57: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:30:57: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:30:57: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:30:57: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:30:57: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:30:57: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:30:57: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:30:57: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:30:57: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:30:57: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:30:57: ISAKMP:(2118): processing CERT_REQ payload. message ID = 0 Jun 1 10:30:57: ISAKMP:(2118): peer wants a CT_X509_SIGNATURE cert Jun 1 10:30:57: ISAKMP:(2118): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:30:57: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:30:57: ISAKMP:(2118): processing vendor id payload Jun 1 10:30:57: ISAKMP:(2118): vendor ID is Unity Jun 1 10:30:57: ISAKMP:(2118): processing vendor id payload Jun 1 10:30:57: ISAKMP:(2118): vendor ID is DPD Jun 1 10:30:57: ISAKMP:(2118): processing vendor id payload Jun 1 10:30:57: ISAKMP:(2118): speaking to another IOS box! Jun 1 10:30:57: ISAKMP:received payload type 20 Jun 1 10:30:57: ISAKMP (2118): NAT found, both nodes inside NAT Jun 1 10:30:57: ISAKMP:received payload type 20 Jun 1 10:30:57: ISAKMP (2118): My hash no match - this node inside NAT Jun 1 10:30:57: ISAKMP:(2118):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:30:57: ISAKMP:(2118):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:30:57: ISAKMP:(2118):Send initial contact Jun 1 10:30:57: ISAKMP:(2118): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(2118): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(2118): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(2118): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(2118):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:30:57: ISAKMP:(2118):Using FQDN as My ID Jun 1 10:30:57: ISAKMP:(2118):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:30:57: ISAKMP (2118): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:30:57: ISAKMP:(2118):Total payload length: 25 Jun 1 10:30:57: ISAKMP:(2118): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:57: ISAKMP:(2118): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:30:57: ISAKMP (2118): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:30:57: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:30:57: ISAKMP:(2118): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:30:57: ISAKMP:(2118): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:30:57: ISAKMP:(2118):Sending an IKE IPv4 Packet. Jun 1 10:30:57: ISAKMP:(2118):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:30:57: ISAKMP:(2118):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:30:57: ISAKMP (2117): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:30:58: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 SPOKE_0268# Jun 1 10:30:58: ISAKMP:(2113):purging SA., sa=87B3DC10, delme=87B3DC10 Jun 1 10:30:59: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 SPOKE_0268# Jun 1 10:31:00: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:00: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 288 < 1000 SPOKE_0268# Jun 1 10:31:01: ISAKMP:(2114):purging node -1692886380 SPOKE_0268# Jun 1 10:31:03: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:04: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 684 < 1000 Jun 1 10:31:04: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 684 < 1000 Jun 1 10:31:04: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:04: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:31:04: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:31:04: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:31:04: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:31:04: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:04: ISAKMP:(2118):peer does not do paranoid keepalives. Jun 1 10:31:04: ISAKMP:(2118):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:04: ISAKMP:(2117):peer does not do paranoid keepalives. Jun 1 10:31:04: ISAKMP:(2116):peer does not do paranoid keepalives. Jun 1 10:31:04: ISAKMP:(2115):peer does not do paranoid keepalives. Jun 1 10:31:04: ISAKMP:(2114):peer does not do paranoid keepalives. Jun 1 10:31:04: ISAKMP:(2118):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:04: ISAKMP: Unlocking peer struct 0x8847D7E0 for isadb_mark_sa_deleted(), count 0 Jun 1 10:31:04: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 8847D7E0 Jun 1 10:31:04: ISAKMP:(2118):deleting node 1996799020 error FALSE reason "IKE deleted" Jun 1 10:31:04: ISAKMP:(2118): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:04: ISAKMP:(2118): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:04: ISAKMP:(2118):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:31:04: ISAKMP:(2118):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:31:04: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared]: Socket 87454954 for HUB01_IP not open or does not exist Jun 1 10:31:10: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:31:10: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:10: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:31:10: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:31:10: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:31:10: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:31:10: ISAKMP: New peer created peer = 0x8763F940 peer_handle = 0x8000645D Jun 1 10:31:10: ISAKMP: Locking peer struct 0x8763F940, refcount 1 for isakmp_initiator Jun 1 10:31:10: ISAKMP: local port 500, remote port 500 Jun 1 10:31:10: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:31:10: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87C92A2C Jun 1 10:31:10: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:31:10: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:31:10: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:31:10: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:31:10: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:31:10: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:31:10: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:31:10: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:31:10: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:31:10: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:31:10: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:31:10: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:31:10: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:31:10: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:31:10: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:31:10: ISAKMP:(0): processing vendor id payload Jun 1 10:31:10: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:31:10: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:31:10: ISAKMP : Scanning profiles for xauth ... Jun 1 10:31:10: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:31:10: ISAKMP: encryption AES-CBC Jun 1 10:31:10: ISAKMP: keylength of 256 Jun 1 10:31:10: ISAKMP: hash SHA Jun 1 10:31:10: ISAKMP: default group 1 Jun 1 10:31:10: ISAKMP: auth RSA sig Jun 1 10:31:10: ISAKMP: life type in seconds Jun 1 10:31:10: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:31:10: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:31:10: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:31:10: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:31:10: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:31:10: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:31:10: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:31:10: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:31:10: ISAKMP:(0): processing vendor id payload Jun 1 10:31:10: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:31:10: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:31:10: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:31:10: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:31:10: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:10: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:31:10: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:31:10: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:31:10: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:31:10: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:31:10: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:31:10: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:31:10: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:31:10: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:31:10: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:31:10: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:31:10: ISAKMP:(2119): processing CERT_REQ payload. message ID = 0 Jun 1 10:31:10: ISAKMP:(2119): peer wants a CT_X509_SIGNATURE cert Jun 1 10:31:10: ISAKMP:(2119): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:31:10: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:31:10: ISAKMP:(2119): processing vendor id payload Jun 1 10:31:10: ISAKMP:(2119): vendor ID is Unity Jun 1 10:31:10: ISAKMP:(2119): processing vendor id payload Jun 1 10:31:10: ISAKMP:(2119): vendor ID is DPD Jun 1 10:31:10: ISAKMP:(2119): processing vendor id payload Jun 1 10:31:10: ISAKMP:(2119): speaking to another IOS box! Jun 1 10:31:10: ISAKMP:received payload type 20 Jun 1 10:31:10: ISAKMP (2119): NAT found, both nodes inside NAT Jun 1 10:31:10: ISAKMP:received payload type 20 Jun 1 10:31:10: ISAKMP (2119): My hash no match - this node inside NAT Jun 1 10:31:10: ISAKMP:(2119):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:31:10: ISAKMP:(2119):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:31:10: ISAKMP:(2119):Send initial contact Jun 1 10:31:10: ISAKMP:(2119): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(2119): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(2119): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(2119): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(2119):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:31:10: ISAKMP:(2119):Using FQDN as My ID Jun 1 10:31:10: ISAKMP:(2119):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:31:10: ISAKMP (2119): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:31:10: ISAKMP:(2119):Total payload length: 25 Jun 1 10:31:10: ISAKMP:(2119): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:10: ISAKMP:(2119): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:10: ISAKMP (2119): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:31:10: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:31:10: ISAKMP:(2119): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:31:10: ISAKMP:(2119): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:31:10: ISAKMP:(2119):Sending an IKE IPv4 Packet. Jun 1 10:31:10: ISAKMP:(2119):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:31:10: ISAKMP:(2119):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:31:11: ISAKMP (2118): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:31:11: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:11: ISAKMP:(2114):purging SA., sa=87D82C70, delme=87D82C70 SPOKE_0268# Jun 1 10:31:13: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:14: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 968 < 1000 Jun 1 10:31:14: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 968 < 1000 SPOKE_0268# Jun 1 10:31:14: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 SPOKE_0268# Jun 1 10:31:15: ISAKMP:(2115):purging node -680561793 Jun 1 10:31:16: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 SPOKE_0268# Jun 1 10:31:17: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:17: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:31:17: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:31:17: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:31:17: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:31:17: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:17: ISAKMP:(2119):peer does not do paranoid keepalives. Jun 1 10:31:17: ISAKMP:(2119):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:17: ISAKMP:(2118):peer does not do paranoid keepalives. Jun 1 10:31:17: ISAKMP:(2117):peer does not do paranoid keepalives. Jun 1 10:31:17: ISAKMP:(2116):peer does not do paranoid keepalives. Jun 1 10:31:17: ISAKMP:(2115):peer does not do paranoid keepalives. Jun 1 10:31:17: ISAKMP:(2119):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:17: ISAKMP: Unlocking peer struct 0x8763F940 for isadb_mark_sa_deleted(), count 0 SPOKE_0268# Jun 1 10:31:17: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 8763F940 Jun 1 10:31:17: ISAKMP:(2119):deleting node 347174396 error FALSE reason "IKE deleted" Jun 1 10:31:17: ISAKMP:(2119): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:17: ISAKMP:(2119): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:17: ISAKMP:(2119):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:31:17: ISAKMP:(2119):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:31:17: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared]: Socket 87C36B58 for HUB01_IP not open or does not exist Jun 1 10:31:23: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:31:23: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:23: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:31:23: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:31:23: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:31:23: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:31:23: ISAKMP: New peer created peer = 0x8847D7E0 peer_handle = 0x8000645F Jun 1 10:31:23: ISAKMP: Locking peer struct 0x8847D7E0, refcount 1 for isakmp_initiator Jun 1 10:31:23: ISAKMP: local port 500, remote port 500 Jun 1 10:31:23: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:31:23: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87B3DC10 Jun 1 10:31:23: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:31:23: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:31:23: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:31:23: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:31:23: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:31:23: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:31:23: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:31:23: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:31:23: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:31:23: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:31:23: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 SPOKE_0268# Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:31:23: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:31:23: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:31:23: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:31:23: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:31:23: ISAKMP:(0): processing vendor id payload Jun 1 10:31:23: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:31:23: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:31:23: ISAKMP : Scanning profiles for xauth ... Jun 1 10:31:23: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:31:23: ISAKMP: encryption AES-CBC Jun 1 10:31:23: ISAKMP: keylength of 256 Jun 1 10:31:23: ISAKMP: hash SHA Jun 1 10:31:23: ISAKMP: default group 1 Jun 1 10:31:23: ISAKMP: auth RSA sig Jun 1 10:31:23: ISAKMP: life type in seconds Jun 1 10:31:23: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:31:23: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:31:23: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:31:23: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:31:23: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:31:23: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:31:23: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:31:23: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:31:23: ISAKMP:(0): processing vendor id payload Jun 1 10:31:23: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:31:23: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:31:23: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:31:23: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:31:23: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:23: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:31:23: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:31:23: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:31:23: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:31:23: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:31:23: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:31:23: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:31:23: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:31:23: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:31:23: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:31:23: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:31:23: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:31:23: ISAKMP:(2120): processing CERT_REQ payload. message ID = 0 Jun 1 10:31:23: ISAKMP:(2120): peer wants a CT_X509_SIGNATURE cert Jun 1 10:31:23: ISAKMP:(2120): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:31:23: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:31:23: ISAKMP:(2120): processing vendor id payload Jun 1 10:31:23: ISAKMP:(2120): vendor ID is Unity Jun 1 10:31:23: ISAKMP:(2120): processing vendor id payload Jun 1 10:31:23: ISAKMP:(2120): vendor ID is DPD Jun 1 10:31:23: ISAKMP:(2120): processing vendor id payload Jun 1 10:31:23: ISAKMP:(2120): speaking to another IOS box! Jun 1 10:31:23: ISAKMP:received payload type 20 Jun 1 10:31:23: ISAKMP (2120): NAT found, both nodes inside NAT Jun 1 10:31:23: ISAKMP:received payload type 20 Jun 1 10:31:23: ISAKMP (2120): My hash no match - this node inside NAT Jun 1 10:31:23: ISAKMP:(2120):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:31:23: ISAKMP:(2120):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:31:23: ISAKMP:(2120):Send initial contact Jun 1 10:31:23: ISAKMP:(2120): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(2120): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(2120): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(2120): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(2120):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:31:23: ISAKMP:(2120):Using FQDN as My ID Jun 1 10:31:23: ISAKMP:(2120):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:31:23: ISAKMP (2120): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:31:23: ISAKMP:(2120):Total payload length: 25 Jun 1 10:31:23: ISAKMP:(2120): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:23: ISAKMP:(2120): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:23: ISAKMP (2120): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:31:23: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:31:23: ISAKMP:(2120): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:31:23: ISAKMP:(2120): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:31:23: ISAKMP:(2120):Sending an IKE IPv4 Packet. Jun 1 10:31:23: ISAKMP:(2120):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:31:23: ISAKMP:(2120):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:31:23: ISAKMP (2119): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:31:23: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:23: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 680 < 1000 Jun 1 10:31:24: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 SPOKE_0268# Jun 1 10:31:25: ISAKMP:(2115):purging SA., sa=87A9F57C, delme=87A9F57C Jun 1 10:31:25: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 SPOKE_0268# Jun 1 10:31:27: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 SPOKE_0268# Jun 1 10:31:28: ISAKMP:(2116):purging node 283939560 Jun 1 10:31:29: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:30: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:30: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:31:30: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:31:30: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:31:30: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:31:30: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:30: ISAKMP:(2120):peer does not do paranoid keepalives. Jun 1 10:31:30: ISAKMP:(2120):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:30: ISAKMP:(2119):peer does not do paranoid keepalives. Jun 1 10:31:30: ISAKMP:(2118):peer does not do paranoid keepalives. Jun 1 10:31:30: ISAKMP:(2117):peer does not do paranoid keepalives. Jun 1 10:31:30: ISAKMP:(2116):peer does not do paranoid keepalives. Jun 1 10:31:30: ISAKMP:(2120):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:30: ISAKMP: Unlocking peer struct 0x8847D7E0 for isadb_mark_sa_deleted(), count 0 SPOKE_0268# Jun 1 10:31:30: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 8847D7E0 Jun 1 10:31:30: ISAKMP:(2120):deleting node 989920234 error FALSE reason "IKE deleted" Jun 1 10:31:30: ISAKMP:(2120): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:30: ISAKMP:(2120): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:30: ISAKMP:(2120):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:31:30: ISAKMP:(2120):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:31:30: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared]: Socket 87454954 for HUB01_IP not open or does not exist Jun 1 10:31:36: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:31:36: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:36: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:31:36: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:31:36: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:31:36: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:31:36: ISAKMP: New peer created peer = 0x8763F940 peer_handle = 0x80006461 Jun 1 10:31:36: ISAKMP: Locking peer struct 0x8763F940, refcount 1 for isakmp_initiator Jun 1 10:31:36: ISAKMP: local port 500, remote port 500 Jun 1 10:31:36: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:31:36: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87A9F57C Jun 1 10:31:36: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:31:36: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:31:36: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:31:36: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:31:36: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:31:36: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:31:36: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:31:36: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:31:36: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:31:36: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:31:36: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:31:36: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:31:36: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:31:36: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:31:36: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:31:36: ISAKMP:(0): processing vendor id payload Jun 1 10:31:36: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:31:36: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:31:36: ISAKMP : Scanning profiles for xauth ... Jun 1 10:31:36: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:31:36: ISAKMP: encryption AES-CBC Jun 1 10:31:36: ISAKMP: keylength of 256 Jun 1 10:31:36: ISAKMP: hash SHA Jun 1 10:31:36: ISAKMP: default group 1 Jun 1 10:31:36: ISAKMP: auth RSA sig Jun 1 10:31:36: ISAKMP: life type in seconds Jun 1 10:31:36: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:31:36: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:31:36: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:31:36: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:31:36: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:31:36: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:31:36: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:31:36: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:31:36: ISAKMP:(0): processing vendor id payload Jun 1 10:31:36: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:31:36: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:31:36: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:31:36: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:31:36: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) SPOKE_0268# Jun 1 10:31:36: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:36: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:31:36: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:31:36: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:31:36: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:31:36: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:31:36: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:31:36: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:31:36: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:31:36: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:31:36: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:31:36: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:31:36: ISAKMP:(2121): processing CERT_REQ payload. message ID = 0 Jun 1 10:31:36: ISAKMP:(2121): peer wants a CT_X509_SIGNATURE cert Jun 1 10:31:36: ISAKMP:(2121): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:31:36: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:31:36: ISAKMP:(2121): processing vendor id payload Jun 1 10:31:36: ISAKMP:(2121): vendor ID is Unity Jun 1 10:31:36: ISAKMP:(2121): processing vendor id payload Jun 1 10:31:36: ISAKMP:(2121): vendor ID is DPD Jun 1 10:31:36: ISAKMP:(2121): processing vendor id payload Jun 1 10:31:36: ISAKMP:(2121): speaking to another IOS box! Jun 1 10:31:36: ISAKMP:received payload type 20 Jun 1 10:31:36: ISAKMP (2121): NAT found, both nodes inside NAT Jun 1 10:31:36: ISAKMP:received payload type 20 Jun 1 10:31:36: ISAKMP (2121): My hash no match - this node inside NAT Jun 1 10:31:36: ISAKMP:(2121):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:31:36: ISAKMP:(2121):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:31:36: ISAKMP:(2121):Send initial contact Jun 1 10:31:36: ISAKMP:(2121): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(2121): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(2121): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(2121): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(2121):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:31:36: ISAKMP:(2121):Using FQDN as My ID Jun 1 10:31:36: ISAKMP:(2121):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:31:36: ISAKMP (2121): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:31:36: ISAKMP:(2121):Total payload length: 25 Jun 1 10:31:36: ISAKMP:(2121): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:36: ISAKMP:(2121): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:36: ISAKMP (2121): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:31:36: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:31:36: ISAKMP:(2121): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:31:36: ISAKMP:(2121): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:31:36: ISAKMP:(2121):Sending an IKE IPv4 Packet. Jun 1 10:31:36: ISAKMP:(2121):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:31:36: ISAKMP:(2121):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:31:36: ISAKMP (2120): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:31:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:37: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 136 < 1000 Jun 1 10:31:37: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 136 < 1000 SPOKE_0268# Jun 1 10:31:38: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:38: ISAKMP:(2116):purging SA., sa=87C638F4, delme=87C638F4 SPOKE_0268# Jun 1 10:31:40: ISAKMP:(2117):purging node 1162453125 SPOKE_0268# Jun 1 10:31:41: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:31:41: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:41: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 28 < 1000 Jun 1 10:31:42: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:31:42: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:31:42: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:31:42: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:31:42: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:31:42: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:42: ISAKMP:(2121):peer does not do paranoid keepalives. Jun 1 10:31:42: ISAKMP:(2121):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:42: ISAKMP:(2120):peer does not do paranoid keepalives. Jun 1 10:31:42: ISAKMP:(2119):peer does not do paranoid keepalives. Jun 1 10:31:42: ISAKMP:(2118):peer does not do paranoid keepalives. Jun 1 10:31:42: ISAKMP:(2117):peer does not do paranoid keepalives. Jun 1 10:31:42: ISAKMP:(2121):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:42: ISAKMP: Unlocking peer struct 0x8763F940 for isadb_mark_sa_deleted(), count 0 SPOKE_0268# Jun 1 10:31:42: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 8763F940 Jun 1 10:31:42: ISAKMP:(2121):deleting node 2143496957 error FALSE reason "IKE deleted" Jun 1 10:31:42: ISAKMP:(2121): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:42: ISAKMP:(2121): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:42: ISAKMP:(2121):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:31:42: ISAKMP:(2121):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:31:42: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared]: Socket 87C36B58 for HUB01_IP not open or does not exist Jun 1 10:31:49: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:31:49: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:49: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:31:49: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:31:49: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:31:49: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:31:49: ISAKMP: New peer created peer = 0x8847D7E0 peer_handle = 0x80006463 Jun 1 10:31:49: ISAKMP: Locking peer struct 0x8847D7E0, refcount 1 for isakmp_initiator Jun 1 10:31:49: ISAKMP: local port 500, remote port 500 Jun 1 10:31:49: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:31:49: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87C62CC0 Jun 1 10:31:49: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:31:49: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:31:49: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:49: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:49: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:31:49: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:31:49: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:31:49: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:31:49: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:31:49: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:31:49: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:31:49: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:31:49: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:49: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:31:50: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:31:50: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:31:50: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:31:50: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:31:50: ISAKMP:(0): processing vendor id payload Jun 1 10:31:50: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:31:50: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:31:50: ISAKMP : Scanning profiles for xauth ... Jun 1 10:31:50: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:31:50: ISAKMP: encryption AES-CBC Jun 1 10:31:50: ISAKMP: keylength of 256 Jun 1 10:31:50: ISAKMP: hash SHA Jun 1 10:31:50: ISAKMP: default group 1 Jun 1 10:31:50: ISAKMP: auth RSA sig Jun 1 10:31:50: ISAKMP: life type in seconds Jun 1 10:31:50: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:31:50: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:31:50: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:31:50: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:31:50: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:31:50: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:31:50: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:31:50: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:31:50: ISAKMP:(0): processing vendor id payload Jun 1 10:31:50: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:31:50: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:31:50: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:31:50: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:31:50: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:31:50: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:31:50: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:31:50: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:31:50: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:31:50: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:31:50: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:31:50: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:31:50: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:31:50: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:31:50: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:31:50: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:31:50: ISAKMP:(2122): processing CERT_REQ payload. message ID = 0 Jun 1 10:31:50: ISAKMP:(2122): peer wants a CT_X509_SIGNATURE cert Jun 1 10:31:50: ISAKMP:(2122): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:31:50: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:31:50: ISAKMP:(2122): processing vendor id payload Jun 1 10:31:50: ISAKMP:(2122): vendor ID is Unity Jun 1 10:31:50: ISAKMP:(2122): processing vendor id payload Jun 1 10:31:50: ISAKMP:(2122): vendor ID is DPD Jun 1 10:31:50: ISAKMP:(2122): processing vendor id payload Jun 1 10:31:50: ISAKMP:(2122): speaking to another IOS box! Jun 1 10:31:50: ISAKMP:received payload type 20 Jun 1 10:31:50: ISAKMP (2122): NAT found, both nodes inside NAT Jun 1 10:31:50: ISAKMP:received payload type 20 Jun 1 10:31:50: ISAKMP (2122): My hash no match - this node inside NAT Jun 1 10:31:50: ISAKMP:(2122):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:31:50: ISAKMP:(2122):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:31:50: ISAKMP:(2122):Send initial contact Jun 1 10:31:50: ISAKMP:(2122): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(2122): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(2122): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(2122): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(2122):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:31:50: ISAKMP:(2122):Using FQDN as My ID Jun 1 10:31:50: ISAKMP:(2122):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:31:50: ISAKMP (2122): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:31:50: ISAKMP:(2122):Total payload length: 25 Jun 1 10:31:50: ISAKMP:(2122): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:50: ISAKMP:(2122): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:50: ISAKMP (2122): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:31:50: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:31:50: ISAKMP:(2122): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:31:50: ISAKMP:(2122): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:31:50: ISAKMP:(2122):Sending an IKE IPv4 Packet. Jun 1 10:31:50: ISAKMP:(2122):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:31:50: ISAKMP:(2122):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:31:50: ISAKMP (2121): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:31:50: ISAKMP:(2117):purging SA., sa=87BF1428, delme=87BF1428 Jun 1 10:31:50: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:51: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 480 < 1000 Jun 1 10:31:51: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 480 < 1000 SPOKE_0268# Jun 1 10:31:52: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 SPOKE_0268# Jun 1 10:31:54: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:31:54: ISAKMP:(2118):purging node 1996799020 SPOKE_0268# Jun 1 10:31:55: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:55: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 324 < 1000 Jun 1 10:31:55: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 324 < 1000 Jun 1 10:31:56: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:31:56: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:31:56: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:31:56: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:31:56: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:31:56: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:31:56: ISAKMP:(2122):peer does not do paranoid keepalives. Jun 1 10:31:56: ISAKMP:(2122):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:56: ISAKMP:(2121):peer does not do paranoid keepalives. Jun 1 10:31:56: ISAKMP:(2120):peer does not do paranoid keepalives. Jun 1 10:31:56: ISAKMP:(2119):peer does not do paranoid keepalives. Jun 1 10:31:56: ISAKMP:(2118):peer does not do paranoid keepalives. Jun 1 10:31:56: ISAKMP:(2122):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:31:56: ISAKMP: Unlocking peer struct 0x8847D7E0 for isadb_mark_sa_deleted(), count 0 Jun 1 10:31:56: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 8847D7E0 Jun 1 10:31:56: ISAKMP:(2122):deleting node -926115534 error FALSE reason "IKE deleted" Jun 1 10:31:56: ISAKMP:(2122): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:56: ISAKMP:(2122): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:31:56: ISAKMP:(2122):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:31:56: ISAKMP:(2122):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:31:56: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared]: Socket 87454954 for HUB01_IP not open or does not exist Jun 1 10:32:02: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:32:02: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:32:02: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:32:02: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:32:02: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:32:02: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:32:02: ISAKMP: New peer created peer = 0x87BD69F8 peer_handle = 0x80006465 Jun 1 10:32:02: ISAKMP: Locking peer struct 0x87BD69F8, refcount 1 for isakmp_initiator Jun 1 10:32:02: ISAKMP: local port 500, remote port 500 Jun 1 10:32:02: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:32:02: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 877C00A8 Jun 1 10:32:02: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:32:02: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:32:02: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:32:02: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:32:02: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:32:02: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:32:02: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:32:02: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:32:02: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:32:02: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:32:02: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:02: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:32:02: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:32:02: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:32:02: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:32:02: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:32:02: ISAKMP:(0): processing vendor id payload Jun 1 10:32:02: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:32:02: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:32:02: ISAKMP : Scanning profiles for xauth ... Jun 1 10:32:02: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:32:02: ISAKMP: encryption AES-CBC Jun 1 10:32:02: ISAKMP: keylength of 256 Jun 1 10:32:02: ISAKMP: hash SHA Jun 1 10:32:02: ISAKMP: default group 1 Jun 1 10:32:02: ISAKMP: auth RSA sig Jun 1 10:32:02: ISAKMP: life type in seconds Jun 1 10:32:02: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:32:02: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:32:02: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:32:02: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:32:02: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:32:02: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:32:02: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:32:02: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:32:02: ISAKMP:(0): processing vendor id payload Jun 1 10:32:02: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:32:02: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:32:02: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:32:02: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:32:02: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:02: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:32:02: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:32:02: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:32:02: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:32:02: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:32:02: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:32:02: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:32:02: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:32:02: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:32:02: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:32:02: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:32:02: ISAKMP:(2123): processing CERT_REQ payload. message ID = 0 Jun 1 10:32:02: ISAKMP:(2123): peer wants a CT_X509_SIGNATURE cert Jun 1 10:32:02: ISAKMP:(2123): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:32:02: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:32:02: ISAKMP:(2123): processing vendor id payload Jun 1 10:32:02: ISAKMP:(2123): vendor ID is Unity Jun 1 10:32:02: ISAKMP:(2123): processing vendor id payload Jun 1 10:32:02: ISAKMP:(2123): vendor ID is DPD Jun 1 10:32:02: ISAKMP:(2123): processing vendor id payload Jun 1 10:32:02: ISAKMP:(2123): speaking to another IOS box! Jun 1 10:32:02: ISAKMP:received payload type 20 Jun 1 10:32:02: ISAKMP (2123): NAT found, both nodes inside NAT Jun 1 10:32:02: ISAKMP:received payload type 20 Jun 1 10:32:02: ISAKMP (2123): My hash no match - this node inside NAT Jun 1 10:32:02: ISAKMP:(2123):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:32:02: ISAKMP:(2123):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:32:02: ISAKMP:(2123):Send initial contact Jun 1 10:32:02: ISAKMP:(2123): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(2123): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(2123): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(2123): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(2123):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:32:02: ISAKMP:(2123):Using FQDN as My ID Jun 1 10:32:02: ISAKMP:(2123):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:32:02: ISAKMP (2123): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:32:02: ISAKMP:(2123):Total payload length: 25 Jun 1 10:32:02: ISAKMP:(2123): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:02: ISAKMP:(2123): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:02: ISAKMP (2123): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:32:02: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:32:02: ISAKMP:(2123): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:32:02: ISAKMP:(2123): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:32:02: ISAKMP:(2123):Sending an IKE IPv4 Packet. Jun 1 10:32:02: ISAKMP:(2123):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:32:02: ISAKMP:(2123):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:32:02: ISAKMP (2122): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:32:03: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 SPOKE_0268# Jun 1 10:32:04: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 696 < 1000 Jun 1 10:32:04: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 696 < 1000 Jun 1 10:32:04: ISAKMP:(2118):purging SA., sa=87BF0498, delme=87BF0498 SPOKE_0268# Jun 1 10:32:05: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:05: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 32 < 1000 Jun 1 10:32:05: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 32 < 1000 SPOKE_0268# Jun 1 10:32:07: ISAKMP:(2119):purging node 347174396 SPOKE_0268# Jun 1 10:32:09: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:32:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:32:10: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:32:10: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:32:10: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:32:10: ISAKMP:(2123):peer does not do paranoid keepalives. Jun 1 10:32:10: ISAKMP:(2123):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:10: ISAKMP:(2122):peer does not do paranoid keepalives. Jun 1 10:32:10: ISAKMP:(2121):peer does not do paranoid keepalives. Jun 1 10:32:10: ISAKMP:(2120):peer does not do paranoid keepalives. Jun 1 10:32:10: ISAKMP:(2119):peer does not do paranoid keepalives. Jun 1 10:32:10: ISAKMP:(2123):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:10: ISAKMP: Unlocking peer struct 0x87BD69F8 for isadb_mark_sa_deleted(), count 0 Jun 1 10:32:10: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 87BD69F8 Jun 1 10:32:10: ISAKMP:(2123):deleting node 216143393 error FALSE reason "IKE deleted" Jun 1 10:32:10: ISAKMP:(2123): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:10: ISAKMP:(2123): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:10: ISAKMP:(2123):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:32:10: ISAKMP:(2123):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:32:10: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared]: Socket 87C36B58 for HUB01_IP not open or does not exist Jun 1 10:32:16: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:32:16: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:32:16: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:32:16: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:32:16: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:32:16: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:32:16: ISAKMP: New peer created peer = 0x87873894 peer_handle = 0x80006467 Jun 1 10:32:16: ISAKMP: Locking peer struct 0x87873894, refcount 1 for isakmp_initiator Jun 1 10:32:16: ISAKMP: local port 500, remote port 500 Jun 1 10:32:16: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:32:16: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 87D82C70 Jun 1 10:32:16: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:32:16: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:32:16: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:32:16: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:32:16: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:32:16: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:32:16: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:32:16: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:32:16: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:32:16: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:32:16: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 SPOKE_0268# Jun 1 10:32:16: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:32:16: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:32:16: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:32:16: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:32:16: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:32:16: ISAKMP:(0): processing vendor id payload Jun 1 10:32:16: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:32:16: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:32:16: ISAKMP : Scanning profiles for xauth ... Jun 1 10:32:16: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:32:16: ISAKMP: encryption AES-CBC Jun 1 10:32:16: ISAKMP: keylength of 256 Jun 1 10:32:16: ISAKMP: hash SHA Jun 1 10:32:16: ISAKMP: default group 1 Jun 1 10:32:16: ISAKMP: auth RSA sig Jun 1 10:32:16: ISAKMP: life type in seconds Jun 1 10:32:16: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:32:16: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:32:16: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:32:16: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:32:16: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:32:16: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:32:16: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:32:16: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:32:16: ISAKMP:(0): processing vendor id payload Jun 1 10:32:16: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:32:16: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:32:16: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:32:16: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:32:16: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:16: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:32:16: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:32:16: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:32:16: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:32:16: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:32:16: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:32:16: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:32:16: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:32:16: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:32:16: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:32:16: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:32:16: ISAKMP:(2124): processing CERT_REQ payload. message ID = 0 Jun 1 10:32:16: ISAKMP:(2124): peer wants a CT_X509_SIGNATURE cert Jun 1 10:32:16: ISAKMP:(2124): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:32:16: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:32:16: ISAKMP:(2124): processing vendor id payload Jun 1 10:32:16: ISAKMP:(2124): vendor ID is Unity Jun 1 10:32:16: ISAKMP:(2124): processing vendor id payload Jun 1 10:32:16: ISAKMP:(2124): vendor ID is DPD Jun 1 10:32:16: ISAKMP:(2124): processing vendor id payload Jun 1 10:32:16: ISAKMP:(2124): speaking to another IOS box! Jun 1 10:32:16: ISAKMP:received payload type 20 Jun 1 10:32:16: ISAKMP (2124): NAT found, both nodes inside NAT Jun 1 10:32:16: ISAKMP:received payload type 20 Jun 1 10:32:16: ISAKMP (2124): My hash no match - this node inside NAT Jun 1 10:32:16: ISAKMP:(2124):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:32:16: ISAKMP:(2124):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:32:16: ISAKMP:(2124):Send initial contact Jun 1 10:32:16: ISAKMP:(2124): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(2124): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(2124): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(2124): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(2124):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:32:16: ISAKMP:(2124):Using FQDN as My ID Jun 1 10:32:16: ISAKMP:(2124):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:32:16: ISAKMP (2124): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:32:16: ISAKMP:(2124):Total payload length: 25 Jun 1 10:32:16: ISAKMP:(2124): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:16: ISAKMP:(2124): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:16: ISAKMP (2124): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:32:16: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:32:16: ISAKMP:(2124): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:32:16: ISAKMP:(2124): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:32:16: ISAKMP:(2124):Sending an IKE IPv4 Packet. Jun 1 10:32:16: ISAKMP:(2124):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:32:16: ISAKMP:(2124):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:32:16: ISAKMP (2123): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:32:17: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:32:17: ISAKMP:(2119):purging SA., sa=87C92A2C, delme=87C92A2C SPOKE_0268# Jun 1 10:32:18: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 SPOKE_0268# Jun 1 10:32:20: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:32:20: ISAKMP:(2120):purging node 989920234 SPOKE_0268# Jun 1 10:32:21: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:32:22: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87C36B58 Jun 1 10:32:22: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:32:22: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:32:22: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:32:22: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:32:22: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:32:22: ISAKMP:(2124):peer does not do paranoid keepalives. Jun 1 10:32:22: ISAKMP:(2124):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:22: ISAKMP:(2123):peer does not do paranoid keepalives. Jun 1 10:32:22: ISAKMP:(2122):peer does not do paranoid keepalives. Jun 1 10:32:22: ISAKMP:(2121):peer does not do paranoid keepalives. Jun 1 10:32:22: ISAKMP:(2120):peer does not do paranoid keepalives. Jun 1 10:32:22: ISAKMP:(2124):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:22: ISAKMP: Unlocking peer struct 0x87873894 for isadb_mark_sa_deleted(), count 0 Jun 1 10:32:22: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 87873894 Jun 1 10:32:22: ISAKMP:(2124):deleting node -1539160926 error FALSE reason "IKE deleted" Jun 1 10:32:22: ISAKMP:(2124): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:22: ISAKMP:(2124): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:22: ISAKMP:(2124):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:32:22: ISAKMP:(2124):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:32:22: IPSEC(key_engine): got a queue event with 1 KMI message(s) SPOKE_0268# Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared]: crypto_ss_listen_start already listening Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Opening a socket with profile vpnprof1 Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 0 Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Triggering tunnel immediately. Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared]: Adding Tunnel1 tunnel interface to shared list Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared]: Socket 87454954 for HUB01_IP not open or does not exist Jun 1 10:32:29: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb Jun 1 10:32:29: CRYPTO_SS(TUNNEL SEC): Active open, socket info: local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:32:29: IPSEC(recalculate_mtu): reset sadb_root 88243F1C mtu to 1500 Jun 1 10:32:29: IPSEC(sa_request): , (key eng. msg.) OUTBOUND local= SRC_IP:500, remote= HUB01_IP:500, local_proxy= SRC_IP/255.255.255.255/47/0, remote_proxy= HUB01_IP/255.255.255.255/47/0, protocol= ESP, transform= esp-aes 256 esp-md5-hmac (Transport), lifedur= 3600s and 4608000kb, spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0 Jun 1 10:32:29: ISAKMP:(0): SA request profile is (NULL) Jun 1 10:32:29: ISAKMP: Created a peer struct for HUB01_IP, peer port 500 Jun 1 10:32:29: ISAKMP: New peer created peer = 0x87898B00 peer_handle = 0x80006469 Jun 1 10:32:29: ISAKMP: Locking peer struct 0x87898B00, refcount 1 for isakmp_initiator Jun 1 10:32:29: ISAKMP: local port 500, remote port 500 Jun 1 10:32:29: ISAKMP: set new node 0 to QM_IDLE Jun 1 10:32:29: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 877C0AC4 Jun 1 10:32:29: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. Jun 1 10:32:29: ISAKMP:(0):No pre-shared key with HUB01_IP! Jun 1 10:32:29: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID Jun 1 10:32:29: ISAKMP:(0): constructed NAT-T vendor-07 ID Jun 1 10:32:29: ISAKMP:(0): constructed NAT-T vendor-03 ID Jun 1 10:32:29: ISAKMP:(0): constructed NAT-T vendor-02 ID Jun 1 10:32:29: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM Jun 1 10:32:29: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 Jun 1 10:32:29: ISAKMP:(0): beginning Main Mode exchange Jun 1 10:32:29: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_NO_STATE Jun 1 10:32:29: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:29: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): good socket ready message Jun 1 10:32:29: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_NO_STATE Jun 1 10:32:29: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:32:29: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 Jun 1 10:32:29: ISAKMP:(0): processing SA payload. message ID = 0 Jun 1 10:32:29: ISAKMP:(0): processing vendor id payload Jun 1 10:32:29: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:32:29: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:32:29: ISAKMP : Scanning profiles for xauth ... Jun 1 10:32:29: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy Jun 1 10:32:29: ISAKMP: encryption AES-CBC Jun 1 10:32:29: ISAKMP: keylength of 256 Jun 1 10:32:29: ISAKMP: hash SHA Jun 1 10:32:29: ISAKMP: default group 1 Jun 1 10:32:29: ISAKMP: auth RSA sig Jun 1 10:32:29: ISAKMP: life type in seconds Jun 1 10:32:29: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 Jun 1 10:32:29: ISAKMP:(0):atts are acceptable. Next payload is 0 Jun 1 10:32:29: ISAKMP:(0):Acceptable atts:actual life: 0 Jun 1 10:32:29: ISAKMP:(0):Acceptable atts:life: 0 Jun 1 10:32:29: ISAKMP:(0):Fill atts in sa vpi_length:4 Jun 1 10:32:29: ISAKMP:(0):Fill atts in sa life_in_seconds:86400 Jun 1 10:32:29: ISAKMP:(0): IKE->PKI Start PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0): PKI->IKE Started PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0):Returning Actual lifetime: 86400 Jun 1 10:32:29: ISAKMP:(0)::Started lifetime timer: 86400. Jun 1 10:32:29: ISAKMP:(0): processing vendor id payload Jun 1 10:32:29: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch Jun 1 10:32:29: ISAKMP (0): vendor ID is NAT-T RFC 3947 Jun 1 10:32:29: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:32:29: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 Jun 1 10:32:29: ISAKMP:(0): IKE->PKI Get configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0): PKI->IKE Got configured TrustPoints state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0): IKE->PKI Get IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(0): PKI->IKE Got IssuerNames state (I) MM_SA_SETUP (peer HUB01_IP) Jun 1 10:32:29: ISAKMP (0): constructing CERT_REQ for issuer cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:32:29: ISAKMP (0): constructing CERT_REQ for issuer cn=CAServer,dc=DomainName,dc=local Jun 1 10:32:29: ISAKMP:(0): sending packet to HUB01_IP my_port 500 peer_port 500 (I) MM_SA_SETUP Jun 1 10:32:29: ISAKMP:(0):Sending an IKE IPv4 Packet. Jun 1 10:32:29: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE Jun 1 10:32:29: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 Jun 1 10:32:29: ISAKMP (0): received packet from HUB01_IP dport 500 sport 500 Global (I) MM_SA_SETUP Jun 1 10:32:29: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH Jun 1 10:32:29: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 Jun 1 10:32:29: ISAKMP:(0): processing KE payload. message ID = 0 Jun 1 10:32:29: ISAKMP:(0): processing NONCE payload. message ID = 0 Jun 1 10:32:29: ISAKMP:(2125): processing CERT_REQ payload. message ID = 0 Jun 1 10:32:29: ISAKMP:(2125): peer wants a CT_X509_SIGNATURE cert Jun 1 10:32:29: ISAKMP:(2125): peer wants cert issued by cn= DOMAIN,dc=FQ,dc=DN Jun 1 10:32:29: Choosing trustpoint hub01.FQDN.com:PORT as issuer Jun 1 10:32:29: ISAKMP:(2125): processing vendor id payload Jun 1 10:32:29: ISAKMP:(2125): vendor ID is Unity Jun 1 10:32:29: ISAKMP:(2125): processing vendor id payload Jun 1 10:32:29: ISAKMP:(2125): vendor ID is DPD Jun 1 10:32:29: ISAKMP:(2125): processing vendor id payload Jun 1 10:32:29: ISAKMP:(2125): speaking to another IOS box! Jun 1 10:32:29: ISAKMP:received payload type 20 Jun 1 10:32:29: ISAKMP (2125): NAT found, both nodes inside NAT Jun 1 10:32:29: ISAKMP:received payload type 20 Jun 1 10:32:29: ISAKMP (2125): My hash no match - this node inside NAT Jun 1 10:32:29: ISAKMP:(2125):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE Jun 1 10:32:29: ISAKMP:(2125):Old State = IKE_I_MM4 New State = IKE_I_MM4 Jun 1 10:32:29: ISAKMP:(2125):Send initial contact Jun 1 10:32:29: ISAKMP:(2125): IKE->PKI Get self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(2125): PKI->IKE Got self CertificateChain state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(2125): IKE->PKI Get SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(2125): PKI->IKE Got SubjectName state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(2125):My ID configured as IPv4 Addr, but Addr not in Cert! Jun 1 10:32:29: ISAKMP:(2125):Using FQDN as My ID Jun 1 10:32:29: ISAKMP:(2125):SA is doing RSA signature authentication using id type ID_FQDN Jun 1 10:32:29: ISAKMP (2125): ID payload next-payload : 6 type : 2 FQDN name : SPOKE.FQDN.XYZ protocol : 17 port : 0 length : 25 Jun 1 10:32:29: ISAKMP:(2125):Total payload length: 25 Jun 1 10:32:29: ISAKMP:(2125): IKE->PKI Get CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:29: ISAKMP:(2125): PKI->IKE Got CertificateChain to be sent to peer state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:29: ISAKMP (2125): constructing CERT payload for hostname=SPOKE.FQDN.XYZ Jun 1 10:32:29: ISKAMP: growing send buffer from 1024 to 3072 Jun 1 10:32:29: ISAKMP:(2125): using the hub01.FQDN.com:PORT trustpoint's keypair to sign Jun 1 10:32:29: ISAKMP:(2125): sending packet to HUB01_IP my_port 4500 peer_port 4500 (I) MM_KEY_EXCH Jun 1 10:32:29: ISAKMP:(2125):Sending an IKE IPv4 Packet. Jun 1 10:32:29: ISAKMP:(2125):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE SPOKE_0268# Jun 1 10:32:29: ISAKMP:(2125):Old State = IKE_I_MM4 New State = IKE_I_MM5 Jun 1 10:32:29: ISAKMP (2124): received packet from HUB01_IP dport 4500 sport 4500 Global (I) MM_NO_STATE Jun 1 10:32:30: ISAKMP:(2120):purging SA., sa=87B3DC10, delme=87B3DC10 Jun 1 10:32:30: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 SPOKE_0268# Jun 1 10:32:32: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:32: ISAKMP:(2121):purging node 2143496957 SPOKE_0268# Jun 1 10:32:33: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 0 < 1000 Jun 1 10:32:34: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 492 < 1000 Jun 1 10:32:34: IPSEC(ERROR): crypto_notify_rp Rejected notify RP, elapse time 492 < 1000 SPOKE_0268# Jun 1 10:32:35: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): connection lookup returned 87454954 Jun 1 10:32:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Found Tunnel1 interface in shared list Jun 1 10:32:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Removing Tunnel1 interface from shared list Jun 1 10:32:36: IPSEC-IFC MGRE/Tu1[shared](SRC_IP/HUB01_IP): Closing socket Jun 1 10:32:36: CRYPTO_SS(TUNNEL SEC): Closed socket. Jun 1 10:32:36: CRYPTO_SS(TUNNEL SEC): local SRC_IP SRC_IP/255.255.255.255/0, remote HUB01_IP HUB01_IP/255.255.255.255/0, prot 47, ifc Tu1 Jun 1 10:32:36: ISAKMP:(2125):peer does not do paranoid keepalives. Jun 1 10:32:36: ISAKMP:(2125):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:36: ISAKMP:(2124):peer does not do paranoid keepalives. Jun 1 10:32:36: ISAKMP:(2123):peer does not do paranoid keepalives. Jun 1 10:32:36: ISAKMP:(2122):peer does not do paranoid keepalives. Jun 1 10:32:36: ISAKMP:(2121):peer does not do paranoid keepalives. Jun 1 10:32:36: ISAKMP:(2125):deleting SA reason "P1 delete notify (in)" state (I) MM_KEY_EXCH (peer HUB01_IP) Jun 1 10:32:36: ISAKMP: Unlocking peer struct 0x87898B00 for isadb_mark_sa_deleted(), count 0 Jun 1 10:32:36: ISAKMP: Deleting peer node by peer_reap for HUB01_IP: 87898B00 Jun 1 10:32:36: ISAKMP:(2125):deleting node 879246213 error FALSE reason "IKE deleted" Jun 1 10:32:36: ISAKMP:(2125): IKE->PKI End PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:36: ISAKMP:(2125): PKI->IKE Ended PKI Session state (I) MM_NO_STATE (peer HUB01_IP) Jun 1 10:32:36: ISAKMP:(2125):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL Jun 1 10:32:36: ISAKMP:(2125):Old State = IKE_I_MM5 New State = IKE_DEST_SA Jun 1 10:32:36: IPSEC(key_engine): got a queue event with 1 KMI message(s)
06-04-2018 09:07 AM
Hello,
I noticed on your hub router, there is no crypto map VPN ?
interface GigabitEthernet0/0/0
description Public Interface
ip address XX XX
ip mtu 1480
ip nat outside
ip access-group WANInterface in
ip tcp adjust-mss 1440
negotiation auto
crypto map VPN
crypto ipsec fragmentation after-encryption
ip virtual-reassembly
ip virtual-reassembly-out
06-05-2018 01:59 AM
06-06-2018 01:46 AM - edited 06-07-2018 05:31 AM
Hello,
Does anybody have a clue ?
I can provide more information if needed !
Best
06-07-2018 05:42 AM
Hello,
which access list is being matched in the crypto map ? Did you leave anything else out of the configuration you have posted ?
06-12-2018 06:40 AM
06-12-2018 06:41 AM
06-25-2018 01:34 AM
Hello,
Any ideas, any advices ?
best,
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide