# run show log IKE-TRACE [Sep 19 11:17:26][ <-> ] ikev2_free_exchange_data: Freeing exchange data from SA 1277000, ED 1279028 (1) [Sep 19 11:17:26][ <-> ] ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 1277000 [Sep 19 11:17:26][ <-> ] ssh_ikev2_ts_free: ts 0x1286920, ref_cnt 2 [Sep 19 11:17:26][ <-> ] ssh_ikev2_ts_free: ts 0x1286940, ref_cnt 2 [Sep 19 11:17:26][ <-> ] ssh_ikev2_ts_free: ts 0x1286940, ref_cnt 1 [Sep 19 11:17:26][ <-> ] ssh_ikev2_ts_free: ts 0x1286920, ref_cnt 1 [Sep 19 11:17:26][ <-> ] ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 1277000 [Sep 19 11:17:26][ <-> ] ikev2_free_exchange_data: Notify call: exchange_data_free [Sep 19 11:17:26][ <-> ] Freeing P2 Ed for sa-cfg N/A [Sep 19 11:17:26][ <-> ] iked_pm_ike_exchange_data_free found sa_cfg_instanceinstance[instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870] p2_ed=0x12a5c30, tunnel_id=67108870 [Sep 19 11:17:26][ <-> ] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 12a5c00 from list for sa_cfg N/A [Sep 19 11:17:26][ <-> ] ikev2_free_exchange_data: Successfully freed exchange data from SA 1277000 [Sep 19 11:17:26][ <-> ] ikev2_fallback_negotiation_free: Freeing reference to IKE SA 1277000 to ref count 2 [Sep 19 11:17:26][ <-> ] ssh_ikev2_ike_sa_free: Notify call: ike_sa_free_ref [Sep 19 11:17:26][ <-> ] Freeing reference to P1 SA 7353756 to ref count 2 [Sep 19 11:17:31][ <-> ] *** Processing received packet from :54987 to :0, VR 0, packet len: 96, on Interface: ge-0/0/0.0 [Sep 19 11:17:31][ <-> ] ---------> Received from :54987 to :0, VR 0, length 96 on IF ge-0/0/0.0 [Sep 19 11:17:31][ <-> ] ikev2_packet_st_input_start: [11f2800/0] ******** Processing received ************ [Sep 19 11:17:31][ <-> ] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa [Sep 19 11:17:31][ <-> ] ike_sa_find: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:31][ <-> ] ike_sa_find: Found SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:31][ <-> ] Found IKEv1 SA [Sep 19 11:17:31][ <-> ] ikev2_packet_st_input_v1_get_sa: [11f2800/deadbeee] Packet to existing v1 SA [Sep 19 11:17:31][ <-> ] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start [Sep 19 11:17:31][ <-> ] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Sep 19 11:17:31][ <-> ] ike_udp_callback_common: Packet from :54987, use_natt=1 data[0..96] = 00000000 8e65c82e aa59e182 2866b7a7 ... [Sep 19 11:17:31][ <-> ] ike_get_sa: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } / 791918f2, remote = :54987 [Sep 19 11:17:31][ <-> ] ike_sa_find: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:31][ <-> ] ike_sa_find: Found SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:31][ <-> ] ike_alloc_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119} [Sep 19 11:17:31][ <-> ] ike_alloc_negotiation: Found slot 5, max 6 [Sep 19 11:17:31][ <-> ] ike_udp_callback_common: New informational negotiation message_id = 791918f2 initialized using slot 5 [Sep 19 11:17:31][ <-> ] ike_udp_callback_common: Old negotiation message_id = 791918f2, slot 5 [Sep 19 11:17:31][ <-> ] ike_decode_packet: Start [Sep 19 11:17:31][ <-> ] ike_decode_packet: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119} / 791918f2, nego = 5 [Sep 19 11:17:31][ <-> ] ike_decode_packet: first_payload_type:8. [Sep 19 11:17:31][ <-> ] ike_decode_packet: Decrypting packet [Sep 19 11:17:31][ <-> ] ike_decode_packet: next_payload_type:11. [Sep 19 11:17:31][ <-> ] ike_decode_packet: next_payload_type:0. [Sep 19 11:17:31][ <-> ] IKEv1 packet R(:4500 <- :500): len= 92, mID=791918f2, HDR, HASH, N(R_U_THERE) [Sep 19 11:17:31][ <-> ] ike_state_step: Current state = Done (53)/-1, exchange = 5, auth_method = any, Responder [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 2, fields = 000c / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 2, fields = 000c / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 2, fields = 001f / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 2, fields = 0008 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 2, fields = 0020 / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 3, fields = 0001 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 3, fields = 0016 / 06e0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 3, fields = 0016 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 3, fields = 0037 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 4, fields = 0001 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 4, fields = 0012 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 4, fields = 0012 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 4, fields = 0024 / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 4, fields = 0024 / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 4, fields = 0037 / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 4, fields = 0020 / 0680 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 0, fields = 0001 / 06c0 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start QM I (14), xchg = 32, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start QM R (15), xchg = 32, auth = 1, fields = 0031 / 0206 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = QM HASH SA I (16), xchg = 32, auth = 1, fields = 0031 / 0206 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = QM HASH SA R (17), xchg = 32, auth = 1, fields = 0020 / 0200 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = QM HASH I (18), xchg = 32, auth = 1, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = QM done R (19), xchg = 32, auth = 1, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start NGM I (20), xchg = 33, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start NGM R (21), xchg = 33, auth = 1, fields = 0021 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = NGM HASH SA I (22), xchg = 33, auth = 1, fields = 0021 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = NGM HASH SA R (23), xchg = 33, auth = 1, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = NGM done I (24), xchg = 33, auth = 1, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start CFG I (25), xchg = 6, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start CFG R (26), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR I (27), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 1, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = CFG done I (29), xchg = 6, auth = 1, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start CFG I (25), xchg = 6, auth = 0, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start CFG R (26), xchg = 6, auth = 0, fields = 0800 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR I (27), xchg = 6, auth = 0, fields = 0800 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 0, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = CFG done I (29), xchg = 6, auth = 0, fields = ffff / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start GDOI I (30), xchg = 32, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Start GDOI R (31), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = GDOI ID I (32), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = GDOI SA R (33), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = GDOI HASH3 I (34), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = GDOI KD R (35), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = GDOI DONE I (36), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (37), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (38), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (39), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (40), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (41), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (42), xchg = 240, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (43), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (44), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (45), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (46), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (47), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (48), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (49), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (50), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (51), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = unknown (52), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matching with state = Any (0), xchg = 256, auth = 1, fields = 0220 / ffff [Sep 19 11:17:31][ <-> ] ike_state_step: Matched state = Any (0) [Sep 19 11:17:31][ <-> ] ike_state_step: Calling input function[0] = ike_st_i_encrypt [Sep 19 11:17:31][ <-> ] ike_st_i_encrypt: Check that packet was encrypted succeeded [Sep 19 11:17:31][ <-> ] ike_state_step: Calling input function[1] = ike_st_i_gen_hash [Sep 19 11:17:31][ <-> ] ike_st_i_gen_hash: Start, hash[0..20] = e657b217 1931d48d ... [Sep 19 11:17:31][ <-> ] ike_state_step: Calling input function[2] = ike_st_i_n [Sep 19 11:17:31][ <-> ] ike_st_i_n: Start, doi = 1, protocol = 1, code = DPD Are You There (36136), spi[0..16] = 8e65c82e aa59e182 ..., data[0..4] = 006aa859 00000000 ... [Sep 19 11:17:31][ <-> ] ikev2_fb_notification: Phase-II authenticated notification call entered, IKE SA 1277000 [Sep 19 11:17:31][ <-> ] ikev2_allocate_exchange_data: Calling exchange_data_alloc [Sep 19 11:17:31][ <-> ] iked_pm_ike_exchange_data_alloc: Successfully inserted pm_ed 12a8a00 into list for sa_cfg N/A [Sep 19 11:17:31][ <-> ] Exchange data allocated for IKE SA 7353756. VR 0 [Sep 19 11:17:31][ <-> ] ikev2_allocate_exchange_data: Successfully allocated exchange data for SA 1277000 [Sep 19 11:17:31][ <-> ] ikev2_fb_phase_ii_pending_natt_operations: Processing pending NAT-T operations [Sep 19 11:17:31][ <-> ] ikev2_free_exchange_data: Freeing exchange data from SA 1277000, ED 1279028 (1) [Sep 19 11:17:31][ <-> ] ikev2_free_exchange_data: Notify call: exchange_data_free [Sep 19 11:17:31][ <-> ] Freeing P2 Ed for sa-cfg N/A [Sep 19 11:17:31][ <-> ] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 12a8a00 from list for sa_cfg N/A [Sep 19 11:17:31][ <-> ] ikev2_free_exchange_data: Successfully freed exchange data from SA 1277000 [Sep 19 11:17:31][ <-> ] ssh_ike_connect_notify: Start, remote_name = :500, flags = 00010000 [Sep 19 11:17:31][ <-> ] ike_sa_find_ip_port: Start, remote = all:500 [Sep 19 11:17:31][ <-> ] ike_alloc_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119} [Sep 19 11:17:31][ <-> ] ike_alloc_negotiation: Found slot 6, max 7 [Sep 19 11:17:31][ <-> ] ike_init_info_exchange: New informational negotiation message_id = 9f93cd7f initialized using slot 6 [Sep 19 11:17:31][ <-> ] ike_init_info_exchange: Created random message id = 9f93cd7f [Sep 19 11:17:31][ <-> ] ike_init_info_exchange: Phase 1 done, use HASH and N or D payload [Sep 19 11:17:31][ <-> ] ssh_ike_connect_notify: SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 6 [Sep 19 11:17:31][ <-> ] ike_encode_packet: Start, SA = { 0x8e65c82e aa59e182 - 2866b7a7 db565119 } / 9f93cd7f, nego = 6 [Sep 19 11:17:31][ <-> ] ike_encode_packet: Payload length = 24 [Sep 19 11:17:31][ <-> ] ike_encode_packet: Payload length = 32 [Sep 19 11:17:31][ <-> ] ike_encode_packet: Payload length = 92 [Sep 19 11:17:31][ <-> ] ike_encode_packet: Calling finalizing function for payload[0].type = 8 [Sep 19 11:17:31][ <-> ] IKEv1 packet S(:4500 -> :500): len= 92, mID=9f93cd7f, HDR, HASH, N(R_U_THERE_ACK) [Sep 19 11:17:31][ <-> ] ike_encode_packet: Encrypting packet [Sep 19 11:17:31][ <-> ] ike_encode_packet: Final length = 92 [Sep 19 11:17:31][ <-> ] ssh_ike_connect_notify: Sending notification to (null):500 [Sep 19 11:17:31][ <-> ] ike_send_packet: Start, send SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 6, dst = :54987 [Sep 19 11:17:31][ <-> ] ike_packet_free: Start [Sep 19 11:17:31][ <-> ] ike_delete_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 6 [Sep 19 11:17:31][ <-> ] ike_free_negotiation_info: Start, nego = 6 [Sep 19 11:17:31][ <-> ] ike_free_negotiation: Start, nego = 6 [Sep 19 11:17:31][ <-> ] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered [Sep 19 11:17:31][ <-> ] ike_state_step: Calling input function[3] = ike_st_i_private [Sep 19 11:17:31][ <-> ] ike_st_i_private: Start [Sep 19 11:17:31][ <-> ] ike_state_step: Calling output function[0] = ike_st_o_n_done [Sep 19 11:17:31][ <-> ] ike_packet_free: Start [Sep 19 11:17:31][ <-> ] ike_state_step: All done, new state = Done (53) [Sep 19 11:17:31][ <-> ] ike_process_packet: Connected, sending notify [Sep 19 11:17:31][ <-> ] ike_send_notify: Connected, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 5 [Sep 19 11:17:31][ <-> ] ike_delete_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 5 [Sep 19 11:17:31][ <-> ] ike_free_negotiation_info: Start, nego = 5 [Sep 19 11:17:31][ <-> ] ike_free_negotiation: Start, nego = 5 [Sep 19 11:17:31][ <-> ] ike_packet_free: Start [Sep 19 11:17:31][ <-> ] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered [Sep 19 11:17:31][ <-> ] ikev2_packet_destroy: [11f2800/deadbeee] Destructor [Sep 19 11:17:31][ <-> ] ikev2_packet_free: [11f2800/deadbeee] Freeing [Sep 19 11:17:31][ <-> ] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local remote [Sep 19 11:17:31][ <-> ] ike_retransmit_callback: Start, retransmit SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 3 [Sep 19 11:17:31][ <-> ] ike_send_packet: Start, retransmit previous packet SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 3, dst = :54987 routing table id = 0 [Sep 19 11:17:31][ <-> ] IKEv1 packet S(:4500 -> :54987): mID=657ff8aa (retransmit count=1) [Sep 19 11:17:31][ <-> ] ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Sep 19 11:17:32][ <-> ] Received IPSec SA lsize update message for Tunnel Id = 67108870; In-spi = 0x137e0173, Out-spi = 0xa80b791f, SA lifesize remaining = 500000kb [Sep 19 11:17:36][ <-> ] *** Processing received packet from :54987 to :0, VR 0, packet len: 80, on Interface: ge-0/0/0.0 [Sep 19 11:17:36][ <-> ] ---------> Received from :54987 to :0, VR 0, length 80 on IF ge-0/0/0.0 [Sep 19 11:17:36][ <-> ] ikev2_packet_st_input_start: [11f2c00/0] ******** Processing received ************ [Sep 19 11:17:36][ <-> ] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa [Sep 19 11:17:36][ <-> ] ike_sa_find: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] ike_sa_find: Found SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] Found IKEv1 SA [Sep 19 11:17:36][ <-> ] ikev2_packet_st_input_v1_get_sa: [11f2c00/deadbeee] Packet to existing v1 SA [Sep 19 11:17:36][ <-> ] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start [Sep 19 11:17:36][ <-> ] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Sep 19 11:17:36][ <-> ] ike_udp_callback_common: Packet from :54987, use_natt=1 data[0..80] = 00000000 8e65c82e aa59e182 2866b7a7 ... [Sep 19 11:17:36][ <-> ] ike_get_sa: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } / c354dba1, remote = :54987 [Sep 19 11:17:36][ <-> ] ike_sa_find: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] ike_sa_find: Found SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] ike_alloc_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119} [Sep 19 11:17:36][ <-> ] ike_alloc_negotiation: Found slot 5, max 6 [Sep 19 11:17:36][ <-> ] ike_udp_callback_common: New informational negotiation message_id = c354dba1 initialized using slot 5 [Sep 19 11:17:36][ <-> ] ike_udp_callback_common: Old negotiation message_id = c354dba1, slot 5 [Sep 19 11:17:36][ <-> ] ike_decode_packet: Start [Sep 19 11:17:36][ <-> ] ike_decode_packet: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119} / c354dba1, nego = 5 [Sep 19 11:17:36][ <-> ] ike_decode_packet: first_payload_type:8. [Sep 19 11:17:36][ <-> ] ike_decode_packet: Decrypting packet [Sep 19 11:17:36][ <-> ] ike_decode_packet: next_payload_type:12. [Sep 19 11:17:36][ <-> ] ike_decode_packet: next_payload_type:0. [Sep 19 11:17:36][ <-> ] IKEv1 packet R(:4500 <- :500): len= 76, mID=c354dba1, HDR, HASH, DEL [Sep 19 11:17:36][ <-> ] ike_state_step: Current state = Done (53)/-1, exchange = 5, auth_method = any, Responder [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 2, fields = 000c / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 2, fields = 000c / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 2, fields = 001f / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 2, fields = 0008 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 2, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 3, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 3, fields = 0016 / 06e0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 3, fields = 0016 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 3, fields = 0037 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 4, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 4, fields = 0012 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 4, fields = 0012 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 4, fields = 0024 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 4, fields = 0024 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 4, fields = 0037 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 4, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 0, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start QM I (14), xchg = 32, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start QM R (15), xchg = 32, auth = 1, fields = 0031 / 0206 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = QM HASH SA I (16), xchg = 32, auth = 1, fields = 0031 / 0206 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = QM HASH SA R (17), xchg = 32, auth = 1, fields = 0020 / 0200 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = QM HASH I (18), xchg = 32, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = QM done R (19), xchg = 32, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start NGM I (20), xchg = 33, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start NGM R (21), xchg = 33, auth = 1, fields = 0021 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = NGM HASH SA I (22), xchg = 33, auth = 1, fields = 0021 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = NGM HASH SA R (23), xchg = 33, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = NGM done I (24), xchg = 33, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start CFG I (25), xchg = 6, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start CFG R (26), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR I (27), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG done I (29), xchg = 6, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start CFG I (25), xchg = 6, auth = 0, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start CFG R (26), xchg = 6, auth = 0, fields = 0800 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR I (27), xchg = 6, auth = 0, fields = 0800 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG done I (29), xchg = 6, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start GDOI I (30), xchg = 32, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start GDOI R (31), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI ID I (32), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI SA R (33), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI HASH3 I (34), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI KD R (35), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI DONE I (36), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (37), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (38), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (39), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (40), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (41), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (42), xchg = 240, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (43), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (44), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (45), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (46), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (47), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (48), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (49), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (50), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (51), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (52), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Any (0), xchg = 256, auth = 1, fields = 0220 / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Done (53), xchg = 256, auth = 1, fields = 0120 / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matched state = Done (53) [Sep 19 11:17:36][ <-> ] ike_state_step: Calling input function[0] = ike_st_i_encrypt [Sep 19 11:17:36][ <-> ] ike_st_i_encrypt: Check that packet was encrypted succeeded [Sep 19 11:17:36][ <-> ] ike_state_step: Calling input function[1] = ike_st_i_gen_hash [Sep 19 11:17:36][ <-> ] ike_st_i_gen_hash: Start, hash[0..20] = 68f71d2c 19fe619a ... [Sep 19 11:17:36][ <-> ] ike_state_step: Calling input function[2] = ike_st_i_d [Sep 19 11:17:36][ <-> ] ike_st_i_d: Start, doi = 1, protocol = 3, spis[0..1][0..4] = [a80b791f 00000000 ...] [Sep 19 11:17:36][ <-> ] ikev2_fb_delete: Authenticated IPsec SA delete notification from IKE SA 1277000, from :54987 for protocol ESP containing 1 SPIs [Sep 19 11:17:36][ <-> ] ikev2_allocate_exchange_data: Calling exchange_data_alloc [Sep 19 11:17:36][ <-> ] iked_pm_ike_exchange_data_alloc: Successfully inserted pm_ed 12a8a00 into list for sa_cfg N/A [Sep 19 11:17:36][ <-> ] Exchange data allocated for IKE SA 7353756. VR 0 [Sep 19 11:17:36][ <-> ] ikev2_allocate_exchange_data: Successfully allocated exchange data for SA 1277000 [Sep 19 11:17:36][ <-> ] ikev2_fb_delete: FB; Calling v2 policy function ipsec_spi_delete_received [Sep 19 11:17:36][ <-> ] iked_pm_ipsec_spi_delete_received: Received IPsec SPI delete for SPI 0xa80b791f from the IKE library [Sep 19 11:17:36][ <-> ] kmd_sa_free free sa for instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 [Sep 19 11:17:36][ <-> ] Freeing the SA spi=0xa80b791f, proto=ESP [Sep 19 11:17:36][ <-> ] Out bound SA. Not sending notification [Sep 19 11:17:36][ <-> ] Deleted (spi=0xa80b791f, protocol=ESP dst=) entry from the peer hash table. Reason: IPSec SA delete payload received from peer, corresponding IPSec SAs cleared [Sep 19 11:17:36][ <-> ] kmd_update_sa_delete_in_kernel [Sep 19 11:17:36][ <-> ] iked_deactivate_sa_pair_and_update_kernel [Sep 19 11:17:36][ <-> ] In iked_ipsec_sa_pair_delete Deleting GENCFG msg with key; Tunnel = 67108870;SPI-In = 0x137e0173 [Sep 19 11:17:36][ <-> ] Deleted SA pair for tunnel = 67108870 with SPI-In = 0x137e0173 to kernel [Sep 19 11:17:36][ <-> ] iked_route_update_needed_on_sa_create_delete: SA-CFG instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 rc traffic-selector [Sep 19 11:17:36][ <-> ] iked_deactivate_group_instance_sa_cfg [Sep 19 11:17:36][ <-> ] iked_deactivate_group_instance_sa_cfg register deferred timer [Sep 19 11:17:36][ <-> ] iked_tunnel_event_add_event_in_sa_cfg: Updating tunnel-event for sa-cfg instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 with IPSec SA delete payload received from peer, corresponding IPS [Sep 19 11:17:36][ <-> ] iked_tunnel_event_add_event_in_sa_cfg: tunnel-event IPSec SA delete payload received from peer, corresponding IPSec SAs cleared count incremented to 6 [Sep 19 11:17:36][ <-> ] kmd_ipsec_tunnel_entry_delete: processing SA instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 (flags: 0x608c29) [Sep 19 11:17:36][ <-> ] iked_lookup_peer_entry: Peer entry 0x127a000 FOUND for local :4500 and remote :54987 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent INSTANCE-dyn-vpn_0002_0008_0000 for sa_cfg instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent dyn-vpn for sa_cfg INSTANCE-dyn-vpn_0002_0008_0000 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent INSTANCE-dyn-vpn_0002_0008_0000 for sa_cfg instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent dyn-vpn for sa_cfg INSTANCE-dyn-vpn_0002_0008_0000 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent INSTANCE-dyn-vpn_0002_0008_0000 for sa_cfg instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent dyn-vpn for sa_cfg INSTANCE-dyn-vpn_0002_0008_0000 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_update_sa_cfg_child_sa_count updated sa count for sa_cfg dyn-vpn to 1 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_update_sa_cfg_child_sa_count updated sa count for sa_cfg INSTANCE-dyn-vpn_0002_0008_0000 to 1 [Sep 19 11:17:36][ <-> ] kmd_sa_free free sa for instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 [Sep 19 11:17:36][ <-> ] Freeing the SA spi=0x137e0173, proto=ESP [Sep 19 11:17:36][ <-> ] Deleted (spi=0x137e0173, protocol=ESP dst=) entry from the peer hash table. Reason: IPSec SA delete payload received from peer, corresponding IPSec SAs cleared [Sep 19 11:17:36][ <-> ] iked_tunnel_event_add_event_in_sa_cfg: Updating tunnel-event for sa-cfg instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 with IPSec SA delete payload received from peer, corresponding IPS [Sep 19 11:17:36][ <-> ] kmd_update_sa_delete_in_kernel [Sep 19 11:17:36][ <-> ] Deleted (spi=0x137e0173, protocol=ESP) entry from the inbound sa spi hash table [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent INSTANCE-dyn-vpn_0002_0008_0000 for sa_cfg instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent dyn-vpn for sa_cfg INSTANCE-dyn-vpn_0002_0008_0000 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_update_sa_cfg_child_sa_count updated sa count for sa_cfg dyn-vpn to 0 [Sep 19 11:17:36][ <-> ] iked_sa_cfg_update_sa_cfg_child_sa_count updated sa count for sa_cfg INSTANCE-dyn-vpn_0002_0008_0000 to 0 [Sep 19 11:17:36][ <-> ] kmd_sa_free child_sa_cnt = 0 [Sep 19 11:17:36][ <-> ] iked_lookup_peer_entry: Peer entry 0x127a000 FOUND for local :4500 and remote :54987 [Sep 19 11:17:36][ <-> ] iked_peer_remove_sa_cfg_entry: remove sa_cfg tunnel_id entry 67108870 from peer entry 0x127a000 [Sep 19 11:17:36][ <-> ] iked_peer_remove_sa_cfg_entry: Moving sa-cfg instance-INSTANCE-dyn-vpn_0002_0008_0000_67108870 to inactive list for peer-entry 0x127a000 [Sep 19 11:17:36][ <-> ] ikev2_fb_phase_ii_pending_natt_operations: Processing pending NAT-T operations [Sep 19 11:17:36][ <-> ] ikev2_free_exchange_data: Freeing exchange data from SA 1277000, ED 1279028 (1) [Sep 19 11:17:36][ <-> ] ikev2_free_exchange_data: Notify call: exchange_data_free [Sep 19 11:17:36][ <-> ] Freeing P2 Ed for sa-cfg N/A [Sep 19 11:17:36][ <-> ] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 12a8a00 from list for sa_cfg N/A [Sep 19 11:17:36][ <-> ] ikev2_free_exchange_data: Successfully freed exchange data from SA 1277000 [Sep 19 11:17:36][ <-> ] ike_state_step: Calling input function[3] = ike_st_i_private [Sep 19 11:17:36][ <-> ] ike_st_i_private: Start [Sep 19 11:17:36][ <-> ] ike_state_step: Calling output function[0] = ike_st_o_d_done [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ike_state_step: All done, new state = Done (53) [Sep 19 11:17:36][ <-> ] ike_process_packet: Connected, sending notify [Sep 19 11:17:36][ <-> ] ike_send_notify: Connected, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 5 [Sep 19 11:17:36][ <-> ] ike_delete_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 5 [Sep 19 11:17:36][ <-> ] ike_free_negotiation_info: Start, nego = 5 [Sep 19 11:17:36][ <-> ] ike_free_negotiation: Start, nego = 5 [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered [Sep 19 11:17:36][ <-> ] ikev2_packet_destroy: [11f2c00/deadbeee] Destructor [Sep 19 11:17:36][ <-> ] ikev2_packet_free: [11f2c00/deadbeee] Freeing [Sep 19 11:17:36][ <-> ] *** Processing received packet from :54987 to :0, VR 0, packet len: 96, on Interface: ge-0/0/0.0 [Sep 19 11:17:36][ <-> ] ---------> Received from :54987 to :0, VR 0, length 96 on IF ge-0/0/0.0 [Sep 19 11:17:36][ <-> ] ikev2_packet_st_input_start: [11f3000/0] ******** Processing received ************ [Sep 19 11:17:36][ <-> ] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa [Sep 19 11:17:36][ <-> ] ike_sa_find: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] ike_sa_find: Found SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] Found IKEv1 SA [Sep 19 11:17:36][ <-> ] ikev2_packet_st_input_v1_get_sa: [11f3000/deadbeee] Packet to existing v1 SA [Sep 19 11:17:36][ <-> ] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start [Sep 19 11:17:36][ <-> ] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Sep 19 11:17:36][ <-> ] ike_udp_callback_common: Packet from :54987, use_natt=1 data[0..96] = 00000000 8e65c82e aa59e182 2866b7a7 ... [Sep 19 11:17:36][ <-> ] ike_get_sa: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } / d03e1449, remote = :54987 [Sep 19 11:17:36][ <-> ] ike_sa_find: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] ike_sa_find: Found SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] ike_alloc_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119} [Sep 19 11:17:36][ <-> ] ike_alloc_negotiation: Found slot 5, max 6 [Sep 19 11:17:36][ <-> ] ike_udp_callback_common: New informational negotiation message_id = d03e1449 initialized using slot 5 [Sep 19 11:17:36][ <-> ] ike_udp_callback_common: Old negotiation message_id = d03e1449, slot 5 [Sep 19 11:17:36][ <-> ] ike_decode_packet: Start [Sep 19 11:17:36][ <-> ] ike_decode_packet: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119} / d03e1449, nego = 5 [Sep 19 11:17:36][ <-> ] ike_decode_packet: first_payload_type:8. [Sep 19 11:17:36][ <-> ] ike_decode_packet: Decrypting packet [Sep 19 11:17:36][ <-> ] ike_decode_packet: next_payload_type:12. [Sep 19 11:17:36][ <-> ] ike_decode_packet: next_payload_type:0. [Sep 19 11:17:36][ <-> ] IKEv1 packet R(:4500 <- :500): len= 92, mID=d03e1449, HDR, HASH, DEL [Sep 19 11:17:36][ <-> ] ike_state_step: Current state = Done (53)/-1, exchange = 5, auth_method = any, Responder [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 2, fields = 000c / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 2, fields = 000c / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 2, fields = 001f / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 2, fields = 0008 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 2, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 3, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 3, fields = 0016 / 06e0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 3, fields = 0016 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 3, fields = 0037 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 3, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 4, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 4, fields = 0012 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 4, fields = 0012 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 4, fields = 0024 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 4, fields = 0024 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA I (10), xchg = 4, auth = 4, fields = 0037 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = AM SA R (11), xchg = 4, auth = 4, fields = 0020 / 0680 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 0, fields = 0001 / 06c0 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start QM I (14), xchg = 32, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start QM R (15), xchg = 32, auth = 1, fields = 0031 / 0206 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = QM HASH SA I (16), xchg = 32, auth = 1, fields = 0031 / 0206 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = QM HASH SA R (17), xchg = 32, auth = 1, fields = 0020 / 0200 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = QM HASH I (18), xchg = 32, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = QM done R (19), xchg = 32, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start NGM I (20), xchg = 33, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start NGM R (21), xchg = 33, auth = 1, fields = 0021 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = NGM HASH SA I (22), xchg = 33, auth = 1, fields = 0021 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = NGM HASH SA R (23), xchg = 33, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = NGM done I (24), xchg = 33, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start CFG I (25), xchg = 6, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start CFG R (26), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR I (27), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 1, fields = 0820 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG done I (29), xchg = 6, auth = 1, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start CFG I (25), xchg = 6, auth = 0, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start CFG R (26), xchg = 6, auth = 0, fields = 0800 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR I (27), xchg = 6, auth = 0, fields = 0800 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG HASH ATTR SA R (28), xchg = 6, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = CFG done I (29), xchg = 6, auth = 0, fields = ffff / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start GDOI I (30), xchg = 32, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Start GDOI R (31), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI ID I (32), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI SA R (33), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI HASH3 I (34), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI KD R (35), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = GDOI DONE I (36), xchg = 32, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (37), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (38), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (39), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (40), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (41), xchg = 33, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (42), xchg = 240, auth = 1, fields = 0000 / 0000 [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (43), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (44), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (45), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (46), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (47), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (48), xchg = 240, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (49), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (50), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (51), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = unknown (52), xchg = 241, auth = 1, fields = ffff / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Any (0), xchg = 256, auth = 1, fields = 0220 / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matching with state = Done (53), xchg = 256, auth = 1, fields = 0120 / ffff [Sep 19 11:17:36][ <-> ] ike_state_step: Matched state = Done (53) [Sep 19 11:17:36][ <-> ] ike_state_step: Calling input function[0] = ike_st_i_encrypt [Sep 19 11:17:36][ <-> ] ike_st_i_encrypt: Check that packet was encrypted succeeded [Sep 19 11:17:36][ <-> ] ike_state_step: Calling input function[1] = ike_st_i_gen_hash [Sep 19 11:17:36][ <-> ] ike_st_i_gen_hash: Start, hash[0..20] = f05a1158 f30ba02b ... [Sep 19 11:17:36][ <-> ] ike_state_step: Calling input function[2] = ike_st_i_d [Sep 19 11:17:36][ <-> ] ike_st_i_d: Start, doi = 1, protocol = 1, spis[0..1][0..16] = [8e65c82e aa59e182 ...] [Sep 19 11:17:36][ <-> ] ike_sa_find: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] ike_sa_find: Found SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] :4500 (Responder) <-> :54987 { 8e65c82e aa59e182 - 2866b7a7 db565119 [5] / 0xd03e1449 } Info; delete spi[16] = 0x8e65c82e aa59e182 2866b7a7 db565119 [Sep 19 11:17:36][ <-> ] iked_pv_audit_callback: Empty SSH audit event [Sep 19 11:17:36][ <-> ] ike_state_step: Calling input function[3] = ike_st_i_private [Sep 19 11:17:36][ <-> ] ike_st_i_private: Start [Sep 19 11:17:36][ <-> ] ike_state_step: Calling output function[0] = ike_st_o_d_done [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ike_state_step: All done, new state = Done (53) [Sep 19 11:17:36][ <-> ] ike_process_packet: Connected, sending notify [Sep 19 11:17:36][ <-> ] ike_send_notify: Connected, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 5 [Sep 19 11:17:36][ <-> ] ike_delete_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = 5 [Sep 19 11:17:36][ <-> ] ike_free_negotiation_info: Start, nego = 5 [Sep 19 11:17:36][ <-> ] ike_free_negotiation: Start, nego = 5 [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered [Sep 19 11:17:36][ <-> ] ikev2_packet_destroy: [11f3000/deadbeee] Destructor [Sep 19 11:17:36][ <-> ] ikev2_packet_free: [11f3000/deadbeee] Freeing [Sep 19 11:17:36][ <-> ] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local remote [Sep 19 11:17:36][ <-> ] ike_remove_callback: Start, delete SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = -1 [Sep 19 11:17:36][ <-> ] ike_delete_negotiation: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119}, nego = -1 [Sep 19 11:17:36][ <-> ] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table [Sep 19 11:17:36][ <-> ] ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table [Sep 19 11:17:36][ <-> ] ike_sa_delete: Start, SA = { 8e65c82e aa59e182 - 2866b7a7 db565119 } [Sep 19 11:17:36][ <-> ] ike_free_negotiation_cfg: Start, nego = 0 [Sep 19 11:17:36][ <-> ] ike_free_negotiation: Start, nego = 0 [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered [Sep 19 11:17:36][ <-> ] ike_free_negotiation_cfg: Start, nego = 1 [Sep 19 11:17:36][ <-> ] ike_free_negotiation: Start, nego = 1 [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered [Sep 19 11:17:36][ <-> ] ike_free_negotiation_cfg: Start, nego = 2 [Sep 19 11:17:36][ <-> ] ike_free_negotiation: Start, nego = 2 [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered [Sep 19 11:17:36][ <-> ] ikev2_fb_negotiation_done_qm: Entered IKE error code Aborted notification (8199) (neg 1277800) [Sep 19 11:17:36][ <-> ] ike_free_negotiation_qm: Start, nego = 3 [Sep 19 11:17:36][ <-> ] ike_free_negotiation: Start, nego = 3 [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ikev2_fb_qm_sa_freed: QM free Entered [Sep 19 11:17:36][ <-> ] ikev2_fb_phase_qm_clear_pm_data: Clearing FB negotiation 1277800 from qm_info 1287780 [Sep 19 11:17:36][ <-> ] ikev2_fallback_negotiation_free: Fallback negotiation 1277800 has still 1 references [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 4 [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 4 [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 1 [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 1 [Sep 19 11:17:36][ <-> ] ike_free_negotiation_qm: Start, nego = 4 [Sep 19 11:17:36][ <-> ] ike_free_negotiation: Start, nego = 4 [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ike_packet_free: Start [Sep 19 11:17:36][ <-> ] ikev2_fb_qm_sa_freed: QM free Entered [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 4 [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 4 [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 1 [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 1 [Sep 19 11:17:36][ <-> ] ike_free_negotiation_isakmp: Start, nego = -1 [Sep 19 11:17:36][ <-> ] ike_free_negotiation: Start, nego = -1 [Sep 19 11:17:36][ <-> ] ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA 1277000 is freed [Sep 19 11:17:36][ <-> ] ikev2_fb_isakmp_sa_freed: FB; Calling v2 policy function ike_sa_delete [Sep 19 11:17:36][ <-> ] ikev2_fb_isakmp_sa_freed: Notify call: ike_sa_delete [Sep 19 11:17:36][ <-> ] IKE SA delete called for p1 sa 7353756 (ref cnt 2) local:, remote:, IKEv1 [Sep 19 11:17:36][ <-> ] P1 SA 7353756 stop timer. timer duration 30, reason 0. [Sep 19 11:17:36][ <-> ] Freeing reference to P1 SA 7353756 to ref count 1 [Sep 19 11:17:36][ <-> ] P1 SA 7353756 reference count is not zero (1). Delaying deletion of SA [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 1 [Sep 19 11:17:36][ <-> ] ike_free_id_payload: Start, id type = 2 [Sep 19 11:17:36][ <-> ] ike_free_sa: Start [Sep 19 11:17:36][ <-> ] ikev2_fb_ipsec_complete: FB; Calling v2 policy function ipsec_sa_done [Sep 19 11:17:36][ <-> ] Inside iked_pm_ipsec_sa_done [Sep 19 11:17:36][ <-> ] iked_pm_ipsec_sa_done p2_ed tunnel_id <0> for msg_id <657ff8aa> [Sep 19 11:17:36][ <-> ] iked_pm_ipsec_sa_done slot released for msg_id <657ff8aa> [Sep 19 11:17:36][ <-> ] IPSec negotiation failed for SA-CFG INSTANCE-dyn-vpn_0002_0008_0000 for local:, remote: IKEv1. status: Aborted [Sep 19 11:17:36][ <-> ] P2 ed info: flags 0x80, P2 error: Error ok [Sep 19 11:17:36][ <-> ] iked_tunnel_event_add_event_in_peer_entry: Event ITE_MIN is called. Ignoring... [Sep 19 11:17:36][ <-> ] iked_unset_sa_cfg_p2_ed unset_sa_cfg_p2_ed, sa_cfg=INSTANCE-dyn-vpn_0002_0008_0000 [Sep 19 11:17:36][ <-> ] iked_pm_ipsec_sa_done check for auto trigger additional ts [Sep 19 11:17:36][ <-> ] iked_sa_cfg_get_parent_sa_cfg Found parent dyn-vpn for sa_cfg INSTANCE-dyn-vpn_0002_0008_0000 [Sep 19 11:17:36][ <-> ] IKEv1 Error : Aborted notification [Sep 19 11:17:36][ <-> ] ikev2_fb_qm_negotiation_destructor: Freeing fallback negotiation context [Sep 19 11:17:36][ <-> ] ikev2_fallback_negotiation_free: Freeing fallback negotiation 1277800 [Sep 19 11:17:36][ <-> ] ikev2_free_exchange_data: Freeing exchange data from SA 1277000, ED 12a4028 (1) [Sep 19 11:17:36][ <-> ] ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 1277000 [Sep 19 11:17:36][ <-> ] ssh_ikev2_ts_free: ts 0x1286700, ref_cnt 2 [Sep 19 11:17:36][ <-> ] ssh_ikev2_ts_free: ts 0x1286740, ref_cnt 2 [Sep 19 11:17:36][ <-> ] ssh_ikev2_ts_free: ts 0x1286740, ref_cnt 1 [Sep 19 11:17:36][ <-> ] ssh_ikev2_ts_free: ts 0x1286700, ref_cnt 1 [Sep 19 11:17:36][ <-> ] ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 1277000 [Sep 19 11:17:36][ <-> ] ikev2_free_exchange_data: Notify call: exchange_data_free [Sep 19 11:17:36][ <-> ] Freeing P2 Ed for sa-cfg N/A [Sep 19 11:17:36][ <-> ] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 12a1e00 from list for sa_cfg N/A [Sep 19 11:17:36][ <-> ] ikev2_free_exchange_data: Successfully freed exchange data from SA 1277000 [Sep 19 11:17:36][ <-> ] ikev2_fallback_negotiation_free: Freeing reference to IKE SA 1277000 to ref count 0 [Sep 19 11:17:36][ <-> ] ssh_ikev2_ike_sa_free: Notify call: ike_sa_free_ref [Sep 19 11:17:36][ <-> ] Freeing reference to P1 SA 7353756 to ref count 0 [Sep 19 11:17:36][ <-> ] No more references to IKE SA 7353756 and waiting for delete. Deleting IKE SA [Sep 19 11:17:36][ <-> ] iked_pm_p1_sa_destroy: p1 sa 7353756 (ref cnt 0), waiting_for_del 0x1204b60 [Sep 19 11:17:36][ <-> ] iked_peer_remove_p1sa_entry: Remove p1 sa 7353756 from peer entry 0x127a000 [Sep 19 11:17:36][ <-> ] Deleting p1 sa (7353756) node from IKE p1 SA P-tree [Sep 19 11:17:36][ <-> ] ikev2_transmit_window_uninit: Uninitialising transmit window 1277180 [Sep 19 11:17:36][ <-> ] ikev2_transmit_window_flush: Transmit window 1277180: Flushing. [Sep 19 11:17:36][ <-> ] ikev2_receive_window_uninit: Uninitialising receive window 1277190