Hi Guys, Recently encountered an issue in where Phase 2 of IPsec somehow not functioning well. the issue is I can see encapsulated data but not able to decapsulate any data traffic.
Issue:
#pkts encaps: 5413, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
I ran a debug and I'm able to see this issue "delete SA with spi","not sending KEY_ENGINE_DELETE_SAS", "deleting SA".
Apr 12 10:53:52.057 GMT: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Apr 12 10:53:52.057 GMT: IDB is NULL : in crypto_ipsec_key_engine_delete_sas (), 6145
Apr 12 10:53:52.057 GMT: IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
Apr 12 10:53:52.057 GMT: IPSEC(key_engine_delete_sas): delete SA with spi 0x386CD8DD proto 50 for 220.20.20.20
Apr 12 10:53:52.057 GMT: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 122.1.1.1, sa_proto= 50,
sa_spi= 0x3DFBF9A5(1039923621),
sa_trans= esp-aes 256 esp-sha-hmac , sa_conn_id= 11505
sa_lifetime(k/sec)= (4608000/3600),
(identity) local= 122.1.1.1:0, remote= 220.20.20.20:0,
local_proxy= 122.1.1.1/255.255.255.255/47/0,
remote_proxy= 220.20.20.20/255.255.255.255/47/0
Apr 12 10:53:52.058 GMT: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 220.20.20.20, sa_proto= 50,
sa_spi= 0x386CD8DD(946657501),
sa_trans= esp-aes 256 esp-sha-hmac , sa_conn_id= 11506
sa_lifetime(k/sec)= (4608000/3600),
(identity) local= 122.1.1.1:0, remote= 220.20.20.20:0,
local_proxy= 122.1.1.1/255.255.255.255/47/0,
remote_proxy= 220.20.20.20/255.255.255.255/47/0
Apr 12 10:53:52.058 GMT: IPSEC(send_delete_notify_kmi): not sending KEY_ENGINE_DELETE_SAS
!
Apr 12 10:53:52.059 GMT: ipsec_out_sa_hash_idx: sa=0x7F00A631CA58, hash_idx=872, port=500/500, addr=0x3ECCF1BA/0xC6234A03
Apr 12 10:53:52.062 GMT: IPSEC(ident_delete_notify_kmi): Failed to send KEY_ENG_DELETE_SAS
Apr 12 10:53:52.062 GMT: IPSEC(ident_update_final_flow_stats): Collect Final Stats and update MIB
IPSEC get IKMP peer index from peer 0x7F00A631A660 ikmp handle 0x4007E5B8
IPSEC IKMP peer index 0
[ident_update_final_flow_stats] : Flow delete complete event received for flow id 0x24002521,peer index 0
Apr 12 10:53:53.039 GMT: %CRYPTO-6-IKMP_NO_ID_CERT_FQDN_MATCH: (NOT ERROR BUT WARNING ONLY)ID of <> (type 2) and certificate fqdn with <>.com
Apr 12 10:53:53.039 GMT: %CRYPTO-6-IKMP_NO_ID_CERT_FQDN_MATCH: (NOT ERROR BUT WARNING ONLY)ID of <> (type 2) and certificate fqdn with <>.com
Apr 12 10:53:53.041 GMT: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Apr 12 10:53:53.041 GMT: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Apr 12 10:53:57.233 GMT: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Apr 12 10:53:57.233 GMT: IDB is NULL : in crypto_ipsec_key_engine_delete_sas (), 6145
Apr 12 10:53:57.233 GMT: IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
Apr 12 10:53:57.233 GMT: IPSEC(key_engine_delete_sas): delete SA with spi 0x8CCC617 proto 50 for 60.2.2.2
Apr 12 10:53:57.233 GMT: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 122.1.1.1, sa_proto= 50,
sa_spi= 0x78F35D03(2029214979),
sa_trans= esp-aes 256 esp-sha-hmac , sa_conn_id= 11507
sa_lifetime(k/sec)= (4608000/3600),
(identity) local= 122.1.1.1:0, remote= 60.2.2.2:0,
local_proxy= 122.1.1.1/255.255.255.255/47/0,
remote_proxy= 60.2.2.2/255.255.255.255/47/0
Apr 12 10:53:57.234 GMT: IPSEC(delete_sa): deleting SA,
(sa) sa_dest= 60.2.2.2, sa_proto= 50,
sa_spi= 0x8CCC617(147637783),
sa_trans= esp-aes 256 esp-sha-hmac , sa_conn_id= 11508
sa_lifetime(k/sec)= (4608000/3600),
(identity) local= 122.1.1.1:0, remote= 60.2.2.2:0,
local_proxy= 122.1.1.1/255.255.255.255/47/0,
remote_proxy= 60.2.2.2/255.255.255.255/47/0
I resolve the issue by disabling the tunnel interface for several minutes after enabling again IPSec session went up both phase 1 and phase is working. Note: we have multiple tunnels configured and both experienced the same issue in when Phase 2 is not fully working. We are using cisco router ISR4331/K9 series btw.
No configuration change and no errors observed on IPsec counters.
#pkts encaps: 124, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0
Have you encountered this kind of issue and why bouncing the port for long time resolve the issue ?
I need to verify if the this issue is due to ISP or somehow device issue?
Thanks