[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Certificate valid from 2018 Jan 10th, 13:20:22 GMT to 2021 Jan 10th, 13:20:22 GMT
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_validate_certificate_expiry: Certificate is not expired
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_x509_cert_free: Decreasing reference count of certificate 12b8600 to 0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates_cb: Found 1 certificates
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_private_key: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM KE I (5)/257, exchange = 2, auth_method = signatures, Initiator
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM KE I (5)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_certs
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_certs_base: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_find_private_key: Find private key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates: Request certificates policy call entered, IKE SA 12b0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates: Returning cached certs
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_request_certificates: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[2] = ike_st_o_sig
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_sig: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_find_private_key: Find private key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group type dl-modp
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group size 1024
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group 2
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dh_compute_synch: Requested DH group 2
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Peer public key has length 128
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [2909]
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_calc_mac: Start, initiator = true, local = true
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Requested MIXED-MODE engine
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Real engine is OCTEON
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Secs [0] USecs [14909] Avg Secs [0] Avg Usecs [14806]
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[3] = ike_st_o_status_n
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_status_n: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[4] = ike_st_o_private
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 5 ike_sa 12b0000 (neg 117e000)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: NAT traversal disabled by policy
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[5] = ike_st_o_encrypt
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_encrypt: Marking encryption for packet
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM final I (7)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0xd0c6518b fb9be03e - 2b62479e eccbda43 } / 00000000, nego = -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 91
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 1003
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 260
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 28
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 1412
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 1412, mID=00000000, HDR, ID, CERT, SIG, N(INITIAL_CONTACT)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Encrypting packet
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 1412
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = -1, dst = 222.222.222.222:500
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 1692, on Interface: ge-0/0/3.0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ---------> Received from 222.222.222.222:500 to 111.111.111.111:0, VR 0, length 1692 on IF ge-0/0/3.0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: [11fd400/0]
******** Processing received ************
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43 }
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { d0c6518b fb9be03e - 2b62479e eccbda43 }
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Found IKEv1 SA
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: [11fd400/deadbeee] Packet to existing v1 SA
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Packet from 222.222.222.222:500, use_natt=0 data[0..1692] = d0c6518b fb9be03e 2b62479e eccbda43 ...
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43 } / 00000000, remote = 222.222.222.222:500
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43 }
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { d0c6518b fb9be03e - 2b62479e eccbda43 }
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43} / 00000000, nego = -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: first_payload_type:5.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Decrypting packet
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:6.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:9.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:0.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet R(<none>:500 <- 222.222.222.222:500): len= 1692, mID=00000000, HDR, ID, CERT, SIG, Vid
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM final I (7)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 2, fields = 000c / 06c0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 2, fields = 000c / 0680
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM final I (7)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[0] = ike_st_i_encrypt
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_encrypt: Check that packet was encrypted succeeded
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[1] = ike_st_i_cert
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: Entered new certificate policy call, received a certificate of encoding 4 for IKE SA 12b0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: FB; Calling v2 policy function new_certificate
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[2] = ike_st_i_id
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_id: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[3] = ike_st_i_sig
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_sig: Start, sig[0..256] = 064ff862 9f77f248 ...
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_find_public_key: Find public key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = der_asn1_dn(any
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_public_key: Find pre-shared key policy call entered, IKE SA 12b0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_public_key: Taking reference to fallback negotiation 117e000 (now 3 references)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_find_public_key: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12b0000 ike_sa 0x0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Input function[3] = ike_st_i_sig asked retry later
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_process_packet: No output packet, returning
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_destroy: [11fd400/deadbeee] Destructor
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_free: [11fd400/deadbeee] Freeing
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_remove_callback: Start, delete SA = { 68d29431 c760ceb1 - 65417261 f37f60e5}, nego = -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_delete_negotiation: Start, SA = { 68d29431 c760ceb1 - 65417261 f37f60e5}, nego = -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_delete: Start, SA = { 68d29431 c760ceb1 - 65417261 f37f60e5 }
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation_isakmp: Start, nego = -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation: Start, nego = -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA 0 is freed
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_id_payload: Start, id type = 9
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_id_payload: Start, id type = 9
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_sa: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_find_public_key: FSM_SET_NEXT:ikev2_fb_st_find_public_key_result
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_find_public_key: FB; Calling v2 policy function public_key
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_id_validate: General IKE-ID is enabled, skipping ID validation
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_policy_public_key
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 83, value = 3051310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 82, value = 3050310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..81]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPNRGVAL.COMPANY.uk)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_policy_find_public_key_send_ipc
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKED-PKID-IPC 1 cert, len1<1285> 1st<30> last<0c>
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pkid_send_packet
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_reference_exchange_data: Taking reference to exchange data efe028 (to 3)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 stop timer. timer duration 30, reason 1.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 start timer. timer duration 30, reason 1.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_public_key: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { d0c6518b fb9be03e - 2b62479e eccbda43 [-1] / 0x00000000 } IP; No public key found
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = -1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_negotiation_done_isakmp: Entered IKE error code Authentication failed (24), IKE SA 12b0000 (neg 117e000)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_ike_negotiation_cb: Connect IKE done callback, status Authentication failed (neg 117e000)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 1 references
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { d0c6518b fb9be03e - 2b62479e eccbda43 [-1] / 0x00000000 } IP; Error = Authentication failed (24)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_alloc_negotiation: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43}
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_alloc_negotiation: Found slot 0, max 1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: New informational negotiation message_id = 25c3f7ec initialized using slot 0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: Created random message id = 25c3f7ec
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: No phase 1 done, use only N or D payload
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 12 (0x000c), len = 2, value = 0001
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode V: type = 6 (0x0006), len = 19 (0x0013), value = 4e6f2070 ...
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 8 (0x0008), len = 2, value = 0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0xd0c6518b fb9be03e - 2b62479e eccbda43 } / 25c3f7ec, nego = 0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 59
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 87
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 87, mID=25c3f7ec, HDR, N(AUTHENTICATION_FAILED)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 87
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_notify: Sending notification to 222.222.222.222:500
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = 0, dst = 222.222.222.222:500
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_delete_negotiation: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = 0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation_info: Start, nego = 0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation: Start, nego = 0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: Phase I negotiation result
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: FB; Calling v2 policy function ike_sa_done
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKE negotiation fail for local:111.111.111.111, remote:222.222.222.222 IKEv1 with status: Authentication failed
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_delete_slot_table_entry Slot released msg_id<0> cookie<d0c6518bfb9be03e>
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_tunnel_event_add_event_in_gw: Updating tunnel-event for gateway 217_175_53_26_company_STG-VPN with Internal error: Internal error occurred in PKID
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_tunnel_event_add_event_in_gw: tunnel-event Internal error: Internal error occurred in PKID count incremented to 40720
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKEv1 Error : Authentication failed
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: Phase I negotiation failed, error Authentication failed (neg 117e000)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback. ed efe028. status: Authentication failed
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Detach ed efe028 from P1 SA 5897396, slot 0.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Freeing exchange data from SA 12b0000, ED efe028 (2)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IPSec Rekey for SPI 0x0 failed
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback called for sa-cfg 217_175_53_26_company_STG-VPN local:111.111.111.111, remote:222.222.222.222 IKEv1 with status Authentication failed
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: FB; Calling v2 policy function ike_sa_delete
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKE SA delete called for p1 sa 5897396 (ref cnt 2) local:111.111.111.111, remote:222.222.222.222, IKEv1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 stop timer. timer duration 30, reason 1.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Freeing reference to P1 SA 5897396 to ref count 1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 reference count is not zero (1). Delaying deletion of SA
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing fallback negotiation 117e000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Freeing exchange data from SA 12b0000, ED efe028 (1)
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 12b0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x12a8880, ref_cnt 1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x12a8960, ref_cnt 1
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 12b0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA 12b0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA 12b0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Notify call: exchange_data_free
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Freeing P2 Ed for sa-cfg 217_175_53_26_company_STG-VPN
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_unset_sa_cfg_p2_ed unset_sa_cfg_p2_ed, sa_cfg=217_175_53_26_company_STG-VPN
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 12b8200 from list for sa_cfg N/A
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Successfully freed exchange data from SA 12b0000
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing reference to IKE SA 12b0000 to ref count 0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_free: Notify call: ike_sa_free_ref
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Freeing reference to P1 SA 5897396 to ref count 0
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] No more references to IKE SA 5897396 and waiting for delete. Deleting IKE SA
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_p1_sa_destroy: p1 sa 5897396 (ref cnt 0), waiting_for_del 0x1206f80
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_peer_remove_p1sa_entry: Remove p1 sa 5897396 from peer entry 0x1279c00
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_delete_peer_entry: Requested for peer-entry 0x1279c00 deletion for local 111.111.111.111:500 and remote 222.222.222.222:500 reason:242
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dist_table_entry_update : Dist table entry creation not needed
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_peer_entry_patricia_delete:Peer entry 0x1279c00 deleted for local 111.111.111.111:500 and remote 222.222.222.222:500
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Deleting p1 sa (5897396) node from IKE p1 SA P-tree
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] The tunnel id: 5897396 doesn't exist in P1 SA P-tree
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_uninit: Uninitialising transmit window 12b0180
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_flush: Transmit window 12b0180: Flushing.
[Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_receive_window_uninit: Uninitialising receive window 12b0190
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Triggering negotiation for 217_175_53_26_company_STG-VPN config block
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_callback: lookup peer entry for gateway 217_175_53_26_company_STG-VPN, local_port=500, remote_port=500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_fetch_or_create_peer_entry: peer entry for gateway <217_175_53_26_company_STG-VPN> local 111.111.111.111:500 and remote 222.222.222.222:500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_lookup_peer_entry: Peer entry 0x0 Not FOUND for local 111.111.111.111:500 and remote 222.222.222.222:500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_create_peer_entry: Created peer entry 0x1279c00 for local 111.111.111.111:500 remote 222.222.222.222:500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_fetch_or_create_peer_entry: Create peer entry 0x1279c00 for local 111.111.111.111:500 remote 222.222.222.222:500. gw 217_175_53_26_company_STG-VPN, VR id 0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dist_table_entry_update : Dist table entry creation not needed
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_callback: FOUND peer entry for gateway 217_175_53_26_company_STG-VPN
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_callback need p1 lifetime <30>
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Initiating new P1 SA for gateway 217_175_53_26_company_STG-VPN
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_allocate: Allocating IKE SA 222.222.222.222;500/4500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] chassis 0 fpc 0 pic 0 kmd-instance 0
current tunnel id 5897396
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Allocated IKE SA index 5897397, ref cnt 0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] In iked_p1_sa_patricia_tree_fpc_pic_entry_add ADDED THE PATNODEike sa index 5897397
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 start timer. timer duration 30, reason 1.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_ike_sa_alloc_cb: Allocated IKE SA 12ae000 I60addd7f 37a39502 (222.222.222.222;500/4500)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_init: Transmit window 12ae180 initialised
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_receive_window_init: Receive window 12ae190 initialised
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_ike_sa_alloc_free_temp: Freeing temp context (222.222.222.222;500/4500)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data: Calling exchange_data_alloc
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_exchange_data_alloc: Successfully inserted pm_ed 12b8000 into list for sa_cfg N/A
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Exchange data allocated for IKE SA 5897397. VR 65535
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data: Successfully allocated exchange data for SA 12ae000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ipsec_create_sa: State = IKE_INIT_SA
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data_ike: Allocating IKE exchange data for SA 12ae000 ED efe028
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data_ike: Successfully allocated IKE exchange data for SA 12ae000 ED efe028
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data_ipsec: Allocating IPsec exchange data for SA 12ae000 ED efe028
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data_ipsec: Successfully allocated IPsec exchange data for SA 12ae000 ED efe028
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ipsec_create_sa: Taking reference to IKE SA 12ae000 to ref count 1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_take_ref: Notify call: ike_sa_take_ref
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Taking reference to P1 SA 5897397 to ref count 1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_negotiation Set p2_ed in sa_cfg=217_175_53_26_company_STG-VPN
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_peer_insert_p1sa_entry: Insert p1 sa 5897397 in peer entry 0x1279c00
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_negotiation Convert traffic selectors from V1 format to V2 format for narrowing/matching selectors
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_allocate: Allocated ts 0x1206f80, ref_cnt 1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_allocate: Allocated ts 0x12a8040, ref_cnt 1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation 117e000 (now 1 references)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation 117e000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_initiate_ipsec_sa: Taking reference to IKE SA 12ae000 to ref count 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_take_ref: Notify call: ike_sa_take_ref
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Taking reference to P1 SA 5897397 to ref count 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_initiate_ipsec_sa: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12ae000 ike_sa 0x0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Attach ed efe028 to P1 SA 5897397, slot 0. op handle efe318
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_reference_exchange_data: Taking reference to exchange data efe028 (to 2)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x1206f80, ref_cnt 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x12a8040, ref_cnt 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_start: Taking reference to fallback negotiation 117e000 (now 2 references)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_start: FSM_SET_NEXT:ikev2_fb_i_p1_negotiation_negotiate
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_i_p1_negotiation_start: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12ae000 ike_sa 0x0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_local_address_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_id_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_local_address_request: FB; Calling v2 policy function get_local_address_list
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_id_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_notify_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_id_request: FB; Calling v2 policy function id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_id_request_cb: Local id payload is IDa(type = dn (9), len = 83, value = 3051310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f6e 74692064
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 83, value = 3051310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_notify_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_psk_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_notify_request: FB; Calling v2 policy function notify_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_spd_notify_request Parse notification paylad in last received pkt
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Parsing notification payload for local:111.111.111.111, remote:222.222.222.222 IKEv1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_spd_notify_request: Sending Initial contact
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_psk_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_psk_result
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_psk_request: FB; Calling v2 policy function shared_key
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_pre_shared_key Start...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_pre_shared_key_cb: Found preshared key
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_psk_result: FSM_SET_NEXT:ikev2_fb_st_i_ike_sa_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_sa_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_sa_result
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_sa_request: FSM_SET_NEXT:ikev2_fb_st_i_conf_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_sa_request: FB; Calling v2 policy function fill_ike_sa
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKE SA fill called for negotiation of local:111.111.111.111, remote:222.222.222.222 IKEv1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Initiator's proposing IKE SA payload SA()
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_conf_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_sa_result
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_conf_request: FB; Calling v2 policy function conf_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_conf_request: enter
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_conf_request: ikev1 not use config-payload
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 1 references
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_negotiate: FSM_SET_NEXT:ikev2_fb_i_p1_negotiation_result
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_negotiate: Sending Initial Contact notification
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_negotiate: Taking reference to fallback negotiation 117e000 (now 2 references)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_connect: Start, remote_name = 222.222.222.222:500, xchg = 2, flags = 00090000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_allocate_half: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_allocate: Start, SA = { 60addd7f 37a39502 - 00000000 00000000 }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_init_isakmp_sa: Start, remote = 222.222.222.222:500, initiator = 1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 86400 (0x00015180), len = 4 (0x0004)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 3 (0x00000003), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_connect: SA = { 60addd7f 37a39502 - 00000000 00000000}, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = Start sa negotiation I (1)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[0] = ike_st_o_sa_proposal
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_sa_proposal: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_vids
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_request_vendor_ids: Request vendor ID's policy call entered, IKE SA 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_request_vendor_ids: FB; Calling v2 policy function vendor_id_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: Got a VID of length 16 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_request_vendor_id: Sending VID RFC 3706 (Dead Peer Detection)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: Got a VID of length 28 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_request_vendor_id: Sending VID NetScreen Technologies
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: Got a VID of length 8 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_request_vendor_id: Sending VID draft-ietf-ipsra-isakmp-xauth-06.txt
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: Got a VID of length 20 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_request_vendor_id: Sending VID Juniper Remote Access Head-End
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: No more VIDs
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_isakmp_vendor_ids: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[2] = ike_st_o_private
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 1 ike_sa 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: NAT traversal disabled by policy
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM SA I (3)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0x60addd7f 37a39502 - 00000000 00000000 } / 00000000, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 1 (0x0001), len = 2, value = 0005
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 4 (0x0004), len = 2, value = 0002
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 2 (0x0002), len = 2, value = 0002
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 11 (0x000b), len = 2, value = 0001
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode V: type = 12 (0x000c), len = 4 (0x0004), value = 00015180 ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 3 (0x0003), len = 2, value = 0003
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 64
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 20
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 32
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 12
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 24
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 180
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 180, mID=00000000, HDR, SA, Vid, Vid, Vid, Vid
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 180
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { 60addd7f 37a39502 - 00000000 00000000}, nego = -1, dst = 222.222.222.222:500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 108, on Interface: ge-0/0/3.0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ---------> Received from 222.222.222.222:500 to 111.111.111.111:0, VR 0, length 108 on IF ge-0/0/3.0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: [11fd800/0]
******** Processing received ************
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Not found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Failed to find IKEv1 SA for given spi
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_st_input_v1_create_sa
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_create_sa: [11fd800/0] No IKE SA for packet; requesting permission to create one.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_create_sa: FSM_SET_NEXT:ikev2_packet_st_connect_decision
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_rate_limit: Soft limit for p1 negotiation 100.Current active p1 negotiations 0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] New connection from 222.222.222.222:500 allowed
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_connect_decision: [11fd800/0] Pad allows connection
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Packet from 222.222.222.222:500, use_natt=0 data[0..108] = 60addd7f 37a39502 65b2346a 6bc6df3c ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, remote = 222.222.222.222:500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Not found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find_half: Start, SA = { 60addd7f 37a39502 - 00000000 00000000 }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find_half: Found half SA = { 60addd7f 37a39502 - 00000000 00000000 }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_get_sa: We are initiator, first response packet
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_upgrade: Start, SA = { 60addd7f 37a39502 - 00000000 00000000 } -> { ... - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c} / 00000000, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: first_payload_type:1.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:0.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_payload_sa: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_payload_sa: Found 1 proposals
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_payload_t: Start, # trans = 1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 1 (0x0001), value = 5 (0x0005), size = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 2 (0x0002), value = 2 (0x0002), size = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 4 (0x0004), value = 2 (0x0002), size = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 3 (0x0003), value = 3 (0x0003), size = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 11 (0x000b), value = 1 (0x0001), size = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size V: type = 12 (0x000c), len = 4 (0x0004), padding = 0, size = 8
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 1 (0x0001), value = 5 (0x0005), len = 2, used_bytes = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 2 (0x0002), value = 2 (0x0002), len = 2, used_bytes = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 4 (0x0004), value = 2 (0x0002), len = 2, used_bytes = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 3 (0x0003), value = 3 (0x0003), len = 2, used_bytes = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 11 (0x000b), value = 1 (0x0001), len = 2, used_bytes = 4
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode V: type = 12 (0x000c), len = 4 (0x0004), padding = 0, used_bytes = 8, value = 00015180 00000018 ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet R(<none>:500 <- 222.222.222.222:500): len= 108, mID=00000000, HDR, SA, Vid
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM SA I (3)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM SA I (3)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[0] = ike_st_i_sa_value
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_sa_value: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 86400 (0x00015180), len = 4 (0x0004)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 3 (0x00000003), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 3 (0x00000003), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 86400 (0x00015180), len = 4 (0x0004)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 3 (0x00000003), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 86400 (0x00015180), len = 4 (0x0004)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[1] = ike_st_i_cr
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cr: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[2] = ike_st_i_cert
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[3] = ike_st_i_status_n
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[4] = ike_st_i_vid
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..20] = 4048b7d5 6ebce885 ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 20, IKE SA 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[5] = ike_st_i_private
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_private: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[0] = ike_st_o_ke
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_ke: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group type dl-modp
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group size 1024
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_generate_sync: Requested DH group 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_generate: Generated DH keys using hardware for DH group 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [2905]
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_nonce
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_nonce: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_nonce_data_len: Entered
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_isakmp_nonce_data_len: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[2] = ike_st_o_cr
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_get_certificate_authorities: Get certificate authorities policy call entered, IKE SA 12ae000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_get_certificate_authorities: FB; Calling v2 policy function get_cas
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Adding CAs: enc 4 len 55
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_get_cas_kid_cb: Got 1 CA's from the policy manager
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_get_cas: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[3] = ike_st_o_private
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 3 ike_sa 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: NAT traversal disabled by policy
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM KE I (5)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0x60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 132
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 20
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 60
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 240
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 240, mID=00000000, HDR, KE, Nonce, CR
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 240
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = -1, dst = 222.222.222.222:500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_destroy: [11fd800/0] Destructor
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_free: [11fd800/0] Freeing
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 397, on Interface: ge-0/0/3.0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ---------> Received from 222.222.222.222:500 to 111.111.111.111:0, VR 0, length 397 on IF ge-0/0/3.0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: [11fdc00/0]
******** Processing received ************
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Found IKEv1 SA
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: [11fdc00/deadbeee] Packet to existing v1 SA
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Packet from 222.222.222.222:500, use_natt=0 data[0..397] = 60addd7f 37a39502 65b2346a 6bc6df3c ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, remote = 222.222.222.222:500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c} / 00000000, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: first_payload_type:4.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:10.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:7.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:7.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:0.
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet R(<none>:500 <- 222.222.222.222:500): len= 397, mID=00000000, HDR, KE, Nonce, CR, CR, Vid, Vid, Vid, Vid
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM KE I (5)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM KE I (5)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[0] = ike_st_i_nonce
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_nonce: Start, nonce[0..20] = fe1ad453 9fbd18e3 ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[1] = ike_st_i_ke
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_ke: Ke[0..128] = 1dbe9585 2de8c1cf ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[2] = ike_st_i_cr
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cr: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_certificate_request: Entered new certificate request policy call, IKE SA 12ae000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_certificate_request: FB; Calling v2 policy function new_certificate_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Received Peer CA Name Len 76 Enc 4 Total CAs 1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_certificate_request: Entered new certificate request policy call, IKE SA 12ae000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_certificate_request: FB; Calling v2 policy function new_certificate_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Received Peer CA Name Len 55 Enc 4 Total CAs 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[3] = ike_st_i_status_n
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[4] = ike_st_i_cert
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[5] = ike_st_i_vid
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = 12f5f28c 457168a9 ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..8] = 09002689 dfd6b712 ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 8, IKE SA 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = 90759377 6bc7df3c ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = 1f07f70e aa6514d3 ...
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[6] = ike_st_i_private
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_private: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[0] = ike_st_o_id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_id: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_certs
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_certs_base: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_find_private_key: Find private key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_private_key: Find find private key policy call entered, IKE SA 12ae000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_private_key: Taking reference to fallback negotiation 117e000 (now 3 references)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_find_private_key: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12ae000 ike_sa 0x0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Output function[1] = ike_st_o_certs asked retry later
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_process_packet: No output packet, returning
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_destroy: [11fdc00/deadbeee] Destructor
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_free: [11fdc00/deadbeee] Freeing
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_request_certs: FSM_SET_NEXT:ikev2_fb_st_request_certs_result
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_request_certs: FB; Calling v2 policy function get_certificates
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM certificate callback invoked
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Requesting cert-chain for cert-id company_STG_cert
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Checking CAs: enc 4 len 55
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM trusted CA 1 found in device
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM cert-chain 1 for company_STG_cert found in local database
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Adding cert: enc 4 len 998
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM: Cerificate found in local database
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Certificate valid from 2018 Jan 10th, 13:20:22 GMT to 2021 Jan 10th, 13:20:22 GMT
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_validate_certificate_expiry: Certificate is not expired
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_x509_cert_free: Decreasing reference count of certificate 12b8800 to 0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates_cb: Found 1 certificates
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_private_key: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM KE I (5)/257, exchange = 2, auth_method = signatures, Initiator
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM KE I (5)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_certs
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_certs_base: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_find_private_key: Find private key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates: Request certificates policy call entered, IKE SA 12ae000
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates: Returning cached certs
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_request_certificates: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[2] = ike_st_o_sig
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_sig: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_find_private_key: Find private key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group type dl-modp
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group size 1024
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_compute_synch: Requested DH group 2
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Peer public key has length 128
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [2691]
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_calc_mac: Start, initiator = true, local = true
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Requested MIXED-MODE engine
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Real engine is OCTEON
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Secs [0] USecs [14787] Avg Secs [0] Avg Usecs [14796]
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[3] = ike_st_o_status_n
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_status_n: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[4] = ike_st_o_private
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 5 ike_sa 12ae000 (neg 117e000)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: NAT traversal disabled by policy
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[5] = ike_st_o_encrypt
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_encrypt: Marking encryption for packet
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM final I (7)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0x60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 91
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 1003
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 260
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 28
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 1412
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 1412, mID=00000000, HDR, ID, CERT, SIG, N(INITIAL_CONTACT)
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Encrypting packet
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 1412
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = -1, dst = 222.222.222.222:500
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_remove_callback: Start, delete SA = { 38731d5e 5fd68e5a - b83fae92 7f7c2bb0}, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_delete_negotiation: Start, SA = { 38731d5e 5fd68e5a - b83fae92 7f7c2bb0}, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_delete: Start, SA = { 38731d5e 5fd68e5a - b83fae92 7f7c2bb0 }
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation_isakmp: Start, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation: Start, nego = -1
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA 0 is freed
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_id_payload: Start, id type = 9
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_id_payload: Start, id type = 9
[Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_sa: Start
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 1692, on Interface: ge-0/0/3.0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ---------> Received from 222.222.222.222:500 to 111.111.111.111:0, VR 0, length 1692 on IF ge-0/0/3.0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: [11fe000/0]
******** Processing received ************
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Found IKEv1 SA
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: [11fe000/deadbeee] Packet to existing v1 SA
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Packet from 222.222.222.222:500, use_natt=0 data[0..1692] = 60addd7f 37a39502 65b2346a 6bc6df3c ...
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, remote = 222.222.222.222:500
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c} / 00000000, nego = -1
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: first_payload_type:5.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Decrypting packet
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:6.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:9.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:0.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKEv1 packet R(<none>:500 <- 222.222.222.222:500): len= 1692, mID=00000000, HDR, ID, CERT, SIG, Vid
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM final I (7)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 2, fields = 000c / 06c0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 2, fields = 000c / 0680
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM final I (7)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[0] = ike_st_i_encrypt
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_st_i_encrypt: Check that packet was encrypted succeeded
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[1] = ike_st_i_cert
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: Entered new certificate policy call, received a certificate of encoding 4 for IKE SA 12ae000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: FB; Calling v2 policy function new_certificate
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[2] = ike_st_i_id
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_st_i_id: Start
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[3] = ike_st_i_sig
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_st_i_sig: Start, sig[0..256] = 78a42e70 986dae7b ...
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_find_public_key: Find public key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = der_asn1_dn(any
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_public_key: Find pre-shared key policy call entered, IKE SA 12ae000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_public_key: Taking reference to fallback negotiation 117e000 (now 3 references)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_find_public_key: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12ae000 ike_sa 0x0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Input function[3] = ike_st_i_sig asked retry later
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_process_packet: No output packet, returning
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_destroy: [11fe000/deadbeee] Destructor
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_free: [11fe000/deadbeee] Freeing
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_find_public_key: FSM_SET_NEXT:ikev2_fb_st_find_public_key_result
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_find_public_key: FB; Calling v2 policy function public_key
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_pm_id_validate: General IKE-ID is enabled, skipping ID validation
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_policy_public_key
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 83, value = 3051310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 82, value = 3050310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..81]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPNRGVAL.COMPANY.uk)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_policy_find_public_key_send_ipc
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKED-PKID-IPC 1 cert, len1<1285> 1st<30> last<0c>
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_pkid_send_packet
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_reference_exchange_data: Taking reference to exchange data efe028 (to 3)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 stop timer. timer duration 30, reason 1.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 start timer. timer duration 30, reason 1.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_public_key: Start
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { 60addd7f 37a39502 - 65b2346a 6bc6df3c [-1] / 0x00000000 } IP; No public key found
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = -1
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_negotiation_done_isakmp: Entered IKE error code Authentication failed (24), IKE SA 12ae000 (neg 117e000)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_ike_negotiation_cb: Connect IKE done callback, status Authentication failed (neg 117e000)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 1 references
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { 60addd7f 37a39502 - 65b2346a 6bc6df3c [-1] / 0x00000000 } IP; Error = Authentication failed (24)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_alloc_negotiation: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_alloc_negotiation: Found slot 0, max 1
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: New informational negotiation message_id = aefc9f17 initialized using slot 0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: Created random message id = aefc9f17
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: No phase 1 done, use only N or D payload
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 12 (0x000c), len = 2, value = 0001
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode V: type = 6 (0x0006), len = 19 (0x0013), value = 4e6f2070 ...
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 8 (0x0008), len = 2, value = 0000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0x60addd7f 37a39502 - 65b2346a 6bc6df3c } / aefc9f17, nego = 0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 59
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 87
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 87, mID=aefc9f17, HDR, N(AUTHENTICATION_FAILED)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 87
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_send_notify: Sending notification to 222.222.222.222:500
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = 0, dst = 222.222.222.222:500
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_delete_negotiation: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = 0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation_info: Start, nego = 0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation: Start, nego = 0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: Phase I negotiation result
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: FB; Calling v2 policy function ike_sa_done
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKE negotiation fail for local:111.111.111.111, remote:222.222.222.222 IKEv1 with status: Authentication failed
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_delete_slot_table_entry Slot released msg_id<0> cookie<60addd7f37a39502>
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_tunnel_event_add_event_in_gw: Updating tunnel-event for gateway 217_175_53_26_company_STG-VPN with Internal error: Internal error occurred in PKID
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_tunnel_event_add_event_in_gw: tunnel-event Internal error: Internal error occurred in PKID count incremented to 40721
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKEv1 Error : Authentication failed
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: Phase I negotiation failed, error Authentication failed (neg 117e000)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback. ed efe028. status: Authentication failed
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Detach ed efe028 from P1 SA 5897397, slot 0.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Freeing exchange data from SA 12ae000, ED efe028 (2)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IPSec Rekey for SPI 0x0 failed
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback called for sa-cfg 217_175_53_26_company_STG-VPN local:111.111.111.111, remote:222.222.222.222 IKEv1 with status Authentication failed
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: FB; Calling v2 policy function ike_sa_delete
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKE SA delete called for p1 sa 5897397 (ref cnt 2) local:111.111.111.111, remote:222.222.222.222, IKEv1
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 stop timer. timer duration 30, reason 1.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Freeing reference to P1 SA 5897397 to ref count 1
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 reference count is not zero (1). Delaying deletion of SA
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing fallback negotiation 117e000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Freeing exchange data from SA 12ae000, ED efe028 (1)
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 12ae000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x1206f80, ref_cnt 1
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x12a8040, ref_cnt 1
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 12ae000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA 12ae000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA 12ae000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Notify call: exchange_data_free
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Freeing P2 Ed for sa-cfg 217_175_53_26_company_STG-VPN
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_unset_sa_cfg_p2_ed unset_sa_cfg_p2_ed, sa_cfg=217_175_53_26_company_STG-VPN
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 12b8000 from list for sa_cfg N/A
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Successfully freed exchange data from SA 12ae000
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing reference to IKE SA 12ae000 to ref count 0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_free: Notify call: ike_sa_free_ref
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Freeing reference to P1 SA 5897397 to ref count 0
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] No more references to IKE SA 5897397 and waiting for delete. Deleting IKE SA
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_pm_p1_sa_destroy: p1 sa 5897397 (ref cnt 0), waiting_for_del 0x12a8980
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_peer_remove_p1sa_entry: Remove p1 sa 5897397 from peer entry 0x1279c00
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_delete_peer_entry: Requested for peer-entry 0x1279c00 deletion for local 111.111.111.111:500 and remote 222.222.222.222:500 reason:242
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_dist_table_entry_update : Dist table entry creation not needed
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_peer_entry_patricia_delete:Peer entry 0x1279c00 deleted for local 111.111.111.111:500 and remote 222.222.222.222:500
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Deleting p1 sa (5897397) node from IKE p1 SA P-tree
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] The tunnel id: 5897397 doesn't exist in P1 SA P-tree
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_uninit: Uninitialising transmit window 12ae180
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_flush: Transmit window 12ae180: Flushing.
[Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_receive_window_uninit: Uninitialising receive window 12ae190