VPN Multitunnel GRE

Borys Espada · ‎01-27-2011

I have my network configured in a Multitunnel GRE WAN, which connects a central point me to remote offices.

A point of these offices can not ascertaining the VPN, at this point is installed a cisco router 3700 Software (C3745-A3JK9S-M), Version 12.3 (26), RELEASE SOFTWARE (fc2) trying to establish the VPN with cisco 7200.

this is the message on the router.

Crypto IPSEC debugging is on
Sucre3700#
Jan 27 14:45:26.168: IPSEC(key_engine): got a queue event...
Jan 27 14:45:26.168: IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
Jan 27 14:45:26.168: IPSEC(key_engine_delete_sas): delete SA with spi 518929598/50 for 192.168.168.2
Jan 27 14:45:26.168: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 192.168.168.34, sa_prot= 50,
    sa_spi= 0xB62D2909(3056412937),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2420
Jan 27 14:45:26.172: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x1EEE3CBE(518929598),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2421
Jan 27 14:45:26.172: IPSEC(key_engine): got a queue event...
Jan 27 14:45:26.172: IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
Jan 27 14:45:26.172: IPSEC(key_engine_delete_sas): delete SA with spi 1227442685/50 for 192.168.168.2
Jan 27 14:45:26.172: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 192.168.168.34, sa_prot= 50,
    sa_spi= 0xDE634796(3731048342),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2422
Jan 27 14:45:26.172: IPSEC(add_sa): have new SAs -- expire existing in 30 sec.,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x492949FD(1227442685),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2423,
(identity) local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/255.255.255.255/47/0 (type=1),
    remote_proxy= 192.168.168.2/255.255.255.255/47/0 (type=1)
Jan 27 14:45:26.172: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x492949FD(1227442685),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2423
Jan 27 14:45:40.753: IPSEC(sa_request): ,
(key eng. msg.) OUTBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/255.255.255.255/47/0 (type=1),
    remote_proxy= 192.168.168.2/255.255.255.255/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 120s and 4608000kb,
    spi= 0x4A26CE1B(1244057115), conn_id= 0, keysize= 0, flags= 0x400A
Jan 27 14:45:40.921: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/255.255.255.255/47/0 (type=1),
    remote_proxy= 192.168.168.2/255.255.255.255/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 0s and 0kb,
    spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x2
Jan 27 14:45:40.921: IPSEC(kei_proxy): head = Tunnel0-head-0, map->ivrf = , kei->ivrf =
Jan 27 14:45:40.921: IPSEC(key_engine): got a queue event...
Jan 27 14:45:40.921: IPSEC(initialize_sas): ,
(key eng. msg.) INBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/0.0.0.0/47/0 (type=1),
    remote_proxy= 192.168.168.2/0.0.0.0/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 120s and 4608000kb,
    spi= 0x4A26CE1B(1244057115), conn_id= 2420, keysize= 0, flags= 0x2
Jan 27 14:45:40.921: IPSEC(initialize_sas): ,
(key eng. msg.) OUTBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/0.0.0.0/47/0 (type=1),
    remote_proxy= 192.168.168.2/0.0.0.0/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 120s and 4608000kb,
    spi= 0x6C81C4A9(1820443817), conn_id= 2421, keysize= 0, flags= 0xA
Jan 27 14:45:40.925: IPSEC(kei_proxy): head = Tunnel0-head-0, map->ivrf = , kei->ivrf =
Jan 27 14:45:40.925: IPSEC(crypto_ipsec_sa_find_ident_head): reconnecting with the same proxies and 192.168.168.2
Jan 27 14:45:40.925: IPSEC(add mtree): src 192.168.168.34, dest 192.168.168.2, dest_port 0

Jan 27 14:45:40.925: IPSEC(create_sa): sa created,
(sa) sa_dest= 192.168.168.34, sa_prot= 50,
    sa_spi= 0x4A26CE1B(1244057115),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2420
Jan 27 14:45:40.925: IPSEC(create_sa): sa created,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x6C81C4A9(1820443817),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2421
Jan 27 14:47:07.918: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/255.255.255.255/47/0 (type=1),
    remote_proxy= 192.168.168.2/255.255.255.255/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 0s and 0kb,
    spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x2
Jan 27 14:47:07.918: IPSEC(kei_proxy): head = Tunnel0-head-0, map->ivrf = , kei->ivrf =
Jan 27 14:47:07.918: IPSEC(key_engine): got a queue event...
Jan 27 14:47:07.918: IPSEC(spi_response): getting spi 550149579 for SA
        from 192.168.168.34 to 192.168.168.2   for prot 3
Jan 27 14:47:08.170: IPSEC(key_engine): got a queue event...
Jan 27 14:47:08.170: IPSEC(initialize_sas): ,
(key eng. msg.) INBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/0.0.0.0/47/0 (type=1),
    remote_proxy= 192.168.168.2/0.0.0.0/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 120s and 4608000kb,
    spi= 0x20CA9DCB(550149579), conn_id= 2422, keysize= 0, flags= 0x2
Jan 27 14:47:08.170: IPSEC(initialize_sas): ,
(key eng. msg.) OUTBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/0.0.0.0/47/0 (type=1),
    remote_proxy= 192.168.168.2/0.0.0.0/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 120s and 4608000kb,
    spi= 0x29FF67F0(704604144), conn_id= 2423, keysize= 0, flags= 0xA
Jan 27 14:47:08.170: IPSEC(kei_proxy): head = Tunnel0-head-0, map->ivrf = , kei->ivrf =
Jan 27 14:47:08.170: IPSEC(crypto_ipsec_sa_find_ident_head): reconnecting with the same proxies and 192.168.168.2
Jan 27 14:47:08.170: IPSEC(create_sa): sa created,
(sa) sa_dest= 192.168.168.34, sa_prot= 50,
    sa_spi= 0x20CA9DCB(550149579),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2422
Jan 27 14:47:08.170: IPSEC(create_sa): sa created,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x29FF67F0(704604144),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2423
Jan 27 14:47:08.198: IPSEC(key_engine): got a queue event...
Jan 27 14:47:08.198: IPSEC(key_engine_enable_outbound): rec'd enable notify from ISAKMP
Jan 27 14:47:08.198: IPSEC(key_engine_enable_outbound): enable SA with spi 704604144/50 for 192.168.168.2
Jan 27 14:47:08.198: IPSEC(add_sa): have new SAs -- expire existing in 30 sec.,
(sa) sa_dest= 192.168.168.34, sa_prot= 50,
    sa_spi= 0x4A26CE1B(1244057115),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2420,
(identity) local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/255.255.255.255/47/0 (type=1),
    remote_proxy= 192.168.168.2/255.255.255.255/47/0 (type=1)
Jan 27 14:47:12.698: IPSEC(encapsulate): error in encapsulation fs_encap_decap_fail
Jan 27 14:47:28.387: IPSEC(key_engine): got a queue event...
Jan 27 14:47:28.387: IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
Jan 27 14:47:28.387: IPSEC(key_engine_delete_sas): delete SA with spi 1820443817/50 for 192.168.168.2
Jan 27 14:47:28.387: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 192.168.168.34, sa_prot= 50,
    sa_spi= 0x4A26CE1B(1244057115),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2420
Jan 27 14:47:28.391: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x6C81C4A9(1820443817),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2421
Jan 27 14:47:28.391: IPSEC(key_engine): got a queue event...
Jan 27 14:47:28.391: IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
Jan 27 14:47:28.391: IPSEC(key_engine_delete_sas): delete SA with spi 704604144/50 for 192.168.168.2
Jan 27 14:47:28.391: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 192.168.168.34, sa_prot= 50,
    sa_spi= 0x20CA9DCB(550149579),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2422
Jan 27 14:47:28.391: IPSEC(add_sa): have new SAs -- expire existing in 30 sec.,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x29FF67F0(704604144),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2423,
(identity) local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/255.255.255.255/47/0 (type=1),
    remote_proxy= 192.168.168.2/255.255.255.255/47/0 (type=1)
Jan 27 14:47:28.391: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x29FF67F0(704604144),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2423
Jan 27 14:47:40.760: IPSEC(sa_request): ,
(key eng. msg.) OUTBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/255.255.255.255/47/0 (type=1),
    remote_proxy= 192.168.168.2/255.255.255.255/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 120s and 4608000kb,
    spi= 0x193AC56(26455126), conn_id= 0, keysize= 0, flags= 0x400A
Jan 27 14:47:40.920: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/255.255.255.255/47/0 (type=1),
    remote_proxy= 192.168.168.2/255.255.255.255/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 0s and 0kb,
    spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x2
Jan 27 14:47:40.920: IPSEC(kei_proxy): head = Tunnel0-head-0, map->ivrf = , kei->ivrf =
Jan 27 14:47:40.920: IPSEC(key_engine): got a queue event...
Jan 27 14:47:40.920: IPSEC(initialize_sas): ,
(key eng. msg.) INBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/0.0.0.0/47/0 (type=1),
    remote_proxy= 192.168.168.2/0.0.0.0/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 120s and 4608000kb,
    spi= 0x193AC56(26455126), conn_id= 2420, keysize= 0, flags= 0x2
Jan 27 14:47:40.920: IPSEC(initialize_sas): ,
(key eng. msg.) OUTBOUND local= 192.168.168.34, remote= 192.168.168.2,
    local_proxy= 192.168.168.34/0.0.0.0/47/0 (type=1),
    remote_proxy= 192.168.168.2/0.0.0.0/47/0 (type=1),
    protocol= ESP, transform= esp-3des esp-md5-hmac (Tunnel),
    lifedur= 120s and 4608000kb,
    spi= 0x5CCA2712(1556752146), conn_id= 2421, keysize= 0, flags= 0xA
Jan 27 14:47:40.920: IPSEC(kei_proxy): head = Tunnel0-head-0, map->ivrf = , kei->ivrf =
Jan 27 14:47:40.920: IPSEC(crypto_ipsec_sa_find_ident_head): reconnecting with the same proxies and 192.168.168.2
Jan 27 14:47:40.920: IPSEC(add mtree): src 192.168.168.34, dest 192.168.168.2, dest_port 0

Jan 27 14:47:40.920: IPSEC(create_sa): sa created,
(sa) sa_dest= 192.168.168.34, sa_prot= 50,
    sa_spi= 0x193AC56(26455126),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2420
Jan 27 14:47:40.920: IPSEC(create_sa): sa created,
(sa) sa_dest= 192.168.168.2, sa_prot= 50,
    sa_spi= 0x5CCA2712(1556752146),
    sa_trans= esp-3des esp-md5-hmac , sa_conn_id= 2421

Jan 27 14:49:09.141: ISAKMP: received ke message (1/1)
Jan 27 14:49:09.141: ISAKMP: set new node 0 to QM_IDLE
Jan 27 14:49:09.141: SA has outstanding requests (local 192.168.168.34 port 500, remote 192.168.168.2 port 500)
Jan 27 14:49:09.141: ISAKMP (0:46): sitting IDLE. Starting QM immediately (QM_IDLE      )
Jan 27 14:49:09.141: ISAKMP (0:46): beginning Quick Mode exchange, M-ID of 419162239
Jan 27 14:49:09.141: ISAKMP (0:46): sending packet to 192.168.168.2 my_port 500 peer_port 500 (I) QM_IDLE
Jan 27 14:49:09.141: ISAKMP (0:46): Node 419162239, Input = IKE_MESG_INTERNAL, IKE_INIT_QM
Jan 27 14:49:09.141: ISAKMP (0:46): Old State = IKE_QM_READY New State = IKE_QM_I_QM1
Jan 27 14:49:09.177: ISAKMP (0:46): received packet from 192.168.168.2 dport 500 sport 500 Global (I) QM_IDLE
Jan 27 14:49:09.177: ISAKMP (0:46): processing HASH payload. message ID = 419162239
Jan 27 14:49:09.177: ISAKMP (0:46): processing SA payload. message ID = 419162239
Jan 27 14:49:09.177: ISAKMP (0:46): Checking IPSec proposal 1
Jan 27 14:49:09.177: ISAKMP: transform 1, ESP_3DES
Jan 27 14:49:09.177: ISAKMP:   attributes in transform:
Jan 27 14:49:09.177: ISAKMP:      encaps is 1 (Tunnel)
Jan 27 14:49:09.177: ISAKMP:      SA life type in seconds
Jan 27 14:49:09.181: ISAKMP:      SA life duration (basic) of 120
Jan 27 14:49:09.181: ISAKMP:      SA life type in kilobytes
Jan 27 14:49:09.181: ISAKMP:      SA life duration (VPI) of 0x0 0x46 0x50 0x0
Jan 27 14:49:09.181: ISAKMP:      authenticator is HMAC-MD5
Jan 27 14:49:09.181: ISAKMP (0:46): atts are acceptable.
Jan 27 14:49:09.181: ISAKMP (0:46): processing NONCE payload. message ID = 419162239
Jan 27 14:49:09.181: ISAKMP (0:46): processing ID payload. message ID = 419162239
Jan 27 14:49:09.181: ISAKMP (0:46): processing ID payload. message ID = 419162239
Jan 27 14:49:09.181: ISAKMP (0:46): Creating IPSec SAs
Jan 27 14:49:09.181:         inbound SA from 192.168.168.2 to 192.168.168.34 (f/i) 0/ 0
        (proxy 192.168.168.2 to 192.168.168.34)
Jan 27 14:49:09.181:         has spi 0x72B2D42C and conn_id 2422 and flags 2
Jan 27 14:49:09.181:         lifetime of 120 seconds
Jan 27 14:49:09.181:         lifetime of 4608000 kilobytes
Jan 27 14:49:09.181:         has client flags 0x0
Jan 27 14:49:09.181:         outbound SA from 192.168.168.34 to 192.168.168.2   (f/i) 0/ 0 (proxy 192.168.168.34 to 192.168.168.2 )
Jan 27 14:49:09.181:         has spi 1744602849 and conn_id 2423 and flags A
Jan 27 14:49:09.181:         lifetime of 120 seconds
Jan 27 14:49:09.181:         lifetime of 4608000 kilobytes
Jan 27 14:49:09.181:         has client flags 0x0
Jan 27 14:49:09.181: ISAKMP (0:46): sending packet to 192.168.168.2 my_port 500 peer_port 500 (I) QM_IDLE
Jan 27 14:49:09.181: ISAKMP (0:46): deleting node 419162239 error FALSE reason ""
Jan 27 14:49:09.181: ISAKMP (0:46): Node 419162239, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
Jan 27 14:49:09.181: ISAKMP (0:46): Old State = IKE_QM_I_QM1 New State = IKE_QM_PHASE2_COMPLETE
Jan 27 14:49:34.986: ISAKMP (0:46): received packet from 192.168.168.2 dport 500 sport 500 Global (I) QM_IDLE
Jan 27 14:49:34.986: ISAKMP: set new node -2087255052 to QM_IDLE
Jan 27 14:49:34.986: ISAKMP (0:46): processing HASH payload. message ID = -2087255052
Jan 27 14:49:34.986: ISAKMP (0:46): processing DELETE payload. message ID = -2087255052
Jan 27 14:49:34.986: ISAKMP (0:46): peer does not do paranoid keepalives.

Jan 27 14:49:34.986: ISAKMP (0:46): deleting node -2087255052 error FALSE reason "informational (in) state 1"
Jan 27 14:49:34.986: ISAKMP (0:46): received packet from 192.168.168.2 dport 500 sport 500 Global (I) QM_IDLE
Jan 27 14:49:34.986: ISAKMP: set new node -1586970159 to QM_IDLE
Jan 27 14:49:34.986: ISAKMP (0:46): processing HASH payload. message ID = -1586970159
Jan 27 14:49:34.986: ISAKMP (0:46): processing DELETE payload. message ID = -1586970159
Jan 27 14:49:34.986: ISAKMP (0:46): peer does not do paranoid keepalives.

Jan 27 14:49:34.986: ISAKMP (0:46): deleting node -1586970159 error FALSE reason "informational (in) state 1"
Jan 27 14:49:34.990: ISAKMP (0:46): received packet from 192.168.168.2 dport 500 sport 500 Global (I) QM_IDLE
Jan 27 14:49:34.990: ISAKMP: set new node 1393034179 to QM_IDLE
Jan 27 14:49:34.990: ISAKMP (0:46): processing HASH payload. message ID = 1393034179
Jan 27 14:49:34.990: ISAKMP:received payload type 18
Jan 27 14:49:34.990: ISAKMP (0:46): processing DELETE_WITH_REASON payload, message ID = 1393034179, reason: Unknown delete reason!
Jan 27 14:49:34.990: ISAKMP (0:46): peer does not do paranoid keepalives.

Jan 27 14:49:34.990: ISAKMP (0:46): deleting SA reason "P1 delete notify (in)" state (I) QM_IDLE (peer 192.168.168.2) input queue 0
Jan 27 14:49:34.990: ISAKMP (0:46): deleting node 1393034179 error FALSE reason "informational (in) state 1"
Jan 27 14:49:34.990: ISAKMP (0:46): Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Jan 27 14:49:34.990: ISAKMP (0:46): Old State = IKE_P1_COMPLETE New State = IKE_DEST_SA

Jan 27 14:49:34.990: ISAKMP (0:46): deleting SA reason "" state (I) QM_IDLE (peer 192.168.168.2) input queue 0
Jan 27 14:49:34.990: ISAKMP (0:46): deleting node 419162239 error FALSE reason ""
Jan 27 14:49:34.990: ISAKMP (0:46): deleting node -2087255052 error FALSE reason ""
Jan 27 14:49:34.990: ISAKMP (0:46): deleting node -1586970159 error FALSE reason ""
Jan 27 14:49:34.990: ISAKMP (0:46): deleting node 1393034179 error FALSE reason ""
Jan 27 14:49:34.990: ISAKMP (0:46): Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jan 27 14:49:34.990: ISAKMP (0:46): Old State = IKE_DEST_SA New State = IKE_DEST_SA

Jan 27 14:49:40.767: ISAKMP: received ke message (1/1)
Jan 27 14:49:40.767: ISAKMP (0:0): SA request profile is (NULL)
Jan 27 14:49:40.767: ISAKMP: local port 500, remote port 500
Jan 27 14:49:40.767: ISAKMP: set new node 0 to QM_IDLE
Jan 27 14:49:40.767: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 63CE2D08
Jan 27 14:49:40.767: ISAKMP (0:47): Can not start Aggressive mode, trying Main mode.
Jan 27 14:49:40.767: ISAKMP: Looking for a matching key for 192.168.168.2 in default : success
Jan 27 14:49:40.767: ISAKMP (0:47): found peer pre-shared key matching 192.168.168.2
Jan 27 14:49:40.767: ISAKMP (0:47): constructed NAT-T vendor-07 ID
Jan 27 14:49:40.767: ISAKMP (0:47): constructed NAT-T vendor-03 ID
Jan 27 14:49:40.767: ISAKMP (0:47): constructed NAT-T vendor-02 ID
Jan 27 14:49:40.767: ISAKMP (0:47): Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
Jan 27 14:49:40.767: ISAKMP (0:47): Old State = IKE_READY New State = IKE_I_MM1

Jan 27 14:49:40.767: ISAKMP (0:47): beginning Main Mode exchange
Jan 27 14:49:40.767: ISAKMP (0:47): sending packet to 192.168.168.2 my_port 500 peer_port 500 (I) MM_NO_STATE
Jan 27 14:49:40.787: ISAKMP (0:47): received packet from 192.168.168.2 dport 500 sport 500 Global (I) MM_NO_STATE
Jan 27 14:49:40.791: ISAKMP (0:47): Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jan 27 14:49:40.791: ISAKMP (0:47): Old State = IKE_I_MM1 New State = IKE_I_MM2

Jan 27 14:49:40.791: ISAKMP (0:47): processing SA payload. message ID = 0
Jan 27 14:49:40.791: ISAKMP (0:47): processing vendor id payload
Jan 27 14:49:40.791: ISAKMP (0:47): vendor ID seems Unity/DPD but major 245 mismatch
Jan 27 14:49:40.791: ISAKMP (0:47): vendor ID is NAT-T v7
Jan 27 14:49:40.791: ISAKMP: Looking for a matching key for 192.168.168.2 in default : success
Jan 27 14:49:40.791: ISAKMP (0:47): found peer pre-shared key matching 192.168.168.2
Jan 27 14:49:40.791: ISAKMP (0:47) local preshared key found
Jan 27 14:49:40.791: ISAKMP : Scanning profiles for xauth ...
Jan 27 14:49:40.791: ISAKMP (0:47): Checking ISAKMP transform 1 against priority 1 policy
Jan 27 14:49:40.791: ISAKMP:      encryption 3DES-CBC
Jan 27 14:49:40.791: ISAKMP:      hash SHA
Jan 27 14:49:40.791: ISAKMP:      default group 2
Jan 27 14:49:40.791: ISAKMP:      auth pre-share
Jan 27 14:49:40.791: ISAKMP:      life type in seconds
Jan 27 14:49:40.791: ISAKMP:      life duration (VPI) of 0x0 0x1 0x51 0x80
Jan 27 14:49:40.791: ISAKMP (0:47): atts are acceptable. Next payload is 0
Jan 27 14:49:40.811: ISAKMP (0:47): processing vendor id payload
Jan 27 14:49:40.811: ISAKMP (0:47): vendor ID seems Unity/DPD but major 245 mismatch
Jan 27 14:49:40.811: ISAKMP (0:47): vendor ID is NAT-T v7
Jan 27 14:49:40.811: ISAKMP (0:47): Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jan 27 14:49:40.811: ISAKMP (0:47): Old State = IKE_I_MM2 New State = IKE_I_MM2

Jan 27 14:49:40.815: ISAKMP (0:47): sending packet to 192.168.168.2 my_port 500 peer_port 500 (I) MM_SA_SETUP
Jan 27 14:49:40.815: ISAKMP (0:47): Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Jan 27 14:49:40.815: ISAKMP (0:47): Old State = IKE_I_MM2 New State = IKE_I_MM3

Jan 27 14:49:40.859: ISAKMP (0:47): received packet from 192.168.168.2 dport 500 sport 500 Global (I) MM_SA_SETUP
Jan 27 14:49:40.859: ISAKMP (0:47): Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jan 27 14:49:40.859: ISAKMP (0:47): Old State = IKE_I_MM3 New State = IKE_I_MM4

Jan 27 14:49:40.859: ISAKMP (0:47): processing KE payload. message ID = 0
Jan 27 14:49:40.887: ISAKMP (0:47): processing NONCE payload. message ID = 0
Jan 27 14:49:40.887: ISAKMP: Looking for a matching key for 192.168.168.2 in default : success
Jan 27 14:49:40.887: ISAKMP (0:47): found peer pre-shared key matching 192.168.168.2
Jan 27 14:49:40.887: ISAKMP (0:47): SKEYID state generated
Jan 27 14:49:40.887: ISAKMP (0:47): processing vendor id payload
Jan 27 14:49:40.887: ISAKMP (0:47): vendor ID is Unity
Jan 27 14:49:40.887: ISAKMP (0:47): processing vendor id payload
Jan 27 14:49:40.887: ISAKMP (0:47): vendor ID is DPD
Jan 27 14:49:40.887: ISAKMP (0:47): processing vendor id payload
Jan 27 14:49:40.887: ISAKMP (0:47): speaking to another IOS box!
Jan 27 14:49:40.887: ISAKMP (0:47): Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jan 27 14:49:40.887: ISAKMP (0:47): Old State = IKE_I_MM4 New State = IKE_I_MM4

Jan 27 14:49:40.887: ISAKMP (0:47): Send initial contact
Jan 27 14:49:40.887: ISAKMP (0:47): SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
Jan 27 14:49:40.887: ISAKMP (0:47): ID payload
        next-payload : 8
        type         : 1
        address      : 192.168.168.34
        protocol     : 17
        port         : 500
        length       : 12
Jan 27 14:49:40.887: ISAKMP (47): Total payload length: 12
Jan 27 14:49:40.887: ISAKMP (0:47): sending packet to 192.168.168.2 my_port 500 peer_port 500 (I) MM_KEY_EXCH
Jan 27 14:49:40.891: ISAKMP (0:47): Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Jan 27 14:49:40.891: ISAKMP (0:47): Old State = IKE_I_MM4 New State = IKE_I_MM5

Jan 27 14:49:40.911: ISAKMP (0:47): received packet from 192.168.168.2 dport 500 sport 500 Global (I) MM_KEY_EXCH
Jan 27 14:49:40.911: ISAKMP (0:47): processing ID payload. message ID = 0
Jan 27 14:49:40.911: ISAKMP (0:47): ID payload
        next-payload : 8
        type         : 1
        address      : 192.168.168.2
        protocol     : 17
        port         : 500
        length       : 12
Jan 27 14:49:40.911: ISAKMP (0:47): processing HASH payload. message ID = 0
Jan 27 14:49:40.911: ISAKMP (0:47): SA authentication status:
        authenticated
Jan 27 14:49:40.911: ISAKMP (0:47): SA has been authenticated with 192.168.168.2
Jan 27 14:49:40.911: ISAKMP (0:47): peer matches *none* of the profiles
Jan 27 14:49:40.911: ISAKMP (0:47): Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jan 27 14:49:40.911: ISAKMP (0:47): Old State = IKE_I_MM5 New State = IKE_I_MM6

Jan 27 14:49:40.911: ISAKMP (0:47): Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jan 27 14:49:40.911: ISAKMP (0:47): Old State = IKE_I_MM6 New State = IKE_I_MM6

Jan 27 14:49:40.911: ISAKMP (0:47): Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Jan 27 14:49:40.911: ISAKMP (0:47): Old State = IKE_I_MM6 New State = IKE_P1_COMPLETE

Jan 27 14:49:40.911: ISAKMP (0:47): beginning Quick Mode exchange, M-ID of 2040896964
Jan 27 14:49:40.911: ISAKMP (0:47): sending packet to 192.168.168.2 my_port 500 peer_port 500 (I) QM_IDLE
Jan 27 14:49:40.911: ISAKMP (0:47): Node 2040896964, Input = IKE_MESG_INTERNAL, IKE_INIT_QM
Jan 27 14:49:40.911: ISAKMP (0:47): Old State = IKE_QM_READY New State = IKE_QM_I_QM1
Jan 27 14:49:40.911: ISAKMP (0:47): Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
Jan 27 14:49:40.911: ISAKMP (0:47): Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

Jan 27 14:49:40.939: ISAKMP (0:47): received packet from 192.168.168.2 dport 500 sport 500 Global (I) QM_IDLE
Jan 27 14:49:40.939: ISAKMP (0:47): processing HASH payload. message ID = 2040896964
Jan 27 14:49:40.939: ISAKMP (0:47): processing SA payload. message ID = 2040896964
Jan 27 14:49:40.939: ISAKMP (0:47): Checking IPSec proposal 1
Jan 27 14:49:40.939: ISAKMP: transform 1, ESP_3DES
Jan 27 14:49:40.939: ISAKMP:   attributes in transform:
Jan 27 14:49:40.939: ISAKMP:      encaps is 1 (Tunnel)
Jan 27 14:49:40.939: ISAKMP:      SA life type in seconds
Jan 27 14:49:40.939: ISAKMP:      SA life duration (basic) of 120
Jan 27 14:49:40.939: ISAKMP:      SA life type in kilobytes
Jan 27 14:49:40.939: ISAKMP:      SA life duration (VPI) of 0x0 0x46 0x50 0x0
Jan 27 14:49:40.939: ISAKMP:      authenticator is HMAC-MD5
Jan 27 14:49:40.939: ISAKMP (0:47): atts are acceptable.
Jan 27 14:49:40.939: ISAKMP (0:47): processing NONCE payload. message ID = 2040896964
Jan 27 14:49:40.939: ISAKMP (0:47): processing ID payload. message ID = 2040896964
Jan 27 14:49:40.939: ISAKMP (0:47): processing ID payload. message ID = 2040896964
Jan 27 14:49:40.943: ISAKMP (0:47): Creating IPSec SAs
Jan 27 14:49:40.943:         inbound SA from 192.168.168.2 to 192.168.168.34 (f/i) 0/ 0
        (proxy 192.168.168.2 to 192.168.168.34)
Jan 27 14:49:40.943:         has spi 0x84C267D1 and conn_id 2420 and flags 2
Jan 27 14:49:40.943:         lifetime of 120 seconds
Jan 27 14:49:40.943:         lifetime of 4608000 kilobytes
Jan 27 14:49:40.943:         has client flags 0x0
Jan 27 14:49:40.943:         outbound SA from 192.168.168.34 to 192.168.168.2   (f/i) 0/ 0 (proxy 192.168.168.34 to 192.168.168.2 )
Jan 27 14:49:40.943:         has spi 831443622 and conn_id 2421 and flags A
Jan 27 14:49:40.943:         lifetime of 120 seconds
Jan 27 14:49:40.943:         lifetime of 4608000 kilobytes
Jan 27 14:49:40.943:         has client flags 0x0
Jan 27 14:49:40.943: ISAKMP (0:47): sending packet to 192.168.168.2 my_port 500 peer_port 500 (I) QM_IDLE
Jan 27 14:49:40.943: ISAKMP (0:47): deleting node 2040896964 error FALSE reason ""
Jan 27 14:49:40.943: ISAKMP (0:47): Node 2040896964, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
Jan 27 14:49:40.943: ISAKMP (0:47): Old State = IKE_QM_I_QM1 New State = IKE_QM_PHASE2_COMPLETE

lginod · ‎01-27-2011

Hi Borys,

I could see from the logs that the IPSec lifetime is set to 120secs and this is causing the tunnel to flap. This is a very small value.

The Cisco default IPsec lifetime is 3600 seconds, and it can be modified by the crypto ipsec security-association lifetime seconds # command. The configurable Cisco IPsec lifetime is from 120-86400 seconds.

Please change this on the device where the tunnel is flapping and let me know.

Sent from Cisco Technical Support iPhone App