IPsec preferred peer + reverse route static

Hello

A bit of a pause with automation this week. I’ve been assigned a task to set up a redundant crypto-based VPN, a task which is in fact quite easy but for some weird reason Cisco documentation doesn’t describe how to do this in the peer preferred feature.
The problem is here that you can’t set up static routes with a track object because there’s nothing to link the track object to if you don’t have logical tunnel interfaces. Of course, there’s always EEM scripts that could activate routes if it sees ”tunnel up/down” events in the syslog but… let’s be serious. Besides, I was curious to see how fast this redundancy works.
vpn_redundancy

R1 has 1.1.1.1, both R2 and R3 have 2.2.2.2 as their loopback to simulate redundant LANs behind them (e.g. distributed data center)

crypto isakmp policy 10
encr 3des
authentication pre-share
group 5
crypto isakmp key cisco address 0.0.0.0
crypto isakmp keepalive 10
crypto ipsec transform-set MYSET esp-3des esp-sha-hmac
mode tunnel
crypto map MYMAP 10 ipsec-isakmp
set peer 101.1.1.1 default !!!by default tunnel goes to R2
set peer 102.1.1.1 !!! if keepalives (DPD) to R2 fail, tunnel is initiated to R3
set transform-set MYSET
match address MYACL
reverse-route static !!!this installs routes to 2.2.2.2 dynamically based on ACL and state of DPD
crypto map MYMAP


ip access-list ext MYACL
permit ip host 1.1.1.1 2.2.2.2

int loopback0
ip addr 1.1.1.1 255.255.255.255

 

Now let’s ping 2.2.2.2 from R1’s 1.1.1.1 when R2 and R3 are up with crypto isakmp debug on.

IOU1#ping 2.2.2.2 source 1.1.1.1
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 2.2.2.2, timeout is 2 seconds:
Packet sent with a source address of 1.1.1.1

*Aug 7 03:11:44.860: ISAKMP:(0): SA request profile is (NULL)
*Aug 7 03:11:44.860: ISAKMP: Created a peer struct for 101.1.1.1, peer port 500
*Aug 7 03:11:44.860: ISAKMP: New peer created peer = 0xF2F1E4D8 peer_handle = 0x80000006
*Aug 7 03:11:44.860: ISAKMP: Locking peer struct 0xF2F1E4D8, refcount 1 for isakmp_initiator
*Aug 7 03:11:44.860: ISAKMP: local port 500, remote port 500
*Aug 7 03:11:44.860: ISAKMP: set new node 0 to QM_IDLE
*Aug 7 03:11:44.860: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = F2F30F50
*Aug 7 03:11:44.860: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
*Aug 7 03:11:44.860: ISAKMP:(0):found peer pre-shared key matching 101.1.1.1
*Aug 7 03:11:44.860: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
*Aug 7 03:11:44.860: ISAKMP:(0): constructed NAT-T vendor-07 ID
*Aug 7 03:11:44.860: ISAKMP:(0): constructed NAT-T vendor-03 ID
*Aug 7 03:11:44.860: ISAKMP:(0): constructed NAT-T vendor-02 ID
*Aug 7 03:11:44.860: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
*Aug 7 03:11:44.860: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1

*Aug 7 03:11:44.860: ISAKMP:(0): beginning Main Mode exchange
*Aug 7 03:11:44.860: ISAKMP:(0): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
*Aug 7 03:11:44.860: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Aug 7 03:11:44.863: ISAKMP (0): received packet from 101.1.1.1 dport 500 sport 500 Global (I) MM_NO_STATE
*Aug 7 03:11:44.863: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Aug 7 03:11:44.863: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2

*Aug 7 03:11:44.863: ISAKMP:(0): processing SA payload. message ID = 0
*Aug 7 03:11:44.863: ISAKMP:(0): processing vendor id payload
*Aug 7 03:11:44.863: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
*Aug 7 03:11:44.863: ISAKMP (0): vendor ID is NAT-T RFC 3947
*Aug 7 03:11:44.863: ISAKMP:(0):found peer pre-shared key matching 101.1.1.1
*Aug 7 03:11:44.863: ISAKMP:(0): local preshared key found
*Aug 7 03:11:44.863: ISAKMP : Scanning profiles for xauth ...
*Aug 7 03:11:44.863: ISAKMP:(0):Checking ISAKMP transform 1 against priority 10 policy
*Aug 7 03:11:44.863: ISAKMP: encryption 3DES-CBC
*Aug 7 03:11:44.863: ISAKMP: hash SHA
*Aug 7 03:11:44.863: ISAKMP: default group 5
*Aug 7 03:11:44.863: ISAKMP: auth pre-share
*Aug 7 03:11:44.863: ISAKMP: life type in seconds
*Aug 7 03:11:44.863: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80
*Aug 7 03:11:44.863: ISAKMP:(0):atts are acceptable. Next payload is 0
*Aug 7 03:11:44.863: ISAKMP:(0):Acceptable atts:actual life: 0
*Aug 7 03:11:44.863: ISAKMP:(0):Acceptable atts:life: 0
*Aug 7 03:11:44.863: ISAKMP:(0):Fill atts in sa vpi_length:4
*Aug 7 03:11:44.863: ISAKMP:(0):Fill atts in sa life_in_seconds:86400
*Aug 7 03:11:44.863: ISAKMP:(0):Returning Actual lifetime: 86400
*Aug 7 03:11:44.863: ISAKMP:(0)::Started lifetime timer: 86400.

*Aug 7 03:11:44.863: ISAKMP:(0): processing vendor id payload
*Aug 7 03:11:44.863: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
*Aug 7 03:11:44.863: ISAKMP (0): vendor ID is NAT-T RFC 3947
*Aug 7 03:11:44.863: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Aug 7 03:11:44.863: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2

*Aug 7 03:11:44.863: ISAKMP:(0): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_SA_SETUP
*Aug 7 03:11:44.863: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Aug 7 03:11:44.863: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Aug 7 03:11:44.863: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3

*Aug 7 03:11:44.882: ISAKMP (0): received packet from 101.1.1.1 dport 500 sport 500 Global (I) MM_SA_SETUP
*Aug 7 03:11:44.882: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Aug 7 03:11:44.882: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4

*Aug 7 03:11:44.882: ISAKMP:(0): processing KE payload. message ID = 0
*Aug 7 03:11:44.896: ISAKMP:(0): processing NONCE payload. message ID = 0
*Aug 7 03:11:44.896: ISAKMP:(0):found peer pre-shared key matching 101.1.1.1
*Aug 7 03:11:44.896: ISAKMP:(1004): processing vendor id payload
*Aug 7 03:11:44.896: ISAKMP:(1004): vendor ID is Unity
*Aug 7 03:11:44.896: ISAKMP:(1004): processing vendor id payload
*Aug 7 03:11:44.896: ISAKMP:(1004): vendor ID is DPD
*Aug 7 03:11:44.896: ISAKMP:(1004): processing vendor id payload
*Aug 7 03:11:44.896: ISAKMP:(1004): speaking to another IOS box!
*Aug 7 03:11:44.896: ISAKMP:received payload type 20
*Aug 7 03:11:44.896: ISAKMP (1004): His hash no match - this node outside NAT
*Aug 7 03:11:44.896: ISAKMP:received payload type 20
*Aug 7 03:11:44.896: ISAKMP (1004): No NAT Found for self or peer
*Aug 7 03:11:44.896: ISAKMP:(1004):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Aug 7 03:11:44.896: ISAKMP:(1004):Old State = IKE_I_MM4 New State = IKE_I_MM4

*Aug 7 03:11:44.897: ISAKMP:(1004):Send initial contact
*Aug 7 03:11:44.897: ISAKMP:(1004):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
*Aug 7 03:11:44.897: ISAKMP (1004): ID payload
next-payload : 8
type : 1
address : 100.1.1.1
protocol : 17
port : 500
length : 12
*Aug 7 03:11:44.897: ISAKMP:(1004):Total payload length: 12
*Aug 7 03:11:44.897: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_KEY_EXCH
*Aug 7 03:11:44.897: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:11:44.897: ISAKMP:(1004):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Aug 7 03:11:44.897: ISAKMP:(1004):Old State = IKE_I_MM4 New State = IKE_I_MM5

*Aug 7 03:11:44.899: ISAKMP (1004): received packet from 101.1.1.1 dport 500 sport 500 Global (I) MM_KEY_EXCH
*Aug 7 03:11:44.899: ISAKMP:(1004): processing ID payload. message ID = 0
*Aug 7 03:11:44.899: ISAKMP (1004): ID payload
next-payload : 8
type : 1
address : 101.1.1.1
protocol : 17
port : 500
length : 12
*Aug 7 03:11:44.899: ISAKMP:(0):: peer matches *none* of the profiles
*Aug 7 03:11:44.899: ISAKMP:(1004): processing HASH payload. message ID = 0
*Aug 7 03:11:44.899: ISAKMP:(1004):SA authentication status:
authenticated
*Aug 7 03:11:44.899: ISAKMP:(1004):SA has been authenticated with 101.1.1.1
*Aug 7 03:11:44.899: ISAKMP: Trying to insert a peer 100.1.1.1/101.1.1.1/500/, and inserted successfully F2F1E4D8.
*Aug 7 03:11:44.899: ISAKMP:(1004):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Aug 7 03:11:44.899: ISAKMP:(1004):Old State = IKE_I_MM5 New State = IKE_I_MM6

*Aug 7 03:11:44.900: ISAKMP:(1004):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Aug 7 03:11:44.900: ISAKMP:(1004):Old State = IKE_I_MM6 New State = IKE_I_MM6

*Aug 7 03:11:44.909: ISAKMP:(1004):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Aug 7 03:11:44.909: ISAKMP:(1004):Old State = IKE_I_MM6 New State = IKE_P1_COMPLETE

*Aug 7 03:11:44.909: ISAKMP:(1004):IKE_DPD is enabled, initializing timers
*Aug 7 03:11:44.909: ISAKMP:(1004):beginning Quick Mode exchange, M-ID of 3736979590
*Aug 7 03:11:44.909: ISAKMP:(1004):QM Initiator gets spi
*Aug 7 03:11:44.909: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:11:44.909: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:11:44.909: ISAKMP:(1004):Node 3736979590, Input = IKE_MESG_INTERNAL, IKE_INIT_QM
*Aug 7 03:11:44.909: ISAKMP:(1004):Old State = IKE_QM_READY New State = IKE_QM_I_QM1
*Aug 7 03:11:44.909: ISAKMP:(1004):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Aug 7 03:11:44.909: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

*Aug 7 03:11:44.913: ISAKMP (1004): received packet from 101.1.1.1 dport 500 sport 500 Global (I) QM_IDLE
*Aug 7 03:11:44.913: ISAKMP:(1004): processing HASH payload. message ID = 3736979590
*Aug 7 03:11:44.913: ISAKMP:(1004): processing SA payload. message ID = 3736979590
*Aug 7 03:11:44.913: ISAKMP:(1004):Checking IPSec proposal 1
*Aug 7 03:11:44.913: ISAKMP: transform 1, ESP_3DES
*Aug 7 03:11:44.913: ISAKMP: attributes in transform:
*Aug 7 03:11:44.913: ISAKMP: encaps is 1 (Tunnel)
*Aug 7 03:11:44.913: ISAKMP: SA life type in seconds
*Aug 7 03:11:44.913: ISAKMP: SA life duration (basic) of 3600
*Aug 7 03:11:44.913: ISAKMP: SA life type in kilobytes
*Aug 7 03:11:44.913: ISAKMP: SA life duration (VPI) of 0x0 0x46 0x50 0x0
*Aug 7 03:11:44.913: ISAKMP: authenticator is HMAC-SHA
*Aug 7 03:11:44.913: ISAKMP:(1004):atts are acceptable.
*Aug 7 03:11:44.913: ISAKMP:(1004): processing NONCE payload. message ID = 3736979590
*Aug 7 03:11:44.913: ISAKMP:(1004): processing ID payload. message ID = 3736979590
*Aug 7 03:11:44.913: ISAKMP:(1004): processing ID payload. message ID = 3736979590
*Aug 7 03:11:44.913: ISAKMP:(1004):Node 3736979590, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
*Aug 7 03:11:44.913: ISAKMP:(1004):Old State = IKE_QM_I_QM1 New State = IKE_QM_IPSEC_INSTALL_AWAIT
*Aug 7 03:11:44.913: ISAKMP: Failed to find peer index node to update peer_info_list
*Aug 7 03:11:44.914: ISAKMP:(1004):Received IPSec Install callback... proceeding with the negotiation
*Aug 7 03:11:44.914: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:11:44.914: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:11:44.914: ISAKMP:(1004):deleting node -557987706 error FALSE reason "No Error"
*Aug 7 03:11:44.914: ISAKMP:(1004):Node 3736979590, Input = IKE_MESG_FROM_IPSEC, IPSEC_INSTALL_DONE
*Aug 7 03:11:44.914: ISAKMP:(1004):Old State = IKE_QM_IPSEC_INSTALL_AWAIT New State = IKE_QM_PHASE2_COMPLETE.!!!!
Success rate is 80 percent (4/5), round-trip min/avg/max = 8/12/18 ms
IOU1#
*Aug 7 03:11:57.029: ISAKMP (1004): received packet from 101.1.1.1 dport 500 sport 500 Global (I) QM_IDLE
*Aug 7 03:11:57.029: ISAKMP: set new node 2039185025 to QM_IDLE
*Aug 7 03:11:57.029: ISAKMP:(1004): processing HASH payload. message ID = 2039185025
*Aug 7 03:11:57.029: ISAKMP:(1004): processing NOTIFY DPD/R_U_THERE protocol 1
spi 0, message ID = 2039185025, sa = 0xF2F30F50
*Aug 7 03:11:57.029: ISAKMP:(1004):deleting node 2039185025 error FALSE reason "Informational (in) state 1"
*Aug 7 03:11:57.029: ISAKMP:(1004):Input = IKE_MESG_FROM_PEER, IKE_INFO_NOTIFY
*Aug 7 03:11:57.029: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

*Aug 7 03:11:57.029: ISAKMP:(1004):DPD/R_U_THERE received from peer 101.1.1.1, sequence 0x6EEFB371
*Aug 7 03:11:57.029: ISAKMP: set new node 1411802357 to QM_IDLE
*Aug 7 03:11:57.029: ISAKMP:(1004):Sending NOTIFY DPD/R_U_THERE_ACK protocol 1
spi 4087798040, message ID = 1411802357
*Aug 7 03:11:57.029: ISAKMP:(1004): seq. no 0x6EEFB371
*Aug 7 03:11:57.029: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:11:57.029: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:11:57.030: ISAKMP:(1004):purging node 1411802357
*Aug 7 03:11:57.030: ISAKMP:(1004):Input = IKE_MESG_FROM_PEER, IKE_MESG_KEEP_ALIVE
IOU1#
*Aug 7 03:11:57.030: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

Now on R2 let’s shut down the public facing interface eth0/0 and see what happens on R1.

IOU1#ping 2.2.2.2 source 1.1.1.1
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 2.2.2.2, timeout is 2 seconds:
Packet sent with a source address of 1.1.1.1
.....
Success rate is 0 percent (0/5)

*Aug 7 03:14:55.573: ISAKMP: DPD received KMI message.
*Aug 7 03:14:55.573: ISAKMP: set new node 1236715696 to QM_IDLE
*Aug 7 03:14:55.573: ISAKMP:(1004):Sending NOTIFY DPD/R_U_THERE protocol 1
spi 4073138204, message ID = 1236715696
*Aug 7 03:14:55.573: ISAKMP:(1004): seq. no 0x484909A3
*Aug 7 03:14:55.573: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:14:55.574: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:14:55.574: ISAKMP:(1004):purging node 1236715696
IOU1#show ip route
*Aug 7 03:14:57.586: ISAKMP:(1004):DPD incrementing error counter (1/5)
*Aug 7 03:14:57.586: ISAKMP: set new node -140430850 to QM_IDLE
*Aug 7 03:14:57.586: ISAKMP:(1004):Sending NOTIFY DPD/R_U_THERE protocol 1
spi 4087797952, message ID = 4154536446
*Aug 7 03:14:57.586: ISAKMP:(1004): seq. no 0x484909A4
*Aug 7 03:14:57.586: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:14:57.586: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:14:57.586: ISAKMP:(1004):purging node -140430850
*Aug 7 03:14:57.586: ISAKMP:(1004):Input = IKE_MESG_FROM_TIMER, IKE_TIMER_PEERS_ALIVE
IOU1#
*Aug 7 03:14:57.586: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

IOU1#
*Aug 7 03:14:59.592: ISAKMP:(1004):DPD incrementing error counter (2/5)
*Aug 7 03:14:59.592: ISAKMP: set new node 2080816415 to QM_IDLE
*Aug 7 03:14:59.592: ISAKMP:(1004):Sending NOTIFY DPD/R_U_THERE protocol 1
spi 4087797952, message ID = 2080816415
*Aug 7 03:14:59.592: ISAKMP:(1004): seq. no 0x484909A5
*Aug 7 03:14:59.592: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:14:59.592: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:14:59.592: ISAKMP:(1004):purging node 2080816415
*Aug 7 03:14:59.592: ISAKMP:(1004):Input = IKE_MESG_FROM_TIMER, IKE_TIMER_PEERS_ALIVE
IOU1#
*Aug 7 03:14:59.592: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

IOU1#
*Aug 7 03:15:02.855: ISAKMP:(1004):DPD incrementing error counter (3/5)
*Aug 7 03:15:02.855: ISAKMP: set new node 527308109 to QM_IDLE
*Aug 7 03:15:02.855: ISAKMP:(1004):Sending NOTIFY DPD/R_U_THERE protocol 1
spi 4087797952, message ID = 527308109
*Aug 7 03:15:02.855: ISAKMP:(1004): seq. no 0x484909A6
*Aug 7 03:15:02.855: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:15:02.855: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:15:02.855: ISAKMP:(1004):purging node 527308109
*Aug 7 03:15:02.855: ISAKMP:(1004):Input = IKE_MESG_FROM_TIMER, IKE_TIMER_PEERS_ALIVE
IOU1#
*Aug 7 03:15:02.855: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

IOU1#
*Aug 7 03:15:04.855: ISAKMP:(1004):DPD incrementing error counter (4/5)
*Aug 7 03:15:04.855: ISAKMP: set new node -345256241 to QM_IDLE
*Aug 7 03:15:04.855: ISAKMP:(1004):Sending NOTIFY DPD/R_U_THERE protocol 1
spi 4087797952, message ID = 3949711055
*Aug 7 03:15:04.855: ISAKMP:(1004): seq. no 0x484909A7
*Aug 7 03:15:04.855: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:15:04.855: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:15:04.855: ISAKMP:(1004):purging node -345256241
*Aug 7 03:15:04.855: ISAKMP:(1004):Input = IKE_MESG_FROM_TIMER, IKE_TIMER_PEERS_ALIVE
IOU1#
*Aug 7 03:15:04.855: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

IOU1#
*Aug 7 03:15:06.860: ISAKMP:(1004):DPD incrementing error counter (5/5)
*Aug 7 03:15:06.860: ISAKMP:(1004):peer 101.1.1.1 not responding!
*Aug 7 03:15:06.860: ISAKMP:(1004):peer does not do paranoid keepalives.

*Aug 7 03:15:06.860: ISAKMP:(1004):deleting SA reason "End of ipsec tunnel" state (I) QM_IDLE (peer 101.1.1.1)
*Aug 7 03:15:06.860: ISAKMP:(1004):Input = IKE_MESG_FROM_TIMER, IKE_TIMER_PEERS_ALIVE
*Aug 7 03:15:06.860: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

*Aug 7 03:15:06.860: ISAKMP: Failed to find peer index node to update peer_info_list
*Aug 7 03:15:06.860: ISAKMP: set new node 186812859 to QM_IDLE
*Aug 7 03:15:06.861: ISAKMP:(1004): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:15:06.861: ISAKMP:(1004):Sending an IKE IPv4 Packet.
*Aug 7 03:15:06.861: ISAKMP:(1004):purging node 186812859
*Aug 7 03:15:06.861: ISAKMP:(1004):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
*Aug 7 03:15:06.861: ISAKMP:(1004):Old State = IKE_P1_COMPLETE New State = IKE_DEST_SA

*Aug 7 03:15:06.861: ISAKMP:(1004):deleting SA reason "End of ipsec tunnel" state (I) QM_IDLE (peer 101.1.1.1)
*Aug 7 03:15:06.861: ISAKMP: Unlocking peer struct 0xF2F1E4D8 for isadb_mark_sa_deleted(), count 0
IOU1#
*Aug 7 03:15:06.861: ISAKMP:(1004):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Aug 7 03:15:06.861: ISAKMP:(1004):Old State = IKE_DEST_SA New State = IKE_DEST_SA

*Aug 7 03:15:06.988: ISAKMP: Deleting peer node by peer_reap for 101.1.1.1: F2F1E4D8
*Aug 7 03:15:06.988: ISAKMP: ignoring request to send delete notify (no ISAKMP sa) src 100.1.1.1 dst 101.1.1.1 for SPI 0xA9FAAD12
IOU1#ping 2.2.2.2 source 1.1.1.1
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 2.2.2.2, timeout is 2 seconds:
Packet sent with a source address of 1.1.1.1

*Aug 7 03:15:26.674: ISAKMP:(0): SA request profile is (NULL)
*Aug 7 03:15:26.674: ISAKMP: Created a peer struct for 101.1.1.1, peer port 500
*Aug 7 03:15:26.674: ISAKMP: New peer created peer = 0xF2F1E4D8 peer_handle = 0x80000007
*Aug 7 03:15:26.674: ISAKMP: Locking peer struct 0xF2F1E4D8, refcount 1 for isakmp_initiator
*Aug 7 03:15:26.674: ISAKMP: local port 500, remote port 500
*Aug 7 03:15:26.674: ISAKMP: set new node 0 to QM_IDLE
*Aug 7 03:15:26.674: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = F4AB36C8
*Aug 7 03:15:26.674: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
*Aug 7 03:15:26.674: ISAKMP:(0):found peer pre-shared key matching 101.1.1.1
*Aug 7 03:15:26.674: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
*Aug 7 03:15:26.674: ISAKMP:(0): constructed NAT-T vendor-07 ID
*Aug 7 03:15:26.674: ISAKMP:(0): constructed NAT-T vendor-03 ID
*Aug 7 03:15:26.674: ISAKMP:(0): constructed NAT-T vendor-02 ID
*Aug 7 03:15:26.674: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
*Aug 7 03:15:26.674: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1

*Aug 7 03:15:26.674: ISAKMP:(0): beginning Main Mode exchange
*Aug 7 03:15:26.674: ISAKMP:(0): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
*Aug 7 03:15:26.674: ISAKMP:(0):Sending an IKE IPv4 Packet......
Success rate is 0 percent (0/5)
IOU1#
*Aug 7 03:15:36.676: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
*Aug 7 03:15:36.676: ISAKMP (0): incrementing error counter on sa, attempt 1 of 5: retransmit phase 1
*Aug 7 03:15:36.676: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
*Aug 7 03:15:36.676: ISAKMP:(0): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
*Aug 7 03:15:36.676: ISAKMP:(0):Sending an IKE IPv4 Packet.
IOU1#
*Aug 7 03:15:46.684: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
*Aug 7 03:15:46.684: ISAKMP (0): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
*Aug 7 03:15:46.684: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
*Aug 7 03:15:46.684: ISAKMP:(0): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
*Aug 7 03:15:46.684: ISAKMP:(0):Sending an IKE IPv4 Packet.
IOU1#
*Aug 7 03:15:56.676: ISAKMP: set new node 0 to QM_IDLE
*Aug 7 03:15:56.676: ISAKMP:(0):SA is still budding. Attached new ipsec request to it. (local 100.1.1.1, remote 101.1.1.1)
*Aug 7 03:15:56.676: ISAKMP: Error while processing SA request: Failed to initialize SA
*Aug 7 03:15:56.676: ISAKMP: Error while processing KMI message 0, error 2.
*Aug 7 03:15:56.693: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
*Aug 7 03:15:56.693: ISAKMP (0): incrementing error counter on sa, attempt 3 of 5: retransmit phase 1
*Aug 7 03:15:56.693: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
IOU1#
*Aug 7 03:15:56.693: ISAKMP:(0): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
*Aug 7 03:15:56.693: ISAKMP:(0):Sending an IKE IPv4 Packet.
IOU1#
*Aug 7 03:16:06.698: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
*Aug 7 03:16:06.698: ISAKMP (0): incrementing error counter on sa, attempt 4 of 5: retransmit phase 1
*Aug 7 03:16:06.698: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
*Aug 7 03:16:06.698: ISAKMP:(0): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
*Aug 7 03:16:06.698: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Aug 7 03:16:06.865: ISAKMP:(1004):purging SA., sa=F2F30F50, delme=F2F30F50
IOU1#
*Aug 7 03:16:16.699: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
*Aug 7 03:16:16.699: ISAKMP (0): incrementing error counter on sa, attempt 5 of 5: retransmit phase 1
*Aug 7 03:16:16.699: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
*Aug 7 03:16:16.699: ISAKMP:(0): sending packet to 101.1.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
*Aug 7 03:16:16.699: ISAKMP:(0):Sending an IKE IPv4 Packet.
IOU1#
*Aug 7 03:16:26.682: ISAKMP:(0):peer does not do paranoid keepalives.

*Aug 7 03:16:26.682: ISAKMP:(0):deleting SA reason "P1 delete notify (in)" state (I) MM_NO_STATE (peer 101.1.1.1)
*Aug 7 03:16:26.682: ISAKMP:(0): SA request profile is (NULL)
*Aug 7 03:16:26.682: ISAKMP: Created a peer struct for 102.1.1.1, peer port 500
*Aug 7 03:16:26.682: ISAKMP: New peer created peer = 0xF4A92B30 peer_handle = 0x80000008
*Aug 7 03:16:26.682: ISAKMP: Locking peer struct 0xF4A92B30, refcount 1 for isakmp_initiator
*Aug 7 03:16:26.682: ISAKMP: local port 500, remote port 500
*Aug 7 03:16:26.682: ISAKMP: set new node 0 to QM_IDLE
*Aug 7 03:16:26.682: ISAKMP:(0):insert sa successfully sa = F2F30F50
*Aug 7 03:16:26.682: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
*Aug 7 03:16:26.682: ISAKMP:(0):found peer pre-shared key matching 102.1.1.1
*Aug 7 03:16:26.682: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
*Aug 7 03:16:26.682: ISAKMP:(0): constructed NAT-T vendor-07 ID
*Aug 7 03:16:26.682: ISAKMP:(0): constructed NAT-T vendor-03 ID
*Aug 7 03:16:26.682: ISAKMP:(0): constructed NAT-T vendor-02 ID
*Aug 7 03:16:26.682: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
*Aug 7 03:16:26.682: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1

*Aug 7 03:16:26.682: ISAKMP:(0): beginning Main Mode exchange
*Aug 7 03:16:26.682: ISAKMP:(0): sending packet to 102.1.1.1 my_port 500 peer_port 500 (I) MM_NO_STATE
*Aug 7 03:16:26.682: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Aug 7 03:16:26.682: ISAKMP:(0):deleting SA reason "P1 delete notify (in)" state (I) MM_NO_STATE (peer 101.1.1.1)
*Aug 7 03:16:26.682: ISAKMP: Unlocking peer struct 0xF2F1E4D8 for isadb_mark_sa_deleted(), count 0
*Aug 7 03:16:26.682: ISAKMP: Deleting peer node by peer_reap for 101.1.1.1: F2F1E4D8
*Aug 7 03:16:26.683: ISAKMP:(0):deleting node 189642018 error FALSE reason "IKE deleted"
*Aug 7 03:16:26.683: ISAKMP:(0):deleting node -162170267 error FALSE reason "IKE deleted"
*Aug 7 03:16:26.683: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
*Aug 7 03:16:26.683: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_DEST_SA

*Aug 7 03:16:26.684: ISAKMP (0): received packet from 102.1.1.1 dport 500 sport 500 Global (I) MM_NO_STATE
*Aug 7 03:16:26.684: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Aug 7 03:16:26.684: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2

*Aug 7 03:16:26.684: ISAKMP:(0): processing SA payload. message ID = 0
*Aug 7 03:16:26.684: ISAKMP:(0): processing vendor id payload
*Aug 7 03:16:26.684: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
*Aug 7 03:16:26.684: ISAKMP (0): vendor ID is NAT-T RFC 3947
*Aug 7 03:16:26.684: ISAKMP:(0):found peer pre-shared key matching 102.1.1.1
*Aug 7 03:16:26.684: ISAKMP:(0): local preshared key found
*Aug 7 03:16:26.684: ISAKMP : Scanning profiles for xauth ...
*Aug 7 03:16:26.684: ISAKMP:(0):Checking ISAKMP transform 1 against priority 10 policy
*Aug 7 03:16:26.684: ISAKMP: encryption 3DES-CBC
*Aug 7 03:16:26.684: ISAKMP: hash SHA
*Aug 7 03:16:26.684: ISAKMP: default group 5
*Aug 7 03:16:26.684: ISAKMP: auth pre-share
*Aug 7 03:16:26.684: ISAKMP: life type in seconds
*Aug 7 03:16:26.684: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80
*Aug 7 03:16:26.684: ISAKMP:(0):atts are acceptable. Next payload is 0
*Aug 7 03:16:26.684: ISAKMP:(0):Acceptable atts:actual life: 0
*Aug 7 03:16:26.684: ISAKMP:(0):Acceptable atts:life: 0
*Aug 7 03:16:26.684: ISAKMP:(0):Fill atts in sa vpi_length:4
*Aug 7 03:16:26.684: ISAKMP:(0):Fill atts in sa life_in_seconds:86400
*Aug 7 03:16:26.684: ISAKMP:(0):Returning Actual lifetime: 86400
*Aug 7 03:16:26.684: ISAKMP:(0)::Started lifetime timer: 86400.

*Aug 7 03:16:26.684: ISAKMP:(0): processing vendor id payload
*Aug 7 03:16:26.684: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
*Aug 7 03:16:26.684: ISAKMP (0): vendor ID is NAT-T RFC 3947
*Aug 7 03:16:26.684: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Aug 7 03:16:26.684: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2

*Aug 7 03:16:26.684: ISAKMP:(0): sending packet to 102.1.1.1 my_port 500 peer_port 500 (I) MM_SA_SETUP
*Aug 7 03:16:26.684: ISAKMP:(0):Sending an IKE IPv4 Packet.
*Aug 7 03:16:26.684: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Aug 7 03:16:26.684: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3

*Aug 7 03:16:26.698: ISAKMP (0): received packet from 102.1.1.1 dport 500 sport 500 Global (I) MM_SA_SETUP
*Aug 7 03:16:26.698: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Aug 7 03:16:26.698: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4

*Aug 7 03:16:26.698: ISAKMP:(0): processing KE payload. message ID = 0
*Aug 7 03:16:26.709: ISAKMP:(0): processing NONCE payload. message ID = 0
*Aug 7 03:16:26.709: ISAKMP:(0):found peer pre-shared key matching 102.1.1.1
*Aug 7 03:16:26.709: ISAKMP:(1005): processing vendor id payload
*Aug 7 03:16:26.709: ISAKMP:(1005): vendor ID is Unity
*Aug 7 03:16:26.709: ISAKMP:(1005): processing vendor id payload
*Aug 7 03:16:26.709: ISAKMP:(1005): vendor ID is DPD
*Aug 7 03:16:26.709: ISAKMP:(1005): processing vendor id payload
*Aug 7 03:16:26.709: ISAKMP:(1005): speaking to another IOS box!
*Aug 7 03:16:26.709: ISAKMP:received payload type 20
*Aug 7 03:16:26.709: ISAKMP (1005): His hash no match - this node outside NAT
*Aug 7 03:16:26.709: ISAKMP:received payload type 20
*Aug 7 03:16:26.709: ISAKMP (1005): No NAT Found for self or peer
*Aug 7 03:16:26.709: ISAKMP:(1005):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Aug 7 03:16:26.709: ISAKMP:(1005):Old State = IKE_I_MM4 New State = IKE_I_MM4

*Aug 7 03:16:26.709: ISAKMP:(1005):Send initial contact
*Aug 7 03:16:26.709: ISAKMP:(1005):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
*Aug 7 03:16:26.709: ISAKMP (1005): ID payload
next-payload : 8
type : 1
address : 100.1.1.1
protocol : 17
port : 500
length : 12
*Aug 7 03:16:26.709: ISAKMP:(1005):Total payload length: 12
*Aug 7 03:16:26.709: ISAKMP:(1005): sending packet to 102.1.1.1 my_port 500 peer_port 500 (I) MM_KEY_EXCH
*Aug 7 03:16:26.709: ISAKMP:(1005):Sending an IKE IPv4 Packet.
*Aug 7 03:16:26.710: ISAKMP:(1005):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Aug 7 03:16:26.710: ISAKMP:(1005):Old State = IKE_I_MM4 New State = IKE_I_MM5

*Aug 7 03:16:26.711: ISAKMP (1005): received packet from 102.1.1.1 dport 500 sport 500 Global (I) MM_KEY_EXCH
*Aug 7 03:16:26.711: ISAKMP:(1005): processing ID payload. message ID = 0
*Aug 7 03:16:26.711: ISAKMP (1005): ID payload
next-payload : 8
type : 1
address : 102.1.1.1
protocol : 17
port : 500
length : 12
*Aug 7 03:16:26.711: ISAKMP:(0):: peer matches *none* of the profiles
*Aug 7 03:16:26.711: ISAKMP:(1005): processing HASH payload. message ID = 0
*Aug 7 03:16:26.711: ISAKMP:(1005):SA authentication status:
authenticated
*Aug 7 03:16:26.711: ISAKMP:(1005):SA has been authenticated with 102.1.1.1
*Aug 7 03:16:26.711: ISAKMP: Trying to insert a peer 100.1.1.1/102.1.1.1/500/, and inserted successfully F4A92B30.
*Aug 7 03:16:26.711: ISAKMP:(1005):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Aug 7 03:16:26.711: ISAKMP:(1005):Old State = IKE_I_MM5 New State = IKE_I_MM6

*Aug 7 03:16:26.711: ISAKMP:(1005):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
*Aug 7 03:16:26.711: ISAKMP:(1005):Old State = IKE_I_MM6 New State = IKE_I_MM6

*Aug 7 03:16:26.717: ISAKMP:(1005):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
*Aug 7 03:16:26.717: ISAKMP:(1005):Old State = IKE_I_MM6 New State = IKE_P1_COMPLETE

*Aug 7 03:16:26.717: ISAKMP:(1005):IKE_DPD is enabled, initializing timers
*Aug 7 03:16:26.717: ISAKMP:(1005):beginning Quick Mode exchange, M-ID of 777919085
*Aug 7 03:16:26.717: ISAKMP:(1005):QM Initiator gets spi
*Aug 7 03:16:26.717: ISAKMP:(1005): sending packet to 102.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:16:26.717: ISAKMP:(1005):Sending an IKE IPv4 Packet.
*Aug 7 03:16:26.717: ISAKMP:(1005):Node 777919085, Input = IKE_MESG_INTERNAL, IKE_INIT_QM
*Aug 7 03:16:26.717: ISAKMP:(1005):Old State = IKE_QM_READY New State = IKE_QM_I_QM1
*Aug 7 03:16:26.717: ISAKMP:(1005):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Aug 7 03:16:26.717: ISAKMP:(1005):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

*Aug 7 03:16:26.719: ISAKMP (1005): received packet from 102.1.1.1 dport 500 sport 500 Global (I) QM_IDLE
*Aug 7 03:16:26.719: ISAKMP:(1005): processing HASH payload. message ID = 777919085
*Aug 7 03:16:26.719: ISAKMP:(1005): processing SA payload. message ID = 777919085
*Aug 7 03:16:26.719: ISAKMP:(1005):Checking IPSec proposal 1
*Aug 7 03:16:26.719: ISAKMP: transform 1, ESP_3DES
*Aug 7 03:16:26.719: ISAKMP: attributes in transform:
*Aug 7 03:16:26.719: ISAKMP: encaps is 1 (Tunnel)
*Aug 7 03:16:26.719: ISAKMP: SA life type in seconds
*Aug 7 03:16:26.719: ISAKMP: SA life duration (basic) of 3600
*Aug 7 03:16:26.719: ISAKMP: SA life type in kilobytes
*Aug 7 03:16:26.719: ISAKMP: SA life duration (VPI) of 0x0 0x46 0x50 0x0
*Aug 7 03:16:26.719: ISAKMP: authenticator is HMAC-SHA
*Aug 7 03:16:26.719: ISAKMP:(1005):atts are acceptable.
*Aug 7 03:16:26.719: ISAKMP:(1005): processing NONCE payload. message ID = 777919085
*Aug 7 03:16:26.719: ISAKMP:(1005): processing ID payload. message ID = 777919085
*Aug 7 03:16:26.719: ISAKMP:(1005): processing ID payload. message ID = 777919085
*Aug 7 03:16:26.719: ISAKMP:(1005):Node 777919085, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
*Aug 7 03:16:26.719: ISAKMP:(1005):Old State = IKE_QM_I_QM1 New State = IKE_QM_IPSEC_INSTALL_AWAIT
*Aug 7 03:16:26.720: ISAKMP: Failed to find peer index node to update peer_info_list
*Aug 7 03:16:26.720: ISAKMP:(1005):Received IPSec Install callback... proceeding with the negotiation
*Aug 7 03:16:26.720: ISAKMP:(1005): sending packet to 102.1.1.1 my_port 500 peer_port 500 (I) QM_IDLE
*Aug 7 03:16:26.720: ISAKMP:(1005):Sending an IKE IPv4 Packet.
*Aug 7 03:16:26.720: ISAKMP:(1005):deleting node 777919085 error FALSE reason "No Error"
*Aug 7 03:16:26.720: ISAKMP:(1005):Node 777919085, Input = IKE_MESG_FROM_IPSEC, IPSEC_INSTALL_DONE
IOU1#
*Aug 7 03:16:26.720: ISAKMP:(1005):Old State = IKE_QM_IPSEC_INSTALL_AWAIT New State = IKE_QM_PHASE2_COMPLETE
IOU1#


 

It’s interesting to see how much time elapsed: a lot! I shut down the interface at around 3:14:40. The DPD realized there’s a problem at 3:14:55 so it started sending keepalives every 2 seconds. It gave up at 3:15:06. This is already 26 seconds. I pinged 2.2.2.2 again at 3:15:26, R2 didn’t respond so isakmp gave up after another minute and only then did it probe R3. This gives us around 90 seconds of delay in case of a failure of the primary vpn peer.

 

Skomentuj

Wprowadź swoje dane lub kliknij jedną z tych ikon, aby się zalogować:

Logo WordPress.com

Komentujesz korzystając z konta WordPress.com. Wyloguj /  Zmień )

Zdjęcie na Google

Komentujesz korzystając z konta Google. Wyloguj /  Zmień )

Zdjęcie z Twittera

Komentujesz korzystając z konta Twitter. Wyloguj /  Zmień )

Zdjęcie na Facebooku

Komentujesz korzystając z konta Facebook. Wyloguj /  Zmień )

Połączenie z %s