[May 12 22:46:44]ikev2_packet_allocate: Allocated packet db4400 from freelist
[May 12 22:46:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 00000000 00000000 } / 00000000, remote = 10.90.3.53:500
[May 12 22:46:44]ike_sa_allocate: Start, SA = { d2212b4a bf2e3dca - e37dc164 392f36bc }
[May 12 22:46:44]ike_init_isakmp_sa: Start, remote = 10.90.3.53:500, initiator = 0
[May 12 22:46:44]ike_decode_packet: Start
[May 12 22:46:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 00000000, nego = -1
[May 12 22:46:44]ike_decode_payload_sa: Start
[May 12 22:46:44]ike_decode_payload_t: Start, # trans = 1
[May 12 22:46:44]ike_st_i_vid: VID[0..8] = 09002689 dfd6b712 ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = 16f6ca16 e4a4066d ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = 3b9031dc e4fcf88b ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = f14b94b7 bff1fef0 ...
[May 12 22:46:44]ike_st_i_vid: VID[0..20] = 166f932d 55eb64d8 ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = 8404adf9 cda05760 ...
[May 12 22:46:44]ike_st_i_vid: VID[0..16] = 12f5f28c 457168a9 ...
[May 12 22:46:44]ike_st_i_vid: VID[0..40] = f4ed19e0 c114eb51 ...
[May 12 22:46:44]ike_st_i_id: Start
[May 12 22:46:44]ike_st_i_sa_proposal: Start
[May 12 22:46:44]ike_free_id_payload: Start, id type = 2
[May 12 22:46:44]Gateway t400-ike-gw: number of connections=0, limit=50
[May 12 22:46:44]ike_isakmp_sa_reply: Start
[May 12 22:46:44]ike_state_restart_packet: Start, restart packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1
[May 12 22:46:44]ike_st_i_sa_proposal: Start
[May 12 22:46:44]ike_st_i_nonce: Start, nonce[0..20] = 17ae63ae 45e3c62f ...
[May 12 22:46:44]ike_st_i_cert: Start
[May 12 22:46:44]ike_st_i_hash_key: Start, no key_hash
[May 12 22:46:44]ike_st_i_ke: Ke[0..128] = fa8eea0f b5f74226 ...
[May 12 22:46:44]ike_st_i_cr: Start
[May 12 22:46:44]ike_st_i_private: Start
[May 12 22:46:44]ike_st_o_sa_values: Start
[May 12 22:46:44]ike_st_o_ke: Start
[May 12 22:46:44]ike_st_o_nonce: Start
[May 12 22:46:44]ike_policy_reply_isakmp_nonce_data_len: Start
[May 12 22:46:44]ike_st_o_id: Start
[May 12 22:46:44]ike_policy_reply_isakmp_id: Start
[May 12 22:46:44]ike_state_restart_packet: Start, restart packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1
[May 12 22:46:44]ike_st_o_id: Start
[May 12 22:46:44]ike_st_o_certs_base: Start
[May 12 22:46:44]ike_st_o_sig_or_hash: Start, auth_method = 4
[May 12 22:46:44]ike_st_o_hash: Start
[May 12 22:46:44]ike_find_pre_shared_key: Find pre shared key key for 10.90.3.25:500, id = ipv4(any:0,[0..3]=10.90.3.25) -> 10.90.3.53:500, id = fqdn(any:0,[0..14]=vpn.example.com)
[May 12 22:46:44]Gateway t400-ike-gw: number of connections=0, limit=50
[May 12 22:46:44]ike_policy_reply_find_pre_shared_key: Start
[May 12 22:46:44]ike_state_restart_packet: Start, restart packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1
[May 12 22:46:44]ike_st_o_sig_or_hash: Start, auth_method = 4
[May 12 22:46:44]ike_st_o_hash: Start
[May 12 22:46:44]ike_find_pre_shared_key: Find pre shared key key for 10.90.3.25:500, id = ipv4(any:0,[0..3]=10.90.3.25) -> 10.90.3.53:500, id = fqdn(any:0,[0..14]=vpn.example.com)
[May 12 22:46:44]ike_calc_mac: Start, initiator = false, local = true
[May 12 22:46:44]ike_policy_reply_isakmp_vendor_ids: Start
[May 12 22:46:44]ike_st_o_status_n: Start
[May 12 22:46:44]ike_st_o_private: Start
[May 12 22:46:44]ike_policy_reply_private_payload_out: Start
[May 12 22:46:44]ike_policy_reply_private_payload_out: Start
[May 12 22:46:44]ike_policy_reply_private_payload_out: Start
[May 12 22:46:44]ike_st_o_calc_skeyid: Calculating skeyid
[May 12 22:46:44]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / 00000000, nego = -1
[May 12 22:46:44]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:46:44]ikev2_packet_allocate: Allocated packet db4800 from freelist
[May 12 22:46:44]ikev2_packet_allocate: Allocated packet db4c00 from freelist
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / 5a228a12, remote = 10.90.3.53:500
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:44]ike_decode_packet: Start
[May 12 22:46:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 5a228a12, nego = 0
[May 12 22:46:44]<none>:500 (Responder) <-> 10.90.3.53:500 { d2212b4a bf2e3dca - 33beba3f 9273a105 [0] / 0x5a228a12 } Info; Trying to decrypt, but no decryption context initialized
[May 12 22:46:44]<none>:500 (Responder) <-> 10.90.3.53:500 { d2212b4a bf2e3dca - 33beba3f 9273a105 [0] / 0x5a228a12 } Info; Error = No SA established (8194)
[May 12 22:46:44]ike_send_notify: Notification to informational exchange ignored
[May 12 22:46:44]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 0
[May 12 22:46:44]ike_free_negotiation_info: Start, nego = 0
[May 12 22:46:44]ike_free_negotiation: Start, nego = 0
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / 00000000, remote = 10.90.3.53:500
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ike_decode_packet: Start
[May 12 22:46:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 00000000, nego = -1
[May 12 22:46:44]ike_st_i_hash: Start, hash[0..16] = e41c121a 1354dd7a ...
[May 12 22:46:44]ike_calc_mac: Start, initiator = false, local = false
[May 12 22:46:44]ike_st_i_cert: Start
[May 12 22:46:44]ike_st_i_private: Start
[May 12 22:46:44]ike_st_o_wait_done: Marking for waiting for done
[May 12 22:46:44]ike_st_o_all_done: MESSAGE: Phase 1 { 0xd2212b4a bf2e3dca - 0x33beba3f 9273a105 } / 00000000, version = 1.0, xchg = Aggressive, auth_method = Pre shared keys with XAuth (initiator), Responder, cipher = 3des-cbc, hash = md5,
[May 12 22:46:44]10.90.3.25:500 (Responder) <-> 10.90.3.53:500 { d2212b4a bf2e3dca - 33beba3f 9273a105 [-1] / 0x00000000 } Aggr; MESSAGE: Phase 1 version = 1.0, auth_method = Pre shared keys with XAuth (initiator), cipher = 3des-cbc, hash =
[May 12 22:46:44]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1
[May 12 22:46:44]iked_pm_ike_sa_done: local:10.90.3.25, remote:10.90.3.53 IKEv1
[May 12 22:46:44]IKE negotiation done for local:10.90.3.25, remote:10.90.3.53 IKEv1 with status: Error ok
[May 12 22:46:44]ssh_ike_connect_cfg: Start, remote_name = :500, flags = 00008000
[May 12 22:46:44]ike_sa_find_ip_port: Remote = all:500, Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:44]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:44]ssh_ike_connect_cfg: SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 0
[May 12 22:46:44]ike_init_cfg_negotiation: Start, initiator = 1, message_id = 121320f6
[May 12 22:46:44]ike_st_o_gen_hash: Start
[May 12 22:46:44]ike_st_o_cfg_attr: Start
[May 12 22:46:44]ike_st_o_private: Start
[May 12 22:46:44]ike_policy_reply_private_payload_out: Start
[May 12 22:46:44]ike_st_o_encrypt: Marking encryption for packet
[May 12 22:46:44]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / 121320f6, nego = 0
[May 12 22:46:44]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 0, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:46:44]ikev2_packet_allocate: Allocated packet db5000 from freelist
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / 121320f6, remote = 10.90.3.53:500
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ike_st_o_done: ISAKMP SA negotiation done
[May 12 22:46:44]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1
[May 12 22:46:44]ike_free_negotiation_isakmp: Start, nego = -1
[May 12 22:46:44]ike_free_negotiation: Start, nego = -1
[May 12 22:46:44]ike_decode_packet: Start
[May 12 22:46:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 121320f6, nego = 0
[May 12 22:46:44]ike_decode_payload_attr: Start
[May 12 22:46:44]ike_st_i_encrypt: Check that packet was encrypted succeeded
[May 12 22:46:44]ike_st_i_gen_hash: Start, hash[0..16] = 4fa7c8ae 44e6009c ...
[May 12 22:46:44]ike_st_i_cfg_attr: Start
[May 12 22:46:44]ike_st_i_private: Start
[May 12 22:46:44]ike_st_o_cfg_wait_done: Marking for waiting for done
[May 12 22:46:44]ike_st_o_cfg_wait_done: MESSAGE: CFG Mode wait done
[May 12 22:46:44]<none>:500 (Initiator) <-> 10.90.3.53:500 { d2212b4a bf2e3dca - 33beba3f 9273a105 [0] / 0x121320f6 } CFG; MESSAGE: CFG Mode wait done
[May 12 22:46:44]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 0
[May 12 22:46:44]iked_deferred_free_inactive_peer_entry: Free 1 peer_entry(s)
[May 12 22:46:44]ssh_ike_connect_cfg: Start, remote_name = :500, flags = 00008000
[May 12 22:46:44]ike_sa_find_ip_port: Remote = all:500, Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:44]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:44]ssh_ike_connect_cfg: SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:46:44]ike_init_cfg_negotiation: Start, initiator = 1, message_id = 73577dcd
[May 12 22:46:44]ike_st_o_gen_hash: Start
[May 12 22:46:44]ike_st_o_cfg_attr: Start
[May 12 22:46:44]ike_st_o_private: Start
[May 12 22:46:44]ike_policy_reply_private_payload_out: Start
[May 12 22:46:44]ike_st_o_encrypt: Marking encryption for packet
[May 12 22:46:44]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / 73577dcd, nego = 1
[May 12 22:46:44]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:46:44]ikev2_packet_allocate: Allocated packet db5400 from freelist
[May 12 22:46:44]ikev2_packet_allocate: Allocated packet db5800 from freelist
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / 73577dcd, remote = 10.90.3.53:500
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ike_decode_packet: Start
[May 12 22:46:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 73577dcd, nego = 1
[May 12 22:46:44]ike_decode_payload_attr: Start
[May 12 22:46:44]ike_st_i_encrypt: Check that packet was encrypted succeeded
[May 12 22:46:44]ike_st_i_gen_hash: Start, hash[0..16] = 8227a88e 22fb5f43 ...
[May 12 22:46:44]ike_st_i_cfg_attr: Start
[May 12 22:46:44]ike_st_i_private: Start
[May 12 22:46:44]ike_st_o_cfg_wait_done: Marking for waiting for done
[May 12 22:46:44]ike_st_o_cfg_wait_done: MESSAGE: CFG Mode wait done
[May 12 22:46:44]<none>:500 (Initiator) <-> 10.90.3.53:500 { d2212b4a bf2e3dca - 33beba3f 9273a105 [1] / 0x73577dcd } CFG; MESSAGE: CFG Mode wait done
[May 12 22:46:44]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / 73577dcd, remote = 10.90.3.53:500
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ike_decode_packet: Start
[May 12 22:46:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 73577dcd, nego = 1
[May 12 22:46:44]ike_decode_payload_attr: Start
[May 12 22:46:44]ike_st_o_cfg_done: CFG negotiation done
[May 12 22:46:44]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:46:44]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:46:44]ike_free_negotiation_cfg: Start, nego = 1
[May 12 22:46:44]ike_free_negotiation: Start, nego = 1
[May 12 22:46:44]ssh_ike_connect_cfg: Start, remote_name = :500, flags = 00008000
[May 12 22:46:44]ike_sa_find_ip_port: Remote = all:500, Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:44]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:44]ssh_ike_connect_cfg: SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:46:44]ike_init_cfg_negotiation: Start, initiator = 1, message_id = 32e1b892
[May 12 22:46:44]ike_st_o_gen_hash: Start
[May 12 22:46:44]ike_st_o_cfg_attr: Start
[May 12 22:46:44]ike_st_o_private: Start
[May 12 22:46:44]ike_policy_reply_private_payload_out: Start
[May 12 22:46:44]ike_st_o_encrypt: Marking encryption for packet
[May 12 22:46:44]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / 32e1b892, nego = 1
[May 12 22:46:44]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:46:44]ikev2_packet_allocate: Allocated packet db5c00 from freelist
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / a7c3bbbd, remote = 10.90.3.53:500
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:44]ike_init_qm_negotiation: Start, initiator = 0, message_id = a7c3bbbd
[May 12 22:46:44]ike_decode_packet: Start
[May 12 22:46:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / a7c3bbbd, nego = 2
[May 12 22:46:44]ike_decode_payload_sa: Start
[May 12 22:46:44]ike_decode_payload_t: Start, # trans = 1
[May 12 22:46:44]ike_st_i_encrypt: Check that packet was encrypted succeeded
[May 12 22:46:44]ike_st_i_qm_hash_1: Start, hash[0..16] = 10298a9e 0ea323ca ...
[May 12 22:46:44]ike_st_i_qm_nonce: Nonce[0..20] = 317c6a55 90d633eb ...
[May 12 22:46:44]ike_st_i_qm_sa_proposals: Start
[May 12 22:46:44]Added (spi=0xba2670b1, protocol=0) entry to the spi table
[May 12 22:46:44]Added (spi=0x61858014, protocol=0) entry to the spi table
[May 12 22:46:44]ike_qm_sa_reply: Start
[May 12 22:46:44]ike_qm_sa_reply: Selected proposal 0, and transform 0 for protocol 0
[May 12 22:46:44]ike_state_restart_packet: Start, restart packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 2
[May 12 22:46:44]ike_st_i_qm_sa_proposals: Start
[May 12 22:46:44]ike_st_i_private: Start
[May 12 22:46:44]ike_st_o_qm_hash_2: Start
[May 12 22:46:44]ike_st_o_qm_sa_values: Start
[May 12 22:46:44]ike_st_o_qm_nonce: Start
[May 12 22:46:44]ike_policy_reply_qm_nonce_data_len: Start
[May 12 22:46:44]ike_st_o_qm_optional_ke: Start
[May 12 22:46:44]ike_st_o_qm_optional_ids: Start
[May 12 22:46:44]ikev2_fb_qm_local_id: Using ipv4_subnet(any:0,[0..7]=0.0.0.0/0) as local QM identity
[May 12 22:46:44]ike_policy_reply_qm_local_id: Start
[May 12 22:46:44]ikev2_fb_qm_remote_id: Using ipv4(any:0,[0..3]=44.128.0.13) as remote QM identity
[May 12 22:46:44]ike_policy_reply_qm_remote_id: Start
[May 12 22:46:44]ike_st_qm_optional_id: Start
[May 12 22:46:44]ike_st_qm_optional_id: Start
[May 12 22:46:44]ike_st_o_qm_optional_responder_lifetime_n: Start
[May 12 22:46:44]ike_st_o_private: Start
[May 12 22:46:44]Construction NHTB payload for  local:10.90.3.25, remote:10.90.3.53 IKEv1 P1 SA index 5598114 sa-cfg INSTANCE-t400-vpn_0002_0004_0000
[May 12 22:46:44]Not route based VPN. Not sending NHTB notify payload for sa-cfg INSTANCE-t400-vpn_0002_0004_0000
[May 12 22:46:44]ike_policy_reply_private_payload_out: Start
[May 12 22:46:44]ike_st_o_encrypt: Marking encryption for packet
[May 12 22:46:44]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / a7c3bbbd, nego = 2
[May 12 22:46:44]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 2, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:46:44]ikev2_packet_allocate: Allocated packet db6000 from freelist
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / a7c3bbbd, remote = 10.90.3.53:500
[May 12 22:46:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:44]ike_decode_packet: Start
[May 12 22:46:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / a7c3bbbd, nego = 2
[May 12 22:46:44]ike_st_i_encrypt: Check that packet was encrypted succeeded
[May 12 22:46:44]ike_st_i_qm_hash_3: Start, hash[0..16] = 207a4850 1bef48a0 ...
[May 12 22:46:44]ike_st_i_private: Start
[May 12 22:46:44]<none>:500 (Responder) <-> 10.90.3.53:500 { d2212b4a bf2e3dca - 33beba3f 9273a105 [2] / 0xa7c3bbbd } QM; MESSAGE: Phase 2 connection succeeded, No PFS, group = 0
[May 12 22:46:44]ike_qm_call_callback: MESSAGE: Phase 2 connection succeeded, No PFS, group = 0
[May 12 22:46:44]<none>:500 (Responder) <-> 10.90.3.53:500 { d2212b4a bf2e3dca - 33beba3f 9273a105 [2] / 0xa7c3bbbd } QM; MESSAGE: SA[0][0] = ESP aes, life = 0 kB/28800 sec, group = 0, tunnel, hmac-sha1-96, Extended seq not used, key len = 
[May 12 22:46:44]ike_qm_call_callback: MESSAGE: SA[0][0] = ESP aes, life = 0 kB/28800 sec, group = 0, tunnel, hmac-sha1-96, Extended seq not used, key len = 256, key rounds = 0
[May 12 22:46:44]iked_pm_ipsec_sa_install: local:10.90.3.25, remote:10.90.3.53  IKEv1 for SA-CFG INSTANCE-t400-vpn_0002_0004_0000
[May 12 22:46:44]iked_dialup_ipsec_sa_install: Created new SA-CFG (instance-INSTANCE-t400-vpn_0002_0004_0000_268173330) for xauth user tepafray remote-id vpn.example.com for peer 10.90.3.53:500 
[May 12 22:46:44]In iked_sa_config_install Adding GENCFG msg with key; Tunnel = 268173330, SPI-In = 0x0
[May 12 22:46:44]Successfully added SA Config
[May 12 22:46:44]Added (spi=0xba2670b1, protocol=ESP dst=10.90.3.25) entry to the peer hash table
[May 12 22:46:44]Added (spi=0x235d97e, protocol=ESP dst=10.90.3.53) entry to the peer hash table
[May 12 22:46:44]Hardlife timer started for inbound instance-INSTANCE-t400-vpn_0002_0004_0000_268173330 with 28800 seconds/0 kilobytes
[May 12 22:46:44]Softlife timer started for inbound instance-INSTANCE-t400-vpn_0002_0004_0000_268173330 with 28209 seconds/0 kilobytes
[May 12 22:46:44]In iked_ipsec_sa_pair_add Adding GENCFG msg with key; Tunnel = 268173330;SPI-In = 0xba2670b1
[May 12 22:46:44]Added dependency on SA config blob with tunnelid = 268173330
[May 12 22:46:44]Successfully added ipsec SA PAIR
[May 12 22:46:44]ike_st_o_qm_wait_done: Marking for waiting for done
[May 12 22:46:44]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 2
[May 12 22:46:44]IPSec  negotiation done successfully for SA-CFG INSTANCE-t400-vpn_0002_0004_0000 for local:10.90.3.25, remote:10.90.3.53  IKEv1 
[May 12 22:46:54]ike_retransmit_callback: Start, retransmit SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:46:54]ike_send_packet: Start, retransmit previous packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1, dst = 10.90.3.53:500 routing table id = 0
[May 12 22:46:59]ikev2_packet_allocate: Allocated packet db6400 from freelist
[May 12 22:46:59]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:59]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:46:59]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / 6252a2f5, remote = 10.90.3.53:500
[May 12 22:46:59]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:46:59]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:59]ike_decode_packet: Start
[May 12 22:46:59]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 6252a2f5, nego = 3
[May 12 22:46:59]ike_st_i_encrypt: Check that packet was encrypted succeeded
[May 12 22:46:59]ike_st_i_gen_hash: Start, hash[0..16] = 5595ae22 d457d93f ...
[May 12 22:46:59]ike_st_i_n: Start, doi = 1, protocol = 1, code = DPD Are You There (36136), spi[0..16] = d2212b4a bf2e3dca ..., data[0..4] = 31a377cc 00000000 ...
[May 12 22:46:59]ssh_ike_connect_notify: Start, remote_name = :500, flags = 00010000
[May 12 22:46:59]ike_sa_find_ip_port: Remote = all:500, Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:59]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:46:59]ssh_ike_connect_notify: SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4
[May 12 22:46:59]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / 3d2b40fc, nego = 4
[May 12 22:46:59]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:46:59]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4
[May 12 22:46:59]ike_free_negotiation_info: Start, nego = 4
[May 12 22:46:59]ike_free_negotiation: Start, nego = 4
[May 12 22:46:59]ike_st_i_private: Start
[May 12 22:46:59]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 3
[May 12 22:46:59]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 3
[May 12 22:46:59]ike_free_negotiation_info: Start, nego = 3
[May 12 22:46:59]ike_free_negotiation: Start, nego = 3
[May 12 22:47:04]ike_retransmit_callback: Start, retransmit SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:47:04]ike_send_packet: Start, retransmit previous packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1, dst = 10.90.3.53:500 routing table id = 0
[May 12 22:47:14]ikev2_packet_allocate: Allocated packet db6800 from freelist
[May 12 22:47:14]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:47:14]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:47:14]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / f07588a6, remote = 10.90.3.53:500
[May 12 22:47:14]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:47:14]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:14]ike_decode_packet: Start
[May 12 22:47:14]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / f07588a6, nego = 3
[May 12 22:47:14]ike_st_i_encrypt: Check that packet was encrypted succeeded
[May 12 22:47:14]ike_st_i_gen_hash: Start, hash[0..16] = f43889fe 000be71d ...
[May 12 22:47:14]ike_st_i_n: Start, doi = 1, protocol = 1, code = DPD Are You There (36136), spi[0..16] = d2212b4a bf2e3dca ..., data[0..4] = 31a377cd 00000000 ...
[May 12 22:47:14]ssh_ike_connect_notify: Start, remote_name = :500, flags = 00010000
[May 12 22:47:14]ike_sa_find_ip_port: Remote = all:500, Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:14]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:14]ssh_ike_connect_notify: SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4
[May 12 22:47:14]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / ea1d952d, nego = 4
[May 12 22:47:14]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:47:14]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4
[May 12 22:47:14]ike_free_negotiation_info: Start, nego = 4
[May 12 22:47:14]ike_free_negotiation: Start, nego = 4
[May 12 22:47:14]ike_st_i_private: Start
[May 12 22:47:14]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 3
[May 12 22:47:14]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 3
[May 12 22:47:14]ike_free_negotiation_info: Start, nego = 3
[May 12 22:47:14]ike_free_negotiation: Start, nego = 3
[May 12 22:47:14]ike_retransmit_callback: Start, retransmit SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:47:14]ike_send_packet: Start, retransmit previous packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1, dst = 10.90.3.53:500 routing table id = 0
[May 12 22:47:24]ike_retransmit_callback: Start, retransmit SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:47:24]ike_send_packet: Start, retransmit previous packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1, dst = 10.90.3.53:500 routing table id = 0
[May 12 22:47:29]ikev2_packet_allocate: Allocated packet db6c00 from freelist
[May 12 22:47:29]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:47:29]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:47:29]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / 8e457297, remote = 10.90.3.53:500
[May 12 22:47:29]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:47:29]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:29]ike_decode_packet: Start
[May 12 22:47:29]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 8e457297, nego = 3
[May 12 22:47:29]ike_st_i_encrypt: Check that packet was encrypted succeeded
[May 12 22:47:29]ike_st_i_gen_hash: Start, hash[0..16] = a3cad948 2e5af2d9 ...
[May 12 22:47:29]ike_st_i_n: Start, doi = 1, protocol = 1, code = DPD Are You There (36136), spi[0..16] = d2212b4a bf2e3dca ..., data[0..4] = 31a377ce 00000000 ...
[May 12 22:47:29]ssh_ike_connect_notify: Start, remote_name = :500, flags = 00010000
[May 12 22:47:29]ike_sa_find_ip_port: Remote = all:500, Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:29]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:29]ssh_ike_connect_notify: SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4
[May 12 22:47:29]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / 36108ed5, nego = 4
[May 12 22:47:29]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:47:29]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4
[May 12 22:47:29]ike_free_negotiation_info: Start, nego = 4
[May 12 22:47:29]ike_free_negotiation: Start, nego = 4
[May 12 22:47:29]ike_st_i_private: Start
[May 12 22:47:29]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 3
[May 12 22:47:29]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 3
[May 12 22:47:29]ike_free_negotiation_info: Start, nego = 3
[May 12 22:47:29]ike_free_negotiation: Start, nego = 3
[May 12 22:47:34]ike_retransmit_callback: Start, retransmit SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:47:34]ike_send_packet: Start, retransmit previous packet SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1, dst = 10.90.3.53:500 routing table id = 0
[May 12 22:47:44]ikev2_packet_allocate: Allocated packet db7000 from freelist
[May 12 22:47:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:47:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[May 12 22:47:44]ike_get_sa: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 } / 3bd7cb83, remote = 10.90.3.53:500
[May 12 22:47:44]ike_sa_find: Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:47:44]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:44]ike_decode_packet: Start
[May 12 22:47:44]ike_decode_packet: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105} / 3bd7cb83, nego = 3
[May 12 22:47:44]ike_st_i_encrypt: Check that packet was encrypted succeeded
[May 12 22:47:44]ike_st_i_gen_hash: Start, hash[0..16] = effbd078 53454f3b ...
[May 12 22:47:44]ike_st_i_n: Start, doi = 1, protocol = 1, code = DPD Are You There (36136), spi[0..16] = d2212b4a bf2e3dca ..., data[0..4] = 31a377cf 00000000 ...
[May 12 22:47:44]ssh_ike_connect_notify: Start, remote_name = :500, flags = 00010000
[May 12 22:47:44]ike_sa_find_ip_port: Remote = all:500, Found SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:44]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:44]ssh_ike_connect_notify: SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4
[May 12 22:47:44]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / 17082faa, nego = 4
[May 12 22:47:44]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:47:44]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 4
[May 12 22:47:44]ike_free_negotiation_info: Start, nego = 4
[May 12 22:47:44]ike_free_negotiation: Start, nego = 4
[May 12 22:47:44]ike_st_i_private: Start
[May 12 22:47:44]ike_send_notify: Connected, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 3
[May 12 22:47:44]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 3
[May 12 22:47:44]ike_free_negotiation_info: Start, nego = 3
[May 12 22:47:44]ike_free_negotiation: Start, nego = 3
[May 12 22:47:44]ike_retransmit_callback: Start, retransmit SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:47:44]ike_retransmit_callback: Isakmp query retry limit reached, deleting
[May 12 22:47:44]<none>:500 (Initiator) <-> 10.90.3.53:500 { d2212b4a bf2e3dca - 33beba3f 9273a105 [1] / 0x32e1b892 } CFG; Error = Timeout (8197)
[May 12 22:47:44]ike_send_notify: Private notification, do not send notification
[May 12 22:47:44]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:47:44]ike_free_negotiation_cfg: Start, nego = 1
[May 12 22:47:44]ike_free_negotiation: Start, nego = 1
[May 12 22:47:44]iked_pm_ike_sa_delete_notify_done_cb: For p1 sa index 5598114, ref cnt 2, status: Error ok
[May 12 22:47:44]ike_expire_callback: Start, expire SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1
[May 12 22:47:44]ike_alloc_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}
[May 12 22:47:44]ike_encode_packet: Start, SA = { 0xd2212b4a bf2e3dca - 33beba3f 9273a105 } / 15029041, nego = 1
[May 12 22:47:44]ike_send_packet: Start, send SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1, dst = 10.90.3.53:500,  routing table id = 0
[May 12 22:47:44]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = 1
[May 12 22:47:44]ike_free_negotiation_info: Start, nego = 1
[May 12 22:47:44]ike_free_negotiation: Start, nego = 1
[May 12 22:47:44]ike_remove_callback: Start, delete SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1
[May 12 22:47:44]ike_delete_negotiation: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105}, nego = -1
[May 12 22:47:44]ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
[May 12 22:47:44]ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table
[May 12 22:47:44]ike_sa_delete: Start, SA = { d2212b4a bf2e3dca - 33beba3f 9273a105 }
[May 12 22:47:44]ike_free_negotiation_cfg: Start, nego = 0
[May 12 22:47:44]ike_free_negotiation: Start, nego = 0
[May 12 22:47:44]ike_free_negotiation_qm: Start, nego = 2
[May 12 22:47:44]ike_free_negotiation: Start, nego = 2
[May 12 22:47:44]ike_free_id_payload: Start, id type = 4
[May 12 22:47:44]ike_free_id_payload: Start, id type = 4
[May 12 22:47:44]ike_free_id_payload: Start, id type = 1
[May 12 22:47:44]ike_free_id_payload: Start, id type = 1
[May 12 22:47:44]ike_free_negotiation_isakmp: Start, nego = -1
[May 12 22:47:44]ike_free_negotiation: Start, nego = -1
[May 12 22:47:44]IKE SA delete called for p1 sa 5598114 (ref cnt 1) local:10.90.3.25, remote:10.90.3.53, IKEv1 
[May 12 22:47:44]iked_pm_p1_sa_destroy:  p1 sa 5598114 (ref cnt 0), waiting_for_del 0x0
[May 12 22:47:44]Reducing number of connection for ike gateway t400-ike-gw to 0
[May 12 22:47:44]ike_free_id_payload: Start, id type = 1
[May 12 22:47:44]ike_free_id_payload: Start, id type = 2
[May 12 22:47:44]ike_free_sa: Start
[May 12 22:48:35]Deleted (spi=0xba2670b1, protocol=ESP dst=10.90.3.25) entry from the peer hash table. Reason: VPN monitoring
[May 12 22:48:35]Delete notifcation for sa spi 0xba2670b1 (sa_cfg instance-INSTANCE-t400-vpn_0002_0004_0000_268173330) is not sent as IKE SA not found
[May 12 22:48:35]Not route based VPN. Not deleting NHTB entry
[May 12 22:48:35]In iked_ipsec_sa_pair_delete Deleting GENCFG msg with key; Tunnel = 268173330;SPI-In = 0xba2670b1
[May 12 22:48:35]Deleted SA pair for tunnel = 268173330 with SPI-In = 0xba2670b1 to kernel
[May 12 22:48:35]Deleted (spi=0xba2670b1, protocol=ESP) entry from the inbound sa spi hash table
[May 12 22:48:35]Deleted (spi=0x235d97e, protocol=ESP dst=10.90.3.53) entry from the peer hash table. Reason: VPN monitoring