Sep 11 14:55:03 AU-FW-01 clear-log[6711]: logfile cleared [Sep 11 14:55:18][ <-> ] *** Processing received packet from :54503 to :0, VR 0, packet len: 400, on Interface: ge-0/0/0.0 [Sep 11 14:55:18][ <-> ] ---------> Received from :54503 to :0, VR 0, length 400 on IF ge-0/0/0.0 [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_start: [11e0800/0] ******** Processing received ************ [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa [Sep 11 14:55:18][ <-> ] Failed to find IKEv1 SA for given spi [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_st_input_v1_create_sa [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_v1_create_sa: [11e0800/0] No IKE SA for packet; requesting permission to create one. [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_v1_create_sa: FSM_SET_NEXT:ikev2_packet_st_connect_decision [Sep 11 14:55:18][ <-> ] iked_pm_ike_rate_limit: Soft limit for p1 negotiation 100.Current active p1 negotiations 0 [Sep 11 14:55:18][ <-> ] New connection from :54503 allowed [Sep 11 14:55:18][ <-> ] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Sep 11 14:55:18][ <-> ] ike_udp_callback_common: Packet from :54503, use_natt=0 data[0..400] = cd7f8e7f 27f00015 00000000 00000000 ... [Sep 11 14:55:18][ <-> ] ike_get_sa: Start, SA = { cd7f8e7f 27f00015 - 00000000 00000000 } / 00000000, remote = :54503 [Sep 11 14:55:18][ <-> ] ike_get_sa: We are responder and this is initiators first packet [Sep 11 14:55:18][ <-> ] ike_cookie_create: Cookie create [Sep 11 14:55:18][ <-> ] 00000000: 8e3b 453e 644a cb77 .;E>dJ.w [Sep 11 14:55:18][ <-> ] ike_sa_allocate: Start, SA = { cd7f8e7f 27f00015 - 8e3b453e 644acb77 } [Sep 11 14:55:18][ <-> ] ike_udp_callback_common: New SA [Sep 11 14:55:18][ <-> ] ike_init_isakmp_sa: Start, remote = :54503, initiator = 0 [Sep 11 14:55:18][ <-> ] ikev2_fb_new_connection: New ISAKMP connection from remote address /54503 [Sep 11 14:55:18][ <-> ] ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation efd800 (now 1 references) [Sep 11 14:55:18][ <-> ] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation efd800 [Sep 11 14:55:18][ <-> ] ikev2_fb_p1_negotiation_allocate_sa: FSM_SET_NEXT:ikev2_fb_p1_negotiation_wait_sa_done [Sep 11 14:55:18][ <-> ] ikev2_fb_p1_negotiation_allocate_sa: Taking reference to fallback negotiation efd800 (now 2 references) [Sep 11 14:55:18][ <-> ] ikev2_fb_p1_negotiation_wait_sa_done: Suspending until the IKE SA is done (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_st_new_p1_connection_start: FSM_SET_NEXT:ikev2_fb_st_new_p1_connection_local_addresses [Sep 11 14:55:18][ <-> ] ikev2_fb_st_new_p1_connection_start: FB; Calling v2 policy function ike_sa_allocate [Sep 11 14:55:18][ <-> ] iked_pm_p1_sa_alloc: Incremented active p1 negotiations.Current active p1 negotiations 1 [Sep 11 14:55:18][ <-> ] chassis 0 fpc 0 pic 0 kmd-instance 0 current tunnel id 7353656 [Sep 11 14:55:18][ <-> ] Allocated IKE SA index 7353657, ref cnt 0 [Sep 11 14:55:18][ <-> ] P1 SA 7353657 start timer. timer duration 30, reason 1. [Sep 11 14:55:18][ <-> ] ikev2_fb_ike_sa_allocate_cb: New IKE SA allocated successfully efe000 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_ike_sa_allocate_cb: Taking reference to IKE SA efe000 to ref count 1 [Sep 11 14:55:18][ <-> ] ssh_ikev2_ike_sa_take_ref: Notify call: ike_sa_take_ref [Sep 11 14:55:18][ <-> ] Taking reference to P1 SA 7353657 to ref count 1 [Sep 11 14:55:18][ <-> ] ikev2_fb_ike_sa_allocate_cb: Taking reference to IKE SA efe000 to ref count 2 [Sep 11 14:55:18][ <-> ] ssh_ikev2_ike_sa_take_ref: Notify call: ike_sa_take_ref [Sep 11 14:55:18][ <-> ] Taking reference to P1 SA 7353657 to ref count 2 [Sep 11 14:55:18][ <-> ] iked_pm_ike_exchange_data_alloc: Successfully inserted pm_ed 127aa00 into list for sa_cfg N/A [Sep 11 14:55:18][ <-> ] Exchange data allocated for IKE SA 7353657. VR 65535 [Sep 11 14:55:18][ <-> ] ssh_isakmp_update_responder_cookie: Updating responder IKE cookie [Sep 11 14:55:18][ <-> ] ssh_isakmp_update_responder_cookie: Original IKE cookie [Sep 11 14:55:18][ <-> ] 00000000: 8e3b 453e 644a cb77 .;E>dJ.w [Sep 11 14:55:18][ <-> ] ssh_isakmp_update_responder_cookie: New IKE cookie [Sep 11 14:55:18][ <-> ] 00000000: 463d bae5 ee46 8f03 F=...F.. [Sep 11 14:55:18][ <-> ] ikev2_fb_st_new_p1_connection_local_addresses: Accepting new Phase-1 negotiation: local=:500, remote=:54503 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_st_new_p1_connection_local_addresses: FSM_SET_NEXT:ikev2_fb_st_new_p1_connection_result [Sep 11 14:55:18][ <-> ] ikev2_fb_st_new_p1_connection_local_addresses: FB; Calling v2 policy function get_local_address_list [Sep 11 14:55:18][ <-> ] ssh_isakmp_update_responder_cookie: Updating responder IKE cookie [Sep 11 14:55:18][ <-> ] ssh_isakmp_update_responder_cookie: Original IKE cookie [Sep 11 14:55:18][ <-> ] 00000000: 463d bae5 ee46 8f03 F=...F.. [Sep 11 14:55:18][ <-> ] ssh_isakmp_update_responder_cookie: New IKE cookie [Sep 11 14:55:18][ <-> ] 00000000: 463d bae5 ee46 8f03 F=...F.. [Sep 11 14:55:18][ <-> ] ikev2_fb_st_new_p1_connection_result: Accepting new Phase-1 negotiation: local=:500, remote=:54503 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fallback_negotiation_free: Fallback negotiation efd800 has still 1 references [Sep 11 14:55:18][ <-> ] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local remote [Sep 11 14:55:18][ <-> ] ike_decode_packet: Start, SA = { cd7f8e7f 27f00015 - 463dbae5 ee468f03} / 00000000, nego = -1 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute_size: decode_size B: type = 1 (0x0001), value = 7 (0x0007), size = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute_size: decode_size B: type = 14 (0x000e), value = 128 (0x0080), size = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute_size: decode_size B: type = 2 (0x0002), value = 2 (0x0002), size = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute_size: decode_size B: type = 3 (0x0003), value = 65001 (0xfde9), size = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute_size: decode_size B: type = 4 (0x0004), value = 2 (0x0002), size = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute_size: decode_size B: type = 11 (0x000b), value = 1 (0x0001), size = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute_size: decode_size B: type = 12 (0x000c), value = 28740 (0x7044), size = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute: decode B: type = 1 (0x0001), value = 7 (0x0007), len = 2, used_bytes = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute: decode B: type = 14 (0x000e), value = 128 (0x0080), len = 2, used_bytes = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute: decode B: type = 2 (0x0002), value = 2 (0x0002), len = 2, used_bytes = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute: decode B: type = 3 (0x0003), value = 65001 (0xfde9), len = 2, used_bytes = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute: decode B: type = 4 (0x0004), value = 2 (0x0002), len = 2, used_bytes = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute: decode B: type = 11 (0x000b), value = 1 (0x0001), len = 2, used_bytes = 4 [Sep 11 14:55:18][ <-> ] ssh_ike_decode_data_attribute: decode B: type = 12 (0x000c), value = 28740 (0x7044), len = 2, used_bytes = 4 [Sep 11 14:55:18][ <-> ] IKEv1 packet R(:500 <- :500): len= 400, mID=00000000, HDR, SA, Vid, Vid, Vid, Vid, KE, Nonce, ID, Vid [Sep 11 14:55:18][ <-> ] ike_state_step: Current state = Start sa negotiation R (2)/-1, exchange = 4, auth_method = any, Responder [Sep 11 14:55:18][ <-> ] ike_state_step: Matched state = Start sa negotiation R (2) [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[0] = ike_st_i_vid [Sep 11 14:55:18][ <-> ] ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ... [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA efe000 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id [Sep 11 14:55:18][ <-> ] iked_pm_ike_received_vendor_id: Received vendor-id for RFC 3706 (Dead Peer Detection) [Sep 11 14:55:18][ <-> ] ike_st_i_vid: VID[0..8] = 09002689 dfd6b712 ... [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 8, IKE SA efe000 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id [Sep 11 14:55:18][ <-> ] ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ... [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA efe000 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_check_natt_vendor_id: NAT-T vendor id [draft-ietf-ipsec-nat-t-ike-03] [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id [Sep 11 14:55:18][ <-> ] iked_pm_ike_received_vendor_id: Received vendor-id for draft-ietf-ipsec-nat-t-ike-03 [Sep 11 14:55:18][ <-> ] ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ... [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA efe000 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_check_natt_vendor_id: NAT-T vendor id [draft-ietf-ipsec-nat-t-ike-02] [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id [Sep 11 14:55:18][ <-> ] iked_pm_ike_received_vendor_id: Received vendor-id for draft-ietf-ipsec-nat-t-ike-02 [Sep 11 14:55:18][ <-> ] ike_st_i_vid: VID[0..17] = 4a4e5052 20495053 ... [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 17, IKE SA efe000 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id [Sep 11 14:55:18][ <-> ] iked_pm_ike_received_vendor_id: Received vendor-id for JNPR IPSec Client [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[1] = ike_st_i_id [Sep 11 14:55:18][ <-> ] ike_st_i_id: Start [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[2] = ike_st_i_sa_proposal [Sep 11 14:55:18][ <-> ] ike_st_i_sa_proposal: Start [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_select_sa: Select IKE SA policy call entered, IKE SA efe000 (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_isakmp_select_sa: Taking reference to fallback negotiation efd800 (now 2 references) [Sep 11 14:55:18][ <-> ] ike_state_step: Input function[2] = ike_st_i_sa_proposal asked retry later [Sep 11 14:55:18][ <-> ] ike_process_packet: No output packet, returning [Sep 11 14:55:18][ <-> ] ikev2_fb_st_select_ike_sa: FSM_SET_NEXT:ikev2_fb_st_select_ike_sa_finish [Sep 11 14:55:18][ <-> ] ikev2_fb_st_select_ike_sa: FB; Calling v2 policy function select_ike_sa [Sep 11 14:55:18][ <-> ] Search for a tunnel matching the IKE peers, local:, remote: IKEv1 [Sep 11 14:55:18][ <-> ] iked_pm_phase1_sa_cfg_lookup_by_addr: Address based phase 1 SA-CFG lookup failed for local:, remote: IKEv1 [Sep 11 14:55:18][ <-> ] iked_pm_phase1_sa_cfg_lookup_by_id called with id type 2 [Sep 11 14:55:18][ <-> ] iked_pm_sa_cfg_lookup_by_id partial match type 2 [Sep 11 14:55:18][ <-> ] iked_pm_dynamic_gw_local_addr_based_lookup: called with local ip: [Sep 11 14:55:18][ <-> ] Not doing MM check since initiator=FALSE and exch_type=4 [Sep 11 14:55:18][ <-> ] dynamic gateway match unsuccessful: [Sep 11 14:55:18][ <-> ] iked_pm_ike_spd_select_ike_sa: Setting tunnel-event IKE gateway configuration lookup failed during negotiation for P1-SA 7353657 [Sep 11 14:55:18][ <-> ] iked_pm_ike_spd_select_ike_sa failed. rc 1, error_code: No proposal chosen [Sep 11 14:55:18][ <-> ] ikev2_fb_spd_select_sa_cb: IKEv2 SA select failed with error No proposal chosen (neg efd800) [Sep 11 14:55:18][ <-> ] ike_isakmp_sa_reply: Start [Sep 11 14:55:18][ <-> ] ikev2_fallback_negotiation_free: Fallback negotiation efd800 has still 1 references [Sep 11 14:55:18][ <-> ] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local remote [Sep 11 14:55:18][ <-> ] ike_state_restart_packet: Start, restart packet SA = { cd7f8e7f 27f00015 - 463dbae5 ee468f03}, nego = -1 [Sep 11 14:55:18][ <-> ] ike_state_step: Current state = Start sa negotiation R (2)/2, exchange = 4, auth_method = any, Responder [Sep 11 14:55:18][ <-> ] ike_state_step: Matched state = Start sa negotiation R (2) [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[2] = ike_st_i_sa_proposal [Sep 11 14:55:18][ <-> ] ike_st_i_sa_proposal: Start [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[3] = ike_st_i_nonce [Sep 11 14:55:18][ <-> ] ike_st_i_nonce: Start, nonce[0..64] = dbd19318 45022a3b ... [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[4] = ike_st_i_cert [Sep 11 14:55:18][ <-> ] ike_st_i_cert: Start [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[5] = ike_st_i_hash_key [Sep 11 14:55:18][ <-> ] ike_st_i_hash_key: Start, no key_hash [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[6] = ike_st_i_ke [Sep 11 14:55:18][ <-> ] ike_st_i_ke: Ke[0..128] = 24c63f4d f118efe9 ... [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[7] = ike_st_i_cr [Sep 11 14:55:18][ <-> ] ike_st_i_cr: Start [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[8] = ike_st_i_status_n [Sep 11 14:55:18][ <-> ] ike_state_step: Calling input function[9] = ike_st_i_private [Sep 11 14:55:18][ <-> ] ike_st_i_private: Start [Sep 11 14:55:18][ <-> ] ike_state_step: Calling output function[0] = ike_st_o_sa_values [Sep 11 14:55:18][ <-> ] ike_st_o_sa_values: Start [Sep 11 14:55:18][ <-> ] ike_state_step: Output function[0] = ike_st_o_sa_values failed [Sep 11 14:55:18][ <-> ] ike_state_restart_packet: Error, send notify [Sep 11 14:55:18][ <-> ] ikev2_fb_negotiation_done_isakmp: Entered IKE error code No proposal chosen (14), IKE SA efe000 (neg efd800) [Sep 11 14:55:18][ <-> ] :500 (Responder) <-> :54503 { cd7f8e7f 27f00015 - 463dbae5 ee468f03 [-1] / 0x00000000 } Aggr; Error = No proposal chosen (14) [Sep 11 14:55:18][ <-> ] ike_init_info_exchange: No phase 1 done, use only N or D payload [Sep 11 14:55:18][ <-> ] ssh_ike_encode_data_attribute: encode B: type = 12 (0x000c), len = 2, value = 0001 [Sep 11 14:55:18][ <-> ] ssh_ike_encode_data_attribute: encode V: type = 6 (0x0006), len = 34 (0x0022), value = 436f756c ... [Sep 11 14:55:18][ <-> ] ssh_ike_encode_data_attribute: encode B: type = 8 (0x0008), len = 2, value = 0000 [Sep 11 14:55:18][ <-> ] ike_encode_packet: Start, SA = { 0xcd7f8e7f 27f00015 - 463dbae5 ee468f03 } / 78694efa, nego = 0 [Sep 11 14:55:18][ <-> ] IKEv1 packet S(:500 -> :500): len= 102, mID=78694efa, HDR, N(NO_PROPOSAL_CHOSEN) [Sep 11 14:55:18][ <-> ] ike_send_notify: Sending notification to :54503 [Sep 11 14:55:18][ <-> ] ike_send_packet: Start, send SA = { cd7f8e7f 27f00015 - 463dbae5 ee468f03}, nego = 0, dst = :54503 [Sep 11 14:55:18][ <-> ] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered [Sep 11 14:55:18][ <-> ] ikev2_fb_p1_negotiation_wait_sa_done: Phase-I negotiation is now done (neg efd800) [Sep 11 14:55:18][ <-> ] ikev2_fb_p1_negotiation_wait_sa_done: FB; Calling v2 policy function ike_sa_done [Sep 11 14:55:18][ <-> ] IKE negotiation fail for local:, remote: IKEv1 with status: No proposal chosen [Sep 11 14:55:18][ <-> ] iked_delete_slot_table_entry Slot released msg_id<0> cookie [Sep 11 14:55:18][ <-> ] iked_tunnel_event_add_event_in_gw: tunnel-event IKE gateway configuration lookup failed during negotiation count incremented to 309 [Sep 11 14:55:18][ <-> ] IKEv1 Error : No proposal chosen [Sep 11 14:55:18][ <-> ] ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context [Sep 11 14:55:18][ <-> ] ikev2_fallback_negotiation_free: Freeing fallback negotiation efd800 [Sep 11 14:55:18][ <-> ] ikev2_free_exchange_data: Notify call: exchange_data_free [Sep 11 14:55:18][ <-> ] Freeing P2 Ed for sa-cfg N/A [Sep 11 14:55:18][ <-> ] P2_ED doesn't have p1_sa pointer or peer-entry. Not calling iked_pm_reset_p2_ed_in_peer_entry_sacfgs [Sep 11 14:55:18][ <-> ] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 127aa00 from list for sa_cfg N/A [Sep 11 14:55:18][ <-> ] ikev2_fallback_negotiation_free: Freeing reference to IKE SA efe000 to ref count 1 [Sep 11 14:55:18][ <-> ] ssh_ikev2_ike_sa_free: Notify call: ike_sa_free_ref [Sep 11 14:55:18][ <-> ] Freeing reference to P1 SA 7353657 to ref count 1 [Sep 11 14:55:18][ <-> ] *** Processing received packet from :54503 to :0, VR 0, packet len: 40, on Interface: ge-0/0/0.0 [Sep 11 14:55:18][ <-> ] ---------> Received from :54503 to :0, VR 0, length 40 on IF ge-0/0/0.0 [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_start: [11e0c00/0] ******** Processing received ************ [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa [Sep 11 14:55:18][ <-> ] ike_sa_find: Found SA = { cd7f8e7f 27f00015 - 463dbae5 ee468f03 } [Sep 11 14:55:18][ <-> ] Found IKEv1 SA [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_v1_get_sa: [11e0c00/deadbeee] Packet to existing v1 SA [Sep 11 14:55:18][ <-> ] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start [Sep 11 14:55:18][ <-> ] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library [Sep 11 14:55:18][ <-> ] ike_udp_callback_common: Packet from :54503, use_natt=0 data[0..40] = cd7f8e7f 27f00015 463dbae5 ee468f03 ... [Sep 11 14:55:18][ <-> ] ike_get_sa: Start, SA = { cd7f8e7f 27f00015 - 463dbae5 ee468f03 } / 28b89779, remote = :54503 [Sep 11 14:55:18][ <-> ] ike_sa_find: Found SA = { cd7f8e7f 27f00015 - 463dbae5 ee468f03 } [Sep 11 14:55:18][ <-> ] ike_udp_callback_common: New informational negotiation message_id = 28b89779 initialized using slot 0 [Sep 11 14:55:18][ <->