[Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Triggering negotiation for ipsec-vpn-besFarm config block [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_pm_trigger_callback: non-natt case for gateway ike-gate-besFarm, lookup peer entry from local_port=0, remote_port=500. [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_create_peer_entry: Created peer entry 0x9cc500 for local LOCAL_IP:500 remote REMOTE_IP:500 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_fetch_or_create_peer_entry: Create peer entry 0x9cc500 for local LOCAL_IP:500 remote REMOTE_IP:500. gw ike-gate-besFarm, VR id 0 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_pm_trigger_callback: FOUND non-natt peer entry for gateway ike-gate-besFarm [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Initiating new P1 SA for gateway ike-gate-besFarm [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] P1 SA 7726156 start timer. timer duration 30, reason 1. [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_peer_insert_p1sa_entry: Insert p1 sa 7726156 in peer entry 0x9cc500 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation dfb800 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_pm_ike_spd_notify_request: Sending Initial contact [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] IKE SA fill called for negotiation of local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfb800 has still 1 references [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect: Start, remote_name = REMOTE_IP:500, xchg = 2, flags = 00090000 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_allocate: Start, SA = { b947c54b 940baaa6 - 00000000 00000000 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_init_isakmp_sa: Start, remote = REMOTE_IP:500, initiator = 1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect: SA = { b947c54b 940baaa6 - 00000000 00000000}, nego = -1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_sa_proposal: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_isakmp_vendor_ids: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM SA I (3) [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xb947c54b 940baaa6 - 00000000 00000000 } / 00000000, nego = -1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 288 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { b947c54b 940baaa6 - 00000000 00000000}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Found half SA = { b947c54b 940baaa6 - 00000000 00000000 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_get_sa: We are intiator, first response packet [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_upgrade: Start, SA = { b947c54b 940baaa6 - 00000000 00000000 } -> { ... - cec2aeea 5b4966c1 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} / 00000000, nego = -1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Found 1 proposals [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_t: Start, # trans = 1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM SA I (3)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_sa_value: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_cr: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..8] = 09002689 dfd6b712 ... [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ... [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = 12f5f28c 457168a9 ... [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ... [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_ke: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Requested DH group 2 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Generated DH keys using hardware for DH group 2 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [12871] [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_nonce: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_isakmp_nonce_data_len: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM KE I (5) [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xb947c54b 940baaa6 - cec2aeea 5b4966c1 } / 00000000, nego = -1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 228 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} / 00000000, nego = -1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM KE I (5)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_nonce: Start, nonce[0..32] = df180c5d 9a9ad817 ... [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_ke: Ke[0..128] = c663c290 31e14e00 ... [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_cr: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_id: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_hash: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_dh_compute_synch: Requested DH group 2 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [6286] [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_find_pre_shared_key: Find pre shared key key for LOCAL_IP:500, id = ipv4(any:0,[0..3]=LOCAL_IP) -> REMOTE_IP:500, id = No Id [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_find_pre_shared_key: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_calc_mac: Start, initiator = true, local = true [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_status_n: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_encrypt: Marking encryption for packet [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM final I (7) [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xb947c54b 940baaa6 - cec2aeea 5b4966c1 } / 00000000, nego = -1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Encrypting packet [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 92 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} / 00000000, nego = -1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM final I (7)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_id: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_hash: Start, hash[0..20] = aa27f2da e14d5253 ... [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_calc_mac: Start, initiator = true, local = false [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_wait_done: Marking for waiting for done [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_all_done: MESSAGE: Phase 1 { 0xb947c54b 940baaa6 - 0xcec2aeea 5b4966c1 } / 00000000, version = 1.0, xchg = Identity protect, auth_method = Pre shared keys, Initiator, cipher = aes- [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM done I (9) [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfb800 has still 1 references [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = -1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_process_packet: No output packet, returning [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_pm_ike_sa_done: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] IKE negotiation done for local:LOCAL_IP, remote:REMOTE_IP IKEv1 with status: Error ok [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] P1 SA 7726156 stop timer. timer duration 30, reason 1. [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_pm_ipsec_spi_allocate: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Added (spi=0xe14e9aeb, protocol=0) entry to the spi table [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_pm_ipsec_spi_allocate: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Added (spi=0x216e4773, protocol=0) entry to the spi table [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfb800 has still 1 references [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect_ipsec: Start, remote_name = :500, flags = 00010000 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find_ip_port: Remote = all:500, Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 0, max 1 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect_ipsec: SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = 0 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_init_qm_negotiation: Start, initiator = 1, message_id = aa2fc25d [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start QM I (14)/-1, exchange = 32, auth_method = phase1, Initiator [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_hash_1: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_sa_proposals: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_nonce: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_qm_nonce_data_len: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_optional_ke: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Requested DH group 2 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Generated DH keys using hardware for DH group 2 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [5882] [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_optional_ids: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_qm_optional_id: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_qm_optional_id: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Construction NHTB payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 P1 SA index 7726156 sa-cfg ipsec-vpn-besFarm [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] Peer router vendor is not Juniper. Not sending NHTB payload for sa-cfg ipsec-vpn-besFarm [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_st_o_encrypt: Marking encryption for packet [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = QM HASH SA I (16) [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xb947c54b 940baaa6 - cec2aeea 5b4966c1 } / aa2fc25d, nego = 0 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_finalize_qm_hash_1: Hash[0..20] = 67c763fa 2266ba1d ... [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Encrypting packet [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 300 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = 0, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:06][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } / c5d960d1, remote = REMOTE_IP:500 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM done I (9)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_o_done: ISAKMP SA negotiation done [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = Done (30) [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_udp_callback_common: Connected, sending notify [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = -1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_isakmp: Start, nego = -1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = -1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 1, max 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_init_cfg_negotiation: Start, initiator = 0, message_id = c5d960d1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation e04000 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_fb_alloc_cfgmode_negotiation: Accepting new Cfg/XAuth negotiation: local=:500, remote=REMOTE_IP:500 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} / c5d960d1, nego = 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_attr: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start CFG R (26)/-1, exchange = 6, auth_method = any, Responder [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_gen_hash: Start, hash[0..20] = d298ab17 081498a9 ... [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_cfg_attr: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_process_packet: No output packet, returning [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_cfg_attrs_reply: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation e04000 has still 2 references [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation e04000 has still 1 references [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Freeing fallback negotiation e04000 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } / aa2fc25d, remote = REMOTE_IP:500 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} / aa2fc25d, nego = 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Found 1 proposals [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_t: Start, # trans = 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = QM HASH SA I (16)/-1, exchange = 32, auth_method = phase1, Initiator [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_qm_hash_2: Start, hash[0..20] = 1e88b761 ee509bce ... [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_qm_sa_values: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_qm_nonce: Nonce[0..32] = 34074b8e b228cfaa ... [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_qm_ke: Ke[0..128] = 8701e25d 99b9723e ... [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_hash_3: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_o_encrypt: Marking encryption for packet [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] iked_dh_compute_synch: Requested DH group 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [5804] [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_qm_call_callback: MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_qm_call_callback: MESSAGE: SA[0][0] = ESP aes, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-96, Extended seq not used, key len = 128, key rounds = 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] iked_pm_ipsec_sa_install: local:LOCAL_IP, remote:REMOTE_IP IKEv1 for SA-CFG ipsec-vpn-besFarm [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Creating a SA spi=0xe14e9aeb, proto=ESP pair_index = 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Added (spi=0xe14e9aeb, protocol=ESP dst=LOCAL_IP) entry to the peer hash table [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] iked_peer_insert_sa_cfg_entry: insert sa_cfg tunnel_id entry 131073 into peer entry 0x9cc500 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Creating a SA spi=0xc625ef80, proto=ESP pair_index = 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Added (spi=0xc625ef80, protocol=ESP dst=REMOTE_IP) entry to the peer hash table [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] iked_nhtb_update_on_sa_create: Interface st0.0 is P2P for sa_cfg ipsec-vpn-besFarm. Thus ignoring NHTB notification message [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Hardlife timer started for inbound ipsec-vpn-besFarm with 3600 seconds/0 kilobytes [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Softlife timer started for inbound ipsec-vpn-besFarm with 2966 seconds/0 kilobytes [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] In iked_fill_sa_bundle [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ipsec-vpn-besFarm : VPN Monitor Interval=0(0) Optimized=0(0) [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] SA bundle remote gateway: IP REMOTE_IP chosen [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] SA bundle local gateway: IP LOCAL_IP chosen [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipsec_ipc_sa_pair [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipc_sa_keys [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipc_sa_keys [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipc_sa_keys [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipc_sa_keys [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ----------------Voyager ipsec SA BUNDLE------------------- [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] SA pair update request for: Tunnel index: 131073 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Local Gateway address: LOCAL_IP [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Primary remote Gateway address: REMOTE_IP [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Backup remote Gateway State: Active [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Anti replay: counter-based enabled [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Window_size: 64 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Server Time: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Peer : Static [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Mode : Tunnel [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] VPN Type : route-based [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Tunnel mtu: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] DF bit: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] local-if ifl idx: 75 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] tunnel-if ifl idx: 71 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Tunnel mtu: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] DPD interval: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] policy id: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] NATT enabled: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] SA Idle time: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] SA Outbound install delay time: 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] IKED ID: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] DIST ID: 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ----------------Incoming SA ------------------- [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] SPI: 0xe14e9aeb Protocol: 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Algorithm: 130 Auth key. length: 20 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Encr key. length; 16 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ----------------Outgoing SA ------------------- [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] SPI: 0xc625ef80 Protocol: 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Algorithm: 130 Auth key. length: 20 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Encr key. length; 16 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] In iked_ipsec_sa_pair_add Adding GENCFG msg with key; Tunnel = 131073;SPI-In = 0xe14e9aeb [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Added dependency on SA config blob with tunnelid = 131073 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] Successfully added ipsec SA PAIR [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] iked_is_anchoring_instance sa_dist_id=0, self_dist_id=255 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] kmd_update_tunnel_interface: update ifl st0.0 status UP for sa_cfg ipsec-vpn-besFarm [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_wait_done: Marking for waiting for done [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = QM HASH I (18) [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xb947c54b 940baaa6 - cec2aeea 5b4966c1 } / aa2fc25d, nego = 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Encrypting packet [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 60 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = 0, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] IPSec negotiation done successfully for SA-CFG ipsec-vpn-besFarm for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] IPSec SA done callback. ed dfe028. status: Error ok [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] IPSec SA done callback with sa-cfg NULL in p2_ed. status: Error ok [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfb800 has still 1 references [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Freeing fallback negotiation dfb800 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } / de8dd94a, remote = REMOTE_IP:500 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 2, max 3 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1} / de8dd94a, nego = 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Done (30)/-1, exchange = 5, auth_method = any, Responder [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_gen_hash: Start, hash[0..20] = 5a970d7d a998672c ... [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_n: Start, doi = 1, protocol = 1, code = Payload malformed (16), spi[0..0] = 00000000 00000000 ..., data[0..0] = 00000000 00000000 ... [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { b947c54b 940baaa6 - cec2aeea 5b4966c1 [2] / 0xde8dd94a } Info; Received notify err = Payload malformed (16) to isakmp sa, delete it [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = Done (30) [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_process_packet: Connected, sending notify [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_delete_negotiation: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_info: Start, nego = 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 2 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_remove_callback: Start, delete SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = -1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_delete_negotiation: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1}, nego = -1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_sa_delete: Start, SA = { b947c54b 940baaa6 - cec2aeea 5b4966c1 } [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_qm: Start, nego = 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_cfg: Start, nego = 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_isakmp: Start, nego = -1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = -1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA df5400 is freed [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] IKE SA delete called for p1 sa 7726156 (ref cnt 1) local:LOCAL_IP, remote:REMOTE_IP, IKEv1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] P1 SA 7726156 stop timer. timer duration 30, reason 0. [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] iked_pm_p1_sa_destroy: p1 sa 7726156 (ref cnt 0), waiting_for_del 0x0 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] iked_peer_remove_p1sa_entry: Remove p1 sa 7726156 from peer entry 0x9cc500 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 1 [Oct 14 16:06:07][LOCAL_IP <-> REMOTE_IP] ike_free_sa: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Inside iked_get_primary_addr_by_intf_name... AF = 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_get_primary_addr_by_intf_name:2264 intf_name fe-0/0/1.0, af=inet, addr_len=4 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_get_primary_addr_by_intf_name:2268 ip address = LOCAL_IP ifam_flags = 0xc0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Got address LOCAL_IP as prefered address for interface fe-0/0/1.0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_cfg_populate_sa_cfg_with_ike_gateway_info: Found ip address for local interface LOCAL_IP [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_ipsec_is_ifl_installed: Bind interface st0.0 index<71> [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] In iked_ipsec_is_ifl_installed if:fe-0/0/1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_iface2zone: Returning zone = 8 for if: fe-0/0/1.0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_iface2zone: Returning zone = 9 for if: st0.0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_ipsec_is_ifl_installed: Bind interface st0.0, index<71>, IFL ext is up [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] SA CFG Name: ipsec-vpn-besFarm [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Interface name: fe-0/0/1, Unit: 0, AF: 2, ksa_cfg_ifl_index: 75 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Local gateway: LOCAL_IP [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Remote gateway: REMOTE_IP [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Inside iked_get_primary_addr_by_intf_name... AF = 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_get_primary_addr_by_intf_name:2264 intf_name fe-0/0/1.0, af=inet, addr_len=4 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_get_primary_addr_by_intf_name:2268 ip address = LOCAL_IP ifam_flags = 0xc0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Got address LOCAL_IP as prefered address for interface fe-0/0/1.0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_ipsec_is_ifl_installed: Found ip address for external interface LOCAL_IP. Marking sa-cfg ipsec-vpn-besFarm as ifa up [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_check_if_sa_cfg_ready: SA-CFG is ready [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Added sa_cfg ipsec-vpn-besFarm to sadb hash tbl at hash:1818 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_is_anchoring_instance sa_dist_id=0, self_dist_id=255 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_deactivate_bind_interface: No more NHTB entries are active for st0.0. Bringing down the interface [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] kmd_update_tunnel_interface: update ifl st0.0 status DOWN for sa_cfg ipsec-vpn-besFarm [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] In iked_ipsec_sa_config_add: if:fe-0/0/1 flags = 0x600a29 UP [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] In iked_fill_sa_bundle [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ipsec-vpn-besFarm : VPN Monitor Interval=0(0) Optimized=0(0) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] SA bundle remote gateway: IP REMOTE_IP chosen [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] SA bundle local gateway: IP LOCAL_IP chosen [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Installing SA ipsec-vpn-besFarm (mode: tunnel) tunnel ID 131073 to kernel [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ----------------Voyager ipsec SA BUNDLE------------------- [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] SA Config add request for: Tunnel index: 131073 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Local Gateway address: LOCAL_IP [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Primary remote Gateway address: REMOTE_IP [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Backup remote Gateway State: Active [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Anti replay: counter-based enabled [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Window_size: 64 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Server Time: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Peer : Static [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Mode : Tunnel [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] VPN Type : route-based [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Tunnel mtu: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] DF bit: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] local-if ifl idx: 75 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] tunnel-if ifl idx: 71 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Tunnel mtu: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] DPD interval: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] policy id: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] NATT enabled: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] SA Idle time: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] SA Outbound install delay time: 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] IKED ID: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] DIST ID: 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] In iked_sa_config_install Adding GENCFG msg with key; Tunnel = 131073, SPI-In = 0x0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Successfully added SA Config [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_deactivate_bind_interface: No more NHTB entries are active for st0.0. Bringing down the interface [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] kmd_update_tunnel_interface: update ifl st0.0 status DOWN for sa_cfg ipsec-vpn-besFarm [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_is_anchoring_instance sa_dist_id=0, self_dist_id=255 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_stop_vpnm_timer: processing SA ipsec-vpn-besFarm [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Triggering negotiation for ipsec-vpn-besFarm config block [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_pm_trigger_callback: non-natt case for gateway ike-gate-besFarm, lookup peer entry from local_port=0, remote_port=0. [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_create_peer_entry: Created peer entry 0xdf8400 for local LOCAL_IP:500 remote REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_fetch_or_create_peer_entry: Create peer entry 0xdf8400 for local LOCAL_IP:500 remote REMOTE_IP:500. gw ike-gate-besFarm, VR id 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_pm_trigger_callback: FOUND non-natt peer entry for gateway ike-gate-besFarm [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Initiating new P1 SA for gateway ike-gate-besFarm [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] P1 SA 5384070 start timer. timer duration 30, reason 1. [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_peer_insert_p1sa_entry: Insert p1 sa 5384070 in peer entry 0xdf8400 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation dfc800 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_pm_ike_spd_notify_request: Sending Initial contact [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] IKE SA fill called for negotiation of local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfc800 has still 1 references [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect: Start, remote_name = REMOTE_IP:500, xchg = 2, flags = 00090000 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_allocate: Start, SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_init_isakmp_sa: Start, remote = REMOTE_IP:500, initiator = 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect: SA = { 672e2d45 8295fee0 - 00000000 00000000}, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 00000000 00000000 [-1] / 0x00000000 } IP; Start isakmp sa negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 00000000 00000000 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0000 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_sa_proposal: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_isakmp_vendor_ids: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM SA I (3) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0x672e2d45 8295fee0 - 00000000 00000000 } / 00000000, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 288 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { 672e2d45 8295fee0 - 00000000 00000000}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_get_sa: We are intiator, first response packet [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_upgrade: Start, SA = { 672e2d45 8295fee0 - 00000000 00000000 } -> { ... - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Packet to old negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1} / 00000000, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Found 1 proposals [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_t: Start, # trans = 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0401 SA VID [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM SA I (3)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_sa_value: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_cr: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..8] = 09002689 dfd6b712 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = 12f5f28c 457168a9 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_ke: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Requested DH group 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_create_contexts: Initialized JSF CRYPTO for kmd instance 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_create_contexts: System supports hardware DH mode [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Generated DH keys using hardware for DH group 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [7663] [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_nonce: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_isakmp_nonce_data_len: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM KE I (5) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0x672e2d45 8295fee0 - 486658ce 478642f1 } / 00000000, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 228 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Ignoring the ifa preferred address add/change message as previous local address is the same [Oct 14 16:06:13]KMD_INTERNAL_ERROR: iked_ifstate_eoc_handler: EOC msg received [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Packet to old negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1} / 00000000, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0012 KE NONCE [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM KE I (5)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_nonce: Start, nonce[0..32] = 42379f11 73b3b407 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_ke: Ke[0..128] = b4e4668b f6b39f21 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_cr: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_id: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_hash: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_compute_synch: Requested DH group 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [5991] [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Diffie-hellman secret g^xy[128] = 0x5b09028e b49ce8cb 1ed76cdb 1d68cd14 41 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_find_pre_shared_key: Find pre shared key key for LOCAL_IP:500, id = ipv4(any:0,[0..3]=LOCAL_IP) -> REMOTE_IP:500, id = No Id [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_find_pre_shared_key: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Hash algorithm = hmac-sha1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Prf key[11] = 0x32303135 4d696172 657465 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Calculating SKEYID [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Output of SKEYID hash[20] = 0x308c2f72 63396edf 6955fdb2 f1568644 161afba1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Output of SKEYID_d hash[20] = 0xd0daec53 1da14743 f9033378 be5ec63e 3d84f1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Output of SKEYID_a hash[20] = 0xfabfc3db 59c7fa0d 8e71135e 2a1da88e a880f6 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Output SKEYID_e hash[20] = 0xbff12c42 49f37051 83c0c9a5 a1e82dce ecd4c142 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Final encryption key[16] = 0xbff12c42 49f37051 83c0c9a5 a1e82dce [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_calc_mac: Start, initiator = true, local = true [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Output of HASH_I hash[20] = 0x9debbfa1 03c3315d 4f24de4f 11778b34 5e90aeb4 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_status_n: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_encrypt: Marking encryption for packet [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM final I (7) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0x672e2d45 8295fee0 - 486658ce 478642f1 } / 00000000, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Encrypting packet [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 92 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Packet to old negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1} / 00000000, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0024 ID HASH [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM final I (7)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_id: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_hash: Start, hash[0..20] = 4c4739fc bbc39e94 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_calc_mac: Start, initiator = true, local = false [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Output of HASH_R hash[20] = 0x4c4739fc bbc39e94 7a6710c2 74b75ae4 ed999662 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; dec->enc iv[16] = 0xe5563df9 06ceeff1 ea6684d0 e2e32bb2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_wait_done: Marking for waiting for done [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_all_done: MESSAGE: Phase 1 { 0x672e2d45 8295fee0 - 0x486658ce 478642f1 } / 00000000, version = 1.0, xchg = Identity protect, auth_method = Pre shared keys, Initiator, cipher = aes- [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; MESSAGE: Phase 1 version = 1.0, auth_method = Pre shared keys, cipher = ae [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM done I (9) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfc800 has still 1 references [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Connected [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_process_packet: No output packet, returning [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0024 ID HASH [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM done I (9)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_done: ISAKMP SA negotiation done [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = Done (30) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_udp_callback_common: Connected, sending notify [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / 0x00000000 } IP; Connected [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_isakmp: Start, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1} [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 0, max 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_init_cfg_negotiation: Start, initiator = 0, message_id = e7c2bc4f [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [0] / 0xe7c2bc4f } CFG; New negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation e04000 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fb_alloc_cfgmode_negotiation: Accepting new Cfg/XAuth negotiation: local=:500, remote=REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [0] / 0xe7c2bc4f } CFG; Output of phase 2 IV hash[16] = 0xb382b16a f308794b 361a74df f1b4135f [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1} / e7c2bc4f, nego = 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_attr: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [0] / 0xe7c2bc4f } CFG; Version = 1.0, Input packet fields = 0820 HASH ATTR [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start CFG R (26)/-1, exchange = 6, auth_method = any, Responder [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_gen_hash: Start, hash[0..20] = 031d0f0e 9031d88a ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_cfg_attr: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_process_packet: No output packet, returning [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_pm_ike_sa_done: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] IKE negotiation done for local:LOCAL_IP, remote:REMOTE_IP IKEv1 with status: Error ok [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] P1 SA 5384070 stop timer. timer duration 30, reason 1. [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fb_i_p1_check_cfg: Registering CFG mode poll timeout [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fb_i_p1_wait_cfg: Suspending thread until CFG mode is done (neg dfc800) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_cfg_attrs_reply: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation e04000 has still 2 references [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation e04000 has still 1 references [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Freeing fallback negotiation e04000 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fb_i_p1_wait_cfg: Suspending thread until CFG mode is done (neg dfc800) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fb_i_p1_wait_cfg: Suspending thread until CFG mode is done (neg dfc800) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fb_i_p1_wait_cfg: Suspending thread until CFG mode is done (neg dfc800) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fb_i_p1_wait_cfg: XAUTH/CFGmode was not initiated by the server, finishing Phase-I thread [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_pm_ipsec_spi_allocate: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Added (spi=0x36d3e8a3, protocol=0) entry to the spi table [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_pm_ipsec_spi_allocate: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Added (spi=0xb6e93fcc, protocol=0) entry to the spi table [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfc800 has still 1 references [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect_ipsec: Start, remote_name = :500, flags = 00010000 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find_ip_port: Remote = all:500, Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1} [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1} [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 1, max 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect_ipsec: SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_init_qm_negotiation: Start, initiator = 1, message_id = b698f897 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [1] / 0xb698f897 } QM; Start ipsec sa negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [1] / 0xb698f897 } QM; Version = 1.0, Input packet fields = 0000 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start QM I (14)/-1, exchange = 32, auth_method = phase1, Initiator [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_hash_1: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_sa_proposals: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_nonce: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_qm_nonce_data_len: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_optional_ke: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Requested DH group 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Generated DH keys using hardware for DH group 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [6761] [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_optional_ids: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_qm_optional_id: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_qm_optional_id: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Construction NHTB payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 P1 SA index 5384070 sa-cfg ipsec-vpn-besFarm [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] Peer router vendor is not Juniper. Not sending NHTB payload for sa-cfg ipsec-vpn-besFarm [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_o_encrypt: Marking encryption for packet [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [1] / 0xb698f897 } QM; Output of phase 2 IV hash[16] = 0x04ab3c18 3e477152 48a3e190 64a5ec36 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = QM HASH SA I (16) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0x672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, nego = 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_finalize_qm_hash_1: Hash[0..20] = a1643e7c f477723e ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Encrypting packet [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 300 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = 1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b848713d, remote = REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1} [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 2, max 3 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [2] / 0xb848713d } Info; New informational negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [2] / 0xb848713d } Info; Packet to old negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [2] / 0xb848713d } Info; Output of phase 2 IV hash[16] = 0x7402bbcd 8055ece2 77df6fb1 88337582 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1} / b848713d, nego = 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [2] / 0xb848713d } Info; Version = 1.0, Input packet fields = 0220 HASH N [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Done (30)/-1, exchange = 5, auth_method = any, Responder [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_gen_hash: Start, hash[0..20] = d8d3757a 66b9a487 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_n: Start, doi = 1, protocol = 1, code = Payload malformed (16), spi[0..0] = 00000000 00000000 ..., data[0..0] = 00000000 00000000 ... [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [2] / 0xb848713d } Info; Received notify err = Payload malformed (16) to isakmp sa, delete it [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = Done (30) [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_process_packet: Connected, sending notify [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [2] / 0xb848713d } Info; Connected [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_delete_negotiation: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [2] / 0xb848713d } Info; Deleting negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_info: Start, nego = 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 2 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_remove_callback: Start, delete SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / unknown } IP; Removing negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_delete_negotiation: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1}, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { 672e2d45 8295fee0 - 486658ce 478642f1 [-1] / unknown } IP; Deleting negotiation [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_delete: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_cfg: Start, nego = 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_qm: Start, nego = 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfc800 has still 1 references [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_isakmp: Start, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = -1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA df6400 is freed [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] IKE SA delete called for p1 sa 5384070 (ref cnt 2) local:LOCAL_IP, remote:REMOTE_IP, IKEv1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] P1 SA 5384070 stop timer. timer duration 30, reason 0. [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] P1 SA 5384070 reference count is not zero (1). Delaying deletion of SA [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 1 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_free_sa: Start [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Freeing fallback negotiation dfc800 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_pm_p1_sa_destroy: p1 sa 5384070 (ref cnt 0), waiting_for_del 0xd774a0 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_peer_remove_p1sa_entry: Remove p1 sa 5384070 from peer entry 0xdf8400 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_peer_entry_patricia_delete:Peer entry 0xdf8400 deleted for local LOCAL_IP:500 and remote REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:06:13][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:06:18][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:06:25][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:06:38][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / e7c2bc4f, remote = REMOTE_IP:500 [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { 672e2d45 8295fee0 - 00000000 00000000 } [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { 672e2d45 8295fee0 - 486658ce 478642f1 } / b698f897, remote = REMOTE_IP:500 [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:07:01][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Triggering negotiation for ipsec-vpn-besFarm config block [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_pm_trigger_callback: non-natt case for gateway ike-gate-besFarm, lookup peer entry from local_port=0, remote_port=0. [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_create_peer_entry: Created peer entry 0x9cc400 for local LOCAL_IP:500 remote REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_fetch_or_create_peer_entry: Create peer entry 0x9cc400 for local LOCAL_IP:500 remote REMOTE_IP:500. gw ike-gate-besFarm, VR id 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_pm_trigger_callback: FOUND non-natt peer entry for gateway ike-gate-besFarm [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Initiating new P1 SA for gateway ike-gate-besFarm [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] P1 SA 5384071 start timer. timer duration 30, reason 1. [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_peer_insert_p1sa_entry: Insert p1 sa 5384071 in peer entry 0x9cc400 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation dfc800 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_pm_ike_spd_notify_request: Sending Initial contact [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] IKE SA fill called for negotiation of local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfc800 has still 1 references [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect: Start, remote_name = REMOTE_IP:500, xchg = 2, flags = 00090000 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_allocate: Start, SA = { fbdbf289 7306656a - 00000000 00000000 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_init_isakmp_sa: Start, remote = REMOTE_IP:500, initiator = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect: SA = { fbdbf289 7306656a - 00000000 00000000}, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 00000000 00000000 [-1] / 0x00000000 } IP; Start isakmp sa negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 00000000 00000000 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0000 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_sa_proposal: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_isakmp_vendor_ids: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM SA I (3) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xfbdbf289 7306656a - 00000000 00000000 } / 00000000, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 288 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { fbdbf289 7306656a - 00000000 00000000}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Found half SA = { fbdbf289 7306656a - 00000000 00000000 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_get_sa: We are intiator, first response packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_upgrade: Start, SA = { fbdbf289 7306656a - 00000000 00000000 } -> { ... - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Packet to old negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} / 00000000, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Found 1 proposals [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_t: Start, # trans = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0401 SA VID [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM SA I (3)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_sa_value: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_cr: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..8] = 09002689 dfd6b712 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = 12f5f28c 457168a9 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_ke: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Requested DH group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Generated DH keys using hardware for DH group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [5736] [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_nonce: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_isakmp_nonce_data_len: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM KE I (5) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xfbdbf289 7306656a - 84a44d2c 85d424a1 } / 00000000, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 228 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Packet to old negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} / 00000000, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0012 KE NONCE [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM KE I (5)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_nonce: Start, nonce[0..32] = 01a1d512 6f0f0969 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_ke: Ke[0..128] = 0a35b729 d85f4b85 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_cr: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_id: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_hash: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_compute_synch: Requested DH group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [5554] [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Diffie-hellman secret g^xy[128] = 0x9f1b5636 74fa175a 1605029b d7b5b945 c2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_find_pre_shared_key: Find pre shared key key for LOCAL_IP:500, id = ipv4(any:0,[0..3]=LOCAL_IP) -> REMOTE_IP:500, id = No Id [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_find_pre_shared_key: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Hash algorithm = hmac-sha1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Prf key[11] = 0x32303135 4d696172 657465 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Calculating SKEYID [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Output of SKEYID hash[20] = 0x4dbf5f68 e280392b b41649e9 973b5e9c dcd342a8 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Output of SKEYID_d hash[20] = 0x4ef08ae9 1eca75db 7fbd7ff4 f1d20fc3 df80da [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Output of SKEYID_a hash[20] = 0xdbf3e7e0 522918bd def64a51 1ea71ca1 9efcd8 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Output SKEYID_e hash[20] = 0xda807406 5e187f1d f7dd284e b9ec479d c634639f [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Final encryption key[16] = 0xda807406 5e187f1d f7dd284e b9ec479d [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_calc_mac: Start, initiator = true, local = true [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Output of HASH_I hash[20] = 0xd8c69ef7 b071e7c2 c29201ad c88a900e 85dcf434 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_status_n: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_encrypt: Marking encryption for packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM final I (7) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xfbdbf289 7306656a - 84a44d2c 85d424a1 } / 00000000, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Encrypting packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 92 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = -1, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 00000000, remote = REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Packet to old negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} / 00000000, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0024 ID HASH [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM final I (7)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_id: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_hash: Start, hash[0..20] = d352dbdf baee6c92 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_calc_mac: Start, initiator = true, local = false [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Output of HASH_R hash[20] = 0xd352dbdf baee6c92 fe990c99 f1fa569b 6e711357 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_cert: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; dec->enc iv[16] = 0x56924591 e3a174f2 cd35b8fc 148524d9 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_wait_done: Marking for waiting for done [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_all_done: MESSAGE: Phase 1 { 0xfbdbf289 7306656a - 0x84a44d2c 85d424a1 } / 00000000, version = 1.0, xchg = Identity protect, auth_method = Pre shared keys, Initiator, cipher = aes- [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; MESSAGE: Phase 1 version = 1.0, auth_method = Pre shared keys, cipher = ae [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = MM done I (9) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfc800 has still 1 references [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Connected [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_process_packet: No output packet, returning [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_pm_ike_sa_done: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] IKE negotiation done for local:LOCAL_IP, remote:REMOTE_IP IKEv1 with status: Error ok [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] P1 SA 5384071 stop timer. timer duration 30, reason 1. [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_pm_ipsec_spi_allocate: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Added (spi=0x37ad464, protocol=0) entry to the spi table [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_pm_ipsec_spi_allocate: local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Added (spi=0x76c0d84e, protocol=0) entry to the spi table [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfc800 has still 1 references [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect_ipsec: Start, remote_name = :500, flags = 00010000 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find_ip_port: Remote = all:500, Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 0, max 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ssh_ike_connect_ipsec: SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_init_qm_negotiation: Start, initiator = 1, message_id = b77e0809 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Start ipsec sa negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Version = 1.0, Input packet fields = 0000 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start QM I (14)/-1, exchange = 32, auth_method = phase1, Initiator [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_hash_1: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_sa_proposals: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_nonce: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_qm_nonce_data_len: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_optional_ke: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Requested DH group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_generate_sync: Generated DH keys using hardware for DH group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [5890] [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_optional_ids: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_qm_optional_id: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_qm_optional_id: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Construction NHTB payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 P1 SA index 5384071 sa-cfg ipsec-vpn-besFarm [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Peer router vendor is not Juniper. Not sending NHTB payload for sa-cfg ipsec-vpn-besFarm [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_encrypt: Marking encryption for packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Output of phase 2 IV hash[16] = 0x94db6d91 3fc11450 6d225e70 9129443f [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = QM HASH SA I (16) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xfbdbf289 7306656a - 84a44d2c 85d424a1 } / b77e0809, nego = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_finalize_qm_hash_1: Hash[0..20] = caba8d14 f8030ec9 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Encrypting packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 300 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = 0, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0024 ID HASH [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = MM done I (9)/-1, exchange = 2, auth_method = pre shared key, Initiator [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_done: ISAKMP SA negotiation done [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = Done (30) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_udp_callback_common: Connected, sending notify [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / 0x00000000 } IP; Connected [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_isakmp: Start, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 1, max 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_init_cfg_negotiation: Start, initiator = 0, message_id = 157f923a [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [1] / 0x157f923a } CFG; New negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation e04000 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fb_alloc_cfgmode_negotiation: Accepting new Cfg/XAuth negotiation: local=:500, remote=REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [1] / 0x157f923a } CFG; Output of phase 2 IV hash[16] = 0x7a06d1df 0e9cf36e a371441c 0a0b5c9e [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} / 157f923a, nego = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_attr: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [1] / 0x157f923a } CFG; Version = 1.0, Input packet fields = 0820 HASH ATTR [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Start CFG R (26)/-1, exchange = 6, auth_method = any, Responder [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_gen_hash: Start, hash[0..20] = c912fa6a 12b2b057 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_cfg_attr: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_process_packet: No output packet, returning [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_cfg_attrs_reply: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation e04000 has still 2 references [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation e04000 has still 1 references [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Freeing fallback negotiation e04000 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / b77e0809, remote = REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Packet to old negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} / b77e0809, nego = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_sa: Found 1 proposals [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_payload_t: Start, # trans = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Version = 1.0, Input packet fields = 0037 SA KE ID HASH NONCE [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = QM HASH SA I (16)/-1, exchange = 32, auth_method = phase1, Initiator [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_qm_hash_2: Start, hash[0..20] = af7bc6a4 749730ae ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_qm_sa_values: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_qm_nonce: Nonce[0..32] = 9ff0db9c 9bd151ff ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_qm_ke: Ke[0..128] = 57290bc3 3b0d4bad ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_hash_3: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_policy_reply_private_payload_out: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_encrypt: Marking encryption for packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_get_group: DH Group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_dh_compute_synch: Requested DH group 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [5461] [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Diffie-hellman secret g^(qm)xy[128] = 0x35b33c0c 114fd28d 54ac2ffa 32495d0d 33016 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_qm_call_callback: MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; MESSAGE: SA[0][0] = ESP aes, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-9 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_qm_call_callback: MESSAGE: SA[0][0] = ESP aes, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-96, Extended seq not used, key len = 128, key rounds = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Ipsec keys, mac = hmac-sha1, proto = 3 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; spi[4] = 0x037ad464 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; keymat.skeyid_d[20] = 0x4ef08ae9 1eca75db 7fbd7ff4 f1d20fc3 df80da84 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; keymat.gqmxy[128] = 0x35b33c0c 114fd28d 54ac2ffa 32495d0d 33016d4d... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; keymat.ni[16] = 0x5eacfc5f db3da2da b939d549 55444ddb [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; keymat.nr[32] = 0x9ff0db9c 9bd151ff dd2e5513 bf4299c3 d364ff4f 6bfcb6f7 af5d796d [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; key.out[36] = 0x89d74576 142038d3 ca37f377 71bc918e a8a25b59 b6ada1f0 ac8dae36 48 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Ipsec keys, mac = hmac-sha1, proto = 3 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; spi[4] = 0xcb732e05 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; keymat.skeyid_d[20] = 0x4ef08ae9 1eca75db 7fbd7ff4 f1d20fc3 df80da84 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; keymat.gqmxy[128] = 0x35b33c0c 114fd28d 54ac2ffa 32495d0d 33016d4d... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; keymat.ni[16] = 0x5eacfc5f db3da2da b939d549 55444ddb [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; keymat.nr[32] = 0x9ff0db9c 9bd151ff dd2e5513 bf4299c3 d364ff4f 6bfcb6f7 af5d796d [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; key.out[36] = 0x76572110 50b0e420 39ffa54e a06b8393 2d2fe847 4d4e9e86 b04863c8 d8 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_pm_ipsec_sa_install: local:LOCAL_IP, remote:REMOTE_IP IKEv1 for SA-CFG ipsec-vpn-besFarm [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Parsing notification payload for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Creating a SA spi=0x37ad464, proto=ESP pair_index = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Added (spi=0x37ad464, protocol=ESP dst=LOCAL_IP) entry to the peer hash table [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_peer_insert_sa_cfg_entry: insert sa_cfg tunnel_id entry 131073 into peer entry 0x9cc400 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Creating a SA spi=0xcb732e05, proto=ESP pair_index = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Added (spi=0xcb732e05, protocol=ESP dst=REMOTE_IP) entry to the peer hash table [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_nhtb_update_on_sa_create: Interface st0.0 is P2P for sa_cfg ipsec-vpn-besFarm. Thus ignoring NHTB notification message [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Hardlife timer started for inbound ipsec-vpn-besFarm with 3600 seconds/0 kilobytes [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Softlife timer started for inbound ipsec-vpn-besFarm with 2978 seconds/0 kilobytes [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] In iked_fill_sa_bundle [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ipsec-vpn-besFarm : VPN Monitor Interval=0(0) Optimized=0(0) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] SA bundle remote gateway: IP REMOTE_IP chosen [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] SA bundle local gateway: IP LOCAL_IP chosen [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipsec_ipc_sa_pair [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipc_sa_keys [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipc_sa_keys [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipc_sa_keys [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] In iked_fill_ipc_sa_keys [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ----------------Voyager ipsec SA BUNDLE------------------- [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] SA pair update request for: Tunnel index: 131073 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Local Gateway address: LOCAL_IP [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Primary remote Gateway address: REMOTE_IP [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Backup remote Gateway State: Active [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Anti replay: counter-based enabled [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Window_size: 64 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Server Time: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Peer : Static [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Mode : Tunnel [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] VPN Type : route-based [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Tunnel mtu: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] DF bit: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] local-if ifl idx: 75 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] tunnel-if ifl idx: 71 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Tunnel mtu: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] DPD interval: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] policy id: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] NATT enabled: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] SA Idle time: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] SA Outbound install delay time: 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] IKED ID: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] DIST ID: 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ----------------Incoming SA ------------------- [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] SPI: 0x37ad464 Protocol: 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Algorithm: 130 Auth key. length: 20 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Encr key. length; 16 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ----------------Outgoing SA ------------------- [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] SPI: 0xcb732e05 Protocol: 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Algorithm: 130 Auth key. length: 20 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Encr key. length; 16 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] In iked_ipsec_sa_pair_add Adding GENCFG msg with key; Tunnel = 131073;SPI-In = 0x37ad464 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Added dependency on SA config blob with tunnelid = 131073 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] Successfully added ipsec SA PAIR [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_is_anchoring_instance sa_dist_id=0, self_dist_id=255 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] kmd_update_tunnel_interface: update ifl st0.0 status UP for sa_cfg ipsec-vpn-besFarm [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_o_qm_wait_done: Marking for waiting for done [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = QM HASH I (18) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Start, SA = { 0xfbdbf289 7306656a - 84a44d2c 85d424a1 } / b77e0809, nego = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Encrypting packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_encode_packet: Final length = 60 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_packet: Start, send SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = 0, dst = REMOTE_IP:500, routing table id = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [0] / 0xb77e0809 } QM; Connected [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] IPSec negotiation done successfully for SA-CFG ipsec-vpn-besFarm for local:LOCAL_IP, remote:REMOTE_IP IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] IPSec SA done callback. ed dfe028. status: Error ok [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] IPSec SA done callback with sa-cfg NULL in p2_ed. status: Error ok [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Fallback negotiation dfc800 has still 1 references [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fallback_negotiation_free: Freeing fallback negotiation dfc800 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 9179b567, remote = REMOTE_IP:500 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_alloc_negotiation: Found slot 2, max 3 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [2] / 0x9179b567 } Info; New informational negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [2] / 0x9179b567 } Info; Packet to old negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [2] / 0x9179b567 } Info; Output of phase 2 IV hash[16] = 0x4c733b32 2deafd44 1edc58ac c1de4917 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1} / 9179b567, nego = 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_decode_packet: Decrypting packet [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [2] / 0x9179b567 } Info; Version = 1.0, Input packet fields = 0220 HASH N [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: Current state = Done (30)/-1, exchange = 5, auth_method = any, Responder [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_encrypt: Check that packet was encrypted succeeded [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_gen_hash: Start, hash[0..20] = b89cd1bd 2f76c37f ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_n: Start, doi = 1, protocol = 1, code = Payload malformed (16), spi[0..0] = 00000000 00000000 ..., data[0..0] = 00000000 00000000 ... [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [2] / 0x9179b567 } Info; Received notify err = Payload malformed (16) to isakmp sa, delete it [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_st_i_private: Start [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_state_step: All done, new state = Done (30) [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_process_packet: Connected, sending notify [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_send_notify: Connected, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [2] / 0x9179b567 } Info; Connected [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_delete_negotiation: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] :500 (Responder) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [2] / 0x9179b567 } Info; Deleting negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_info: Start, nego = 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 2 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_remove_callback: Start, delete SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / unknown } IP; Removing negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_delete_negotiation: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1}, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] LOCAL_IP:500 (Initiator) <-> REMOTE_IP:500 { fbdbf289 7306656a - 84a44d2c 85d424a1 [-1] / unknown } IP; Deleting negotiation [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_sa_delete: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_qm: Start, nego = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 4 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_cfg: Start, nego = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation_isakmp: Start, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_negotiation: Start, nego = -1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA df6400 is freed [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] IKE SA delete called for p1 sa 5384071 (ref cnt 1) local:LOCAL_IP, remote:REMOTE_IP, IKEv1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] P1 SA 5384071 stop timer. timer duration 30, reason 0. [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_pm_p1_sa_destroy: p1 sa 5384071 (ref cnt 0), waiting_for_del 0x0 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] iked_peer_remove_p1sa_entry: Remove p1 sa 5384071 from peer entry 0x9cc400 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_id_payload: Start, id type = 1 [Oct 14 16:07:12][LOCAL_IP <-> REMOTE_IP] ike_free_sa: Start [Oct 14 16:07:16][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:16][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:16][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:07:16][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:16][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { fbdbf289 7306656a - 00000000 00000000 } [Oct 14 16:07:16][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:07:16][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:07:16][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:07:23][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:23][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:23][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:07:23][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:23][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { fbdbf289 7306656a - 00000000 00000000 } [Oct 14 16:07:23][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:07:23][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:07:23][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:07:36][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:36][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:07:36][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:07:36][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:07:36][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { fbdbf289 7306656a - 00000000 00000000 } [Oct 14 16:07:36][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:07:36][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:07:36][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:08:00][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:08:00][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:08:00][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:08:00][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:08:00][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { fbdbf289 7306656a - 00000000 00000000 } [Oct 14 16:08:00][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:08:00][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:08:00][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500 [Oct 14 16:08:42][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:08:42][LOCAL_IP <-> REMOTE_IP] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Oct 14 16:08:42][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Start, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:08:42][LOCAL_IP <-> REMOTE_IP] ike_sa_find: Not found SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } [Oct 14 16:08:42][LOCAL_IP <-> REMOTE_IP] ike_sa_find_half: Not found half SA = { fbdbf289 7306656a - 00000000 00000000 } [Oct 14 16:08:42][LOCAL_IP <-> REMOTE_IP] ike_get_sa: Invalid cookie, no sa found, SA = { fbdbf289 7306656a - 84a44d2c 85d424a1 } / 157f923a, remote = REMOTE_IP:500 [Oct 14 16:08:42][LOCAL_IP <-> REMOTE_IP] iked_pv_audit_callback: Empty SSH audit event [Oct 14 16:08:42][LOCAL_IP <-> REMOTE_IP] unknown (unknown) <-> unknown { unknown [unknown] / unknown } unknown; Packet to unknown Isakmp SA, ip = REMOTE_IP:500