Buy or Renew
Buy or Renew
Duo Security forums now LIVE! Get answers to all your Duo Security questions. Learn more
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
5528
Views
0
Helpful
3
Replies

ASR IKEv2 fails to rekey IPSEC at 8hours

jonagyula
Level 1
Level 1

‎04-27-2015 07:13 PM - edited ‎02-21-2020 08:12 PM

Hi


please help resolving the following issue. We are facing the problem with the following:

-IKEv2

-PSK

-dVTI  tunnel mode ipsec

- tunnel src in vrf


On the far end non-cisco (DIGI Transport WR44) devices are establishing the IPsec successfully, and the following happens:

 

- IPsec establishes successfully, traffic is passing perfectly

- before 8hrs default IPsec lifetime DIGI initiates the IPsec rekeying about 20 minutes before the expiry

- the rekeying seems successful, all SPI-s renewed at both sides

- no decaps counter increases at both sides, until

- 1-2 minutes before the 8 hrs cisco resets the COMPLETE CRYPTO SESSION, and the connection establishes fine again


I have tried to

- decrease Cisco's IPsec lifetime, no success, cisco initiated IPsec rekeying success, but the result is the same: SPI-s negotiated, but neither side shows any decaps

- increase DIGI side IPsec lifetime over 8 hours, no success, same result.

 

I caught some undocumented syslogs, but nothing useful.

Please help me to get rid of this 20 minute blackout, three times daily.


Other details, configs, debugs:


!!!!CONFIG

crypto ikev2 keyring Digi-key    
 peer digi-routers-ADSL
  address 10.191.240.0 255.255.252.0
  pre-shared-key xxxxxxxxxxxxxxxxxx

crypto ikev2 proposal Digi-ikev2-proposal
 encryption aes-cbc-256
 integrity sha1
 group 5
crypto ikev2 policy Digi-ikev2-policy
 match fvrf any
 match address local 10.191.254.89
 proposal Digi-ikev2-proposal

    
crypto ikev2 profile Digi-ADSL-T-ikev2-profile
  match fvrf T
  match address local interface GigabitEthernet0/0/4
  match identity remote email domain digi.digi
  identity local email asr@asr
  authentication remote pre-share
  authentication local pre-share
  keyring local Digi-key
  dpd 10 2 periodic
  virtual-template 101
 
crypto ipsec profile Digi-ADSL-T-ipsec-profile
 description Ipsec profile for VTI tunnels to Digi routers - ADSL -T
 set security-association lifetime seconds 28800
 set transform-set Digi-ipsec-transform-set
 set reverse-route distance 10
 set reverse-route tag 101
 set ikev2-profile Digi-ADSL-T-ikev2-profile
 tunnel protection ipsec profile Digi-ADSL-T-ipsec-profile

 
 
interface Virtual-Template101 type tunnel
 description DIGI router ADSL VPN T
 ip unnumbered Loopback100
 ip mtu 1422
 ip tcp adjust-mss 1350
 tunnel source GigabitEthernet0/0/4
 tunnel mode ipsec ipv4
 tunnel vrf T
 tunnel protection ipsec profile Digi-ADSL-T-ipsec-profile
 


!!!!!!!! SHOW OUTPUTS


before and after DIGI has completed the IPsec rekeying:


ASR1#sh cry sess rem  10.191.243.83 det
Crypto session current status

Code: C - IKE Configuration mode, D - Dead Peer Detection     
K - Keepalives, N - NAT-traversal, T - cTCP encapsulation     
X - IKE Extended Authentication, F - IKE Fragmentation

Interface: Virtual-Access20
Profile: Digi-ADSL-T-ikev2-profile
Uptime: 07:44:08
Session status: UP-ACTIVE     
Peer: 10.191.243.83 port 500 fvrf: T ivrf: (none)
      Phase1_id: 4626@digi.digi
      Desc: (none)
  Session ID: 20252  
  IKEv2 SA: local 10.191.254.89/500 remote 10.191.243.83/500 Active
          Capabilities:D connid:26 lifetime:16:15:52
  IPSEC FLOW: permit ip 0.0.0.0/0.0.0.0 10.181.196.0/255.255.255.224
        Active SAs: 2, origin: crypto map
        Inbound:  #pkts dec'ed 15521 drop 0 life (KB/Sec) 4608000/7 hours, 55 mins
        Outbound: #pkts enc'ed 16467 drop 0 life (KB/Sec) 4607993/7 hours, 55 mins

ASR#
ASR#
ASR#
ASR#
ASR#
ASR#sh cry sess rem  10.191.243.83 det
Crypto session current status

Code: C - IKE Configuration mode, D - Dead Peer Detection     
K - Keepalives, N - NAT-traversal, T - cTCP encapsulation     
X - IKE Extended Authentication, F - IKE Fragmentation

Interface: Virtual-Access20
Profile: Digi-ADSL-T-ikev2-profile
Uptime: 07:46:01
Session status: UP-ACTIVE     
Peer: 10.191.243.83 port 500 fvrf: T ivrf: (none)
      Phase1_id: 4626@digi.digi
      Desc: (none)
  Session ID: 20252  
  IKEv2 SA: local 10.191.254.89/500 remote 10.191.243.83/500 Active
          Capabilities:D connid:26 lifetime:16:13:59
  IPSEC FLOW: permit ip 0.0.0.0/0.0.0.0 10.181.196.0/255.255.255.224
        Active SAs: 2, origin: crypto map
        Inbound:  #pkts dec'ed 15522 drop 0 life (KB/Sec) 0/7 hours, 54 mins
        Outbound: #pkts enc'ed 16499 drop 0 life (KB/Sec) 4607992/7 hours, 54 mins

 

During the 20 minutes lockup, in the "show platform hardware qfp active feature ipsec datapath drops" output, the "IN_UNEXP_OCT_EXCEPTION" counter is increasing!

ASR#show platform hardware qfp active feature ipsec datapath drops
------------------------------------------------------------------------
Drop Type  Name                                     Packets             
------------------------------------------------------------------------
        3  IN_US_V4_PKT_FOUND_IPSEC_NOT_ENABLED                     9697
        4  IN_US_V4_PKT_SA_NOT_FOUND_SPI                               8
       19  IN_OCT_ANTI_REPLAY_FAIL                                    31
       20  IN_UNEXP_OCT_EXCEPTION                                3007839

 

       62  IN_OCT_MAC_EXCEPTION                                      280

ASR#show platform hardware qfp active feature ipsec datapath drops
------------------------------------------------------------------------
Drop Type  Name                                     Packets             
------------------------------------------------------------------------
        3  IN_US_V4_PKT_FOUND_IPSEC_NOT_ENABLED                     9697
        4  IN_US_V4_PKT_SA_NOT_FOUND_SPI                               8
       19  IN_OCT_ANTI_REPLAY_FAIL                                    31
       20  IN_UNEXP_OCT_EXCEPTION                                3007841

 

Some similar DIGI clients's key renewal IKEv2 and IPsec debug from the Cisco ASR (might be some duplicated lines):

The unknown errors in bold


Apr 23 11:46:46.033: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending DPD/liveness query
Apr 23 11:46:46.033: IKEv2:(SESSION ID = 19748,SA ID = 4):Building packet for encryption.
Apr 23 11:46:46.035: IKEv2:(SESSION ID = 19748,SA ID = 4):Checking if request will fit in peer window
Apr 23 11:46:46.035: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending Packet [To 10.191.243.71:500/From 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2756
IKEv2 INFORMATIONAL Exchange REQUEST
Payload contents:
 ENCR
 
Apr 23 11:46:46.059: IKEv2:(SESSION ID = 19748,SA ID = 4):Received Packet [From 10.191.243.71:500/To 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2756
IKEv2 INFORMATIONAL Exchange RESPONSE
Payload contents:
 
Apr 23 11:46:46.059: IKEv2:(SESSION ID = 19748,SA ID = 4):Processing ACK to informational exchange
Apr 23 11:46:56.059: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending DPD/liveness query
Apr 23 11:46:56.059: IKEv2:(SESSION ID = 19748,SA ID = 4):Building packet for encryption.
Apr 23 11:46:56.060: IKEv2:(SESSION ID = 19748,SA ID = 4):Checking if request will fit in peer window
Apr 23 11:46:56.060: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending Packet [To 10.191.243.71:500/From 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2757
IKEv2 INFORMATIONAL Exchange REQUEST
Payload contents:
 ENCR
 
Apr 23 11:46:56.082: IKEv2:(SESSION ID = 19748,SA ID = 4):Received Packet [From 10.191.243.71:500/To 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2757
IKEv2 INFORMATIONAL Exchange RESPONSE
Payload contents:
 
Apr 23 11:46:56.082: IKEv2:(SESSION ID = 19748,SA ID = 4):Processing ACK to informational exchange
Apr 23 11:47:06.082: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending DPD/liveness query
Apr 23 11:47:06.082: IKEv2:(SESSION ID = 19748,SA ID = 4):Building packet for encryption.
Apr 23 11:47:06.084: IKEv2:(SESSION ID = 19748,SA ID = 4):Checking if request will fit in peer window
Apr 23 11:47:06.084: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending Packet [To 10.191.243.71:500/From 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2758
IKEv2 INFORMATIONAL Exchange REQUEST
Payload contents:
 ENCR
 
Apr 23 11:47:06.106: IKEv2:(SESSION ID = 19748,SA ID = 4):Received Packet [From 10.191.243.71:500/To 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2758
IKEv2 INFORMATIONAL Exchange RESPONSE
Payload contents:
 
Apr 23 11:47:06.106: IKEv2:(SESSION ID = 19748,SA ID = 4):Processing ACK to informational exchange
Apr 23 11:47:07.696: IPSEC(sa_request): ,
  (key eng. msg.) OUTBOUND local= 10.191.254.89:500, remote= 10.191.243.71:500,
    local_proxy= 0.0.0.0/0.0.0.0/256/0,
    remote_proxy= 10.181.194.128/255.255.255.224/256/0,
    protocol= ESP, transform= esp-aes 256 esp-sha-hmac  (Tunnel),
    lifedur= 28000s and 4608000kb,
    spi= 0x1068819F(275284383), conn_id= 0, keysize= 256, flags= 0x0
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):Check for IPSEC rekey
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):Beginning IPSec Rekey as Initiator
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):Set IPSEC DH group
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):Checking for PFS configuration
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):PFS not configured
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):Generating CREATE_CHILD_SA exchange
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):ESP Proposal: 1, SPI size: 4 (IPSec negotiation),
Num. transforms: 3
   AES-CBC   SHA96   Don't use ESN
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):Building packet for encryption.  
Payload contents:
 NOTIFY(REKEY_SA) SA N TSi TSr
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):Checking if request will fit in peer window
Apr 23 11:47:07.696: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending Packet [To 10.191.243.71:500/From 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2759
IKEv2 CREATE_CHILD_SA Exchange REQUEST
Payload contents:
 ENCR
 
Apr 23 11:47:07.721: IKEv2:(SESSION ID = 19748,SA ID = 4):Received Packet [From 10.191.243.71:500/To 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2759
IKEv2 CREATE_CHILD_SA Exchange RESPONSE
Payload contents:
 SA N TSi TSr
Apr 23 11:47:07.721: IKEv2:(SESSION ID = 19748,SA ID = 4):Processing any notify-messages in child SA exchange
Apr 23 11:47:07.721: IKEv2:(SESSION ID = 19748,SA ID = 4):Validating create child message
Apr 23 11:47:07.721: IKEv2:(SESSION ID = 19748,SA ID = 4):Processing CREATE_CHILD_SA exchange
Apr 23 11:47:07.721: IKEv2:(SESSION ID = 19748,SA ID = 4):Checking for PFS configuration
Apr 23 11:47:07.721: IKEv2:(SESSION ID = 19748,SA ID = 4):PFS not configured
Apr 23 11:47:07.721: IKEv2:(SESSION ID = 19748,SA ID = 4):Checking if IKE SA rekey
Apr 23 11:47:07.721: IKEv2:(SESSION ID = 19748,SA ID = 4):Load IPSEC key material
Apr 23 11:47:07.726: IPSEC:(SESSION ID = 19748) (create_sa) sa created,
  (sa) sa_dest= 10.191.254.89, sa_proto= 50,
    sa_spi= 0x416AF6F0(1097529072),
    sa_trans= esp-aes 256 esp-sha-hmac , sa_conn_id= 24986
    sa_lifetime(k/sec)= (4608000/28000),
  (identity) local= 10.191.254.89:0, remote= 10.191.243.71:0,
    local_proxy= 0.0.0.0/0.0.0.0/256/0,
    remote_proxy= 10.181.194.128/255.255.255.224/256/0
Apr 23 11:47:07.731: IPSEC:(SESSION ID = 19748) (create_sa) sa created,
  (sa) sa_dest= 10.191.243.71, sa_proto= 50,
    sa_spi= 0x492F5006(1227837446),
    sa_trans= esp-aes 256 esp-sha-hmac , sa_conn_id= 24985
    sa_lifetime(k/sec)= (4608000/28000),
  (identity) local= 10.191.254.89:0, remote= 10.191.243.71:0,
    local_proxy= 0.0.0.0/0.0.0.0/256/0,
    remote_proxy= 10.181.194.128/255.255.255.224/256/0
Apr 23 11:47:07.737: IPSEC:(SESSION ID = 19748) (update_current_outbound_sa) updated peer 10.191.243.71 current outbound sa to SPI 492F5006
Apr 23 11:47:07.743: IKEv2:(SESSION ID = 19748,SA ID = 4):IKEV2 SA created; inserting SA into database. SA lifetime timer (86400 sec) started
Apr 23 11:47:07.743: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending DELETE INFO message for IPsec SA [SPI: 0x1068819F]
Apr 23 11:47:07.743: IKEv2:(SESSION ID = 19748,SA ID = 4):Building packet for encryption.  
Payload contents:
 DELETE
Apr 23 11:47:07.743: IKEv2:(SESSION ID = 19748,SA ID = 4):Checking if request will fit in peer window
Apr 23 11:47:07.743: IKEv2:(SESSION ID = 19748,SA ID = 4):Sending Packet [To 10.191.243.71:500/From 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2760
IKEv2 INFORMATIONAL Exchange REQUEST
Payload contents:
 ENCR
Apr 23 11:47:07.743: IKEv2:(SESSION ID = 19748,SA ID = 4):Check for existing IPSEC SA
Apr 23 11:47:07.764: IKEv2:(SESSION ID = 19748,SA ID = 4):Received Packet [From 10.191.243.71:500/To 10.191.254.89:500/VRF i3:f3]
Initiator SPI : 00000060FFFFFF9F - Responder SPI : 882705463FF54AD2 Message id: 2760
IKEv2 INFORMATIONAL Exchange RESPONSE
Payload contents:
 DELETE
Apr 23 11:47:07.764: IKEv2:(SESSION ID = 19748,SA ID = 4):Processing ACK to informational exchange
Apr 23 11:47:07.764: IKEv2:(SESSION ID = 19748,SA ID = 4):Check for existing IPSEC SA
Apr 23 11:47:07.765: IPSEC: still in use sa: 0x0
Apr 23 11:47:07.765: IPSEC: sa null
Apr 23 11:47:07.765: IPSEC:(SESSION ID = 19748) still in use sa: 0x7F483D68EB50
Apr 23 11:47:07.766: IPSEC:(SESSION ID = 19748) (key_engine_delete_sas) delete SA with spi 0x1068819F proto 50 for 10.191.254.89
Apr 23 11:47:07.770: IPSEC(send_delete_notify_kmi): not sending KEY_ENGINE_DELETE_SAS
Apr 23 11:57:49.384: IPSEC:(SESSION ID = 19747) still in use sa: 0x7F48378D2BF0
Apr 23 11:57:49.391: IPSEC(send_delete_notify_kmi): not sending KEY_ENGINE_DELETE_SAS
Apr 23 11:57:49.391: IPSEC: still in use sa: 0x0
Apr 23 11:57:49.391: IPSEC: sa null
Apr 23 11:57:49.393 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access32, changed state to down
Apr 23 11:57:49.393 CEST: %LINK-3-UPDOWN: Interface Virtual-Access32, changed state to down
Apr 23 11:57:49.395: IPSEC(ERROR): ident_get_ike_peer_index_from_peer could not find ikmp handle for peer 0x7F483CC19BE0
Apr 23 11:57:49.395: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 11:57:49.395: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_DESTROY_YOURSELF message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 11:57:49.395: IPSEC(MESSAGE): INTF_SM (interface_sm_create_aux_msg_data) called
Apr 23 11:57:49.395: IPSEC(STATES): INTF_SM (interface_action_msg_check_policy) Crypto config being deleted
Apr 23 11:57:49.395: IPSEC(STATES): INTF_SM (interface_action_sadb_check) called
Apr 23 11:57:49.395: IPSEC(STATES): INTF_SM (interface_action_delete_policy) called
Apr 23 11:57:49.395: IPSEC(STATES): INTF_SM (interface_action_delete_sadb) called for interface Virtual-Access32
Apr 23 11:57:49.395: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_not_inuse) SADB 0x7F483DC9DB08 inuse_count 0
Apr 23 11:57:49.395: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_not_inuse) SADB 0x7F483DC9DB08 inuse_count 0
Apr 23 11:57:49.395: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_destroy) called
Apr 23 11:57:49.396: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_end) called
Apr 23 11:57:49.396: IPSEC(ERROR): Failed to remove SADB 0x7F483DC9DB08 from sadb_root_avl_tree
Apr 23 11:57:49.396: IPSEC(STATES): INTF_SM (interface_action_end) killing state machine 0x7F483BDB1E10
Apr 23 11:57:49.551 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access32, changed state to down
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (ipsec_pal_create_interface_state_machine) called for interface Virtual-Access32
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (ipsec_pal_create_interface_state_machine): Created INTF SM 0x7F483BDB1E10
Apr 23 11:57:49.558: IPSEC(MESSAGE): INTF_SM (interface_sm_create_aux_msg_data) called
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_msg_check_policy) Crypto config being added
Apr 23 11:57:49.558: IPSEC(MESSAGE): INTF_SM (interface_sm_extract_data) idb:Virtual-Access32 map:Virtual-Access32-head-0 protection:PROTECTION_CLASS_TUNNEL
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_sadb_check) called
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_new_sadb_exists) called
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_sadb_create) called
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (crypto_create_acl_struct) ACL address:0.0.0.0 mask:0.0.0.0 port:0
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (ipsec_pal_create_sadb_root_state_machine) called for SADB 0x7F483DCE55D0
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_initialize) called
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_initialize) interface Virtual-Access32 hint CRYPTO_SADB_HINT_VTI map Virtual-Access32-head-0
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_download) called
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_download_complete) called
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_inuse) SADB 0x7F483DCE55D0 inuse_count 1
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_attach_intf) called idb:Virtual-Access32 map:Virtual-Access32-head-0
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_sadb_update) called
Apr 23 11:57:49.559: IPSEC(STATES): INTF_SM (interface_action_remove_old_sadb) called
Apr 23 11:57:49.560: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 11:57:49.560: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 11:57:49.560: IPSEC(STATES): (insert_crypto_map) convert secure socket acl to crypto aces seq_no 65537 acl_name  acl_num 0
Apr 23 11:57:49.560: IPSEC(STATES): SADB_ROOT_SM (sadb_root_create_acl_struct) ACL static:65537 dynamic:0
Apr 23 11:57:49.560: IPSEC(STATES): SADB_ROOT_SM (ipsec_sadb_root_create_acl_state_machine) Calling to create bypass ACL SM
Apr 23 11:57:49.560: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_CHANGED message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 11:57:49.560: IPSEC(recalculate_mtu): reset sadb_root 7F483DCE55D0 mtu to 1500
Apr 23 11:57:49.561: IPSEC:(SESSION ID = 19797) (STATES) SADB_ROOT_SM (sadb_root_process_kmi_message) called static seqno 65537 dynamic seqno 0
Apr 23 11:57:49.574: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_KMI_CREATE_SA message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 11:57:49.578: IPSEC:(SESSION ID = 19797) (STATES) ident_set_flow_installed_action Sending crypto_ss_connection_open
Apr 23 11:57:49.578: IPSEC(rte_mgr): VPN Route Added 10.181.198.64 255.255.255.224 via Virtual-Access32 in IP DEFAULT TABLE with tag 101 distance 10
Apr 23 11:57:49.578 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access32, changed state to up
Apr 23 11:57:49.384: IPSEC:(SESSION ID = 19747) still in use sa: 0x7F48378D2BF0
Apr 23 11:57:49.391: IPSEC(send_delete_notify_kmi): not sending KEY_ENGINE_DELETE_SAS
Apr 23 11:57:49.391: IPSEC: still in use sa: 0x0
Apr 23 11:57:49.391: IPSEC: sa null
Apr 23 11:57:49.393 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access32, changed state to down
Apr 23 11:57:49.393 CEST: %LINK-3-UPDOWN: Interface Virtual-Access32, changed state to down
Apr 23 11:57:49.395: IPSEC(ERROR): ident_get_ike_peer_index_from_peer could not find ikmp handle for peer 0x7F483CC19BE0
Apr 23 11:57:49.395: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 11:57:49.395: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_DESTROY_YOURSELF message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 11:57:49.395: IPSEC(MESSAGE): INTF_SM (interface_sm_create_aux_msg_data) called
Apr 23 11:57:49.395: IPSEC(STATES): INTF_SM (interface_action_msg_check_policy) Crypto config being deleted
Apr 23 11:57:49.395: IPSEC(STATES): INTF_SM (interface_action_sadb_check) called
Apr 23 11:57:49.395: IPSEC(STATES): INTF_SM (interface_action_delete_policy) called
Apr 23 11:57:49.395: IPSEC(STATES): INTF_SM (interface_action_delete_sadb) called for interface Virtual-Access32
Apr 23 11:57:49.395: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_not_inuse) SADB 0x7F483DC9DB08 inuse_count 0
Apr 23 11:57:49.395: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_not_inuse) SADB 0x7F483DC9DB08 inuse_count 0
Apr 23 11:57:49.395: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_destroy) called
Apr 23 11:57:49.396: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_end) called
Apr 23 11:57:49.396: IPSEC(ERROR): Failed to remove SADB 0x7F483DC9DB08 from sadb_root_avl_tree
Apr 23 11:57:49.396: IPSEC(STATES): INTF_SM (interface_action_end) killing state machine 0x7F483BDB1E10
Apr 23 11:57:49.551 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access32, changed state to down
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (ipsec_pal_create_interface_state_machine) called for interface Virtual-Access32
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (ipsec_pal_create_interface_state_machine): Created INTF SM 0x7F483BDB1E10
Apr 23 11:57:49.558: IPSEC(MESSAGE): INTF_SM (interface_sm_create_aux_msg_data) called
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_msg_check_policy) Crypto config being added
Apr 23 11:57:49.558: IPSEC(MESSAGE): INTF_SM (interface_sm_extract_data) idb:Virtual-Access32 map:Virtual-Access32-head-0 protection:PROTECTION_CLASS_TUNNEL
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_sadb_check) called
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_new_sadb_exists) called
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_sadb_create) called
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (crypto_create_acl_struct) ACL address:0.0.0.0 mask:0.0.0.0 port:0
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (ipsec_pal_create_sadb_root_state_machine) called for SADB 0x7F483DCE55D0
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_initialize) called
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_initialize) interface Virtual-Access32 hint CRYPTO_SADB_HINT_VTI map Virtual-Access32-head-0
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_download) called
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_download_complete) called
Apr 23 11:57:49.558: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_inuse) SADB 0x7F483DCE55D0 inuse_count 1
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_attach_intf) called idb:Virtual-Access32 map:Virtual-Access32-head-0
Apr 23 11:57:49.558: IPSEC(STATES): INTF_SM (interface_action_sadb_update) called
Apr 23 11:57:49.559: IPSEC(STATES): INTF_SM (interface_action_remove_old_sadb) called
Apr 23 11:57:49.560: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 11:57:49.560: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 11:57:49.560: IPSEC(STATES): (insert_crypto_map) convert secure socket acl to crypto aces seq_no 65537 acl_name  acl_num 0
Apr 23 11:57:49.560: IPSEC(STATES): SADB_ROOT_SM (sadb_root_create_acl_struct) ACL static:65537 dynamic:0
Apr 23 11:57:49.560: IPSEC(STATES): SADB_ROOT_SM (ipsec_sadb_root_create_acl_state_machine) Calling to create bypass ACL SM
Apr 23 11:57:49.560: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_CHANGED message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 11:57:49.560: IPSEC(recalculate_mtu): reset sadb_root 7F483DCE55D0 mtu to 1500
Apr 23 11:57:49.561: IPSEC:(SESSION ID = 19797) (STATES) SADB_ROOT_SM (sadb_root_process_kmi_message) called static seqno 65537 dynamic seqno 0
Apr 23 11:57:49.574: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_KMI_CREATE_SA message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 11:57:49.578: IPSEC:(SESSION ID = 19797) (STATES) ident_set_flow_installed_action Sending crypto_ss_connection_open
Apr 23 11:57:49.578: IPSEC(rte_mgr): VPN Route Added 10.181.198.64 255.255.255.224 via Virtual-Access32 in IP DEFAULT TABLE with tag 101 distance 10
Apr 23 11:57:49.578 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access32, changed state to up
Apr 23 12:04:18.137: IPSEC:(SESSION ID = 19748) still in use sa: 0x7F483D68F5F8
Apr 23 12:04:18.139: IPSEC:(SESSION ID = 19748) (key_engine_delete_sas) delete SA with spi 0x416AF6F0 proto 50 for 10.191.254.89
Apr 23 12:04:18.143: IPSEC(send_delete_notify_kmi): not sending KEY_ENGINE_DELETE_SAS
Apr 23 12:04:18.144: IPSEC: still in use sa: 0x0
Apr 23 12:04:18.144: IPSEC: sa null
Apr 23 12:04:18.146 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access24, changed state to down
Apr 23 12:04:18.146 CEST: %LINK-3-UPDOWN: Interface Virtual-Access24, changed state to down
Apr 23 12:04:18.148: IPSEC(ERROR): ident_get_ike_peer_index_from_peer could not find ikmp handle for peer 0x7F48378CEBB0
Apr 23 12:04:18.148: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 12:04:18.148: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_DESTROY_YOURSELF message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 12:04:18.148: IPSEC(MESSAGE): INTF_SM (interface_sm_create_aux_msg_data) called
Apr 23 12:04:18.148: IPSEC(STATES): INTF_SM (interface_action_msg_check_policy) Crypto config being deleted
Apr 23 12:04:18.148: IPSEC(STATES): INTF_SM (interface_action_sadb_check) called
Apr 23 12:04:18.148: IPSEC(STATES): INTF_SM (interface_action_delete_policy) called
Apr 23 12:04:18.148: IPSEC(STATES): INTF_SM (interface_action_delete_sadb) called for interface Virtual-Access24
Apr 23 12:04:18.149: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_not_inuse) SADB 0x7F48378C6C10 inuse_count 0
Apr 23 12:04:18.149: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_not_inuse) SADB 0x7F48378C6C10 inuse_count 0
Apr 23 12:04:18.149: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_destroy) called
Apr 23 12:04:18.149: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_end) called
Apr 23 12:04:18.149: IPSEC(ERROR): Failed to remove SADB 0x7F48378C6C10 from sadb_root_avl_tree
Apr 23 12:04:18.149: IPSEC(STATES): INTF_SM (interface_action_end) killing state machine 0x7F483C4ADBC8
Apr 23 12:04:18.305 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access24, changed state to down
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (ipsec_pal_create_interface_state_machine) called for interface Virtual-Access24
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (ipsec_pal_create_interface_state_machine): Created INTF SM 0x7F483C4ADBC8
Apr 23 12:04:18.312: IPSEC(MESSAGE): INTF_SM (interface_sm_create_aux_msg_data) called
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (interface_action_msg_check_policy) Crypto config being added
Apr 23 12:04:18.312: IPSEC(MESSAGE): INTF_SM (interface_sm_extract_data) idb:Virtual-Access24 map:Virtual-Access24-head-0 protection:PROTECTION_CLASS_TUNNEL
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (interface_action_sadb_check) called
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (interface_new_sadb_exists) called
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (interface_action_sadb_create) called
Apr 23 12:04:18.312: IPSEC(STATES): SADB_ROOT_SM (crypto_create_acl_struct) ACL address:0.0.0.0 mask:0.0.0.0 port:0
Apr 23 12:04:18.312: IPSEC(STATES): SADB_ROOT_SM (ipsec_pal_create_sadb_root_state_machine) called for SADB 0x7F48378C6C10
Apr 23 12:04:18.312: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_initialize) called
Apr 23 12:04:18.312: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_initialize) interface Virtual-Access24 hint CRYPTO_SADB_HINT_VTI map Virtual-Access24-head-0
Apr 23 12:04:18.312: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_download) called
Apr 23 12:04:18.312: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_download_complete) called
Apr 23 12:04:18.312: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_inuse) SADB 0x7F48378C6C10 inuse_count 1
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (interface_action_attach_intf) called idb:Virtual-Access24 map:Virtual-Access24-head-0
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (interface_action_sadb_update) called
Apr 23 12:04:18.312: IPSEC(STATES): INTF_SM (interface_action_remove_old_sadb) called
Apr 23 12:04:18.314: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 12:04:18.314: IPSEC(STATES): SADB_ROOT_SM (sadb_root_action_cm_state) static_seqno 65537
Apr 23 12:04:18.314: IPSEC(STATES): (insert_crypto_map) convert secure socket acl to crypto aces seq_no 65537 acl_name  acl_num 0
Apr 23 12:04:18.314: IPSEC(STATES): SADB_ROOT_SM (sadb_root_create_acl_struct) ACL static:65537 dynamic:0
Apr 23 12:04:18.314: IPSEC(STATES): SADB_ROOT_SM (ipsec_sadb_root_create_acl_state_machine) Calling to create bypass ACL SM
Apr 23 12:04:18.314: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_CHANGED message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 12:04:18.314: IPSEC(recalculate_mtu): reset sadb_root 7F48378C6C10 mtu to 1500
Apr 23 12:04:18.315: IPSEC:(SESSION ID = 19798) (STATES) SADB_ROOT_SM (sadb_root_process_kmi_message) called static seqno 65537 dynamic seqno 0
Apr 23 12:04:18.317: IPSEC:(SESSION ID = 19798) (crypto_ipsec_sa_find_ident_head) reconnecting with the same proxies and peer 10.191.243.71
Apr 23 12:04:18.321: IPSEC:(SESSION ID = 19798) (create_sa) sa created,
  (sa) sa_dest= 10.191.254.89, sa_proto= 50,
    sa_spi= 0x8F37419D(2402763165),
    sa_trans= esp-aes 256 esp-sha-hmac , sa_conn_id= 24989
    sa_lifetime(k/sec)= (4608000/28000),
  (identity) local= 10.191.254.89:0, remote= 10.191.243.71:0,
    local_proxy= 0.0.0.0/0.0.0.0/256/0,
    remote_proxy= 10.181.194.128/255.255.255.224/256/0
Apr 23 12:04:18.326: IPSEC:(SESSION ID = 19798) (create_sa) sa created,
  (sa) sa_dest= 10.191.243.71, sa_proto= 50,
    sa_spi= 0x492F5007(1227837447),
    sa_trans= esp-aes 256 esp-sha-hmac , sa_conn_id= 24990
    sa_lifetime(k/sec)= (4608000/28000),
  (identity) local= 10.191.254.89:0, remote= 10.191.243.71:0,
    local_proxy= 0.0.0.0/0.0.0.0/256/0,
    remote_proxy= 10.181.194.128/255.255.255.224/256/0
Apr 23 12:04:18.327: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_KMI_CREATE_SA message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 12:04:18.332: IPSEC:(SESSION ID = 19798) (STATES) ident_set_flow_installed_action Sending crypto_ss_connection_open
Apr 23 12:04:18.332: IPSEC(rte_mgr): VPN Route Added 10.181.194.128 255.255.255.224 via Virtual-Access24 in IP DEFAULT TABLE with tag 101 distance 10
Apr 23 12:04:18.332 CEST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access24, changed state to up
Apr 23 12:09:59.272: IPSEC(STATES): SADB_ROOT_SM (sadb_root_process_kmi_message) called static seqno 65537 dynamic seqno 0
Apr 23 12:09:59.272: IPSEC(MESSAGE): SADB_ROOT_SM (print_message_to_acl_state_machine) Sent MSG_ACL_KMI_CREATE_SA message to ACL, static seqno 65537, dynamic seqno 0
Apr 23 12:09:59.772: IPSEC(key_engine_enable_outbound): rec'd enable notify from ISAKMP
Apr 23 12:09:59.775: IPSEC(STATES): ident_set_flow_installed_action Sending crypto_ss_connection_open
Apr 23 12:11:31.733: IPSEC(delete_sa): SA found saving DEL kmi

 


Thanks,


Gyula

 

 

 

 

5 people had this problem
Labels:
0 Helpful
3 Replies 3

paulcian_2
Level 1
Level 1

‎01-03-2017 08:50 AM

I am experiencing the same issue.  Did you ever find the solution?

0 Helpful

anton_polishchuk
Level 1
Level 1

‎03-25-2021 12:52 AM

Hello Folks,

 

Same issue here, I set lifetime to 120sec just for troubleshooting sake and IPSec will rekey one or two times but then throw above errors and drop all SAs...

Tried pretty much everything, changing Encryption, integrity hashes, stripping config to bare minimum and still able to observe this same behavior...

Were you able to resolve this somehow?

Currently I have disabled bytes volume rekey and set time based lifetime to 24hrs... it helps but this is a workaround and not a solution...

Anyone?

 

P.S. I also get:

IPSEC:(SESSION ID = 9) (ERROR) ident_get_ike_peer_index_from_peer could not find ikmp handle for peer

[Ident 80000009]: message = Message - Destroy yourself

And then everything goes downhill from there

 

A

 

0 Helpful

anton_polishchuk
Level 1
Level 1
In response to anton_polishchuk

‎03-25-2021 01:14 AM

Changing DH Group from 16 to 19 solved it for me...

I guess our overlords like EC for some reason...

Is it a weak curve that makes it more attractive over the Group 16?

0 Helpful
Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community:

Customers Also Viewed These Support Documents