Local FW (SRX100B) has IP 86.95.164.48 Remote FW (SRX240B) has IP 212.214.4.178 (IP's obfuscated) root@fw04-k11% tail -f /var/log/vpn-debug-ike Mar 7 20:44:21 ikev2_free_exchange_data: Calling exchange_data_free Mar 7 20:44:21 ikev2_free_exchange_data: Successfully freed exchange data from SA c1d800 Mar 7 20:44:21 ssh_ikev2_ike_sa_free: Calling ike_sa_free_ref Mar 7 20:44:21 ikev2_udp_window_uninit: Freeing transmission windows for SA c1d800 Mar 7 20:44:27 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:44:27 ike_retransmit_callback: Start, retransmit SA = { 1a7627a9 7388d4ac - ec8fe98e f68d4256}, nego = -1 Mar 7 20:44:27 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - ec8fe98e f68d4256 [-1] / 0x00000000 } IP; Retransmitting packet, retries = 5 Mar 7 20:44:27 ike_send_packet: Start, retransmit previous packet SA = { 1a7627a9 7388d4ac - ec8fe98e f68d4256}, nego = -1, dst = 212.214.4.178:500 routing table id = 0 Mar 7 20:44:27 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - ec8fe98e f68d4256 [-1] / 0x00000000 } IP; Sending packet[276] = 0x1a7627a9 7388d4ac ec8fe98e f68d4256 01100200 00000000 00000114 0d000038 00000001 00000001 0000002c 00010001 00000024 Mar 7 20:44:27 ike_send_packet: Inserting retransmission timer after 10.000000 seconds Mar 7 20:44:31 ikev2_packet_allocate: Allocated packet bce400 from freelist Mar 7 20:44:31 ikev2_packet_allocate: [bce400/0] Allocating Mar 7 20:44:31 ikev2_packet_st_input_start: [bce400/0] Processing received Mar 7 20:44:31 ikev2_packet_st_input_v1_get_sa: [bce400/deadbeee] Packet to existing v1 SA Mar 7 20:44:31 ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library Mar 7 20:44:31 ike_udp_callback_common: Packet from 212.214.4.178:500, use_natt=0 data[0..264] = 1a7627a9 7388d4ac 00000000 00000000 ... Mar 7 20:44:31 ike_get_sa: Start, SA = { 1a7627a9 7388d4ac - 00000000 00000000 } / 00000000, remote = 212.214.4.178:500 Mar 7 20:44:31 ike_get_sa: We are the responder and the initiator resent its first packet Mar 7 20:44:31 ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1 Mar 7 20:44:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - ec8fe98e f68d4256 [-1] / 0x00000000 } IP; Packet to old negotiation Mar 7 20:44:31 ike_udp_callback_common: Other end retransmitted its packet Mar 7 20:44:31 ike_udp_callback_common: Cannot resend our response, because we have just sent a packet to other end Mar 7 20:44:31 ikev2_packet_destroy: [bce400/deadbeee] Destructor Mar 7 20:44:31 ikev2_packet_free: [bce400/deadbeee] Freeing Mar 7 20:44:37 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:44:37 ike_retransmit_callback: Start, retransmit SA = { 1a7627a9 7388d4ac - ec8fe98e f68d4256}, nego = -1 Mar 7 20:44:37 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - ec8fe98e f68d4256 [-1] / 0x00000000 } IP; Retransmitting packet, retries = 4 Mar 7 20:44:37 ike_send_packet: Start, retransmit previous packet SA = { 1a7627a9 7388d4ac - ec8fe98e f68d4256}, nego = -1, dst = 212.214.4.178:500 routing table id = 0 Mar 7 20:44:37 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - ec8fe98e f68d4256 [-1] / 0x00000000 } IP; Sending packet[276] = 0x1a7627a9 7388d4ac ec8fe98e f68d4256 01100200 00000000 00000114 0d000038 00000001 00000001 0000002c 00010001 00000024 Mar 7 20:44:37 ike_send_packet: Inserting retransmission timer after 10.000000 seconds Mar 7 20:44:46 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:44:46 ike_remove_callback: Start, delete SA = { 1a7627a9 7388d4ac - ec8fe98e f68d4256}, nego = -1 Mar 7 20:44:46 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - ec8fe98e f68d4256 [-1] / 0x00000000 } IP; Removing negotiation Mar 7 20:44:46 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - ec8fe98e f68d4256 [-1] / 0x00000000 } IP; Connection timed out or error, calling callback Mar 7 20:44:46 ikev2_fb_negotiation_done_isakmp: Entered IKE error code Timeout (8197), IKE SA c1d400 (neg c27000) Mar 7 20:44:46 ike_delete_negotiation: Start, SA = { 1a7627a9 7388d4ac - ec8fe98e f68d4256}, nego = -1 Mar 7 20:44:46 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - ec8fe98e f68d4256 [-1] / 0x00000000 } IP; Deleting negotiation Mar 7 20:44:46 ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table Mar 7 20:44:46 ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table Mar 7 20:44:46 ike_sa_delete: Start, SA = { 1a7627a9 7388d4ac - ec8fe98e f68d4256 } Mar 7 20:44:46 ike_free_negotiation_isakmp: Start, nego = -1 Mar 7 20:44:46 ike_free_negotiation: Start, nego = -1 Mar 7 20:44:46 ike_free_packet: Start Mar 7 20:44:46 ike_free_packet: Start Mar 7 20:44:46 ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA c1d400 is freed Mar 7 20:44:46 ikev2_fb_isakmp_sa_freed: Clearing p1_info from fallback negotiation c27000 Mar 7 20:44:46 ikev2_fb_isakmp_sa_freed: FB; Calling v2 policy function ike_sa_delete Mar 7 20:44:46 ike_free_sa: Start Mar 7 20:44:46 ikev2_fb_p1_negotiation_wait_sa_done: Phase-I negotiation is now done (neg c27000) Mar 7 20:44:46 ikev2_fb_p1_negotiation_wait_sa_done: FB; Calling v2 policy function ike_sa_done Mar 7 20:44:46 IKEv1 Error : Timeout Mar 7 20:44:46 ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context Mar 7 20:44:46 ikev2_fallback_negotiation_free: Freeing fallback negotiation c27000 Mar 7 20:44:46 ikev2_free_exchange_data: Freeing exchange data from SA c1d400, ED c25028 (1) Mar 7 20:44:46 ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA c1d400 Mar 7 20:44:46 ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA c1d400 Mar 7 20:44:46 ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA c1d400 Mar 7 20:44:46 ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA c1d400 Mar 7 20:44:46 ikev2_free_exchange_data: Calling exchange_data_free Mar 7 20:44:46 ikev2_free_exchange_data: Successfully freed exchange data from SA c1d400 Mar 7 20:44:46 ssh_ikev2_ike_sa_free: Calling ike_sa_free_ref Mar 7 20:44:46 ikev2_udp_window_uninit: Freeing transmission windows for SA c1d400 Mar 7 20:44:51 ikev2_packet_allocate: Allocated packet bce800 from freelist Mar 7 20:44:51 ikev2_packet_allocate: [bce800/0] Allocating Mar 7 20:44:51 ikev2_packet_st_input_start: [bce800/0] Processing received Mar 7 20:44:51 ikev2_packet_st_input_v1_create_sa: [bce800/0] No IKE SA for packet; requesting permission to create one. Mar 7 20:44:51 ikev2_packet_st_connect_decision: [bce800/0] Pad allows connection Mar 7 20:44:51 ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library Mar 7 20:44:51 ike_udp_callback_common: Packet from 212.214.4.178:500, use_natt=0 data[0..264] = 1a7627a9 7388d4ac 00000000 00000000 ... Mar 7 20:44:51 ike_get_sa: Start, SA = { 1a7627a9 7388d4ac - 00000000 00000000 } / 00000000, remote = 212.214.4.178:500 Mar 7 20:44:51 ike_get_sa: We are responder and this is initiators first packet Mar 7 20:44:51 ike_cookie_create: Cookie create Mar 7 20:44:51 00000000: a6d4 91bd 1b77 f66c .....w.l Mar 7 20:44:51 ike_sa_allocate: Start, SA = { 1a7627a9 7388d4ac - a6d491bd 1b77f66c } Mar 7 20:44:51 ike_udp_callback_common: New SA Mar 7 20:44:51 ike_init_isakmp_sa: Start, remote = 212.214.4.178:500, initiator = 0 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - a6d491bd 1b77f66c [-1] / 0x00000000 } IP; New SA Mar 7 20:44:51 ikev2_fb_new_connection: New ISAKMP connection from remote address 212.214.4.178/500 Mar 7 20:44:51 ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation c27000 (now 1 references) Mar 7 20:44:51 ikev2_fallback_negotiation_alloc: Allocated fallback negotiation c27000 Mar 7 20:44:51 ssh_set_thread_debug_info: ikev2_fb_new_connection: set thread debug info - local 0x5760a531 remote 0xd4d605b3neg 0xc27000 neg->ike_sa 0x0 ike_sa 0x0 Mar 7 20:44:51 ikev2_packet_destroy: [bce800/0] Destructor Mar 7 20:44:51 ikev2_packet_free: [bce800/0] Freeing Mar 7 20:44:51 ikev2_fb_p1_negotiation_allocate_sa: Taking reference to fallback negotiation c27000 (now 2 references) Mar 7 20:44:51 ssh_set_thread_debug_info: ikev2_fb_p1_negotiation_allocate_sa: set thread debug info - local 0x5760a531 remote 0xd4d605b3neg 0xc27000 neg->ike_sa 0x0 ike_sa 0x0 Mar 7 20:44:51 ikev2_fb_p1_negotiation_wait_sa_done: Suspending until the IKE SA is done (neg c27000) Mar 7 20:44:51 ikev2_fb_st_new_p1_connection_start: FB; Calling v2 policy function ike_sa_allocate Mar 7 20:44:51 ikev2_fb_ike_sa_allocate_cb: New IKE SA allocated successfully c1d400 (neg c27000) Mar 7 20:44:51 ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref Mar 7 20:44:51 ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref Mar 7 20:44:51 ikev2_allocate_exchange_data: Calling exchange_data_alloc Mar 7 20:44:51 ikev2_allocate_exchange_data: Successfully allocated exchange data for SA c1d400 Mar 7 20:44:51 ikev2_allocate_exchange_data_ike: Allocating IKE exchange data for SA c1d400 ED c25028 Mar 7 20:44:51 ikev2_allocate_exchange_data_ike: Successfully allocated IKE exchange data for SA c1d400 ED c25028 Mar 7 20:44:51 ikev2_allocate_exchange_data_ipsec: Allocating IPsec exchange data for SA c1d400 ED c25028 Mar 7 20:44:51 ikev2_allocate_exchange_data_ipsec: Successfully allocated IPsec exchange data for SA c1d400 ED c25028 Mar 7 20:44:51 ssh_isakmp_update_responder_cookie: Updating responder IKE cookie Mar 7 20:44:51 ssh_isakmp_update_responder_cookie: Original IKE cookie Mar 7 20:44:51 00000000: a6d4 91bd 1b77 f66c .....w.l Mar 7 20:44:51 ssh_isakmp_update_responder_cookie: New IKE cookie Mar 7 20:44:51 00000000: 1748 db27 5917 2319 .H.'Y.#. Mar 7 20:44:51 ikev2_fb_st_new_p1_connection_local_addresses: Accepting new Phase-1 negotiation: local=86.95.164.48:500, remote=212.214.4.178:500 (neg c27000) Mar 7 20:44:51 ikev2_fb_st_new_p1_connection_local_addresses: FB; Calling v2 policy function get_local_address_list Mar 7 20:44:51 ikev2_fallback_negotiation_free: Fallback negotiation c27000 has still 1 references Mar 7 20:44:51 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Received packet[264] = 0x1a7627a9 7388d4ac 00000000 00000000 01100200 00000000 00000108 0d000040 00000001 00000001 00000034 00010801 1a7627a Mar 7 20:44:51 ike_decode_packet: Start Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Packet received[264] = 0x1a7627a9 7388d4ac 00000000 00000000 01100200 00000000 00000108 0d000040 00000001 00000001 00000034 00010801 1a7627a Mar 7 20:44:51 ike_decode_packet: Start, SA = { 1a7627a9 7388d4ac - 1748db27 59172319} / 00000000, nego = -1 Mar 7 20:44:51 ike_decode_packet: first_payload_type:1. Mar 7 20:44:51 ike_decode_packet: next_payload_type:13. Mar 7 20:44:51 ike_decode_packet: next_payload_type:13. Mar 7 20:44:51 ike_decode_packet: next_payload_type:13. Mar 7 20:44:51 ike_decode_packet: next_payload_type:13. Mar 7 20:44:51 ike_decode_packet: next_payload_type:13. Mar 7 20:44:51 ike_decode_packet: next_payload_type:13. Mar 7 20:44:51 ike_decode_packet: next_payload_type:13. Mar 7 20:44:51 ike_decode_packet: next_payload_type:13. Mar 7 20:44:51 ike_decode_packet: next_payload_type:0. Mar 7 20:44:51 ike_decode_payload_sa: Start Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: doi = 1, sit = 0x1 Mar 7 20:44:51 ike_decode_payload_sa: Found 1 proposals Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: Proposal[0] = 0 .protocol[0] = 1, # transforms = 1, spi[8] = 0x1a7627a9 7388d4ac Mar 7 20:44:51 ike_decode_payload_t: Start, # trans = 1 Mar 7 20:44:51 ssh_ike_decode_data_attribute_size: decode_size B: type = 1 (0x0001), value = 7 (0x0007), size = 4 Mar 7 20:44:51 ssh_ike_decode_data_attribute_size: decode_size B: type = 14 (0x000e), value = 256 (0x0100), size = 4 Mar 7 20:44:51 ssh_ike_decode_data_attribute_size: decode_size B: type = 2 (0x0002), value = 2 (0x0002), size = 4 Mar 7 20:44:51 ssh_ike_decode_data_attribute_size: decode_size B: type = 3 (0x0003), value = 1 (0x0001), size = 4 Mar 7 20:44:51 ssh_ike_decode_data_attribute_size: decode_size B: type = 4 (0x0004), value = 2 (0x0002), size = 4 Mar 7 20:44:51 ssh_ike_decode_data_attribute_size: decode_size B: type = 11 (0x000b), value = 1 (0x0001), size = 4 Mar 7 20:44:51 ssh_ike_decode_data_attribute_size: decode_size B: type = 12 (0x000c), value = 28800 (0x7080), size = 4 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: trans[0] = 0, id = 1, # sa = #7 Mar 7 20:44:51 ssh_ike_decode_data_attribute: decode B: type = 1 (0x0001), value = 7 (0x0007), len = 2, used_bytes = 4 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: da[0], type = 1, value[2] = 0x0007 Mar 7 20:44:51 ssh_ike_decode_data_attribute: decode B: type = 14 (0x000e), value = 256 (0x0100), len = 2, used_bytes = 4 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: da[1], type = 14, value[2] = 0x0100 Mar 7 20:44:51 ssh_ike_decode_data_attribute: decode B: type = 2 (0x0002), value = 2 (0x0002), len = 2, used_bytes = 4 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: da[2], type = 2, value[2] = 0x0002 Mar 7 20:44:51 ssh_ike_decode_data_attribute: decode B: type = 3 (0x0003), value = 1 (0x0001), len = 2, used_bytes = 4 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: da[3], type = 3, value[2] = 0x0001 Mar 7 20:44:51 ssh_ike_decode_data_attribute: decode B: type = 4 (0x0004), value = 2 (0x0002), len = 2, used_bytes = 4 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: da[4], type = 4, value[2] = 0x0002 Mar 7 20:44:51 ssh_ike_decode_data_attribute: decode B: type = 11 (0x000b), value = 1 (0x0001), len = 2, used_bytes = 4 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: da[5], type = 11, value[2] = 0x0001 Mar 7 20:44:51 ssh_ike_decode_data_attribute: decode B: type = 12 (0x000c), value = 28800 (0x7080), len = 2, used_bytes = 4 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode SA: da[6], type = 12, value[2] = 0x7080 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode VID: data[16] = 0xafcad713 68a1f1c9 6b8696fc 77570100 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode VID: data[28] = 0x69936922 8741c6d4 ca094c93 e242c9de 19e7b7c6 00000005 00000500 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x27bab5dc 01ea0760 ea4e3190 ac27c0d0 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x6105c422 e76847e4 3f968480 1292aecd Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x4485152d 18b6bbcd 0be8a846 9579ddcc Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode VID: data[16] = 0xcd604643 35df21f8 7cfdb2fc 68b6a448 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x90cb8091 3ebb696e 086381b5 ec427b1f Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x7d9419a6 5310ca6f 2c179d92 15529d56 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0401 SA VID Mar 7 20:44:51 ike_state_step: Current state = Start sa negotiation R (2)/-1, exchange = 2, auth_method = any, Responder Mar 7 20:44:51 ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 Mar 7 20:44:51 ike_state_step: Matched state = Start sa negotiation R (2) Mar 7 20:44:51 ike_state_step: Calling input function[0] = ike_st_i_vid Mar 7 20:44:51 ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ... Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d400 Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:44:51 ike_st_i_vid: VID[0..28] = 69936922 8741c6d4 ... Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 28, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d400 Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:44:51 ike_st_i_vid: VID[0..16] = 27bab5dc 01ea0760 ... Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d400 Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:44:51 ike_st_i_vid: VID[0..16] = 6105c422 e76847e4 ... Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d400 Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:44:51 ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ... Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d400 Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:44:51 ike_st_i_vid: VID[0..16] = cd604643 35df21f8 ... Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d400 Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Received NAT-T vendor id [draft-ietf-ipsec-nat-t-ike-02] Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:44:51 ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ... Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d400 Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Received NAT-T vendor id [draft-ietf-ipsec-nat-t-ike-02] Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:44:51 ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ... Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d400 Mar 7 20:44:51 ikev2_fb_check_natt_vendor_id: Received NAT-T vendor id [draft-ietf-ipsec-nat-t-ike-03] Mar 7 20:44:51 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:44:51 ike_state_step: Calling input function[1] = ike_st_i_sa_proposal Mar 7 20:44:51 ike_st_i_sa_proposal: Start Mar 7 20:44:51 ikev2_fb_isakmp_select_sa: Select IKE SA policy call entered, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_isakmp_select_sa: Taking reference to fallback negotiation c27000 (now 2 references) Mar 7 20:44:51 ssh_set_thread_debug_info: ikev2_fb_isakmp_select_sa: set thread debug info - local 0x5760a531 remote 0xd4d605b3neg 0xc27000 neg->ike_sa 0xc1d400 ike_sa 0x0 Mar 7 20:44:51 ike_state_step: Input function[1] = ike_st_i_sa_proposal asked retry later Mar 7 20:44:51 ike_process_packet: No output packet, returning Mar 7 20:44:51 ikev2_fb_st_select_ike_sa: FB; Calling v2 policy function select_ike_sa Mar 7 20:44:51 ssh_ikev2_sa_select: SA_SELECT: Selecting IKEv1 proposal. Mar 7 20:44:51 ssh_ikev2_sav1_select: Comparing 1 input proposals against 1 policy proposals Mar 7 20:44:51 ssh_ikev2_sav1_select: Comparing input proposal #0 against policy proposal #1 Mar 7 20:44:51 ikev2_choose_v1_proposal: Comparing 1 protocol(s) Mar 7 20:44:51 ikev2_choose_v1_proposal: Comparing transforms of protocol 1 Mar 7 20:44:51 ikev2_choose_v1_transform: Comparing 1 input transforms against 1 policy transforms Mar 7 20:44:51 ikev2_choose_v1_transform: Comparing input transform #0 against policy transform #0 Mar 7 20:44:51 ikev2_choose_v1_transform: Transform id 1 matches, comparing attributes Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing 7 input attributes against 7 policy attributes Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 0 against policy attribute 0 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Input and policy attributes of type 1 match Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 1 against policy attribute 0 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 1 against policy attribute 1 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Input and policy attributes of type 14 match Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 2 against policy attribute 0 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 2 against policy attribute 1 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 2 against policy attribute 2 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 2 against policy attribute 3 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Input and policy attributes of type 2 match Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 3 against policy attribute 0 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 3 against policy attribute 1 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 3 against policy attribute 2 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 3 against policy attribute 3 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 3 against policy attribute 4 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 3 against policy attribute 5 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 3 against policy attribute 6 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Input and policy attributes of type 3 match Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 4 against policy attribute 0 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 4 against policy attribute 1 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Comparing input attribute 4 against policy attribute 2 Mar 7 20:44:51 ikev2_ikev1_attribute_check: Input and policy attributes of type 4 match Mar 7 20:44:51 ikev2_ikev1_attribute_check: Input attribute 5 is life type/duration, ignoring Mar 7 20:44:51 ikev2_ikev1_attribute_check: Input attribute 6 is life type/duration, ignoring Mar 7 20:44:51 ikev2_ikev1_attribute_check: Attributes matched successfully Mar 7 20:44:51 ikev2_ikev1_attribute_check: Setting life in seconds to 28800 from policy Mar 7 20:44:51 ikev2_choose_v1_transform: Attributes match; selected input transform 0 Mar 7 20:44:51 ikev2_choose_v1_proposal: Protocols match Mar 7 20:44:51 ikev2_choose_v1_proposal: Selected proposal number 0 and transforms for 1 protocols Mar 7 20:44:51 ikev2_choose_v1_proposal: Selected transform id 1 for protocol 1 Mar 7 20:44:51 ssh_ikev2_sav1_select: Proposals match Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 7 (0x00000007), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encryption alg = 7 (aes-cbc) Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 14 (0x000e), value = 256 (0x00000100), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Key length = 256 Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Hash alg = 2 (sha1) Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Auth method = 1 Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Group = 2, b93ef0 Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Life duration 28800 secs Mar 7 20:44:51 ikev2_fb_spd_select_sa_cb: Diffie-Hellman group number 2 selected Mar 7 20:44:51 ikev2_fb_spd_select_sa_cb: Authentication method number 1 selected Mar 7 20:44:51 ikev2_fb_spd_select_sa_cb: Set IKE SA lifetime to 28800 seconds Mar 7 20:44:51 ike_isakmp_sa_reply: Start Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 7 (0x00000007), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encryption alg = 7 (aes-cbc) Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 14 (0x000e), value = 256 (0x00000100), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Key length = 256 Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Hash alg = 2 (sha1) Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Auth method = 1 Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Group = 2, b93ef0 Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) Mar 7 20:44:51 ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 2 (0x0002) Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Life duration 28800 secs Mar 7 20:44:51 ikev2_fallback_negotiation_free: Fallback negotiation c27000 has still 1 references Mar 7 20:44:51 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Restart packet Mar 7 20:44:51 ike_state_restart_packet: Start, restart packet SA = { 1a7627a9 7388d4ac - 1748db27 59172319}, nego = -1 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0401 SA VID Mar 7 20:44:51 ike_state_step: Current state = Start sa negotiation R (2)/1, exchange = 2, auth_method = pre shared key, Responder Mar 7 20:44:51 ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 Mar 7 20:44:51 ike_state_step: Matched state = Start sa negotiation R (2) Mar 7 20:44:51 ike_state_step: Calling input function[1] = ike_st_i_sa_proposal Mar 7 20:44:51 ike_st_i_sa_proposal: Start Mar 7 20:44:51 ike_state_step: Calling input function[2] = ike_st_i_cr Mar 7 20:44:51 ike_st_i_cr: Start Mar 7 20:44:51 ike_state_step: Calling input function[3] = ike_st_i_cert Mar 7 20:44:51 ike_st_i_cert: Start Mar 7 20:44:51 ike_state_step: Calling input function[4] = ike_st_i_status_n Mar 7 20:44:51 ike_state_step: Calling input function[5] = ike_st_i_private Mar 7 20:44:51 ike_st_i_private: Start Mar 7 20:44:51 ike_state_step: Calling output function[0] = ike_st_o_sa_values Mar 7 20:44:51 ike_st_o_sa_values: Start Mar 7 20:44:51 ike_state_step: Calling output function[1] = ike_st_o_optional_certs Mar 7 20:44:51 ike_state_step: Calling output function[2] = ike_st_o_vids Mar 7 20:44:51 ikev2_fb_isakmp_request_vendor_ids: Request vendor ID's policy call entered, IKE SA c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_isakmp_request_vendor_ids: FB; Calling v2 policy function vendor_id_request Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: Got a VID of length 28 (neg c27000) Mar 7 20:44:51 ikev2_fb_vid_request_cb: No more VIDs Mar 7 20:44:51 ike_policy_reply_isakmp_vendor_ids: Start Mar 7 20:44:51 ike_state_step: Calling output function[3] = ike_st_o_private Mar 7 20:44:51 ike_st_o_private: Start Mar 7 20:44:51 ikev2_fb_private_p_1_out: Phase-I output: packet_number 2 ike_sa c1d400 (neg c27000) Mar 7 20:44:51 ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations Mar 7 20:44:51 ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request Mar 7 20:44:51 ike_policy_reply_private_payload_out: Start Mar 7 20:44:51 ike_state_step: All done, new state = MM SA R (4) Mar 7 20:44:51 ike_encode_packet: Start, SA = { 0x1a7627a9 7388d4ac - 1748db27 59172319 } / 00000000, nego = -1 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode packet, version = 1.0, flags = 0x00000000 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: doi = 1, sit = 0x1 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: Proposal[0] = 0 .protocol[0] = 1, # transforms = 1, spi[0] Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: trans[0] = 0, id = 1, # sa = 7 Mar 7 20:44:51 ssh_ike_encode_data_attribute: encode B: type = 1 (0x0001), len = 2, value = 0007 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: da[0], type = 1, value[2] = 0x0007 Mar 7 20:44:51 ssh_ike_encode_data_attribute: encode B: type = 14 (0x000e), len = 2, value = 0100 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: da[1], type = 14, value[2] = 0x0100 Mar 7 20:44:51 ssh_ike_encode_data_attribute: encode B: type = 2 (0x0002), len = 2, value = 0002 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: da[2], type = 2, value[2] = 0x0002 Mar 7 20:44:51 ssh_ike_encode_data_attribute: encode B: type = 3 (0x0003), len = 2, value = 0001 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: da[3], type = 3, value[2] = 0x0001 Mar 7 20:44:51 ssh_ike_encode_data_attribute: encode B: type = 4 (0x0004), len = 2, value = 0002 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: da[4], type = 4, value[2] = 0x0002 Mar 7 20:44:51 ssh_ike_encode_data_attribute: encode B: type = 11 (0x000b), len = 2, value = 0001 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: da[5], type = 11, value[2] = 0x0001 Mar 7 20:44:51 ssh_ike_encode_data_attribute: encode B: type = 12 (0x000c), len = 2, value = 7080 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode SA: da[6], type = 12, value[2] = 0x7080 Mar 7 20:44:51 ike_encode_packet: Payload length = 56 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0xafcad713 68a1f1c9 6b8696fc 77570100 Mar 7 20:44:51 ike_encode_packet: Payload length = 20 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x27bab5dc 01ea0760 ea4e3190 ac27c0d0 Mar 7 20:44:51 ike_encode_packet: Payload length = 20 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x6105c422 e76847e4 3f968480 1292aecd Mar 7 20:44:51 ike_encode_packet: Payload length = 20 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x4485152d 18b6bbcd 0be8a846 9579ddcc Mar 7 20:44:51 ike_encode_packet: Payload length = 20 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0xcd604643 35df21f8 7cfdb2fc 68b6a448 Mar 7 20:44:51 ike_encode_packet: Payload length = 20 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x90cb8091 3ebb696e 086381b5 ec427b1f Mar 7 20:44:51 ike_encode_packet: Payload length = 20 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x7d9419a6 5310ca6f 2c179d92 15529d56 Mar 7 20:44:51 ike_encode_packet: Payload length = 20 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x4a131c81 07035845 5c5728f2 0e95452f Mar 7 20:44:51 ike_encode_packet: Payload length = 20 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encode VID: vendor id[28] = 0x69936922 8741c6d4 ca094c93 e242c9de 19e7b7c6 00000005 00000500 Mar 7 20:44:51 ike_encode_packet: Payload length = 32 Mar 7 20:44:51 ike_encode_packet: Packet length = 276 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Encoded packet[276] = 0x1a7627a9 7388d4ac 1748db27 59172319 01100200 00000000 00000114 0d000038 00000001 00000001 0000002c 00010001 00000024 Mar 7 20:44:51 ike_encode_packet: Final length = 276 Mar 7 20:44:51 ike_send_packet: Start, send SA = { 1a7627a9 7388d4ac - 1748db27 59172319}, nego = -1, dst = 212.214.4.178:500, routing table id = 0 Mar 7 20:44:51 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Sending packet[276] = 0x1a7627a9 7388d4ac 1748db27 59172319 01100200 00000000 00000114 0d000038 00000001 00000001 0000002c 00010001 00000024 Mar 7 20:44:51 ike_send_packet: Inserting retransmission timer after 10.000000 seconds Mar 7 20:45:01 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:45:01 ike_retransmit_callback: Start, retransmit SA = { 1a7627a9 7388d4ac - 1748db27 59172319}, nego = -1 Mar 7 20:45:01 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Retransmitting packet, retries = 5 Mar 7 20:45:01 ike_send_packet: Start, retransmit previous packet SA = { 1a7627a9 7388d4ac - 1748db27 59172319}, nego = -1, dst = 212.214.4.178:500 routing table id = 0 Mar 7 20:45:01 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Sending packet[276] = 0x1a7627a9 7388d4ac 1748db27 59172319 01100200 00000000 00000114 0d000038 00000001 00000001 0000002c 00010001 00000024 Mar 7 20:45:01 ike_send_packet: Inserting retransmission timer after 10.000000 seconds Mar 7 20:45:11 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:45:11 ike_retransmit_callback: Start, retransmit SA = { 1a7627a9 7388d4ac - 1748db27 59172319}, nego = -1 Mar 7 20:45:11 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Retransmitting packet, retries = 4 Mar 7 20:45:11 ike_send_packet: Start, retransmit previous packet SA = { 1a7627a9 7388d4ac - 1748db27 59172319}, nego = -1, dst = 212.214.4.178:500 routing table id = 0 Mar 7 20:45:11 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Sending packet[276] = 0x1a7627a9 7388d4ac 1748db27 59172319 01100200 00000000 00000114 0d000038 00000001 00000001 0000002c 00010001 00000024 Mar 7 20:45:11 ike_send_packet: Inserting retransmission timer after 10.000000 seconds Mar 7 20:45:21 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:45:21 ike_remove_callback: Start, delete SA = { 1a7627a9 7388d4ac - 1748db27 59172319}, nego = -1 Mar 7 20:45:21 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Removing negotiation Mar 7 20:45:21 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Connection timed out or error, calling callback Mar 7 20:45:21 ikev2_fb_negotiation_done_isakmp: Entered IKE error code Timeout (8197), IKE SA c1d400 (neg c27000) Mar 7 20:45:21 ike_delete_negotiation: Start, SA = { 1a7627a9 7388d4ac - 1748db27 59172319}, nego = -1 Mar 7 20:45:21 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 1748db27 59172319 [-1] / 0x00000000 } IP; Deleting negotiation Mar 7 20:45:21 ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table Mar 7 20:45:21 ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table Mar 7 20:45:21 ike_sa_delete: Start, SA = { 1a7627a9 7388d4ac - 1748db27 59172319 } Mar 7 20:45:21 ike_free_negotiation_isakmp: Start, nego = -1 Mar 7 20:45:21 ike_free_negotiation: Start, nego = -1 Mar 7 20:45:21 ike_free_packet: Start Mar 7 20:45:21 ike_free_packet: Start Mar 7 20:45:21 ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA c1d400 is freed Mar 7 20:45:21 ikev2_fb_isakmp_sa_freed: Clearing p1_info from fallback negotiation c27000 Mar 7 20:45:21 ikev2_fb_isakmp_sa_freed: FB; Calling v2 policy function ike_sa_delete Mar 7 20:45:21 ike_free_sa: Start Mar 7 20:45:21 ikev2_fb_p1_negotiation_wait_sa_done: Phase-I negotiation is now done (neg c27000) Mar 7 20:45:21 ikev2_fb_p1_negotiation_wait_sa_done: FB; Calling v2 policy function ike_sa_done Mar 7 20:45:21 IKEv1 Error : Timeout Mar 7 20:45:21 ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context Mar 7 20:45:21 ikev2_fallback_negotiation_free: Freeing fallback negotiation c27000 Mar 7 20:45:21 ikev2_free_exchange_data: Freeing exchange data from SA c1d400, ED c25028 (1) Mar 7 20:45:21 ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA c1d400 Mar 7 20:45:21 ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA c1d400 Mar 7 20:45:21 ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA c1d400 Mar 7 20:45:21 ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA c1d400 Mar 7 20:45:21 ikev2_free_exchange_data: Calling exchange_data_free Mar 7 20:45:21 ikev2_free_exchange_data: Successfully freed exchange data from SA c1d400 Mar 7 20:45:21 ssh_ikev2_ike_sa_free: Calling ike_sa_free_ref Mar 7 20:45:21 ikev2_udp_window_uninit: Freeing transmission windows for SA c1d400 Mar 7 20:45:25 ssh_ikev2_ike_sa_allocate: Allocating IKE SA 212.214.4.178;500/4500 Mar 7 20:45:25 ikev2_ike_sa_alloc_cb: Allocated IKE SA c1d400 I00f6c2aa bdee3ae2 (212.214.4.178;500/4500) Mar 7 20:45:25 ikev2_udp_window_init: Allocating transmission windows for SA c1d400 Mar 7 20:45:25 ikev2_allocate_exchange_data: Calling exchange_data_alloc Mar 7 20:45:25 ikev2_allocate_exchange_data: Successfully allocated exchange data for SA c1d400 Mar 7 20:45:25 ssh_ikev2_ipsec_create_sa: State = IKE_INIT_SA Mar 7 20:45:25 ikev2_allocate_exchange_data_ike: Allocating IKE exchange data for SA c1d400 ED c25028 Mar 7 20:45:25 ikev2_allocate_exchange_data_ike: Successfully allocated IKE exchange data for SA c1d400 ED c25028 Mar 7 20:45:25 ikev2_allocate_exchange_data_ipsec: Allocating IPsec exchange data for SA c1d400 ED c25028 Mar 7 20:45:25 ikev2_allocate_exchange_data_ipsec: Successfully allocated IPsec exchange data for SA c1d400 ED c25028 Mar 7 20:45:25 ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref Mar 7 20:45:25 ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation c27000 (now 1 references) Mar 7 20:45:25 ikev2_fallback_negotiation_alloc: Allocated fallback negotiation c27000 Mar 7 20:45:25 ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref Mar 7 20:45:25 ssh_set_thread_debug_info: ikev2_fb_initiate_ipsec_sa: set thread debug info - local 0x5760a531 remote 0xd4d605b3neg 0xc27000 neg->ike_sa 0xc1d400 ike_sa 0x0 Mar 7 20:45:25 ikev2_reference_exchange_data: Taking reference to exchange data c25028 (to 2) Mar 7 20:45:25 ikev2_fb_i_p1_negotiation_start: Taking reference to fallback negotiation c27000 (now 2 references) Mar 7 20:45:25 ssh_set_thread_debug_info: ikev2_fb_i_p1_negotiation_start: set thread debug info - local 0x5760a531 remote 0xd4d605b3neg 0xc27000 neg->ike_sa 0xc1d400 ike_sa 0x0 Mar 7 20:45:25 ikev2_fb_st_i_ike_local_address_request: FB; Calling v2 policy function get_local_address_list Mar 7 20:45:25 ikev2_fb_st_i_ike_id_request: FB; Calling v2 policy function id Mar 7 20:45:25 ikev2_fb_id_request_cb: Local id payload is ID(type = ipv4 (1), len = 4, value = 86.95.164.48) Mar 7 20:45:25 ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID ID(type = ipv4 (1), len = 4, value = 86.95.164.48) to IKEv1 ID Mar 7 20:45:25 ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID ipv4(any:0,[0..3]=86.95.164.48) Mar 7 20:45:26 ikev2_fb_st_i_ike_notify_request: FB; Calling v2 policy function notify_request Mar 7 20:45:26 ikev2_fb_st_i_ike_psk_request: FB; Calling v2 policy function shared_key Mar 7 20:45:26 ikev2_fb_find_pre_shared_key_cb: Found preshared key Mar 7 20:45:26 ikev2_fb_st_i_ike_sa_request: FB; Calling v2 policy function fill_ike_sa Mar 7 20:45:26 ikev2_fb_st_i_conf_request: FB; Calling v2 policy function conf_request Mar 7 20:45:26 ikev2_fallback_negotiation_free: Fallback negotiation c27000 has still 1 references Mar 7 20:45:26 ikev2_fb_i_p1_negotiation_negotiate: Sending Initial Contact notification Mar 7 20:45:26 ikev2_fb_i_p1_negotiation_negotiate: Taking reference to fallback negotiation c27000 (now 2 references) Mar 7 20:45:26 ssh_ike_connect: Start, remote_name = 212.214.4.178:500, xchg = 2, flags = 00090000 Mar 7 20:45:26 ike_sa_allocate_half: Start Mar 7 20:45:26 ike_sa_allocate: Start, SA = { 00f6c2aa bdee3ae2 - 00000000 00000000 } Mar 7 20:45:26 ike_init_isakmp_sa: Start, remote = 212.214.4.178:500, initiator = 1 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; SA: Number of proposals = 1 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; SA[0]: Number of protocols = 1 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; SA[0][0]: Number of transforms = 1 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; SA[0][0][0]: ISAKMP protocol Mar 7 20:45:26 ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 7 (0x00000007), len = 2 (0x0002) Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encryption alg = 7 (aes-cbc) Mar 7 20:45:26 ssh_ike_get_data_attribute_int: get_int: type = 14 (0x000e), value = 256 (0x00000100), len = 2 (0x0002) Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Key length = 256 Mar 7 20:45:26 ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002) Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Group = 2, b93ef0 Mar 7 20:45:26 ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002) Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Hash alg = 2 (sha1) Mar 7 20:45:26 ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002) Mar 7 20:45:26 ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 28800 (0x00007080), len = 4 (0x0004) Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Life duration 28800 secs Mar 7 20:45:26 ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 1 (0x00000001), len = 2 (0x0002) Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Auth method = 1 Mar 7 20:45:26 ssh_ike_connect: SA = { 00f6c2aa bdee3ae2 - 00000000 00000000}, nego = -1 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Start isakmp sa negotiation Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0000 Mar 7 20:45:26 ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 2, auth_method = pre shared key, Initiator Mar 7 20:45:26 ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 Mar 7 20:45:26 ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0 Mar 7 20:45:26 ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000 Mar 7 20:45:26 ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000 Mar 7 20:45:26 ike_state_step: Matched state = Start sa negotiation I (1) Mar 7 20:45:26 ike_state_step: Calling output function[0] = ike_st_o_sa_proposal Mar 7 20:45:26 ike_st_o_sa_proposal: Start Mar 7 20:45:26 ike_state_step: Calling output function[1] = ike_st_o_vids Mar 7 20:45:26 ikev2_fb_isakmp_request_vendor_ids: Request vendor ID's policy call entered, IKE SA c1d400 (neg c27000) Mar 7 20:45:26 ikev2_fb_isakmp_request_vendor_ids: FB; Calling v2 policy function vendor_id_request Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 16 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: Got a VID of length 28 (neg c27000) Mar 7 20:45:26 ikev2_fb_vid_request_cb: No more VIDs Mar 7 20:45:26 ike_policy_reply_isakmp_vendor_ids: Start Mar 7 20:45:26 ike_state_step: Calling output function[2] = ike_st_o_private Mar 7 20:45:26 ike_st_o_private: Start Mar 7 20:45:26 ikev2_fb_private_p_1_out: Phase-I output: packet_number 1 ike_sa c1d400 (neg c27000) Mar 7 20:45:26 ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations Mar 7 20:45:26 ikev2_fb_private_p_1_out: Remote end does not support NAT-T (or Vendor IDs not received yet) Mar 7 20:45:26 ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request Mar 7 20:45:26 ike_policy_reply_private_payload_out: Start Mar 7 20:45:26 ike_state_step: All done, new state = MM SA I (3) Mar 7 20:45:26 ike_encode_packet: Start, SA = { 0x00f6c2aa bdee3ae2 - 00000000 00000000 } / 00000000, nego = -1 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode packet, version = 1.0, flags = 0x00000000 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: doi = 1, sit = 0x1 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: Proposal[0] = 1 .protocol[0] = 1, # transforms = 1, spi[8] = 0x00f6c2aa bdee3ae2 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: trans[0] = 0, id = 1, # sa = 7 Mar 7 20:45:26 ssh_ike_encode_data_attribute: encode B: type = 1 (0x0001), len = 2, value = 0007 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: da[0], type = 1, value[2] = 0x0007 Mar 7 20:45:26 ssh_ike_encode_data_attribute: encode B: type = 14 (0x000e), len = 2, value = 0100 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: da[1], type = 14, value[2] = 0x0100 Mar 7 20:45:26 ssh_ike_encode_data_attribute: encode B: type = 4 (0x0004), len = 2, value = 0002 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: da[2], type = 4, value[2] = 0x0002 Mar 7 20:45:26 ssh_ike_encode_data_attribute: encode B: type = 2 (0x0002), len = 2, value = 0002 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: da[3], type = 2, value[2] = 0x0002 Mar 7 20:45:26 ssh_ike_encode_data_attribute: encode B: type = 11 (0x000b), len = 2, value = 0001 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: da[4], type = 11, value[2] = 0x0001 Mar 7 20:45:26 ssh_ike_encode_data_attribute: encode V: type = 12 (0x000c), len = 4 (0x0004), value = 00007080 ... Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: da[5], type = 12, value[4] = 0x00007080 Mar 7 20:45:26 ssh_ike_encode_data_attribute: encode B: type = 3 (0x0003), len = 2, value = 0001 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode SA: da[6], type = 3, value[2] = 0x0001 Mar 7 20:45:26 ike_encode_packet: Payload length = 68 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0xafcad713 68a1f1c9 6b8696fc 77570100 Mar 7 20:45:26 ike_encode_packet: Payload length = 20 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x27bab5dc 01ea0760 ea4e3190 ac27c0d0 Mar 7 20:45:26 ike_encode_packet: Payload length = 20 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x6105c422 e76847e4 3f968480 1292aecd Mar 7 20:45:26 ike_encode_packet: Payload length = 20 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x4485152d 18b6bbcd 0be8a846 9579ddcc Mar 7 20:45:26 ike_encode_packet: Payload length = 20 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0xcd604643 35df21f8 7cfdb2fc 68b6a448 Mar 7 20:45:26 ike_encode_packet: Payload length = 20 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x90cb8091 3ebb696e 086381b5 ec427b1f Mar 7 20:45:26 ike_encode_packet: Payload length = 20 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x7d9419a6 5310ca6f 2c179d92 15529d56 Mar 7 20:45:26 ike_encode_packet: Payload length = 20 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[16] = 0x4a131c81 07035845 5c5728f2 0e95452f Mar 7 20:45:26 ike_encode_packet: Payload length = 20 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encode VID: vendor id[28] = 0x69936922 8741c6d4 ca094c93 e242c9de 19e7b7c6 00000005 00000500 Mar 7 20:45:26 ike_encode_packet: Payload length = 32 Mar 7 20:45:26 ike_encode_packet: Packet length = 288 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Encoded packet[288] = 0x00f6c2aa bdee3ae2 00000000 00000000 01100200 00000000 00000120 0d000044 00000001 00000001 00000038 01010801 00f6c2aa Mar 7 20:45:26 ike_encode_packet: Final length = 288 Mar 7 20:45:26 ike_send_packet: Start, send SA = { 00f6c2aa bdee3ae2 - 00000000 00000000}, nego = -1, dst = 212.214.4.178:500, routing table id = 0 Mar 7 20:45:26 86.95.164.48:500 (Initiator) <-> 212.214.4.178:500 { 00f6c2aa bdee3ae2 - 00000000 00000000 [-1] / 0x00000000 } IP; Sending packet[288] = 0x00f6c2aa bdee3ae2 00000000 00000000 01100200 00000000 00000120 0d000044 00000001 00000001 00000038 01010801 00f6c2aa Mar 7 20:45:26 ike_send_packet: Inserting retransmission timer after 10.000000 seconds Mar 7 20:45:31 ikev2_packet_allocate: Allocated packet bcec00 from freelist Mar 7 20:45:31 ikev2_packet_allocate: [bcec00/0] Allocating Mar 7 20:45:31 ikev2_packet_st_input_start: [bcec00/0] Processing received Mar 7 20:45:31 ikev2_packet_st_input_v1_create_sa: [bcec00/0] No IKE SA for packet; requesting permission to create one. Mar 7 20:45:31 ikev2_packet_st_connect_decision: [bcec00/0] Pad allows connection Mar 7 20:45:31 ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library Mar 7 20:45:31 ike_udp_callback_common: Packet from 212.214.4.178:500, use_natt=0 data[0..264] = 1a7627a9 7388d4ac 00000000 00000000 ... Mar 7 20:45:31 ike_get_sa: Start, SA = { 1a7627a9 7388d4ac - 00000000 00000000 } / 00000000, remote = 212.214.4.178:500 Mar 7 20:45:31 ike_get_sa: We are responder and this is initiators first packet Mar 7 20:45:31 ike_cookie_create: Cookie create Mar 7 20:45:31 00000000: abdd 1263 8e8e 7103 ...c..q. Mar 7 20:45:31 ike_sa_allocate: Start, SA = { 1a7627a9 7388d4ac - abdd1263 8e8e7103 } Mar 7 20:45:31 ike_udp_callback_common: New SA Mar 7 20:45:31 ike_init_isakmp_sa: Start, remote = 212.214.4.178:500, initiator = 0 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - abdd1263 8e8e7103 [-1] / 0x00000000 } IP; New SA Mar 7 20:45:31 ikev2_fb_new_connection: New ISAKMP connection from remote address 212.214.4.178/500 Mar 7 20:45:31 ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation c23800 (now 1 references) Mar 7 20:45:31 ikev2_fallback_negotiation_alloc: Allocated fallback negotiation c23800 Mar 7 20:45:31 ssh_set_thread_debug_info: ikev2_fb_new_connection: set thread debug info - local 0x5760a531 remote 0xd4d605b3neg 0xc23800 neg->ike_sa 0x0 ike_sa 0x0 Mar 7 20:45:31 ikev2_packet_destroy: [bcec00/0] Destructor Mar 7 20:45:31 ikev2_packet_free: [bcec00/0] Freeing Mar 7 20:45:31 ikev2_fb_p1_negotiation_allocate_sa: Taking reference to fallback negotiation c23800 (now 2 references) Mar 7 20:45:31 ssh_set_thread_debug_info: ikev2_fb_p1_negotiation_allocate_sa: set thread debug info - local 0x5760a531 remote 0xd4d605b3neg 0xc23800 neg->ike_sa 0x0 ike_sa 0x0 Mar 7 20:45:31 ikev2_fb_p1_negotiation_wait_sa_done: Suspending until the IKE SA is done (neg c23800) Mar 7 20:45:31 ikev2_fb_st_new_p1_connection_start: FB; Calling v2 policy function ike_sa_allocate Mar 7 20:45:31 ikev2_fb_ike_sa_allocate_cb: New IKE SA allocated successfully c1d800 (neg c23800) Mar 7 20:45:31 ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref Mar 7 20:45:31 ssh_ikev2_ike_sa_take_ref: Calling ike_sa_take_ref Mar 7 20:45:31 ikev2_allocate_exchange_data: Calling exchange_data_alloc Mar 7 20:45:31 ikev2_allocate_exchange_data: Successfully allocated exchange data for SA c1d800 Mar 7 20:45:31 ikev2_allocate_exchange_data_ike: Allocating IKE exchange data for SA c1d800 ED c28028 Mar 7 20:45:31 ikev2_allocate_exchange_data_ike: Successfully allocated IKE exchange data for SA c1d800 ED c28028 Mar 7 20:45:31 ikev2_allocate_exchange_data_ipsec: Allocating IPsec exchange data for SA c1d800 ED c28028 Mar 7 20:45:31 ikev2_allocate_exchange_data_ipsec: Successfully allocated IPsec exchange data for SA c1d800 ED c28028 Mar 7 20:45:31 ssh_isakmp_update_responder_cookie: Updating responder IKE cookie Mar 7 20:45:31 ssh_isakmp_update_responder_cookie: Original IKE cookie Mar 7 20:45:31 00000000: abdd 1263 8e8e 7103 ...c..q. Mar 7 20:45:31 ssh_isakmp_update_responder_cookie: New IKE cookie Mar 7 20:45:31 00000000: 7634 3cd6 4629 6f2a v4<.F)o* Mar 7 20:45:31 ikev2_fb_st_new_p1_connection_local_addresses: Accepting new Phase-1 negotiation: local=86.95.164.48:500, remote=212.214.4.178:500 (neg c23800) Mar 7 20:45:31 ikev2_fb_st_new_p1_connection_local_addresses: FB; Calling v2 policy function get_local_address_list Mar 7 20:45:31 ikev2_fallback_negotiation_free: Fallback negotiation c23800 has still 1 references Mar 7 20:45:31 ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 86.95.164.48 remote 212.214.4.178 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Received packet[264] = 0x1a7627a9 7388d4ac 00000000 00000000 01100200 00000000 00000108 0d000040 00000001 00000001 00000034 00010801 1a7627a Mar 7 20:45:31 ike_decode_packet: Start Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Packet received[264] = 0x1a7627a9 7388d4ac 00000000 00000000 01100200 00000000 00000108 0d000040 00000001 00000001 00000034 00010801 1a7627a Mar 7 20:45:31 ike_decode_packet: Start, SA = { 1a7627a9 7388d4ac - 76343cd6 46296f2a} / 00000000, nego = -1 Mar 7 20:45:31 ike_decode_packet: first_payload_type:1. Mar 7 20:45:31 ike_decode_packet: next_payload_type:13. Mar 7 20:45:31 ike_decode_packet: next_payload_type:13. Mar 7 20:45:31 ike_decode_packet: next_payload_type:13. Mar 7 20:45:31 ike_decode_packet: next_payload_type:13. Mar 7 20:45:31 ike_decode_packet: next_payload_type:13. Mar 7 20:45:31 ike_decode_packet: next_payload_type:13. Mar 7 20:45:31 ike_decode_packet: next_payload_type:13. Mar 7 20:45:31 ike_decode_packet: next_payload_type:13. Mar 7 20:45:31 ike_decode_packet: next_payload_type:0. Mar 7 20:45:31 ike_decode_payload_sa: Start Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: doi = 1, sit = 0x1 Mar 7 20:45:31 ike_decode_payload_sa: Found 1 proposals Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: Proposal[0] = 0 .protocol[0] = 1, # transforms = 1, spi[8] = 0x1a7627a9 7388d4ac Mar 7 20:45:31 ike_decode_payload_t: Start, # trans = 1 Mar 7 20:45:31 ssh_ike_decode_data_attribute_size: decode_size B: type = 1 (0x0001), value = 7 (0x0007), size = 4 Mar 7 20:45:31 ssh_ike_decode_data_attribute_size: decode_size B: type = 14 (0x000e), value = 256 (0x0100), size = 4 Mar 7 20:45:31 ssh_ike_decode_data_attribute_size: decode_size B: type = 2 (0x0002), value = 2 (0x0002), size = 4 Mar 7 20:45:31 ssh_ike_decode_data_attribute_size: decode_size B: type = 3 (0x0003), value = 1 (0x0001), size = 4 Mar 7 20:45:31 ssh_ike_decode_data_attribute_size: decode_size B: type = 4 (0x0004), value = 2 (0x0002), size = 4 Mar 7 20:45:31 ssh_ike_decode_data_attribute_size: decode_size B: type = 11 (0x000b), value = 1 (0x0001), size = 4 Mar 7 20:45:31 ssh_ike_decode_data_attribute_size: decode_size B: type = 12 (0x000c), value = 28800 (0x7080), size = 4 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: trans[0] = 0, id = 1, # sa = #7 Mar 7 20:45:31 ssh_ike_decode_data_attribute: decode B: type = 1 (0x0001), value = 7 (0x0007), len = 2, used_bytes = 4 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: da[0], type = 1, value[2] = 0x0007 Mar 7 20:45:31 ssh_ike_decode_data_attribute: decode B: type = 14 (0x000e), value = 256 (0x0100), len = 2, used_bytes = 4 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: da[1], type = 14, value[2] = 0x0100 Mar 7 20:45:31 ssh_ike_decode_data_attribute: decode B: type = 2 (0x0002), value = 2 (0x0002), len = 2, used_bytes = 4 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: da[2], type = 2, value[2] = 0x0002 Mar 7 20:45:31 ssh_ike_decode_data_attribute: decode B: type = 3 (0x0003), value = 1 (0x0001), len = 2, used_bytes = 4 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: da[3], type = 3, value[2] = 0x0001 Mar 7 20:45:31 ssh_ike_decode_data_attribute: decode B: type = 4 (0x0004), value = 2 (0x0002), len = 2, used_bytes = 4 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: da[4], type = 4, value[2] = 0x0002 Mar 7 20:45:31 ssh_ike_decode_data_attribute: decode B: type = 11 (0x000b), value = 1 (0x0001), len = 2, used_bytes = 4 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: da[5], type = 11, value[2] = 0x0001 Mar 7 20:45:31 ssh_ike_decode_data_attribute: decode B: type = 12 (0x000c), value = 28800 (0x7080), len = 2, used_bytes = 4 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode SA: da[6], type = 12, value[2] = 0x7080 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode VID: data[16] = 0xafcad713 68a1f1c9 6b8696fc 77570100 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode VID: data[28] = 0x69936922 8741c6d4 ca094c93 e242c9de 19e7b7c6 00000005 00000500 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x27bab5dc 01ea0760 ea4e3190 ac27c0d0 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x6105c422 e76847e4 3f968480 1292aecd Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x4485152d 18b6bbcd 0be8a846 9579ddcc Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode VID: data[16] = 0xcd604643 35df21f8 7cfdb2fc 68b6a448 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x90cb8091 3ebb696e 086381b5 ec427b1f Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Decode VID: data[16] = 0x7d9419a6 5310ca6f 2c179d92 15529d56 Mar 7 20:45:31 86.95.164.48:500 (Responder) <-> 212.214.4.178:500 { 1a7627a9 7388d4ac - 76343cd6 46296f2a [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0401 SA VID Mar 7 20:45:31 ike_state_step: Current state = Start sa negotiation R (2)/-1, exchange = 2, auth_method = any, Responder Mar 7 20:45:31 ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0 Mar 7 20:45:31 ike_state_step: Matched state = Start sa negotiation R (2) Mar 7 20:45:31 ike_state_step: Calling input function[0] = ike_st_i_vid Mar 7 20:45:31 ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ... Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d800 Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:45:31 ike_st_i_vid: VID[0..28] = 69936922 8741c6d4 ... Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 28, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d800 Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:45:31 ike_st_i_vid: VID[0..16] = 27bab5dc 01ea0760 ... Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d800 Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:45:31 ike_st_i_vid: VID[0..16] = 6105c422 e76847e4 ... Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d800 Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:45:31 ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ... Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d800 Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:45:31 ike_st_i_vid: VID[0..16] = cd604643 35df21f8 ... Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d800 Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Received NAT-T vendor id [draft-ietf-ipsec-nat-t-ike-02] Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:45:31 ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ... Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d800 Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Received NAT-T vendor id [draft-ietf-ipsec-nat-t-ike-02] Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:45:31 ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ... Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Start ike_sa c1d800 Mar 7 20:45:31 ikev2_fb_check_natt_vendor_id: Received NAT-T vendor id [draft-ietf-ipsec-nat-t-ike-03] Mar 7 20:45:31 ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id Mar 7 20:45:31 ike_state_step: Calling input function[1] = ike_st_i_sa_proposal Mar 7 20:45:31 ike_st_i_sa_proposal: Start Mar 7 20:45:31 ikev2_fb_isakmp_select_sa: Select IKE SA policy call entered, IKE SA c1d800 (neg c23800) Mar 7 20:45:31 ikev2_fb_isakmp_select_sa: Taking reference to fallback negotiation c23800 (now 2 references) Mar 7 20:45:31 ssh_set_thread_debug_info: ikev2_fb_isakmp_select_sa: set thread debug info - local 0x5760a531 remote 0xd4d605b3neg 0xc23800 neg->ike_sa 0xc1d800 ike_sa 0x0 Mar 7 20:45:31 ike_state_step: Input function[1] = ike_st_i_sa_proposal asked retry later Mar 7 20:45:31 ike_process_packet: No output packet, returning Mar 7 20:45:31 ikev2_fb_st_select_ike_sa: FB; Calling v2 policy function select_ike_sa Mar 7 20:45:31 ssh_ikev2_sa_select: SA_SELECT: Selecting IKEv1 proposal. Mar 7 20:45:31 ssh_ikev2_sav1_select: Comparing 1 input proposals against 1 policy proposals Mar 7 20:45:31 ssh_ikev2_sav1_select: Comparing input proposal #0 against policy proposal #1 Mar 7 20:45:31 ikev2_choose_v1_proposal: Comparing 1 protocol(s) Mar 7 20:45:31 ikev2_choose_v1_proposal: Comparing transforms of protocol 1 Mar 7 20:45:31 ikev2_choose_v1_transform: Comparing 1 input transforms against 1 policy transforms Mar 7 20:45:31 ikev2_choose_v1_transform: Comparing input transform #0 against policy transform #0 Mar 7 20:45:31 ikev2_choose_v1_transform: Transform id 1 matches, comparing attributes Mar 7 20:45:31 ikev2_ikev1_attribute_check: Comparing 7 input attributes against 7 policy attributes Mar 7 20:45:31 ikev2_ikev1_attribute_check: Comparing input attribute 0 against policy attribute 0 Mar 7 20:45:31 ikev2_ikev1_attribute_check: Input and policy attributes of type 1 match Mar 7 20:45:31 ikev2_ikev1_attribute_check: Comparing input attribute 1 against policy attribute 0 Mar 7 20:45:31 ikev2_ikev1_attribute_check: Comparing input attribute 1 against policy attribute 1 Mar 7 20:45:31 ikev2_ikev1_attribute_check: Input and policy attributes of type 14 match Mar 7 20:45:31 ikev2_ikev1_attribute_check: Comparing input attribute 2 against policy attribute 0 Mar 7 20:45:31 ikev2_ikev1_attribute_check: Comparing input attribute 2 against policy attribute 1 Mar 7 20:45:31 ikev2_ikev1_attribute_check: Comparing input attri^C