Dmvpn spoke behind nat doesn't recieve registration reply from Hub port forwarding restricted from ISP

[rai1rocks@yahoo.com]

Hi everyone hub and spoke works fine with public IPs but i am troubled with the scenario where Hub having Public IP while the Spoke router is   behind Nat . The ISP CPE does not allow port FWD (4500) and provides Dynamic IP , the spoke is behind ISP cpe   . Hub receives registration request but client doesn't receive reply from hub and  then client resend the registration request . On Hub the status for sho dmvpn  is UP while on the client the status is NHRP.

Your help in this regard is much appreciated .

[Larry Sullivan]

What are results of debugging  nhrp error/detail on both ends?  Did this tunnel work at some point and now doesn't or is this a new tunnel?  If UDP 4500 is not forwarded then this should have never worked behind NAT.  Do the ipsec SPI's match up on both ends?  Have you tried shutting the tunnel on the spoke for about an hour and no shutting?  Seems odd, but this has fixed many a weird DMVPN issue like this before for me.  Seems to re-sync the SPI's. 

[rai1rocks@yahoo.com]

Hi larry , Thanks a lot for replying , yes it has been working earlier for few months with no issues without port forwarding.

results for debug nhrp

Spoke :

.*Nov 16 15:24:28.982: NHRP: Setting retrans delay to 64 for nhs dst 10.1.124.1
*Nov 16 15:24:28.982: NHRP: Attempting to send packet via DEST 10.1.124.1
*Nov 16 15:24:28.982: NHRP: NHRP successfully resolved 10.1.124.1 to NBMA 110.36.222.118
*Nov 16 15:24:28.982: NHRP: Encapsulation succeeded. Tunnel IP addr 110.36.222.118
*Nov 16 15:24:28.982: NHRP: Send Registration Request via Tunnel1 vrf 0, packet size: 108
*Nov 16 15:24:28.982: src: 10.1.124.2, dst: 10.1.124.1
*Nov 16 15:24:28.982: NHRP: 136 bytes out Tunnel1 

interface Tunnel1
description Primary-lnk-sahamid
ip address 10.1.124.2 255.255.255.0
no ip redirects
ip mtu 1400
ip nhrp authentication abcd
ip nhrp map multicast 110.36.222.118
ip nhrp map 10.1.124.1 110.36.222.118
ip nhrp network-id 121
ip nhrp nhs 10.1.124.1
ip tcp adjust-mss 1360
tunnel source Vlan8
tunnel mode gre multipoint
tunnel key 10
end

HUB:

NHRP: Receive Registration Request via Tunnel10 vrf 0, packet size: 108
*Nov 16 19:12:26.550: NHRP: netid_in = 121, to_us = 1
*Nov 16 19:12:26.550: NHRP: Adding Tunnel Endpoints (VPN: 10.1.124.2, NBMA: 103.255.4.44)
*Nov 16 19:12:26.550: NHRP: NHRP subblock already exists for Tunnel Endpoints (VPN: 10.1.124.2, NBMA: 103.255.4.44)
*Nov 16 19:12:26.550: NHRP: Cache already has a subblock node attached for Tunnel Endpoints (VPN: 10.1.124.2, NBMA: 103.255.4.44)
*Nov 16 19:12:26.550: NHRP: nhrp_subblock_check_for_map() - Map Already Exists
*Nov 16 19:12:26.550: NHRP: New mandatory length: 32
*Nov 16 19:12:26.554: NHRP:
vpngtw(config-if)#Attempting to send packet via DEST 10.1.124.2
*Nov 16 19:12:26.554: NHRP: NHRP successfully resolved 10.1.124.2 to NBMA 103.255.4.44
*Nov 16 19:12:26.554: NHRP: Encapsulation succeeded. Tunnel IP addr 103.255.4.44
*Nov 16 19:12:26.554: NHRP: Send Registration Reply via Tunnel10 vrf 0, packet size: 148
*Nov 16 19:12:26.554: src: 10.1.124.1, dst: 10.1.124.2
*Nov 16 19:12:26.554: NHRP: 176 bytes out Tunnel10 

interface Tunnel10
ip address 10.1.124.1 255.255.255.0
no ip redirects
ip nhrp authentication abcd
ip nhrp map multicast dynamic
ip nhrp network-id 121
ip tcp adjust-mss 1360
tunnel source Vlan1820
tunnel mode gre multipoint
tunnel key 10
end

I have kept the tunnel shut for many  Hours.

Also i dont get error msgs regarding SPIs

Port 4500 was never FWDed from Day One but for a week it has stopped working . 

[a.alekseev]

It will work only with tunnel protection....

[Larry Sullivan]

Yeah, SPIs are under crypto debugs and looks like you aren't using IPsec.  So on the spoke, you don't get any debug messages saying that it has received a reply from the hub right?  When did you discover that the CPE doesn't forward 4500?  Before or after this issue?

[rai1rocks@yahoo.com]

yeah right its not getting replies from hub the cpe is 4g sim based router i never forwarded ports when i configured dmvpn it worked fine then but now neither dmvpn works nor forwarding . Also isp appears to be natting or it has started now this may be the cause plus since i cannot bridge hence the cpe is also natting.

[a.alekseev]

use tunnel protection... only IPSec can go through nat/pat devices

[rai1rocks@yahoo.com]

i will post debug for ipsec shortly since ipsec is not working either .

[rai1rocks@yahoo.com]

Hi Larry ,

Now the spoke get to recieve replies but neighbor-ship doesnot come up .

Debugs on Hub

Nov 18 00:10:31.627: ISAKMP (0): received packet from 103.7.79.86 dport 500 sport 3220 Global (N) NEW SA
*Nov 18 00:10:31.627: ISAKMP: Created a peer struct for 103.7.79.86, peer port 3220
*Nov 18 00:10:31.627: ISAKMP: New peer created peer = 0x50A27918 peer_handle = 0x80000007
*Nov 18 00:10:31.627: ISAKMP: Locking peer struct 0x50A27918, refcount 1 for crypto_isakmp_process_block
*Nov 18 00:10:31.627: ISAKMP: local port 500, remote port 3220
*Nov 18 00:10:31.627: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 50AC8D5C
*Nov 18 00:10:31.627: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Nov 18 00:10:31.627: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_MM1

*Nov 18 00:10:31.627: ISAKMP:(0): processing SA payload. message ID = 0
*Nov 18 00:10:31.627: ISAKMP:(0): processing vendor id payload
*Nov 18 00:10:31.627: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
*Nov 18 00:10:31.627: ISAKMP (0): vendor ID is NAT-T RFC 3947
*Nov 18 00:10:31.627: ISAKMP:(0): processing vendor id payload
*Nov 18 00:10:31.627: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch
*Nov 18 00:10:31.627: ISAKMP (0): vendor ID is NAT-T v7
*Nov 18 00:10:31.627: ISAKMP:(0): processing vendor id payload
*Nov 18 00:10:31.627: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch
*Nov 18 00:10:31.627: ISAKMP:(0): vendor ID is NAT-T v3
*Nov 18 00:10:31.631: ISAKMP:(0): processing vendor id payload
*Nov 18 00:10:31.631: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
*Nov 18 00:10:31.631: ISAKMP:(0): vendor ID is NAT-T v2
*Nov 18 00:10:31.631: ISAKMP:(0):found peer pre-shared key matching 103.7.79.86
*Nov 18 00:10:31.631: ISAKMP:(0): local preshared key found
*Nov 18 00:10:31.631: ISAKMP : Scanning profiles for xauth ...
*Nov 18 00:10:31.631: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy
*Nov 18 00:10:31.631: ISAKMP: encryption AES-CBC
*Nov 18 00:10:31.631: ISAKMP: keylength of 192
*Nov 18 00:10:31.631: ISAKMP: hash SHA
*Nov 18 00:10:31.631: ISAKMP: default group 5
*Nov 18 00:10:31.631: ISAKMP: auth pre-share
*Nov 18 00:10:31.631: ISAKMP: life type in seconds
*Nov 18 00:10:31.631: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80
*Nov 18 00:10:31.631: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Nov 18 00:10:31.631: ISAKMP:(0):atts are not acceptable. Next payload is 0
*Nov 18 00:10:31.631: ISAKMP:(0):Checking ISAKMP transform 1 against priority 10 policy
*Nov 18 00:10:31.631: ISAKMP: encryption AES-CBC
*Nov 18 00:10:31.631: ISAKMP: keylength of 192
*Nov 18 00:10:31.631: ISAKMP: hash SHA
*Nov 18 00:10:31.631: ISAKMP: default group 5
*Nov 18 00:10:31.631: ISAKMP: auth pre-share
*Nov 18 00:10:31.631: ISAKMP: life type in seconds
*Nov 18 00:10:31.631: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80
*Nov 18 00:10:31.631: ISAKMP:(0):atts are acceptable. Next payload is 0
*Nov 18 00:10:31.631: ISAKMP:(0):Acceptable atts:actual life: 0
*Nov 18 00:10:31.631: ISAKMP:(0):Acceptable atts:life: 0
*Nov 18 00:10:31.631: ISAKMP:(0):Fill atts in sa vpi_length:4
*Nov 18 00:10:31.631: ISAKMP:(0):Fill atts in sa life_in_seconds:86400
*Nov 18 00:10:31.631: ISAKMP:(0):Returning Actual lifetime: 86400
*Nov 18 00:10:31.631: ISAKMP:(0)::Started lifetime timer: 86400.

*Nov 18 00:10:31.631: ISAKMP:(0): processing vendor id payload
*Nov 18 00:10:31.631: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
*Nov 18 00:10:31.631: ISAKMP (0): vendor ID is NAT-T RFC 3947
*Nov 18 00:10:31.631: ISAKMP:(0): processing vendor id payload
*Nov 18 00:10:31.631: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch
*Nov 18 00:10:31.631: ISAKMP (0): vendor ID is NAT-T v7
*Nov 18 00:10:31.631: ISAKMP:(0): processing vendor id payload
*Nov 18 00:10:31.631: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch
*Nov 18 00:10:31.631: ISAKMP:(0): vendor ID is NAT-T v3
*Nov 18 00:10:31.631: ISAKMP:(0): processing vendor id payload
*Nov 18 00:10:31.631: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
*Nov 18 00:10:31.631: ISAKMP:(0): vendor ID is NAT-T v2
*Nov 18 00:10:31.631: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Nov 18 00:10:31.631: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM1

*Nov 18 00:10:31.631: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
*Nov 18 00:10:31.631: ISAKMP:(0): sending packet to 103.7.79.86 my_port 500 peer_port 3220 (R) MM_SA_SETUP
vpngtw#
*Nov 18 00:10:31.631: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Nov 18 00:10:31.635: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Nov 18 00:10:31.635: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM2

*Nov 18 00:10:31.707: ISAKMP (0): received packet from 103.7.79.86 dport 500 sport 3220 Global (R) MM_SA_SETUP
*Nov 18 00:10:31.707: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Nov 18 00:10:31.707: ISAKMP:(0):Old State = IKE_R_MM2 New State = IKE_R_MM3

*Nov 18 00:10:31.711: ISAKMP:(0): processing KE payload. message ID = 0
*Nov 18 00:10:31.795: ISAKMP:(0): processing NONCE payload. message ID = 0
*Nov 18 00:10:31.795: ISAKMP:(0):found peer pre-shared key matching 103.7.79.86
*Nov 18 00:10:31.795: ISAKMP:(1006): processing vendor id payload
*Nov 18 00:10:31.795: ISAKMP:(1006): vendor ID is DPD
*Nov 18 00:10:31.795: ISAKMP:(1006): processing vendor id payload
*Nov 18 00:10:31.795: ISAKMP:(1006): speaking to another IOS box!
*Nov 18 00:10:31.795: ISAKMP:(1006): processing vendor id payload
*Nov 18 00:10:31.795: ISAKMP:(1006): vendor ID seems Unity/DPD but major 175 mismatch
*Nov 18 00:10:31.795: ISAKMP:(1006): vendor ID is XAUTH
*Nov 18 00:10:31.795: ISAKMP:received payload type 20
*Nov 18 00:10:31.795: ISAKMP (1006): His hash no match - this node outside NAT
*Nov 18 00:10:31.795: ISAKMP:received payload type 20
*Nov 18 00:10:31.795: ISAKMP (1006): His hash no match - this node outside NAT
*Nov 18 00:10:31.795: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Nov 18 00:10:31.795: ISAKMP:(1006):Old State = IKE_R_MM3 New State = IKE_R_MM3

*Nov 18 00:10:31.799: ISAKMP:(1006): sending packet to 103.7.79.86 my_port 500 peer_port 3220 (R) MM_KEY_EXCH
*Nov 18 00:10:31.799: ISAKMP:(1006):Sending an IKE IPv4 Packet.
*Nov 18 00:10:31.799: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Nov 18 00:10:31.799: ISAKMP:(1006):Old State = IKE_R_MM3 New State = IKE_R_MM4

*Nov 18 00:10:32.063: ISAKMP (1006): received packet from 103.7.79.86 dport 4500 sport 2289 Global (R) MM_KEY_EXCH
*Nov 18 00:10:32.063: ISAKMP:(1006):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Nov 18 00:10:32.063: ISAKMP:(1006):Old State = IKE_R_MM4 New State = IKE_R_MM5

*Nov 18 00:10:32.067: ISAKMP:(1006): processing ID payload. message ID = 0
*Nov 18 00:10:32.067: ISAKMP (1006): ID payload
next-payload : 8
type : 1
address : 172.14.1.101
protocol : 17
port : 0
length : 12
*Nov 18 00:10:32.067: ISAKMP:(0):: peer matches *none* of the profiles
*Nov 18 00:10:32.067: ISAKMP:(1006): processing HASH payload. message ID = 0
*Nov 18 00:10:32.067: ISAKMP:(1006): processing NOTIFY INITIAL_CONTACT protocol 1
spi 0, message ID = 0, sa = 0x50AC8D5C
*Nov 18 00:10:32.067: ISAKMP:(1006):SA authentication status:
authenticated
*Nov 18 00:10:32.067: ISAKMP:(1006):SA has been authenticated with 103.7.79.86
*Nov 18 00:10:32.067: ISAKMP:(1006):Detected port floating to port = 2289
*Nov 18 00:10:32.067: ISAKMP: Trying to find existing peer 110.36.222.118/103.7.79.86/2289/
*Nov 18 00:10:32.067: ISAKMP:(1006):SA authentication status:
authenticated
*Nov 18 00:10:32.067: ISAKMP:(1006): Process initial contact,
bring down existing phase 1 and 2 SA's with local 110.36.222.118 remote 103.7.79.86 remote port 2289
*Nov 18 00:10:32.067: ISAKMP: Trying to insert a peer 110.36.222.118/103.7.79.86/2289/, and inserted successfully 50A27918.
*Nov 18 00:10:32.067: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Nov 18 00:10:32.067: ISAKMP:(1006):Old State = IKE_R_MM5 New State = IKE_R_MM5

*Nov 18 00:10:32.067: IPSEC(key_engine): got a queue event with 1 KMI message(s)
*Nov 18 00:10:32.067: ISAKMP:(1006):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
*Nov 18 00:10:32.067: ISAKMP (1006): ID payload
next-payload : 8
type : 1
address : 110.36.222.118
protocol : 17
port : 0
length : 12
*Nov 18 00:10:32.067: ISAKMP:(1006):Total payload length: 12
*Nov 18 00:10:32.067: ISAKMP:(1006): sending packet to 103.7.79.86 my_port 4500 peer_port 2289 (R) MM_KEY_EXCH
*Nov 18 00:10:32.067: ISAKMP:(1006):Sending an IKE IPv4 Packet.
*Nov 18 00:10:32.071: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Nov 18 00:10:32.071: ISAKMP:(1006):Old State = IKE_R_MM5 New State = IKE_P1_COMPLETE

*Nov 18 00:10:32.071: ISAKMP:(1006):IKE_DPD is enabled, initializing timers
*Nov 18 00:10:32.071: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Nov 18 00:10:32.071: ISAKMP:(1006):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

*Nov 18 00:10:32.143: ISAKMP (1006): received packet from 103.7.79.86 dport 4500 sport 2289 Global (R) QM_IDLE
*Nov 18 00:10:32.143: ISAKMP: set new node -395466802 to QM_IDLE
*Nov 18 00:10:32.147: ISAKMP:(1006): processing HASH payload. message ID = 3899500494
*Nov 18 00:10:32.147: ISAKMP:(1006): processing SA payload. message ID = 3899500494
*Nov 18 00:10:32.147: ISAKMP:(1006):Checking IPSec proposal 1
*Nov 18 00:10:32.147: ISAKMP: transform 1, ESP_AES
*Nov 18 00:10:32.147: ISAKMP: attributes in transform:
*Nov 18 00:10:32.147: ISAKMP: encaps is 3 (Tunnel-UDP)
*Nov 18 00:10:32.147: ISAKMP: SA life type in seconds
*Nov 18 00:10:32.147: ISAKMP: SA life duration (basic) of 3600
*Nov 18 00:10:32.147: ISAKMP: SA life type in kilobytes
*Nov 18 00:10:32.147: ISAKMP: SA life duration (VPI) of 0x0 0x46 0x50 0x0
*Nov 18 00:10:32.147: ISAKMP: authenticator is HMAC-SHA
*Nov 18 00:10:32.147: ISAKMP: key length is 192
*Nov 18 00:10:32.147: ISAKMP:(1006):atts are acceptable.
*Nov 18 00:10:32.147: IPSEC(validate_proposal_request): proposal part #1
*Nov 18 00:10:32.147: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 110.36.222.118:0, remote= 103.7.79.86:0,
local_proxy= 110.36.222.118/255.255.255.255/47/0 (type=1),
remote_proxy= 172.14.1.101/255.255.255.255/47/0 (type=1),
protocol= ESP, transform= NONE (Tunnel-UDP),
lifedur= 0s and 0kb,
spi= 0x0(0), conn_id= 0, keysize= 192, flags= 0x0
*Nov 18 00:10:32.147: insert of map into mapdb AVL failed, map + ace pair already exists on the mapdb
*Nov 18 00:10:32.147: Crypto mapdb : proxy_match
src addr : 110.36.222.118
dst addr : 172.14.1.101
protocol : 47
src port : 0
dst port : 0
*Nov 18 00:10:32.147: ISAKMP:(1006): processing NONCE payload. message ID = 3899500494
*Nov 18 00:10:32.147: ISAKMP:(1006): processing ID payload. message ID = 3899500494
*Nov 18 00:10:32.147: ISAKMP:(1006): processing ID payload. message ID = 3899500494
*Nov 18 00:10:32.147: ISAKMP:(1006):QM Responder gets spi
*Nov 18 00:10:32.147: ISAKMP:(1006):Node 3899500494, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
*Nov 18 00:10:32.147: ISAKMP:(1006):Old State = IKE_QM_READY New State = IKE_QM_SPI_STARVE
*Nov 18 00:10:32.151: ISAKMP:(1006): Creating IPSec SAs
*Nov 18 00:10:32.151: inbound SA from 103.7.79.86 to 110.36.222.118 (f/i) 0/ 0
(proxy 172.14.1.101 to 110.36.222.118)
*Nov 18 00:10:32.151: has spi 0x12C047B4 and conn_id 0
*Nov 18 00:10:32.151: lifetime of 3600 seconds
*Nov 18 00:10:32.151: lifetime of 4608000 kilobytes
*Nov 18 00:10:32.151: outbound SA from 110.36.222.118 to 103.7.79.86 (f/i) 0/0
(proxy 110.36.222.118 to 172.14.1.101)
*Nov 18 00:10:32.151: has spi 0xF230D6E8 and conn_id 0
*Nov 18 00:10:32.151: lifetime of 3600 seconds
*Nov 18 00:10:32.151: lifetime of 4608000 kilobytes
*Nov 18 00:10:32.151: ISAKMP:(1006): sending packet to 103.7.79.86 my_port 4500 peer_port 2289 (R) QM_IDLE
*Nov 18 00:10:32.151: ISAKMP:(1006):Sending an IKE IPv4 Packet.
*Nov 18 00:10:32.151: ISAKMP:(1006):Node 3899500494, Input = IKE_MESG_INTERNAL, IKE_GOT_SPI
*Nov 18 00:10:32.151: ISAKMP:(1006):Old State = IKE_QM_SPI_STARVE New State = IKE_QM_R_QM2
*Nov 18 00:10:32.151: IPSEC(key_engine): got a queue event with 1 KMI message(s)
*Nov 18 00:10:32.155: Crypto mapdb : proxy_match
src addr : 110.36.222.118
dst addr : 172.14.1.101
protocol : 47
src port : 0
dst port : 0
*Nov 18 00:10:32.155: IPSEC(crypto_ipsec_sa_find_ident_head): reconnecting with the same proxies and peer 103.7.79.86
*Nov 18 00:10:32.155: IPSEC(policy_db_add_ident): src 110.36.222.118, dest 172.14.1.101, dest_port 0

*Nov 18 00:10:32.155: IPSEC(create_sa): sa created,
(sa) sa_dest= 110.36.222.118, sa_proto= 50,
sa_spi= 0x12C047B4(314591156),
sa_trans= esp-aes 192 esp-sha-hmac , sa_conn_id= 2011
sa_lifetime(k/sec)= (4456895/3600)
*Nov 18 00:10:32.155: IPSEC(create_sa): sa created,
(sa) sa_dest= 103.7.79.86, sa_proto= 50,
sa_spi= 0xF230D6E8(4063287016),
sa_trans= esp-aes 192 esp-sha-hmac , sa_conn_id= 2012
sa_lifetime(k/sec)= (4456895/3600)
*Nov 18 00:10:32.155: IPSEC(crypto_ipsec_update_ident_tunnel_decap_oce): updating Tunnel10 ident 4DEA443C with tun_decap_oce 4BF07C70
*Nov 18 00:10:32.227: ISAKMP (1006): received packet from 103.7.79.86 dport 4500 sport 2289 Global (R) QM_IDLE
*Nov 18 00:10:32.227: ISAKMP:(1006):deleting node -395466802 error FALSE reason "QM done (await)"
*Nov 18 00:10:32.231: ISAKMP:(1006):Node 3899500494, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
*Nov 18 00:10:32.231: ISAKMP:(1006):Old State = IKE_QM_R_QM2 New State = IKE_QM_PHASE2_COMPLETE
*Nov 18 00:10:32.231: IPSEC(key_engine): got a queue event with 1 KMI message(s)
vpngtw#
*Nov 18 00:10:32.231: IPSEC(key_engine_enable_outbound): rec'd enable notify from ISAKMP
*Nov 18 00:10:32.231: IPSEC(key_engine_enable_outbound): enable SA with spi 4063287016/50
*Nov 18 00:10:32.231: IPSEC(update_current_outbound_sa): get enable SA peer 103.7.79.86 current outbound sa to SPI F230D6E8
*Nov 18 00:10:32.231: IPSEC(update_current_outbound_sa): updated peer 103.7.79.86 current outbound sa to SPI F230D6E8

Debugs On Spoke:

*Nov 17 20:27:44.671: IPSEC(sa_request): ,
(key eng. msg.) OUTBOUND local= 172.14.1.101, remote= 110.36.222.118,
local_proxy= 172.14.1.101/255.255.255.255/47/0 (type=1),
remote_proxy= 110.36.222.118/255.255.255.255/47/0 (type=1),
protocol= ESP, transform= esp-aes 192 esp-sha-hmac (Tunnel),
lifedur= 3600s and 4608000kb,
spi= 0x0(0), conn_id= 0, keysize= 192, flags= 0x0
*Nov 17 20:27:44.671: ISAKMP:(0): SA request profile is (NULL)
*Nov 17 20:27:44.671: ISAKMP: Created a peer struct for 110.36.222.118, peer port 500
*Nov 17 20:27:44.671: ISAKMP: New peer created peer = 0x85A59450 peer_handle = 0x80000009
*Nov 17 20:27:44.671: ISAKMP: Locking peer struct 0x85A59450, refcount 1 for isakmp_initiator
*Nov 17 20:27:44.671: ISAKMP: local port 500, remote port 500
*Nov 17 20:27:44.671: ISAKMP: set new node 0 to QM_IDLE
*Nov 17 20:27:44.671: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 85F4A274
*Nov 17 20:27:44.671: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
*Nov 17 20:27:44.671: ISAKMP:(0):found peer pre-shared key matching 110.36.222.118
*Nov 17 20:27:44.671: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
*Nov 17 20:27:44.671: ISAKMP:(0): constructed NAT-T vendor-07 ID
*Nov 17 20:27:44.671: ISAKMP:(0): constructed NAT-T vendor-03 ID
*Nov 17 20:27:44.671: ISAKMP:(0): constructed NAT-T vendor-02 ID
*Nov 17 20:27:44.671: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
*Nov 17 20:27:44.671: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1

*Nov 17 20:27:44.671: ISAKMP:(0): beginning Main Mode exchange
*Nov 17 20:27:44.671: ISAKMP:(0): sending packet to 110.36.222.118 my_port 500 peer_port 500 (I) MM_NO_STATE
*Nov 17 20:27:44.671: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Nov 17 20:27:44.775: ISAKMP (0): received packet from 110.36.222.118 dport 500 sport 500 Global (I) MM_NO_STATE
*Nov 17 20:27:44.775: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Nov 17 20:27:44.775: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2

*Nov 17 20:27:44.775: ISAKMP:(0): processing SA payload. message ID = 0
*Nov 17 20:27:44.779: ISAKMP:(0): processing vendor id payload
*Nov 17 20:27:44.779: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
*Nov 17 20:27:44.779: ISAKMP (0): vendor ID is NAT-T RFC 3947
*Nov 17 20:27:44.779: ISAKMP:(0):found peer pre-shared key matching 110.36.222.118
*Nov 17 20:27:44.779: ISAKMP:(0): local preshared key found
*Nov 17 20:27:44.779: ISAKMP : Scanning profiles for xauth ...
*Nov 17 20:27:44.779: ISAKMP:(0):Checking ISAKMP transform 1 against priority 10 policy
*Nov 17 20:27:44.779: ISAKMP: encryption AES-CBC
*Nov 17 20:27:44.779: ISAKMP: keylength of 192
*Nov 17 20:27:44.779: ISAKMP: hash SHA
*Nov 17 20:27:44.779: ISAKMP: default group 5
*Nov 17 20:27:44.779: ISAKMP: auth pre-share
*Nov 17 20:27:44.779: ISAKMP: life type in seconds
*Nov 17 20:27:44.779: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80
*Nov 17 20:27:44.779: ISAKMP:(0):atts are acceptable. Next payload is 0
*Nov 17 20:27:44.779: ISAKMP:(0):Acceptable atts:actual life: 0
*Nov 17 20:27:44.779: ISAKMP:(0):Acceptable atts:life: 0
*Nov 17 20:27:44.779: ISAKMP:(0):Fill atts in sa vpi_length:4
*Nov 17 20:27:44.779: ISAKMP:(0):Fill atts in sa life_
Router#in_seconds:86400
*Nov 17 20:27:44.779: ISAKMP:(0):Returning Actual lifetime: 86400
*Nov 17 20:27:44.779: ISAKMP:(0)::Started lifetime timer: 86400.

*Nov 17 20:27:44.779: ISAKMP:(0): processing vendor id payload
*Nov 17 20:27:44.779: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
*Nov 17 20:27:44.779: ISAKMP (0): vendor ID is NAT-T RFC 3947
*Nov 17 20:27:44.779: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Nov 17 20:27:44.779: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2

*Nov 17 20:27:44.779: ISAKMP:(0): sending packet to 110.36.222.118 my_port 500 peer_port 500 (I) MM_SA_SETUP
*Nov 17 20:27:44.779: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Nov 17 20:27:44.779: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Nov 17 20:27:44.779: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3

*Nov 17 20:27:44.935: ISAKMP (0): received packet from 110.36.222.118 dport 500 sport 500 Global (I) MM_SA_SETUP
*Nov 17 20:27:44.935: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Nov 17 20:27:44.935: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4

*Nov 17 20:27:44.935: ISAKMP:(0): processing KE payload. message ID = 0
*Nov 17 20:27:45.023: ISAKMP:(0): processing NONCE payload. message ID = 0
*Nov 17 20:27:45.023: ISAKMP:(0):found peer pre-shared key matching 110.36.222.118
*Nov 17 20:27:45.023: ISAKMP:(2008): processing vendor id payload
*Nov 17 20:27:45.023: ISAKMP:(2008): vendor ID is Unity
*Nov 17 20:27:45.023: ISAKMP:(2008): processing vendor id payload
*Nov 17 20:27:45.023: ISAKMP:(2008): vendor ID is DPD
*Nov 17 20:27:45.023: ISAKMP:(2008): processing vendor id payload
*Nov 17 20:27:45.023: ISAKMP:(2008): speaking to another IOS box!
*Nov 17 20:27:45.023: ISAKMP:received payload type 20
*Nov 17 20:27:45.023: ISAKMP (2008): NAT found, both nodes inside NAT
*Nov 17 20:27:45.023: ISAKMP:received payload type 20
*Nov 17 20:27:45.023: ISAKMP (2008): My hash no match - this node inside NAT
*Nov 17 20:27:45.023: ISAKMP:(2008):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Nov 17 20:27:45.023: ISAKMP:(2008):Old State = IKE_I_MM4 New State = IKE_I_MM4

*Nov 17 20:27:45.023: ISAKMP:(2008):Send initial contact
*Nov 17 20:27:45.023: ISAKMP:(2008):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
*Nov 17 20:27:45.023: ISAKMP (2008): ID payload
next-payload : 8
type : 1
address : 172.14.1.101
protocol : 17
port : 0
length : 12
*Nov 17 20:27:45.023: ISAKMP:(2008):Total payload length: 12
*Nov 17 20:27:45.023: ISAKMP:(2008): sending packet to 110.36.222.118 my_port 4500 peer_port 4500 (I) MM_KEY_EXCH
*Nov 17 20:27:45.023: ISAKMP:(2008):Sending an IKE IPv4 Packet.
*Nov 17 20:27:45.023: ISAKMP:(2008):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Nov 17 20:27:45.023: ISAKMP:(2008):Old State = IKE_I_MM4 New State = IKE_I_MM5

*Nov 17 20:27:45.127: ISAKMP (2008): received packet from 110.36.222.118 dport 4500 sport 4500 Global (I) MM_KEY_EXCH
*Nov 17 20:27:45.127: ISAKMP:(2008): processing ID payload. message ID = 0
*Nov 17 20:27:45.127: ISAKMP (2008): ID payload
next-payload : 8
type : 1
address : 110.36.222.118
protocol : 17
port : 0
length : 12
*Nov 17 20:27:45.127: ISAKMP:(0):: peer matches
Router# *none* of the profiles
*Nov 17 20:27:45.127: ISAKMP:(2008): processing HASH payload. message ID = 0
*Nov 17 20:27:45.131: ISAKMP:(2008):SA authentication status:
authenticated
*Nov 17 20:27:45.131: ISAKMP:(2008):SA has been authenticated with 110.36.222.118
*Nov 17 20:27:45.131: ISAKMP:(2008):Setting UDP ENC peer struct 0x85F85614 sa= 0x85F4A274
*Nov 17 20:27:45.131: ISAKMP: Trying to insert a peer 172.14.1.101/110.36.222.118/4500/, and inserted successfully 85A59450.
*Nov 17 20:27:45.131: ISAKMP:(2008):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Nov 17 20:27:45.131: ISAKMP:(2008):Old State = IKE_I_MM5 New State = IKE_I_MM6

*Nov 17 20:27:45.131: ISAKMP:(2008):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Nov 17 20:27:45.131: ISAKMP:(2008):Old State = IKE_I_MM6 New State = IKE_I_MM6

*Nov 17 20:27:45.131: ISAKMP:(2008):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Nov 17 20:27:45.131: ISAKMP:(2008):Old State = IKE_I_MM6 New State = IKE_P1_COMPLETE

*Nov 17 20:27:45.131: ISAKMP:(2008):beginning Quick Mode exchange, M-ID of 1325600505
*Nov 17 20:27:45.131: ISAKMP:(2008):QM Initiator gets spi
*Nov 17 20:27:45.131: ISAKMP:(2008): sending packet to 110.36.222.118 my_port 4500 peer_port 4500 (I) QM_IDLE
*Nov 17 20:27:45.131: ISAKMP:(2008):Sending an IKE IPv4 Packet.
*Nov 17 20:27:45.131: ISAKMP:(2008):Node 1325600505, Input = IKE_MESG_INTERNAL, IKE_INIT_QM
*Nov 17 20:27:45.131: ISAKMP:(2008):Old State = IKE_QM_READY New State = IKE_QM_I_QM1
*Nov 17 20:27:45.131: ISAKMP:(2008):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Nov 17 20:27:45.131: ISAKMP:(2008):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

*Nov 17 20:27:45.203: ISAKMP (2008): received packet from 110.36.222.118 dport 4500 sport 4500 Global (I) QM_IDLE
*Nov 17 20:27:45.203: ISAKMP:(2008): processing HASH payload. message ID = 1325600505
*Nov 17 20:27:45.203: ISAKMP:(2008): processing SA payload. message ID = 1325600505
*Nov 17 20:27:45.203: ISAKMP:(2008):Checking IPSec proposal 1
*Nov 17 20:27:45.203: ISAKMP: transform 1, ESP_AES
*Nov 17 20:27:45.203: ISAKMP: attributes in transform:
*Nov 17 20:27:45.203: ISAKMP: encaps is 3 (Tunnel-UDP)
*Nov 17 20:27:45.203: ISAKMP: SA life type in seconds
*Nov 17 20:27:45.203: ISAKMP: SA life duration (basic) of 3600
*Nov 17 20:27:45.207: ISAKMP: SA life type in kilobytes
*Nov 17 20:27:45.207: ISAKMP: SA life duration (VPI) of 0x0 0x46 0x50 0x0
*Nov 17 20:27:45.207: ISAKMP: authenticator is HMAC-SHA
*Nov 17 20:27:45.207: ISAKMP: key length is 192
*Nov 17 20:27:45.207: ISAKMP:(2008):atts are acceptable.
*Nov 17 20:27:45.207: IPSEC(validate_proposal_request): proposal part #1
*Nov 17 20:27:45.207: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 172.14.1.101, remote= 110.36.222.118,
local_proxy= 172.14.1.101/255.255.255.255/47/0 (type=1),
remote_proxy= 110.36.222.118/255.255.255.255/47/0 (type=1),
protocol= ESP, transform= NONE (Tunnel-UDP),
lifedur= 0s and 0kb,
spi= 0x0(0), conn_id= 0, keysize= 192, flags= 0x0
*Nov 17 20:27:45.207: Crypto mapdb : proxy_match
src addr : 172.14.1.101
dst addr : 110.36.222.118
protocol : 47
src port : 0
dst port : 0
*Nov 17 20:27:45.207: ISAKMP:(2008): processing N
Router#ONCE payload. message ID = 1325600505
*Nov 17 20:27:45.207: ISAKMP:(2008): processing ID payload. message ID = 1325600505
*Nov 17 20:27:45.207: ISAKMP:(2008): processing ID payload. message ID = 1325600505
*Nov 17 20:27:45.207: ISAKMP:(2008): Creating IPSec SAs
*Nov 17 20:27:45.207: inbound SA from 110.36.222.118 to 172.14.1.101 (f/i) 0/ 0
(proxy 110.36.222.118 to 172.14.1.101)
*Nov 17 20:27:45.207: has spi 0x8847D8DB and conn_id 0
*Nov 17 20:27:45.207: lifetime of 3600 seconds
*Nov 17 20:27:45.207: lifetime of 4608000 kilobytes
*Nov 17 20:27:45.207: outbound SA from 172.14.1.101 to 110.36.222.118 (f/i) 0/0
(proxy 172.14.1.101 to 110.36.222.118)
*Nov 17 20:27:45.207: has spi 0xBBA8248F and conn_id 0
*Nov 17 20:27:45.207: lifetime of 3600 seconds
*Nov 17 20:27:45.207: lifetime of 4608000 kilobytes
*Nov 17 20:27:45.207: ISAKMP:(2008): sending packet to 110.36.222.118 my_port 4500 peer_port 4500 (I) QM_IDLE
*Nov 17 20:27:45.207: ISAKMP:(2008):Sending an IKE IPv4 Packet.
*Nov 17 20:27:45.207: ISAKMP:(2008):deleting node 1325600505 error FALSE reason "No Error"
*Nov 17 20:27:45.207: ISAKMP:(2008):Node 1325600505, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
*Nov 17 20:27:45.207: ISAKMP:(2008):Old State = IKE_QM_I_QM1 New State = IKE_QM_PHASE2_COMPLETE
*Nov 17 20:27:45.207: IPSEC(key_engine): got a queue event with 1 KMI message(s)
*Nov 17 20:27:45.207: Crypto mapdb : proxy_match
src addr : 172.14.1.101
dst addr : 110.36.222.118
protocol : 47
src port : 0
dst port : 0
*Nov 17 20:27:45.207: IPSEC(crypto_ipsec_sa_find_ident_head): reconnecting with the same proxies and peer 110.36.222.118
*Nov 17 20:27:45.207: IPSEC(policy_db_add_ident): src 172.14.1.101, dest 110.36.222.118, dest_port 0

*Nov 17 20:27:45.211: IPSEC(create_sa): sa created,
(sa) sa_dest= 172.14.1.101, sa_proto= 50,
sa_spi= 0x8847D8DB(2286409947),
sa_trans= esp-aes 192 esp-sha-hmac , sa_conn_id= 15
sa_lifetime(k/sec)= (4546487/3600)
*Nov 17 20:27:45.211: IPSEC(create_sa): sa created,
(sa) sa_dest= 110.36.222.118, sa_proto= 50,
sa_spi= 0xBBA8248F(3148358799),
sa_trans= esp-aes 192 esp-sha-hmac , sa_conn_id= 16
sa_lifetime(k/sec)= (4546487/3600)
*Nov 17 20:27:45.211: IPSEC(update_current_outbound_sa): updated peer 110.36.222.118 current outbound sa to SPI BBA8248F.

[Larry Sullivan]

What's results of "show crypto ipsec sa" ?