[Jun 27 22:08:34]ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref [Jun 27 22:08:34]Taking reference to P1 SA 3401921 to ref count 1 [Jun 27 22:08:34]iked_pm_trigger_negotiation Set p2_ed in sa_cfg=IKE-SRX [Jun 27 22:08:34]iked_peer_insert_p1sa_entry: Insert p1 sa 3401921 in peer entry 0x118f000 [Jun 27 22:08:34]iked_pm_trigger_negotiation Convert traffic selectors from V1 format to V2 format for narrowing/matchi ng selectors [Jun 27 22:08:34]ssh_ikev2_ts_allocate: Allocated ts 0x11483e0, ref_cnt 1 [Jun 27 22:08:34]ssh_ikev2_ts_allocate: Allocated ts 0x1148420, ref_cnt 1 [Jun 27 22:08:34]ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation 1190000 (now 1 references) [Jun 27 22:08:34]ikev2_fallback_negotiation_alloc: Allocated fallback negotiation 1190000 [Jun 27 22:08:34]ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref [Jun 27 22:08:34]Taking reference to P1 SA 3401921 to ref count 2 [Jun 27 22:08:34]ssh_set_thread_debug_info: ikev2_fb_initiate_ipsec_sa: set thread debug info - local 0xc0a80084 remote 0x797a1751neg 0x1190000 neg->ike_sa 0x1174800 ike_sa 0x0 [Jun 27 22:08:34]Attach ed e1a028 to P1 SA 3401921, slot 0. op handle e1a2b8 [Jun 27 22:08:34]ikev2_reference_exchange_data: Taking reference to exchange data e1a028 (to 2) [Jun 27 22:08:34]ssh_ikev2_ts_free: ts 0x11483e0, ref_cnt 2 [Jun 27 22:08:34]ssh_ikev2_ts_free: ts 0x1148420, ref_cnt 2 [Jun 27 22:08:34]ikev2_fb_i_p1_negotiation_start: Taking reference to fallback negotiation 1190000 (now 2 references) [Jun 27 22:08:34]ssh_set_thread_debug_info: ikev2_fb_i_p1_negotiation_start: set thread debug info - local 0xc0a80084 r emote 0x797a1751neg 0x1190000 neg->ike_sa 0x1174800 ike_sa 0x0 [Jun 27 22:08:34]ikev2_fb_st_i_ike_local_address_request: FB; Calling v2 policy function get_local_address_list [Jun 27 22:08:34]ikev2_fb_st_i_ike_id_request: FB; Calling v2 policy function id [Jun 27 22:08:34]ikev2_fb_id_request_cb: Local id payload is IDa(type = fqdn (2), len = 18, value = zenchowmv.ddns.net) [Jun 27 22:08:34]ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = fqdn (2), len = 18, value = zenchowm v.ddns.net) to IKEv1 ID [Jun 27 22:08:34]ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID fqdn(any:0,[0..17]=zenchowmv.ddn s.net) [Jun 27 22:08:34]ikev2_fb_st_i_ike_notify_request: FB; Calling v2 policy function notify_request [Jun 27 22:08:34]iked_pm_ike_spd_notify_request Parse notification paylad in last received pkt [Jun 27 22:08:34]Parsing notification payload for local:192.168.0.132, remote:121.122.23.81 IKEv1 [Jun 27 22:08:34]iked_pm_ike_spd_notify_request: Sending Initial contact [Jun 27 22:08:34]ikev2_fb_st_i_ike_psk_request: FB; Calling v2 policy function shared_key [Jun 27 22:08:34]iked_pm_ike_pre_shared_key Start... [Jun 27 22:08:34]iked_pm_id_validate NO remote ID, skip validation. [Jun 27 22:08:34]ikev2_fb_find_pre_shared_key_cb: Found preshared key [Jun 27 22:08:34]ikev2_fb_st_i_ike_sa_request: FB; Calling v2 policy function fill_ike_sa [Jun 27 22:08:34]IKE SA fill called for negotiation of local:192.168.0.132, remote:121.122.23.81 IKEv1 [Jun 27 22:08:34]Initiator's proposing IKE SA payload SA() [Jun 27 22:08:34]ikev2_fb_st_i_conf_request: FB; Calling v2 policy function conf_request [Jun 27 22:08:34]iked_pm_ike_conf_request: enter [Jun 27 22:08:34]iked_pm_ike_conf_request: ikev1 not use config-payload [Jun 27 22:08:34]ikev2_fallback_negotiation_free: Fallback negotiation 1190000 has still 1 references [Jun 27 22:08:34]ikev2_fb_i_p1_negotiation_negotiate: Taking reference to fallback negotiation 1190000 (now 2 references) [Jun 27 22:08:34]ssh_ike_connect: Start, remote_name = 121.122.23.81:500, xchg = 4, flags = 00040000 [Jun 27 22:08:34]ike_sa_allocate_half: Start [Jun 27 22:08:34]ike_sa_allocate: Start, SA = { 92376b2f 3896b6bf - 00000000 00000000 } [Jun 27 22:08:34]ike_init_isakmp_sa: Start, remote = 121.122.23.81:500, initiator = 1 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA: Number of proposals = 1 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0]: Number of protocols = 1 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0][0]: Number of transforms = 1 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0][0][0]: ISAKMP protocol [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encryption alg = 5 (3des-cbc) [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Group = 2, 10a0510 [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Hash alg = 2 (sha1) [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 4 (0x0004) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Life duration 28800 secs [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Auth method = 1 [Jun 27 22:08:34]ssh_ike_connect: SA = { 92376b2f 3896b6bf - 00000000 00000000}, nego = -1 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Start isakmp sa negotiation [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Version = 1.0, Input packet fields = 0000 [Jun 27 22:08:34]ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 4, auth_method = pre shared key, Initiator [Jun 27 22:08:34]ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 [Jun 27 22:08:34]ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0 [Jun 27 22:08:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000 [Jun 27 22:08:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000 [Jun 27 22:08:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000 [Jun 27 22:08:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000 [Jun 27 22:08:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000 [Jun 27 22:08:34]ike_state_step: Matched state = Start sa negotiation I (1) [Jun 27 22:08:34]ike_state_step: Calling output function[0] = ike_st_o_sa_proposal [Jun 27 22:08:34]ike_st_o_sa_proposal: Start [Jun 27 22:08:34]ike_state_step: Calling output function[1] = ike_st_o_ke [Jun 27 22:08:34]ike_st_o_ke: Start [Jun 27 22:08:34]ike_find_group_from_sa: No isakmp group defined yet [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encryption alg = 5 (3des-cbc) [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Group = 2, 10a0510 [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Hash alg = 2 (sha1) [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 4 (0x0004) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Life duration 28800 secs [Jun 27 22:08:34]ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Auth method = 1 [Jun 27 22:08:34]iked_dh_get_group: DH Group type dl-modp [Jun 27 22:08:34]iked_dh_get_group: DH Group size 1024 [Jun 27 22:08:34]iked_dh_get_group: DH Group 2 [Jun 27 22:08:34]iked_dh_generate_sync: Requested DH group 2 [Jun 27 22:08:34]iked_dh_generate: Generated DH keys using hardware for DH group 2 [Jun 27 22:08:34]juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [2916] [Jun 27 22:08:34]juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Jun 27 22:08:34]ike_state_step: Calling output function[2] = ike_st_o_nonce [Jun 27 22:08:34]ike_st_o_nonce: Start [Jun 27 22:08:34]ikev2_fb_isakmp_nonce_data_len: Entered [Jun 27 22:08:34]ike_policy_reply_isakmp_nonce_data_len: Start [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Nonce data[16] = 0x313e1e39 3f78b1dd 3eec353c ddd4a270 [Jun 27 22:08:34]ike_state_step: Calling output function[3] = ike_st_o_id [Jun 27 22:08:34]ike_st_o_id: Start [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encoding ID = fqdn(any:0,[0..17]=zenchowmv.ddns.net) [Jun 27 22:08:34]ike_state_step: Calling output function[4] = ike_st_o_vids [Jun 27 22:08:34]ikev2_fb_isakmp_request_vendor_ids: Request vendor ID's policy call entered, IKE SA 1174800 (neg 1190000) [Jun 27 22:08:34]ikev2_fb_isakmp_request_vendor_ids: FB; Calling v2 policy function vendor_id_request [Jun 27 22:08:34]ikev2_fb_vid_request_cb: Got a VID of length 16 (neg 1190000) [Jun 27 22:08:34]iked_pm_ike_request_vendor_id: Sending VID RFC 3706 (Dead Peer Detection) [Jun 27 22:08:34]ikev2_fb_vid_request_cb: Got a VID of length 28 (neg 1190000) [Jun 27 22:08:34]iked_pm_ike_request_vendor_id: Sending VID NetScreen Technologies [Jun 27 22:08:34]ikev2_fb_vid_request_cb: Got a VID of length 8 (neg 1190000) [Jun 27 22:08:34]iked_pm_ike_request_vendor_id: Sending VID draft-ietf-ipsra-isakmp-xauth-06.txt [Jun 27 22:08:34]ikev2_fb_vid_request_cb: No more VIDs [Jun 27 22:08:34]ike_policy_reply_isakmp_vendor_ids: Start [Jun 27 22:08:34]ike_state_step: Calling output function[5] = ike_st_o_private [Jun 27 22:08:34]ike_st_o_private: Start [Jun 27 22:08:34]ikev2_fb_private_p_1_out: Phase-I output: packet_number 1 ike_sa 1174800 (neg 1190000) [Jun 27 22:08:34]ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations [Jun 27 22:08:34]ikev2_fb_private_p_1_out: NAT traversal disabled by policy [Jun 27 22:08:34]ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request [Jun 27 22:08:34]ike_policy_reply_private_payload_out: Start [Jun 27 22:08:34]ike_state_step: All done, new state = AM SA I (10) [Jun 27 22:08:34]ike_encode_packet: Start, SA = { 0x92376b2f 3896b6bf - 00000000 00000000 } / 00000000, nego = -1 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode packet, version = 1.0, flags = 0x00000000 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: doi = 1, sit = 0x1 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: Proposal[0] = 1 .protocol[0] = 1, # transforms = 1, spi[8] = 0x92376b2f 3896b6bf [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: trans[0] = 0, id = 1, # sa = 6 [Jun 27 22:08:34]ssh_ike_encode_data_attribute: encode B: type = 1 (0x0001), len = 2, value = 0005 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[0], type = 1, value[2] = 0x0005 [Jun 27 22:08:34]ssh_ike_encode_data_attribute: encode B: type = 4 (0x0004), len = 2, value = 0002 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[1], type = 4, value[2] = 0x0002 [Jun 27 22:08:34]ssh_ike_encode_data_attribute: encode B: type = 2 (0x0002), len = 2, value = 0002 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[2], type = 2, value[2] = 0x0002 [Jun 27 22:08:34]ssh_ike_encode_data_attribute: encode B: type = 11 (0x000b), len = 2, value = 0001 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[3], type = 11, value[2] = 0x0001 [Jun 27 22:08:34]ssh_ike_encode_data_attribute: encode V: type = 12 (0x000c), len = 4 (0x0004), value = 00007080 ... [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[4], type = 12, value[4] = 0x00007080 [Jun 27 22:08:34]ssh_ike_encode_data_attribute: encode B: type = 3 (0x0003), len = 2, value = 0001 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[5], type = 3, value[2] = 0x0001 [Jun 27 22:08:34]ike_encode_packet: Payload length = 64 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode KE: ke[128] = 0x3caa4d64 08f93f8e d48ff9b9 76fe4659 a1f8119a cf8e2cf2 ad71d21e 8761a261 f6fb8f58 9 [Jun 27 22:08:34]ike_encode_packet: Payload length = 132 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode NONCE: nonce[16] = 0x313e1e39 3f78b1dd 3eec353c ddd4a270 [Jun 27 22:08:34]ike_encode_packet: Payload length = 20 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode ID: packet[22] = 0x02000000 7a656e63 686f776d 762e6464 6e732e6e 6574 [Jun 27 22:08:34]ike_encode_packet: Payload length = 26 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[16] = 0xafcad713 68a1f1c9 6b8696fc 77570100 [Jun 27 22:08:34]ike_encode_packet: Payload length = 20 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[28] = 0x69936922 8741c6d4 ca094c93 e242c9de 19e7b7c6 00000005 00000500 [Jun 27 22:08:34]ike_encode_packet: Payload length = 32 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[8] = 0x09002689 dfd6b712 [Jun 27 22:08:34]ike_encode_packet: Payload length = 12 [Jun 27 22:08:34]ike_encode_packet: Payload length = 334 [Jun 27 22:08:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encoded packet[334] = 0x92376b2f 3896b6bf 00000000 00000000 01100400 00000000 0000014e 04000040 00000001 [Jun 27 22:08:34]ike_encode_packet: Final length = 334 [Jun 27 22:08:34]ike_send_packet: <-------- sending SA = { 92376b2f 3896b6bf - 00000000 00000000}, len = 334, nego = -1, local ip= 192.168.0.132, dst = 121.122.23.81:500, routing table id = 0 [Jun 27 22:08:34]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:08:35] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:08:35]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:08:35]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:08:35]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:08:35]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 131 [Jun 27 22:08:35]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:08:44]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:08:44]ike_retransmit_callback: Start, retransmit SA = { 92376b2f 3896b6bf - 00000000 00000000}, nego = -1 [Jun 27 22:08:44]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Retransmitting packet, retries = 5 [Jun 27 22:08:44]ike_send_packet: Start, retransmit previous packet SA = { 92376b2f 3896b6bf - 00000000 00000000}, nego = -1, dst = 121.122.23.81:500 routing table id = 0 [Jun 27 22:08:44]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:08:45] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:08:45]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:08:45]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:08:45]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:08:45]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 132 [Jun 27 22:08:45]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:08:54]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:08:54]ike_retransmit_callback: Start, retransmit SA = { 92376b2f 3896b6bf - 00000000 00000000}, nego = -1 [Jun 27 22:08:54]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Retransmitting packet, retries = 4 [Jun 27 22:08:54]ike_send_packet: Start, retransmit previous packet SA = { 92376b2f 3896b6bf - 00000000 00000000}, nego = -1, dst = 121.122.23.81:500 routing table id = 0 [Jun 27 22:08:54]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:08:55] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:08:55]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:08:55]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:08:55]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:08:55]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 133 [Jun 27 22:08:55]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:09:04]P1 SA 3401921 timer expiry. ref cnt 2, timer reason Force delete timer expired (1), flags 0x0. [Jun 27 22:09:04]iked_tunnel_event_set_for_p1_sa: Setting tunnel-event for all p2-eds for p1-sa 3401921 with event Internal Error: Unknown event (0) [Jun 27 22:09:04]iked_tunnel_event_set_for_p1_sa: Setting tunnel-event Internal Error: Unknown event (0) for P1-SA 3401921 [Jun 27 22:09:04]iked_tunnel_event_add_event_in_gw: Updating tunnel-event for gateway gw_IKE-SRX with No response from peer. Negotiation failed [Jun 27 22:09:04]iked_tunnel_event_add_event_in_gw: tunnel-event No response from peer. Negotiation failed count incremented to 24 [Jun 27 22:09:04]iked_ha_check_ike_sa_activeness_by_rg_id:RG 0 is active on this chassiss [Jun 27 22:09:04]Initiate IKE P1 SA 3401921 delete. curr ref count 2, del flags 0x3. Reason: Internal Error: Unknown event (0) [Jun 27 22:09:04]iked_pm_ike_sa_delete_done_cb: For p1 sa index 3401921, ref cnt 2, status: Error ok [Jun 27 22:09:04]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:09:04]ike_remove_callback: Start, delete SA = { 92376b2f 3896b6bf - 00000000 00000000}, nego = -1 [Jun 27 22:09:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Removing negotiation [Jun 27 22:09:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Connection timed out or error, calling callback [Jun 27 22:09:04]ikev2_fb_negotiation_done_isakmp: Entered IKE error code Timeout (8197), IKE SA 1174800 (neg 1190000) [Jun 27 22:09:04]ikev2_fb_i_ike_negotiation_cb: Connect IKE done callback, status Timeout (neg 1190000) [Jun 27 22:09:04]ikev2_fb_v1_encr_id_to_v2_id: Unknown IKE encryption identifier -1 [Jun 27 22:09:04]ikev2_fb_v1_hash_id_to_v2_prf_id: Unknown IKE hash alg identifier -1 [Jun 27 22:09:04]ikev2_fb_v1_hash_id_to_v2_integ_id: Unknown IKE hash alg identifier -1 [Jun 27 22:09:04]ikev2_fb_i_ike_negotiation_cb: IKE negotiation error 65540 (neg 1190000) [Jun 27 22:09:04]ikev2_fb_i_ike_negotiation_cb: FB; Calling v2 policy function ike_sa_done [Jun 27 22:09:04]iked_pm_ike_sa_done: Phase-1 failed with error (Timeout) p1_sa 3401921 [Jun 27 22:09:04] IKEv1 Error : Timeout [Jun 27 22:09:04]IPSec SA done callback. ed e1a028. status: Timed out [Jun 27 22:09:04]Detach ed e1a028 from P1 SA 3401921, slot 0. [Jun 27 22:09:04]ikev2_free_exchange_data: Freeing exchange data from SA 1174800, ED e1a028 (2) [Jun 27 22:09:04]IPSec Rekey for SPI 0x0 failed [Jun 27 22:09:04]IPSec SA done callback called for sa-cfg IKE-SRX local:192.168.0.132, remote:121.122.23.81 IKEv1 with status Timed out [Jun 27 22:09:04]ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context [Jun 27 22:09:04]ikev2_fb_negotiation_clear_pm_data: Clearing fb pm_data [Jun 27 22:09:04]ikev2_fallback_negotiation_free: Fallback negotiation 1190000 has still 1 references [Jun 27 22:09:04]ikev2_fallback_negotiation_free: Freeing fallback negotiation 1190000 [Jun 27 22:09:04]ikev2_free_exchange_data: Freeing exchange data from SA 1174800, ED e1a028 (1) [Jun 27 22:09:04]ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 1174800 [Jun 27 22:09:04]ssh_ikev2_ts_free: ts 0x11483e0, ref_cnt 1 [Jun 27 22:09:04]ssh_ikev2_ts_free: ts 0x1148420, ref_cnt 1 [Jun 27 22:09:04]ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 1174800 [Jun 27 22:09:04]ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA 1174800 [Jun 27 22:09:04]ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA 1174800 [Jun 27 22:09:04]ikev2_free_exchange_data: Calling exchange_data_free [Jun 27 22:09:04]Freeing P2 Ed for sa-cfg IKE-SRX [Jun 27 22:09:04]iked_unset_sa_cfg_p2_ed unset_sa_cfg_p2_ed, sa_cfg=IKE-SRX [Jun 27 22:09:04]iked_pm_ike_exchange_data_free: Successfully removed pm_ed 118f200 from list for sa_cfg N/A [Jun 27 22:09:04]ikev2_free_exchange_data: Successfully freed exchange data from SA 1174800 [Jun 27 22:09:04]ssh_ikev2_ike_sa_free: Calling ike_sa_free_ref [Jun 27 22:09:04]Freeing reference to P1 SA 3401921 to ref count 1 [Jun 27 22:09:04]ike_delete_negotiation: Start, SA = { 92376b2f 3896b6bf - 00000000 00000000}, nego = -1 [Jun 27 22:09:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 92376b2f 3896b6bf - 00000000 00000000 [-1] / 0x00000000 } Aggr; Deleting negotiation [Jun 27 22:09:04]ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table [Jun 27 22:09:04]ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table [Jun 27 22:09:04]ike_sa_delete: Start, SA = { 92376b2f 3896b6bf - 00000000 00000000 } [Jun 27 22:09:04]ike_free_negotiation_isakmp: Start, nego = -1 [Jun 27 22:09:04]ike_free_negotiation: Start, nego = -1 [Jun 27 22:09:04]ike_free_packet: Start [Jun 27 22:09:04]ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA 1174800 is freed [Jun 27 22:09:04]ikev2_fb_isakmp_sa_freed: FB; Calling v2 policy function ike_sa_delete [Jun 27 22:09:04]IKE SA delete called for p1 sa 3401921 (ref cnt 1) local:192.168.0.132, remote:121.122.23.81, IKEv1 [Jun 27 22:09:04]P1 SA 3401921 stop timer. timer duration 30, reason 0. [Jun 27 22:09:04]iked_fail_to_backup_if_required delete p2 sa, dpd detect peer down [Jun 27 22:09:04]Freeing reference to P1 SA 3401921 to ref count 0 [Jun 27 22:09:04]iked_pm_p1_sa_destroy: p1 sa 3401921 (ref cnt 0), waiting_for_del 0x0 [Jun 27 22:09:04]iked_peer_remove_p1sa_entry: Remove p1 sa 3401921 from peer entry 0x118f000 [Jun 27 22:09:04]iked_delete_peer_entry: Requested for peer-entry 0x118f000 deletion for local 192.168.0.132:500 and remote 121.122.23.81:500 reason:236 [Jun 27 22:09:04]iked_dist_table_entry_update : Dist table entry creation not needed [Jun 27 22:09:04]iked_peer_entry_patricia_delete:Peer entry 0x118f000 deleted for local 192.168.0.132:500 and remote 121.122.23.81:500 [Jun 27 22:09:04]Deleting p1 sa (3401921) node from IKE p1 SA P-tree [Jun 27 22:09:04]The tunnel id: 3401921 doesn't exist in P1 SA P-tree [Jun 27 22:09:04]ikev2_udp_window_uninit: Freeing transmission windows for SA 1174800 [Jun 27 22:09:04]ike_free_id_payload: Start, id type = 2 [Jun 27 22:09:04]ike_free_sa: Start [Jun 27 22:09:04]iked_deferred_free_inactive_peer_entry: Free 1 peer_entry(s) [Jun 27 22:09:05] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:09:05]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:09:05]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:09:05]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:09:05]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 134 [Jun 27 22:09:05]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:09:15] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:09:15]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:09:15]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:09:15]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:09:15]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 135 [Jun 27 22:09:15]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:09:25] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:09:25]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:09:25]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:09:25]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:09:25]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 136 [Jun 27 22:09:25]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:09:34]Triggering all tunnels [Jun 27 22:09:34]iked_pm_trigger_callback called for IKE-SRX [Jun 27 22:09:34]Triggering negotiation for IKE-SRX config block [Jun 27 22:09:34]iked_pm_trigger_callback: lookup peer entry for gateway gw_IKE-SRX, local_port=500, remote_port=500 [Jun 27 22:09:34]iked_lookup_peer_entry: Peer entry 0x0 Not FOUND for local 192.168.0.132:500 and remote 121.122.23.81:500 [Jun 27 22:09:34]iked_create_peer_entry: Created peer entry 0x118f000 for local 192.168.0.132:500 remote 121.122.23.81:500 [Jun 27 22:09:34]iked_fetch_or_create_peer_entry: Create peer entry 0x118f000 for local 192.168.0.132:500 remote 121.122.23.81:500. gw gw_IKE-SRX, VR id 0 [Jun 27 22:09:34]iked_dist_table_entry_update : Dist table entry creation not needed [Jun 27 22:09:34]iked_pm_trigger_callback: FOUND peer entry for gateway gw_IKE-SRX [Jun 27 22:09:34]iked_pm_trigger_callback need p1 lifetime <30> [Jun 27 22:09:34]Initiating new P1 SA for gateway gw_IKE-SRX [Jun 27 22:09:34]ssh_ikev2_ike_sa_allocate: Allocating IKE SA 121.122.23.81;500/4500 [Jun 27 22:09:34]chassis 0 fpc 0 pic 0 kmd-instance 0 current tunnel id 3401921 [Jun 27 22:09:34]Allocated IKE SA index 3401922, ref cnt 0 [Jun 27 22:09:34]In iked_p1_sa_patricia_tree_fpc_pic_entry_add ADDED THE PATNODEike sa index 3401922 [Jun 27 22:09:34]P1 SA 3401922 start timer. timer duration 30, reason 1. [Jun 27 22:09:34]ikev2_ike_sa_alloc_cb: Allocated IKE SA 1174800 I9735eb2f 54fd1e99 (121.122.23.81;500/4500) [Jun 27 22:09:34]ikev2_udp_window_init: Allocating transmission windows for SA 1174800 [Jun 27 22:09:34]ikev2_allocate_exchange_data: Calling exchange_data_alloc [Jun 27 22:09:34]iked_pm_ike_exchange_data_alloc: Successfully inserted pm_ed 118f200 into list for sa_cfg N/A [Jun 27 22:09:34]Exchange data allocated for IKE SA 3401922. VR 65535 [Jun 27 22:09:34]ikev2_allocate_exchange_data: Successfully allocated exchange data for SA 1174800 [Jun 27 22:09:34]ssh_ikev2_ipsec_create_sa: State = IKE_INIT_SA [Jun 27 22:09:34]ikev2_allocate_exchange_data_ike: Allocating IKE exchange data for SA 1174800 ED e1a028 [Jun 27 22:09:34]ikev2_allocate_exchange_data_ike: Successfully allocated IKE exchange data for SA 1174800 ED e1a028 [Jun 27 22:09:34]ikev2_allocate_exchange_data_ipsec: Allocating IPsec exchange data for SA 1174800 ED e1a028 [Jun 27 22:09:34]ikev2_allocate_exchange_data_ipsec: Successfully allocated IPsec exchange data for SA 1174800 ED e1a028 [Jun 27 22:09:34]ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref [Jun 27 22:09:34]Taking reference to P1 SA 3401922 to ref count 1 [Jun 27 22:09:34]iked_pm_trigger_negotiation Set p2_ed in sa_cfg=IKE-SRX [Jun 27 22:09:34]iked_peer_insert_p1sa_entry: Insert p1 sa 3401922 in peer entry 0x118f000 [Jun 27 22:09:34]iked_pm_trigger_negotiation Convert traffic selectors from V1 format to V2 format for narrowing/matching selectors [Jun 27 22:09:34]ssh_ikev2_ts_allocate: Allocated ts 0x10ca020, ref_cnt 1 [Jun 27 22:09:34]ssh_ikev2_ts_allocate: Allocated ts 0x1148420, ref_cnt 1 [Jun 27 22:09:34]ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation 1190000 (now 1 references) [Jun 27 22:09:34]ikev2_fallback_negotiation_alloc: Allocated fallback negotiation 1190000 [Jun 27 22:09:34]ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref [Jun 27 22:09:34]Taking reference to P1 SA 3401922 to ref count 2 [Jun 27 22:09:34]ssh_set_thread_debug_info: ikev2_fb_initiate_ipsec_sa: set thread debug info - local 0xc0a80084 remote 0x797a1751neg 0x1190000 neg->ike_sa 0x1174800 ike_sa 0x0 [Jun 27 22:09:34]Attach ed e1a028 to P1 SA 3401922, slot 0. op handle e1a2b8 [Jun 27 22:09:34]ikev2_reference_exchange_data: Taking reference to exchange data e1a028 (to 2) [Jun 27 22:09:34]ssh_ikev2_ts_free: ts 0x10ca020, ref_cnt 2 [Jun 27 22:09:34]ssh_ikev2_ts_free: ts 0x1148420, ref_cnt 2 [Jun 27 22:09:34]ikev2_fb_i_p1_negotiation_start: Taking reference to fallback negotiation 1190000 (now 2 references) [Jun 27 22:09:34]ssh_set_thread_debug_info: ikev2_fb_i_p1_negotiation_start: set thread debug info - local 0xc0a80084 remote 0x797a1751neg 0x1190000 neg->ike_sa 0x1174800 ike_sa 0x0 [Jun 27 22:09:34]ikev2_fb_st_i_ike_local_address_request: FB; Calling v2 policy function get_local_address_list [Jun 27 22:09:34]ikev2_fb_st_i_ike_id_request: FB; Calling v2 policy function id [Jun 27 22:09:34]ikev2_fb_id_request_cb: Local id payload is IDa(type = fqdn (2), len = 18, value = zenchowmv.ddns.net) [Jun 27 22:09:34]ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = fqdn (2), len = 18, value = zenchowmv.ddns.net) to IKEv1 ID [Jun 27 22:09:34]ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID fqdn(any:0,[0..17]=zenchowmv.ddns.net) [Jun 27 22:09:34]ikev2_fb_st_i_ike_notify_request: FB; Calling v2 policy function notify_request [Jun 27 22:09:34]iked_pm_ike_spd_notify_request Parse notification paylad in last received pkt [Jun 27 22:09:34]Parsing notification payload for local:192.168.0.132, remote:121.122.23.81 IKEv1 [Jun 27 22:09:34]iked_pm_ike_spd_notify_request: Sending Initial contact [Jun 27 22:09:34]ikev2_fb_st_i_ike_psk_request: FB; Calling v2 policy function shared_key [Jun 27 22:09:34]iked_pm_ike_pre_shared_key Start... [Jun 27 22:09:34]iked_pm_id_validate NO remote ID, skip validation. [Jun 27 22:09:34]ikev2_fb_find_pre_shared_key_cb: Found preshared key [Jun 27 22:09:34]ikev2_fb_st_i_ike_sa_request: FB; Calling v2 policy function fill_ike_sa [Jun 27 22:09:34]IKE SA fill called for negotiation of local:192.168.0.132, remote:121.122.23.81 IKEv1 [Jun 27 22:09:34]Initiator's proposing IKE SA payload SA() [Jun 27 22:09:34]ikev2_fb_st_i_conf_request: FB; Calling v2 policy function conf_request [Jun 27 22:09:34]iked_pm_ike_conf_request: enter [Jun 27 22:09:34]iked_pm_ike_conf_request: ikev1 not use config-payload [Jun 27 22:09:34]ikev2_fallback_negotiation_free: Fallback negotiation 1190000 has still 1 references [Jun 27 22:09:34]ikev2_fb_i_p1_negotiation_negotiate: Taking reference to fallback negotiation 1190000 (now 2 references) [Jun 27 22:09:34]ssh_ike_connect: Start, remote_name = 121.122.23.81:500, xchg = 4, flags = 00040000 [Jun 27 22:09:34]ike_sa_allocate_half: Start [Jun 27 22:09:34]ike_sa_allocate: Start, SA = { 9735eb2f 54fd1e99 - 00000000 00000000 } [Jun 27 22:09:34]ike_init_isakmp_sa: Start, remote = 121.122.23.81:500, initiator = 1 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA: Number of proposals = 1 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0]: Number of protocols = 1 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0][0]: Number of transforms = 1 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0][0][0]: ISAKMP protocol [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encryption alg = 5 (3des-cbc) [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Group = 2, 10a0510 [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Hash alg = 2 (sha1) [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 4 (0x0004) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Life duration 28800 secs [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Auth method = 1 [Jun 27 22:09:34]ssh_ike_connect: SA = { 9735eb2f 54fd1e99 - 00000000 00000000}, nego = -1 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Start isakmp sa negotiation [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Version = 1.0, Input packet fields = 0000 [Jun 27 22:09:34]ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 4, auth_method = pre shared key, Initiator [Jun 27 22:09:34]ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 [Jun 27 22:09:34]ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0 [Jun 27 22:09:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000 [Jun 27 22:09:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000 [Jun 27 22:09:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000 [Jun 27 22:09:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000 [Jun 27 22:09:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000 [Jun 27 22:09:34]ike_state_step: Matched state = Start sa negotiation I (1) [Jun 27 22:09:34]ike_state_step: Calling output function[0] = ike_st_o_sa_proposal [Jun 27 22:09:34]ike_st_o_sa_proposal: Start [Jun 27 22:09:34]ike_state_step: Calling output function[1] = ike_st_o_ke [Jun 27 22:09:34]ike_st_o_ke: Start [Jun 27 22:09:34]ike_find_group_from_sa: No isakmp group defined yet [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encryption alg = 5 (3des-cbc) [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Group = 2, 10a0510 [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Hash alg = 2 (sha1) [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 4 (0x0004) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Life duration 28800 secs [Jun 27 22:09:34]ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Auth method = 1 [Jun 27 22:09:34]iked_dh_get_group: DH Group type dl-modp [Jun 27 22:09:34]iked_dh_get_group: DH Group size 1024 [Jun 27 22:09:34]iked_dh_get_group: DH Group 2 [Jun 27 22:09:34]iked_dh_generate_sync: Requested DH group 2 [Jun 27 22:09:34]iked_dh_generate: Generated DH keys using hardware for DH group 2 [Jun 27 22:09:34]juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [2905] [Jun 27 22:09:34]juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Jun 27 22:09:34]ike_state_step: Calling output function[2] = ike_st_o_nonce [Jun 27 22:09:34]ike_st_o_nonce: Start [Jun 27 22:09:34]ikev2_fb_isakmp_nonce_data_len: Entered [Jun 27 22:09:34]ike_policy_reply_isakmp_nonce_data_len: Start [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Nonce data[16] = 0x58abff48 d258c295 6cc82a96 7030d784 [Jun 27 22:09:34]ike_state_step: Calling output function[3] = ike_st_o_id [Jun 27 22:09:34]ike_st_o_id: Start [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encoding ID = fqdn(any:0,[0..17]=zenchowmv.ddns.net) [Jun 27 22:09:34]ike_state_step: Calling output function[4] = ike_st_o_vids [Jun 27 22:09:34]ikev2_fb_isakmp_request_vendor_ids: Request vendor ID's policy call entered, IKE SA 1174800 (neg 1190000) [Jun 27 22:09:34]ikev2_fb_isakmp_request_vendor_ids: FB; Calling v2 policy function vendor_id_request [Jun 27 22:09:34]ikev2_fb_vid_request_cb: Got a VID of length 16 (neg 1190000) [Jun 27 22:09:34]iked_pm_ike_request_vendor_id: Sending VID RFC 3706 (Dead Peer Detection) [Jun 27 22:09:34]ikev2_fb_vid_request_cb: Got a VID of length 28 (neg 1190000) [Jun 27 22:09:34]iked_pm_ike_request_vendor_id: Sending VID NetScreen Technologies [Jun 27 22:09:34]ikev2_fb_vid_request_cb: Got a VID of length 8 (neg 1190000) [Jun 27 22:09:34]iked_pm_ike_request_vendor_id: Sending VID draft-ietf-ipsra-isakmp-xauth-06.txt [Jun 27 22:09:34]ikev2_fb_vid_request_cb: No more VIDs [Jun 27 22:09:34]ike_policy_reply_isakmp_vendor_ids: Start [Jun 27 22:09:34]ike_state_step: Calling output function[5] = ike_st_o_private [Jun 27 22:09:34]ike_st_o_private: Start [Jun 27 22:09:34]ikev2_fb_private_p_1_out: Phase-I output: packet_number 1 ike_sa 1174800 (neg 1190000) [Jun 27 22:09:34]ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations [Jun 27 22:09:34]ikev2_fb_private_p_1_out: NAT traversal disabled by policy [Jun 27 22:09:34]ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request [Jun 27 22:09:34]ike_policy_reply_private_payload_out: Start [Jun 27 22:09:34]ike_state_step: All done, new state = AM SA I (10) [Jun 27 22:09:34]ike_encode_packet: Start, SA = { 0x9735eb2f 54fd1e99 - 00000000 00000000 } / 00000000, nego = -1 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode packet, version = 1.0, flags = 0x00000000 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: doi = 1, sit = 0x1 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: Proposal[0] = 1 .protocol[0] = 1, # transforms = 1, spi[8] = 0x9735eb2f 54fd1e99 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: trans[0] = 0, id = 1, # sa = 6 [Jun 27 22:09:34]ssh_ike_encode_data_attribute: encode B: type = 1 (0x0001), len = 2, value = 0005 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[0], type = 1, value[2] = 0x0005 [Jun 27 22:09:34]ssh_ike_encode_data_attribute: encode B: type = 4 (0x0004), len = 2, value = 0002 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[1], type = 4, value[2] = 0x0002 [Jun 27 22:09:34]ssh_ike_encode_data_attribute: encode B: type = 2 (0x0002), len = 2, value = 0002 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[2], type = 2, value[2] = 0x0002 [Jun 27 22:09:34]ssh_ike_encode_data_attribute: encode B: type = 11 (0x000b), len = 2, value = 0001 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[3], type = 11, value[2] = 0x0001 [Jun 27 22:09:34]ssh_ike_encode_data_attribute: encode V: type = 12 (0x000c), len = 4 (0x0004), value = 00007080 ... [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[4], type = 12, value[4] = 0x00007080 [Jun 27 22:09:34]ssh_ike_encode_data_attribute: encode B: type = 3 (0x0003), len = 2, value = 0001 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[5], type = 3, value[2] = 0x0001 [Jun 27 22:09:34]ike_encode_packet: Payload length = 64 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode KE: ke[128] = 0x54ad3c57 c5e16863 26f45486 f771101f a168bb99 719a6489 cf9b5f1c e2847b6f 0bdc0b49 c [Jun 27 22:09:34]ike_encode_packet: Payload length = 132 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode NONCE: nonce[16] = 0x58abff48 d258c295 6cc82a96 7030d784 [Jun 27 22:09:34]ike_encode_packet: Payload length = 20 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode ID: packet[22] = 0x02000000 7a656e63 686f776d 762e6464 6e732e6e 6574 [Jun 27 22:09:34]ike_encode_packet: Payload length = 26 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[16] = 0xafcad713 68a1f1c9 6b8696fc 77570100 [Jun 27 22:09:34]ike_encode_packet: Payload length = 20 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[28] = 0x69936922 8741c6d4 ca094c93 e242c9de 19e7b7c6 00000005 00000500 [Jun 27 22:09:34]ike_encode_packet: Payload length = 32 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[8] = 0x09002689 dfd6b712 [Jun 27 22:09:34]ike_encode_packet: Payload length = 12 [Jun 27 22:09:34]ike_encode_packet: Payload length = 334 [Jun 27 22:09:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encoded packet[334] = 0x9735eb2f 54fd1e99 00000000 00000000 01100400 00000000 0000014e 04000040 00000001 [Jun 27 22:09:34]ike_encode_packet: Final length = 334 [Jun 27 22:09:34]ike_send_packet: <-------- sending SA = { 9735eb2f 54fd1e99 - 00000000 00000000}, len = 334, nego = -1, local ip= 192.168.0.132, dst = 121.122.23.81:500, routing table id = 0 [Jun 27 22:09:34]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:09:35] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:09:35]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:09:35]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:09:35]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:09:35]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 137 [Jun 27 22:09:35]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:09:44]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:09:44]ike_retransmit_callback: Start, retransmit SA = { 9735eb2f 54fd1e99 - 00000000 00000000}, nego = -1 [Jun 27 22:09:44]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Retransmitting packet, retries = 5 [Jun 27 22:09:44]ike_send_packet: Start, retransmit previous packet SA = { 9735eb2f 54fd1e99 - 00000000 00000000}, nego = -1, dst = 121.122.23.81:500 routing table id = 0 [Jun 27 22:09:44]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:09:45] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:09:45]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:09:45]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:09:45]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:09:45]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 138 [Jun 27 22:09:45]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:09:54]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:09:54]ike_retransmit_callback: Start, retransmit SA = { 9735eb2f 54fd1e99 - 00000000 00000000}, nego = -1 [Jun 27 22:09:54]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Retransmitting packet, retries = 4 [Jun 27 22:09:54]ike_send_packet: Start, retransmit previous packet SA = { 9735eb2f 54fd1e99 - 00000000 00000000}, nego = -1, dst = 121.122.23.81:500 routing table id = 0 [Jun 27 22:09:54]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:09:55] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:09:55]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:09:55]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:09:55]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:09:55]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 139 [Jun 27 22:09:55]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:10:04]P1 SA 3401922 timer expiry. ref cnt 2, timer reason Force delete timer expired (1), flags 0x0. [Jun 27 22:10:04]iked_tunnel_event_set_for_p1_sa: Setting tunnel-event for all p2-eds for p1-sa 3401922 with event Internal Error: Unknown event (0) [Jun 27 22:10:04]iked_tunnel_event_set_for_p1_sa: Setting tunnel-event Internal Error: Unknown event (0) for P1-SA 3401922 [Jun 27 22:10:04]iked_tunnel_event_add_event_in_gw: Updating tunnel-event for gateway gw_IKE-SRX with No response from peer. Negotiation failed [Jun 27 22:10:04]iked_tunnel_event_add_event_in_gw: tunnel-event No response from peer. Negotiation failed count incremented to 25 [Jun 27 22:10:04]iked_ha_check_ike_sa_activeness_by_rg_id:RG 0 is active on this chassiss [Jun 27 22:10:04]Initiate IKE P1 SA 3401922 delete. curr ref count 2, del flags 0x3. Reason: Internal Error: Unknown event (0) [Jun 27 22:10:04]iked_pm_ike_sa_delete_done_cb: For p1 sa index 3401922, ref cnt 2, status: Error ok [Jun 27 22:10:04]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:10:04]ike_remove_callback: Start, delete SA = { 9735eb2f 54fd1e99 - 00000000 00000000}, nego = -1 [Jun 27 22:10:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Removing negotiation [Jun 27 22:10:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Connection timed out or error, calling callback [Jun 27 22:10:04]ikev2_fb_negotiation_done_isakmp: Entered IKE error code Timeout (8197), IKE SA 1174800 (neg 1190000) [Jun 27 22:10:04]ikev2_fb_i_ike_negotiation_cb: Connect IKE done callback, status Timeout (neg 1190000) [Jun 27 22:10:04]ikev2_fb_v1_encr_id_to_v2_id: Unknown IKE encryption identifier -1 [Jun 27 22:10:04]ikev2_fb_v1_hash_id_to_v2_prf_id: Unknown IKE hash alg identifier -1 [Jun 27 22:10:04]ikev2_fb_v1_hash_id_to_v2_integ_id: Unknown IKE hash alg identifier -1 [Jun 27 22:10:04]ikev2_fb_i_ike_negotiation_cb: IKE negotiation error 65540 (neg 1190000) [Jun 27 22:10:04]ikev2_fb_i_ike_negotiation_cb: FB; Calling v2 policy function ike_sa_done [Jun 27 22:10:04]iked_pm_ike_sa_done: Phase-1 failed with error (Timeout) p1_sa 3401922 [Jun 27 22:10:04] IKEv1 Error : Timeout [Jun 27 22:10:04]IPSec SA done callback. ed e1a028. status: Timed out [Jun 27 22:10:04]Detach ed e1a028 from P1 SA 3401922, slot 0. [Jun 27 22:10:04]ikev2_free_exchange_data: Freeing exchange data from SA 1174800, ED e1a028 (2) [Jun 27 22:10:04]IPSec Rekey for SPI 0x0 failed [Jun 27 22:10:04]IPSec SA done callback called for sa-cfg IKE-SRX local:192.168.0.132, remote:121.122.23.81 IKEv1 with status Timed out [Jun 27 22:10:04]ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context [Jun 27 22:10:04]ikev2_fb_negotiation_clear_pm_data: Clearing fb pm_data [Jun 27 22:10:04]ikev2_fallback_negotiation_free: Fallback negotiation 1190000 has still 1 references [Jun 27 22:10:04]ikev2_fallback_negotiation_free: Freeing fallback negotiation 1190000 [Jun 27 22:10:04]ikev2_free_exchange_data: Freeing exchange data from SA 1174800, ED e1a028 (1) [Jun 27 22:10:04]ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 1174800 [Jun 27 22:10:04]ssh_ikev2_ts_free: ts 0x10ca020, ref_cnt 1 [Jun 27 22:10:04]ssh_ikev2_ts_free: ts 0x1148420, ref_cnt 1 [Jun 27 22:10:04]ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 1174800 [Jun 27 22:10:04]ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA 1174800 [Jun 27 22:10:04]ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA 1174800 [Jun 27 22:10:04]ikev2_free_exchange_data: Calling exchange_data_free [Jun 27 22:10:04]Freeing P2 Ed for sa-cfg IKE-SRX [Jun 27 22:10:04]iked_unset_sa_cfg_p2_ed unset_sa_cfg_p2_ed, sa_cfg=IKE-SRX [Jun 27 22:10:04]iked_pm_ike_exchange_data_free: Successfully removed pm_ed 118f200 from list for sa_cfg N/A [Jun 27 22:10:04]ikev2_free_exchange_data: Successfully freed exchange data from SA 1174800 [Jun 27 22:10:04]ssh_ikev2_ike_sa_free: Calling ike_sa_free_ref [Jun 27 22:10:04]Freeing reference to P1 SA 3401922 to ref count 1 [Jun 27 22:10:04]ike_delete_negotiation: Start, SA = { 9735eb2f 54fd1e99 - 00000000 00000000}, nego = -1 [Jun 27 22:10:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { 9735eb2f 54fd1e99 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Deleting negotiation [Jun 27 22:10:04]ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table [Jun 27 22:10:04]ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table [Jun 27 22:10:04]ike_sa_delete: Start, SA = { 9735eb2f 54fd1e99 - 00000000 00000000 } [Jun 27 22:10:04]ike_free_negotiation_isakmp: Start, nego = -1 [Jun 27 22:10:04]ike_free_negotiation: Start, nego = -1 [Jun 27 22:10:04]ike_free_packet: Start [Jun 27 22:10:04]ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA 1174800 is freed [Jun 27 22:10:04]ikev2_fb_isakmp_sa_freed: FB; Calling v2 policy function ike_sa_delete [Jun 27 22:10:04]IKE SA delete called for p1 sa 3401922 (ref cnt 1) local:192.168.0.132, remote:121.122.23.81, IKEv1 [Jun 27 22:10:04]P1 SA 3401922 stop timer. timer duration 30, reason 0. [Jun 27 22:10:04]iked_fail_to_backup_if_required delete p2 sa, dpd detect peer down [Jun 27 22:10:04]Freeing reference to P1 SA 3401922 to ref count 0 [Jun 27 22:10:04]iked_pm_p1_sa_destroy: p1 sa 3401922 (ref cnt 0), waiting_for_del 0x0 [Jun 27 22:10:04]iked_peer_remove_p1sa_entry: Remove p1 sa 3401922 from peer entry 0x118f000 [Jun 27 22:10:04]iked_delete_peer_entry: Requested for peer-entry 0x118f000 deletion for local 192.168.0.132:500 and remote 121.122.23.81:500 reason:236 [Jun 27 22:10:04]iked_dist_table_entry_update : Dist table entry creation not needed [Jun 27 22:10:04]iked_peer_entry_patricia_delete:Peer entry 0x118f000 deleted for local 192.168.0.132:500 and remote 121.122.23.81:500 [Jun 27 22:10:04]Deleting p1 sa (3401922) node from IKE p1 SA P-tree [Jun 27 22:10:04]The tunnel id: 3401922 doesn't exist in P1 SA P-tree [Jun 27 22:10:04]ikev2_udp_window_uninit: Freeing transmission windows for SA 1174800 [Jun 27 22:10:04]ike_free_id_payload: Start, id type = 2 [Jun 27 22:10:04]ike_free_sa: Start [Jun 27 22:10:04]iked_deferred_free_inactive_peer_entry: Free 1 peer_entry(s) [Jun 27 22:10:05] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:10:05]VPNM tunnel (131073) ping count (11) > threshold 10, tunnel down [Jun 27 22:10:05]kmd_sa_cfg_children_sa_free: processing SA IKE-SRX [Jun 27 22:10:15] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:10:15]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:10:15]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:10:15]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:10:15]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 140 [Jun 27 22:10:15]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:10:25] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:10:25]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:10:25]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:10:25]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:10:25]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 141 [Jun 27 22:10:25]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:10:34]Triggering all tunnels [Jun 27 22:10:34]iked_pm_trigger_callback called for IKE-SRX [Jun 27 22:10:34]Triggering negotiation for IKE-SRX config block [Jun 27 22:10:34]iked_pm_trigger_callback: lookup peer entry for gateway gw_IKE-SRX, local_port=500, remote_port=500 [Jun 27 22:10:34]iked_lookup_peer_entry: Peer entry 0x0 Not FOUND for local 192.168.0.132:500 and remote 121.122.23.81:500 [Jun 27 22:10:34]iked_create_peer_entry: Created peer entry 0x118f000 for local 192.168.0.132:500 remote 121.122.23.81:500 [Jun 27 22:10:34]iked_fetch_or_create_peer_entry: Create peer entry 0x118f000 for local 192.168.0.132:500 remote 121.122.23.81:500. gw gw_IKE-SRX, VR id 0 [Jun 27 22:10:34]iked_dist_table_entry_update : Dist table entry creation not needed [Jun 27 22:10:34]iked_pm_trigger_callback: FOUND peer entry for gateway gw_IKE-SRX [Jun 27 22:10:34]iked_pm_trigger_callback need p1 lifetime <30> [Jun 27 22:10:34]Initiating new P1 SA for gateway gw_IKE-SRX [Jun 27 22:10:34]ssh_ikev2_ike_sa_allocate: Allocating IKE SA 121.122.23.81;500/4500 [Jun 27 22:10:34]chassis 0 fpc 0 pic 0 kmd-instance 0 current tunnel id 3401922 [Jun 27 22:10:34]Allocated IKE SA index 3401923, ref cnt 0 [Jun 27 22:10:34]In iked_p1_sa_patricia_tree_fpc_pic_entry_add ADDED THE PATNODEike sa index 3401923 [Jun 27 22:10:34]P1 SA 3401923 start timer. timer duration 30, reason 1. [Jun 27 22:10:34]ikev2_ike_sa_alloc_cb: Allocated IKE SA 1174800 Iccbb2010 ca85d3dd (121.122.23.81;500/4500) [Jun 27 22:10:34]ikev2_udp_window_init: Allocating transmission windows for SA 1174800 [Jun 27 22:10:34]ikev2_allocate_exchange_data: Calling exchange_data_alloc [Jun 27 22:10:34]iked_pm_ike_exchange_data_alloc: Successfully inserted pm_ed 118f200 into list for sa_cfg N/A [Jun 27 22:10:34]Exchange data allocated for IKE SA 3401923. VR 65535 [Jun 27 22:10:34]ikev2_allocate_exchange_data: Successfully allocated exchange data for SA 1174800 [Jun 27 22:10:34]ssh_ikev2_ipsec_create_sa: State = IKE_INIT_SA [Jun 27 22:10:34]ikev2_allocate_exchange_data_ike: Allocating IKE exchange data for SA 1174800 ED e1a028 [Jun 27 22:10:34]ikev2_allocate_exchange_data_ike: Successfully allocated IKE exchange data for SA 1174800 ED e1a028 [Jun 27 22:10:34]ikev2_allocate_exchange_data_ipsec: Allocating IPsec exchange data for SA 1174800 ED e1a028 [Jun 27 22:10:34]ikev2_allocate_exchange_data_ipsec: Successfully allocated IPsec exchange data for SA 1174800 ED e1a028 [Jun 27 22:10:34]ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref [Jun 27 22:10:34]Taking reference to P1 SA 3401923 to ref count 1 [Jun 27 22:10:34]iked_pm_trigger_negotiation Set p2_ed in sa_cfg=IKE-SRX [Jun 27 22:10:34]iked_peer_insert_p1sa_entry: Insert p1 sa 3401923 in peer entry 0x118f000 [Jun 27 22:10:34]iked_pm_trigger_negotiation Convert traffic selectors from V1 format to V2 format for narrowing/matching selectors [Jun 27 22:10:34]ssh_ikev2_ts_allocate: Allocated ts 0x11483e0, ref_cnt 1 [Jun 27 22:10:34]ssh_ikev2_ts_allocate: Allocated ts 0x1148420, ref_cnt 1 [Jun 27 22:10:34]ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation 1190000 (now 1 references) [Jun 27 22:10:34]ikev2_fallback_negotiation_alloc: Allocated fallback negotiation 1190000 [Jun 27 22:10:34]ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref [Jun 27 22:10:34]Taking reference to P1 SA 3401923 to ref count 2 [Jun 27 22:10:34]ssh_set_thread_debug_info: ikev2_fb_initiate_ipsec_sa: set thread debug info - local 0xc0a80084 remote 0x797a1751neg 0x1190000 neg->ike_sa 0x1174800 ike_sa 0x0 [Jun 27 22:10:34]Attach ed e1a028 to P1 SA 3401923, slot 0. op handle e1a2b8 [Jun 27 22:10:34]ikev2_reference_exchange_data: Taking reference to exchange data e1a028 (to 2) [Jun 27 22:10:34]ssh_ikev2_ts_free: ts 0x11483e0, ref_cnt 2 [Jun 27 22:10:34]ssh_ikev2_ts_free: ts 0x1148420, ref_cnt 2 [Jun 27 22:10:34]ikev2_fb_i_p1_negotiation_start: Taking reference to fallback negotiation 1190000 (now 2 references) [Jun 27 22:10:34]ssh_set_thread_debug_info: ikev2_fb_i_p1_negotiation_start: set thread debug info - local 0xc0a80084 remote 0x797a1751neg 0x1190000 neg->ike_sa 0x1174800 ike_sa 0x0 [Jun 27 22:10:34]ikev2_fb_st_i_ike_local_address_request: FB; Calling v2 policy function get_local_address_list [Jun 27 22:10:34]ikev2_fb_st_i_ike_id_request: FB; Calling v2 policy function id [Jun 27 22:10:34]ikev2_fb_id_request_cb: Local id payload is IDa(type = fqdn (2), len = 18, value = zenchowmv.ddns.net) [Jun 27 22:10:34]ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = fqdn (2), len = 18, value = zenchowmv.ddns.net) to IKEv1 ID [Jun 27 22:10:34]ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID fqdn(any:0,[0..17]=zenchowmv.ddns.net) [Jun 27 22:10:34]ikev2_fb_st_i_ike_notify_request: FB; Calling v2 policy function notify_request [Jun 27 22:10:34]iked_pm_ike_spd_notify_request Parse notification paylad in last received pkt [Jun 27 22:10:34]Parsing notification payload for local:192.168.0.132, remote:121.122.23.81 IKEv1 [Jun 27 22:10:34]iked_pm_ike_spd_notify_request: Sending Initial contact [Jun 27 22:10:34]ikev2_fb_st_i_ike_psk_request: FB; Calling v2 policy function shared_key [Jun 27 22:10:34]iked_pm_ike_pre_shared_key Start... [Jun 27 22:10:34]iked_pm_id_validate NO remote ID, skip validation. [Jun 27 22:10:34]ikev2_fb_find_pre_shared_key_cb: Found preshared key [Jun 27 22:10:34]ikev2_fb_st_i_ike_sa_request: FB; Calling v2 policy function fill_ike_sa [Jun 27 22:10:34]IKE SA fill called for negotiation of local:192.168.0.132, remote:121.122.23.81 IKEv1 [Jun 27 22:10:34]Initiator's proposing IKE SA payload SA() [Jun 27 22:10:34]ikev2_fb_st_i_conf_request: FB; Calling v2 policy function conf_request [Jun 27 22:10:34]iked_pm_ike_conf_request: enter [Jun 27 22:10:34]iked_pm_ike_conf_request: ikev1 not use config-payload [Jun 27 22:10:34]ikev2_fallback_negotiation_free: Fallback negotiation 1190000 has still 1 references [Jun 27 22:10:34]ikev2_fb_i_p1_negotiation_negotiate: Taking reference to fallback negotiation 1190000 (now 2 references) [Jun 27 22:10:34]ssh_ike_connect: Start, remote_name = 121.122.23.81:500, xchg = 4, flags = 00040000 [Jun 27 22:10:34]ike_sa_allocate_half: Start [Jun 27 22:10:34]ike_sa_allocate: Start, SA = { ccbb2010 ca85d3dd - 00000000 00000000 } [Jun 27 22:10:34]ike_init_isakmp_sa: Start, remote = 121.122.23.81:500, initiator = 1 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA: Number of proposals = 1 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0]: Number of protocols = 1 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0][0]: Number of transforms = 1 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; SA[0][0][0]: ISAKMP protocol [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encryption alg = 5 (3des-cbc) [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Group = 2, 10a0510 [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Hash alg = 2 (sha1) [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 4 (0x0004) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Life duration 28800 secs [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Auth method = 1 [Jun 27 22:10:34]ssh_ike_connect: SA = { ccbb2010 ca85d3dd - 00000000 00000000}, nego = -1 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Start isakmp sa negotiation [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Version = 1.0, Input packet fields = 0000 [Jun 27 22:10:34]ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 4, auth_method = pre shared key, Initiator [Jun 27 22:10:34]ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 [Jun 27 22:10:34]ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0 [Jun 27 22:10:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000 [Jun 27 22:10:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000 [Jun 27 22:10:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000 [Jun 27 22:10:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000 [Jun 27 22:10:34]ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000 [Jun 27 22:10:34]ike_state_step: Matched state = Start sa negotiation I (1) [Jun 27 22:10:34]ike_state_step: Calling output function[0] = ike_st_o_sa_proposal [Jun 27 22:10:34]ike_st_o_sa_proposal: Start [Jun 27 22:10:34]ike_state_step: Calling output function[1] = ike_st_o_ke [Jun 27 22:10:34]ike_st_o_ke: Start [Jun 27 22:10:34]ike_find_group_from_sa: No isakmp group defined yet [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encryption alg = 5 (3des-cbc) [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Group = 2, 10a0510 [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Hash alg = 2 (sha1) [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 4 (0x0004) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Life duration 28800 secs [Jun 27 22:10:34]ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Auth method = 1 [Jun 27 22:10:34]iked_dh_get_group: DH Group type dl-modp [Jun 27 22:10:34]iked_dh_get_group: DH Group size 1024 [Jun 27 22:10:34]iked_dh_get_group: DH Group 2 [Jun 27 22:10:34]iked_dh_generate_sync: Requested DH group 2 [Jun 27 22:10:34]iked_dh_generate: Generated DH keys using hardware for DH group 2 [Jun 27 22:10:34]juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [2898] [Jun 27 22:10:34]juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware [Jun 27 22:10:34]ike_state_step: Calling output function[2] = ike_st_o_nonce [Jun 27 22:10:34]ike_st_o_nonce: Start [Jun 27 22:10:34]ikev2_fb_isakmp_nonce_data_len: Entered [Jun 27 22:10:34]ike_policy_reply_isakmp_nonce_data_len: Start [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Nonce data[16] = 0xcba08fc6 b5b7c000 76c5701b 27ca3162 [Jun 27 22:10:34]ike_state_step: Calling output function[3] = ike_st_o_id [Jun 27 22:10:34]ike_st_o_id: Start [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encoding ID = fqdn(any:0,[0..17]=zenchowmv.ddns.net) [Jun 27 22:10:34]ike_state_step: Calling output function[4] = ike_st_o_vids [Jun 27 22:10:34]ikev2_fb_isakmp_request_vendor_ids: Request vendor ID's policy call entered, IKE SA 1174800 (neg 1190000) [Jun 27 22:10:34]ikev2_fb_isakmp_request_vendor_ids: FB; Calling v2 policy function vendor_id_request [Jun 27 22:10:34]ikev2_fb_vid_request_cb: Got a VID of length 16 (neg 1190000) [Jun 27 22:10:34]iked_pm_ike_request_vendor_id: Sending VID RFC 3706 (Dead Peer Detection) [Jun 27 22:10:34]ikev2_fb_vid_request_cb: Got a VID of length 28 (neg 1190000) [Jun 27 22:10:34]iked_pm_ike_request_vendor_id: Sending VID NetScreen Technologies [Jun 27 22:10:34]ikev2_fb_vid_request_cb: Got a VID of length 8 (neg 1190000) [Jun 27 22:10:34]iked_pm_ike_request_vendor_id: Sending VID draft-ietf-ipsra-isakmp-xauth-06.txt [Jun 27 22:10:34]ikev2_fb_vid_request_cb: No more VIDs [Jun 27 22:10:34]ike_policy_reply_isakmp_vendor_ids: Start [Jun 27 22:10:34]ike_state_step: Calling output function[5] = ike_st_o_private [Jun 27 22:10:34]ike_st_o_private: Start [Jun 27 22:10:34]ikev2_fb_private_p_1_out: Phase-I output: packet_number 1 ike_sa 1174800 (neg 1190000) [Jun 27 22:10:34]ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations [Jun 27 22:10:34]ikev2_fb_private_p_1_out: NAT traversal disabled by policy [Jun 27 22:10:34]ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request [Jun 27 22:10:34]ike_policy_reply_private_payload_out: Start [Jun 27 22:10:34]ike_state_step: All done, new state = AM SA I (10) [Jun 27 22:10:34]ike_encode_packet: Start, SA = { 0xccbb2010 ca85d3dd - 00000000 00000000 } / 00000000, nego = -1 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode packet, version = 1.0, flags = 0x00000000 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: doi = 1, sit = 0x1 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: Proposal[0] = 1 .protocol[0] = 1, # transforms = 1, spi[8] = 0xccbb2010 ca85d3dd [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: trans[0] = 0, id = 1, # sa = 6 [Jun 27 22:10:34]ssh_ike_encode_data_attribute: encode B: type = 1 (0x0001), len = 2, value = 0005 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[0], type = 1, value[2] = 0x0005 [Jun 27 22:10:34]ssh_ike_encode_data_attribute: encode B: type = 4 (0x0004), len = 2, value = 0002 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[1], type = 4, value[2] = 0x0002 [Jun 27 22:10:34]ssh_ike_encode_data_attribute: encode B: type = 2 (0x0002), len = 2, value = 0002 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[2], type = 2, value[2] = 0x0002 [Jun 27 22:10:34]ssh_ike_encode_data_attribute: encode B: type = 11 (0x000b), len = 2, value = 0001 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[3], type = 11, value[2] = 0x0001 [Jun 27 22:10:34]ssh_ike_encode_data_attribute: encode V: type = 12 (0x000c), len = 4 (0x0004), value = 00007080 ... [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[4], type = 12, value[4] = 0x00007080 [Jun 27 22:10:34]ssh_ike_encode_data_attribute: encode B: type = 3 (0x0003), len = 2, value = 0001 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode SA: da[5], type = 3, value[2] = 0x0001 [Jun 27 22:10:34]ike_encode_packet: Payload length = 64 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode KE: ke[128] = 0xecf7a3ec a46cde7d e2a85e8e 0ab37f78 b8205383 49382530 11e3ffed fc36e886 012d1c70 8 [Jun 27 22:10:34]ike_encode_packet: Payload length = 132 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode NONCE: nonce[16] = 0xcba08fc6 b5b7c000 76c5701b 27ca3162 [Jun 27 22:10:34]ike_encode_packet: Payload length = 20 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode ID: packet[22] = 0x02000000 7a656e63 686f776d 762e6464 6e732e6e 6574 [Jun 27 22:10:34]ike_encode_packet: Payload length = 26 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[16] = 0xafcad713 68a1f1c9 6b8696fc 77570100 [Jun 27 22:10:34]ike_encode_packet: Payload length = 20 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[28] = 0x69936922 8741c6d4 ca094c93 e242c9de 19e7b7c6 00000005 00000500 [Jun 27 22:10:34]ike_encode_packet: Payload length = 32 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encode VID: vendor id[8] = 0x09002689 dfd6b712 [Jun 27 22:10:34]ike_encode_packet: Payload length = 12 [Jun 27 22:10:34]ike_encode_packet: Payload length = 334 [Jun 27 22:10:34]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Encoded packet[334] = 0xccbb2010 ca85d3dd 00000000 00000000 01100400 00000000 0000014e 04000040 00000001 [Jun 27 22:10:34]ike_encode_packet: Final length = 334 [Jun 27 22:10:34]ike_send_packet: <-------- sending SA = { ccbb2010 ca85d3dd - 00000000 00000000}, len = 334, nego = -1, local ip= 192.168.0.132, dst = 121.122.23.81:500, routing table id = 0 [Jun 27 22:10:34]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:10:35] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:10:35]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:10:35]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:10:35]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:10:35]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 142 [Jun 27 22:10:35]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:10:44]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:10:44]ike_retransmit_callback: Start, retransmit SA = { ccbb2010 ca85d3dd - 00000000 00000000}, nego = -1 [Jun 27 22:10:44]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Retransmitting packet, retries = 5 [Jun 27 22:10:44]ike_send_packet: Start, retransmit previous packet SA = { ccbb2010 ca85d3dd - 00000000 00000000}, nego = -1, dst = 121.122.23.81:500 routing table id = 0 [Jun 27 22:10:44]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:10:45] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:10:45]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:10:45]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:10:45]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:10:45]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 143 [Jun 27 22:10:45]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:10:54]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:10:54]ike_retransmit_callback: Start, retransmit SA = { ccbb2010 ca85d3dd - 00000000 00000000}, nego = -1 [Jun 27 22:10:54]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Retransmitting packet, retries = 4 [Jun 27 22:10:54]ike_send_packet: Start, retransmit previous packet SA = { ccbb2010 ca85d3dd - 00000000 00000000}, nego = -1, dst = 121.122.23.81:500 routing table id = 0 [Jun 27 22:10:54]ike_send_packet: Inserting retransmission timer after 10.000000 seconds [Jun 27 22:10:55] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:10:55]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:10:55]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:10:55]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:10:55]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 144 [Jun 27 22:10:55]VPN monitor ping send via tunnel 131073 failed, err 65 [Jun 27 22:11:04]P1 SA 3401923 timer expiry. ref cnt 2, timer reason Force delete timer expired (1), flags 0x0. [Jun 27 22:11:04]iked_tunnel_event_set_for_p1_sa: Setting tunnel-event for all p2-eds for p1-sa 3401923 with event Internal Error: Unknown event (0) [Jun 27 22:11:04]iked_tunnel_event_set_for_p1_sa: Setting tunnel-event Internal Error: Unknown event (0) for P1-SA 3401923 [Jun 27 22:11:04]iked_tunnel_event_add_event_in_gw: Updating tunnel-event for gateway gw_IKE-SRX with No response from peer. Negotiation failed [Jun 27 22:11:04]iked_tunnel_event_add_event_in_gw: tunnel-event No response from peer. Negotiation failed count incremented to 26 [Jun 27 22:11:04]iked_ha_check_ike_sa_activeness_by_rg_id:RG 0 is active on this chassiss [Jun 27 22:11:04]Initiate IKE P1 SA 3401923 delete. curr ref count 2, del flags 0x3. Reason: Internal Error: Unknown event (0) [Jun 27 22:11:04]iked_pm_ike_sa_delete_done_cb: For p1 sa index 3401923, ref cnt 2, status: Error ok [Jun 27 22:11:04]ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 192.168.0.132 remote 121.122.23.81 [Jun 27 22:11:04]ike_remove_callback: Start, delete SA = { ccbb2010 ca85d3dd - 00000000 00000000}, nego = -1 [Jun 27 22:11:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Removing negotiation [Jun 27 22:11:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Connection timed out or error, calling callback [Jun 27 22:11:04]ikev2_fb_negotiation_done_isakmp: Entered IKE error code Timeout (8197), IKE SA 1174800 (neg 1190000) [Jun 27 22:11:04]ikev2_fb_i_ike_negotiation_cb: Connect IKE done callback, status Timeout (neg 1190000) [Jun 27 22:11:04]ikev2_fb_v1_encr_id_to_v2_id: Unknown IKE encryption identifier -1 [Jun 27 22:11:04]ikev2_fb_v1_hash_id_to_v2_prf_id: Unknown IKE hash alg identifier -1 [Jun 27 22:11:04]ikev2_fb_v1_hash_id_to_v2_integ_id: Unknown IKE hash alg identifier -1 [Jun 27 22:11:04]ikev2_fb_i_ike_negotiation_cb: IKE negotiation error 65540 (neg 1190000) [Jun 27 22:11:04]ikev2_fb_i_ike_negotiation_cb: FB; Calling v2 policy function ike_sa_done [Jun 27 22:11:04]iked_pm_ike_sa_done: Phase-1 failed with error (Timeout) p1_sa 3401923 [Jun 27 22:11:04] IKEv1 Error : Timeout [Jun 27 22:11:04]IPSec SA done callback. ed e1a028. status: Timed out [Jun 27 22:11:04]Detach ed e1a028 from P1 SA 3401923, slot 0. [Jun 27 22:11:04]ikev2_free_exchange_data: Freeing exchange data from SA 1174800, ED e1a028 (2) [Jun 27 22:11:04]IPSec Rekey for SPI 0x0 failed [Jun 27 22:11:04]IPSec SA done callback called for sa-cfg IKE-SRX local:192.168.0.132, remote:121.122.23.81 IKEv1 with status Timed out [Jun 27 22:11:04]ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context [Jun 27 22:11:04]ikev2_fb_negotiation_clear_pm_data: Clearing fb pm_data [Jun 27 22:11:04]ikev2_fallback_negotiation_free: Fallback negotiation 1190000 has still 1 references [Jun 27 22:11:04]ikev2_fallback_negotiation_free: Freeing fallback negotiation 1190000 [Jun 27 22:11:04]ikev2_free_exchange_data: Freeing exchange data from SA 1174800, ED e1a028 (1) [Jun 27 22:11:04]ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 1174800 [Jun 27 22:11:04]ssh_ikev2_ts_free: ts 0x11483e0, ref_cnt 1 [Jun 27 22:11:04]ssh_ikev2_ts_free: ts 0x1148420, ref_cnt 1 [Jun 27 22:11:04]ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 1174800 [Jun 27 22:11:04]ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA 1174800 [Jun 27 22:11:04]ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA 1174800 [Jun 27 22:11:04]ikev2_free_exchange_data: Calling exchange_data_free [Jun 27 22:11:04]Freeing P2 Ed for sa-cfg IKE-SRX [Jun 27 22:11:04]iked_unset_sa_cfg_p2_ed unset_sa_cfg_p2_ed, sa_cfg=IKE-SRX [Jun 27 22:11:04]iked_pm_ike_exchange_data_free: Successfully removed pm_ed 118f200 from list for sa_cfg N/A [Jun 27 22:11:04]ikev2_free_exchange_data: Successfully freed exchange data from SA 1174800 [Jun 27 22:11:04]ssh_ikev2_ike_sa_free: Calling ike_sa_free_ref [Jun 27 22:11:04]Freeing reference to P1 SA 3401923 to ref count 1 [Jun 27 22:11:04]ike_delete_negotiation: Start, SA = { ccbb2010 ca85d3dd - 00000000 00000000}, nego = -1 [Jun 27 22:11:04]192.168.0.132:500 (Initiator) <-> 121.122.23.81:500 { ccbb2010 ca85d3dd - 00000000 00000000 [-1] / 0x00000000 } Aggr; Deleting negotiation [Jun 27 22:11:04]ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table [Jun 27 22:11:04]ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table [Jun 27 22:11:04]ike_sa_delete: Start, SA = { ccbb2010 ca85d3dd - 00000000 00000000 } [Jun 27 22:11:04]ike_free_negotiation_isakmp: Start, nego = -1 [Jun 27 22:11:04]ike_free_negotiation: Start, nego = -1 [Jun 27 22:11:04]ike_free_packet: Start [Jun 27 22:11:04]ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA 1174800 is freed [Jun 27 22:11:04]ikev2_fb_isakmp_sa_freed: FB; Calling v2 policy function ike_sa_delete [Jun 27 22:11:04]IKE SA delete called for p1 sa 3401923 (ref cnt 1) local:192.168.0.132, remote:121.122.23.81, IKEv1 [Jun 27 22:11:04]P1 SA 3401923 stop timer. timer duration 30, reason 0. [Jun 27 22:11:04]iked_fail_to_backup_if_required delete p2 sa, dpd detect peer down [Jun 27 22:11:04]Freeing reference to P1 SA 3401923 to ref count 0 [Jun 27 22:11:04]iked_pm_p1_sa_destroy: p1 sa 3401923 (ref cnt 0), waiting_for_del 0x0 [Jun 27 22:11:04]iked_peer_remove_p1sa_entry: Remove p1 sa 3401923 from peer entry 0x118f000 [Jun 27 22:11:04]iked_delete_peer_entry: Requested for peer-entry 0x118f000 deletion for local 192.168.0.132:500 and remote 121.122.23.81:500 reason:236 [Jun 27 22:11:04]iked_dist_table_entry_update : Dist table entry creation not needed [Jun 27 22:11:04]iked_peer_entry_patricia_delete:Peer entry 0x118f000 deleted for local 192.168.0.132:500 and remote 121.122.23.81:500 [Jun 27 22:11:04]Deleting p1 sa (3401923) node from IKE p1 SA P-tree [Jun 27 22:11:04]The tunnel id: 3401923 doesn't exist in P1 SA P-tree [Jun 27 22:11:04]ikev2_udp_window_uninit: Freeing transmission windows for SA 1174800 [Jun 27 22:11:04]ike_free_id_payload: Start, id type = 2 [Jun 27 22:11:04]ike_free_sa: Start [Jun 27 22:11:04]iked_deferred_free_inactive_peer_entry: Free 1 peer_entry(s) [Jun 27 22:11:05] iked_vpnm_timer_callback: VPN Monitor timer kicked in [Jun 27 22:11:05]VPNM tunnel_id<131073> request from <192.168.0.132> to <121.122.23.81>, local if_idx<74>. [Jun 27 22:11:05]Get rtbl_idx=0 for ifl idx 74 [Jun 27 22:11:05]PING (121.122.23.81 via 121.122.23.81): 56 data bytes Tunnel-id:131073 outgoing intf 74, rtbl idx 0 [Jun 27 22:11:05]VPNM send ping pkt (-1/84) bytes for tunnel 131073, seq 145 [Jun 27 22:11:05]VPN monitor ping send via tunnel 131073 failed, err 65