May 14 22:46:13 clear-log[1926]: logfile cleared May 14 22:47:50 Deleted (spi=2745422010, protocol=ESP dst=176.x.x.50) entry from the peer hash table May 14 22:47:50 Deleted (spi=2745422010, protocol=ESP dst=176.x.x.50) entry from the dynamic sa spi hash table May 14 22:47:50 jnp_ike_connect_delete: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:47:50 jnp_ike_create_delete_internal: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:47:50 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:47:50 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:47:50 jnp_ike_create_delete_internal: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:47:50 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / a0bf1e64, nego = 0 May 14 22:47:50 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:47:50 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:47:50 ike_free_negotiation_info: Start, nego = 0 May 14 22:47:50 ike_free_negotiation: Start, nego = 0 May 14 22:47:50 Delete notification sent for 1 SPI's peer 195.x.x.178:500; IKE SA was found May 14 22:47:50 NHTB entry not found. Not deleting NHTB entry May 14 22:47:50 In iked_ipsec_sa_pair_delete Deleting GENCFG msg with key; Tunnel = 131073;SPI-In = 2745422010 May 14 22:47:50 Deleted SA pair for tunnel = 131073 with SPI-In = 2745422010 to kernel May 14 22:47:50 Deleted (spi=2745422010, protocol=ESP) entry from the inbound sa spi hash table May 14 22:47:50 Deleted (spi=4018587516, protocol=ESP dst=195.x.x.178) entry from the peer hash table May 14 22:47:50 Deleted (spi=4018587516, protocol=ESP dst=195.x.x.178) entry from the dynamic sa spi hash table May 14 22:47:50 jnp_ike_connect_delete: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:47:50 jnp_ike_create_delete_internal: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:47:50 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:47:50 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:47:50 jnp_ike_create_delete_internal: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:47:50 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 75f3bcd6, nego = 0 May 14 22:47:50 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:47:50 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:47:50 ike_free_negotiation_info: Start, nego = 0 May 14 22:47:50 ike_free_negotiation: Start, nego = 0 May 14 22:47:50 Delete notification sent for 1 SPI's peer 195.x.x.178:500; IKE SA was found May 14 22:47:50 KMD_VPN_DOWN_ALARM_USER: VPN vpn001 from 195.x.x.178 is down. May 14 22:47:50 KMD_VPN_DOWN_ALARM_USER: VPN vpn001 from 195.x.x.178 is down. May 14 22:48:00 kmd_pm_ike_start_p1 May 14 22:48:00 Phase-1 negotiation succeeded for p1_local=ipv4(udp:0,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) May 14 22:48:00 Phase-2 sa_cfg lookup with local_id=ipv4_subnet(any:0,[0..7]=192.168.10.0/24), remote_id=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:48:00 Negotiating IPsec SA with Phase-2 IDS: local_id=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) remote_id=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:48:00 jnp_ike_connect_ipsec: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:48:00 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:48:00 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:48:00 jnp_ike_connect_ipsec: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:48:00 ike_init_qm_negotiation: Start, initiator = 1, message_id = 1df2a798 May 14 22:48:00 ike_st_o_qm_hash_1: Start May 14 22:48:00 ike_st_o_qm_sa_proposals: Start May 14 22:48:00 ike_st_o_qm_nonce: Start May 14 22:48:00 ike_policy_reply_qm_nonce_data_len: Start May 14 22:48:00 ike_st_o_qm_optional_ke: Start May 14 22:48:00 ike_st_o_qm_optional_ids: Start May 14 22:48:00 ike_st_qm_optional_id: Start May 14 22:48:00 ike_st_qm_optional_id: Start May 14 22:48:00 ike_st_o_private: Start May 14 22:48:00 ike_policy_reply_private_payload_out: Start May 14 22:48:00 ike_st_o_encrypt: Marking encryption for packet May 14 22:48:00 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 1df2a798, nego = 0 May 14 22:48:00 ike_finalize_qm_hash_1: Hash[0..20] = e2ea2193 b4a1fcf8 ... May 14 22:48:00 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:48:00 ike_get_sa: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } / 1df2a798, remote = 195.x.x.178:500 May 14 22:48:00 ike_sa_find: Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } May 14 22:48:00 ike_decode_packet: Start May 14 22:48:00 ike_decode_packet: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} / 1df2a798, nego = 0 May 14 22:48:00 ike_decode_payload_sa: Start May 14 22:48:00 ike_decode_payload_t: Start, # trans = 1 May 14 22:48:00 ike_st_i_encrypt: Check that packet was encrypted succeeded May 14 22:48:00 ike_st_i_qm_hash_2: Start, hash[0..20] = 4f7cbadb b71069ad ... May 14 22:48:00 ike_st_i_qm_sa_values: Start May 14 22:48:00 ike_st_i_qm_nonce: Nonce[0..20] = 2f497c0b e5bb9c9a ... May 14 22:48:00 ike_st_i_qm_ke: Ke[0..128] = 4ae27324 5acd4a1d ... May 14 22:48:00 ike_st_i_private: Start May 14 22:48:00 ike_st_o_qm_hash_3: Start May 14 22:48:00 ike_st_o_private: Start May 14 22:48:00 ike_policy_reply_private_payload_out: Start May 14 22:48:00 ike_st_o_encrypt: Marking encryption for packet May 14 22:48:00 176.x.x.50:500 (Initiator) <-> 195.x.x.178:500 { 2afd72c6 817f649f - d7274263 c8f7e6ed [0] / 0x1df2a798 } QM; MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 May 14 22:48:00 ike_qm_call_callback: MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 May 14 22:48:00 176.x.x.50:500 (Initiator) <-> 195.x.x.178:500 { 2afd72c6 817f649f - d7274263 c8f7e6ed [0] / 0x1df2a798 } QM; MESSAGE: SA[0][0] = ESP 3des, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-96, key len = 0, key rounds = 0 May 14 22:48:00 ike_qm_call_callback: MESSAGE: SA[0][0] = ESP 3des, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-96, key len = 0, key rounds = 0 May 14 22:48:00 Added (spi=1194826827, protocol=ESP dst=176.x.x.50) entry to the dynamic sa spi hash table May 14 22:48:00 Added (spi=1194826827, protocol=ESP) entry to the inbound spi hash table May 14 22:48:00 Added (spi=1194826827, protocol=ESP dst=176.x.x.50) entry to the peer hash table May 14 22:48:00 Added (spi=3831433829, protocol=ESP dst=195.x.x.178) entry to the dynamic sa spi hash table May 14 22:48:00 Added (spi=3831433829, protocol=ESP dst=195.x.x.178) entry to the peer hash table May 14 22:48:00 Phase-2 [initiator] done for p1_local=ipv4(udp:500,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) p2_local=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) p2_remote=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:48:00 Hardlife timer started for inbound vpn001 with 3600 seconds/0 kilobytes May 14 22:48:00 Softlife timer started for inbound vpn001 with 2981 seconds/0 kilobytes May 14 22:48:00 In iked_ipsec_sa_pair_add May 14 22:48:00 In iked_ipsec_sa_pair_add Adding GENCFG msg with key; Tunnel = 131073;SPI-In = 47379c4b May 14 22:48:00 Added dependency on SA config blob with tunnelid = 131073 May 14 22:48:00 Successfully added ipsec SA PAIR May 14 22:48:00 KMD_VPN_UP_ALARM_USER: VPN vpn001 from 195.x.x.178 is up. May 14 22:48:00 KMD_VPN_UP_ALARM_USER: VPN vpn001 from 195.x.x.178 is up. May 14 22:48:00 ike_st_o_qm_wait_done: Marking for waiting for done May 14 22:48:00 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 1df2a798, nego = 0 May 14 22:48:00 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:48:00 kmd_pm_ike_p2qm_notify_callback May 14 22:48:00 Quick mode negotiation succeeded for p1_local=ipv4(udp:0,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) p2_local=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) p2_remote=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:48:00 ike_send_notify: Connected, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:48:00 ike_get_sa: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } / 1df2a798, remote = 195.x.x.178:500 May 14 22:48:00 ike_sa_find: Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } May 14 22:48:00 ike_decode_packet: Start May 14 22:48:00 ike_decode_packet: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} / 1df2a798, nego = 0 May 14 22:48:00 ike_st_o_qm_done: Quick Mode negotiation done May 14 22:48:00 ike_send_notify: Connected, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:48:00 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:48:00 ike_free_negotiation_qm: Start, nego = 0 May 14 22:48:00 ike_free_negotiation: Start, nego = 0 May 14 22:48:00 ike_free_id_payload: Start, id type = 4 May 14 22:48:00 ike_free_id_payload: Start, id type = 4 May 14 22:48:00 ike_free_id_payload: Start, id type = 4 May 14 22:48:00 ike_free_id_payload: Start, id type = 4 root> show log kmd May 14 22:46:13 clear-log[1926]: logfile cleared May 14 22:47:50 Deleted (spi=2745422010, protocol=ESP dst=176.x.x.50) entry from the peer hash table May 14 22:47:50 Deleted (spi=2745422010, protocol=ESP dst=176.x.x.50) entry from the dynamic sa spi hash table May 14 22:47:50 jnp_ike_connect_delete: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:47:50 jnp_ike_create_delete_internal: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:47:50 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:47:50 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:47:50 jnp_ike_create_delete_internal: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:47:50 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / a0bf1e64, nego = 0 May 14 22:47:50 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:47:50 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:47:50 ike_free_negotiation_info: Start, nego = 0 May 14 22:47:50 ike_free_negotiation: Start, nego = 0 May 14 22:47:50 Delete notification sent for 1 SPI's peer 195.x.x.178:500; IKE SA was found May 14 22:47:50 NHTB entry not found. Not deleting NHTB entry May 14 22:47:50 In iked_ipsec_sa_pair_delete Deleting GENCFG msg with key; Tunnel = 131073;SPI-In = 2745422010 May 14 22:47:50 Deleted SA pair for tunnel = 131073 with SPI-In = 2745422010 to kernel May 14 22:47:50 Deleted (spi=2745422010, protocol=ESP) entry from the inbound sa spi hash table May 14 22:47:50 Deleted (spi=4018587516, protocol=ESP dst=195.x.x.178) entry from the peer hash table May 14 22:47:50 Deleted (spi=4018587516, protocol=ESP dst=195.x.x.178) entry from the dynamic sa spi hash table May 14 22:47:50 jnp_ike_connect_delete: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:47:50 jnp_ike_create_delete_internal: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:47:50 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:47:50 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:47:50 jnp_ike_create_delete_internal: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:47:50 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 75f3bcd6, nego = 0 May 14 22:47:50 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:47:50 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:47:50 ike_free_negotiation_info: Start, nego = 0 May 14 22:47:50 ike_free_negotiation: Start, nego = 0 May 14 22:47:50 Delete notification sent for 1 SPI's peer 195.x.x.178:500; IKE SA was found May 14 22:47:50 KMD_VPN_DOWN_ALARM_USER: VPN vpn001 from 195.x.x.178 is down. May 14 22:47:50 KMD_VPN_DOWN_ALARM_USER: VPN vpn001 from 195.x.x.178 is down. May 14 22:48:00 kmd_pm_ike_start_p1 May 14 22:48:00 Phase-1 negotiation succeeded for p1_local=ipv4(udp:0,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) May 14 22:48:00 Phase-2 sa_cfg lookup with local_id=ipv4_subnet(any:0,[0..7]=192.168.10.0/24), remote_id=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:48:00 Negotiating IPsec SA with Phase-2 IDS: local_id=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) remote_id=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:48:00 jnp_ike_connect_ipsec: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:48:00 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:48:00 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:48:00 jnp_ike_connect_ipsec: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:48:00 ike_init_qm_negotiation: Start, initiator = 1, message_id = 1df2a798 May 14 22:48:00 ike_st_o_qm_hash_1: Start May 14 22:48:00 ike_st_o_qm_sa_proposals: Start May 14 22:48:00 ike_st_o_qm_nonce: Start May 14 22:48:00 ike_policy_reply_qm_nonce_data_len: Start May 14 22:48:00 ike_st_o_qm_optional_ke: Start May 14 22:48:00 ike_st_o_qm_optional_ids: Start May 14 22:48:00 ike_st_qm_optional_id: Start May 14 22:48:00 ike_st_qm_optional_id: Start May 14 22:48:00 ike_st_o_private: Start May 14 22:48:00 ike_policy_reply_private_payload_out: Start May 14 22:48:00 ike_st_o_encrypt: Marking encryption for packet May 14 22:48:00 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 1df2a798, nego = 0 May 14 22:48:00 ike_finalize_qm_hash_1: Hash[0..20] = e2ea2193 b4a1fcf8 ... May 14 22:48:00 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:48:00 ike_get_sa: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } / 1df2a798, remote = 195.x.x.178:500 May 14 22:48:00 ike_sa_find: Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } May 14 22:48:00 ike_decode_packet: Start May 14 22:48:00 ike_decode_packet: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} / 1df2a798, nego = 0 May 14 22:48:00 ike_decode_payload_sa: Start May 14 22:48:00 ike_decode_payload_t: Start, # trans = 1 May 14 22:48:00 ike_st_i_encrypt: Check that packet was encrypted succeeded May 14 22:48:00 ike_st_i_qm_hash_2: Start, hash[0..20] = 4f7cbadb b71069ad ... May 14 22:48:00 ike_st_i_qm_sa_values: Start May 14 22:48:00 ike_st_i_qm_nonce: Nonce[0..20] = 2f497c0b e5bb9c9a ... May 14 22:48:00 ike_st_i_qm_ke: Ke[0..128] = 4ae27324 5acd4a1d ... May 14 22:48:00 ike_st_i_private: Start May 14 22:48:00 ike_st_o_qm_hash_3: Start May 14 22:48:00 ike_st_o_private: Start May 14 22:48:00 ike_policy_reply_private_payload_out: Start May 14 22:48:00 ike_st_o_encrypt: Marking encryption for packet May 14 22:48:00 176.x.x.50:500 (Initiator) <-> 195.x.x.178:500 { 2afd72c6 817f649f - d7274263 c8f7e6ed [0] / 0x1df2a798 } QM; MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 May 14 22:48:00 ike_qm_call_callback: MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 May 14 22:48:00 176.x.x.50:500 (Initiator) <-> 195.x.x.178:500 { 2afd72c6 817f649f - d7274263 c8f7e6ed [0] / 0x1df2a798 } QM; MESSAGE: SA[0][0] = ESP 3des, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-96, key len = 0, key rounds = 0 May 14 22:48:00 ike_qm_call_callback: MESSAGE: SA[0][0] = ESP 3des, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-96, key len = 0, key rounds = 0 May 14 22:48:00 Added (spi=1194826827, protocol=ESP dst=176.x.x.50) entry to the dynamic sa spi hash table May 14 22:48:00 Added (spi=1194826827, protocol=ESP) entry to the inbound spi hash table May 14 22:48:00 Added (spi=1194826827, protocol=ESP dst=176.x.x.50) entry to the peer hash table May 14 22:48:00 Added (spi=3831433829, protocol=ESP dst=195.x.x.178) entry to the dynamic sa spi hash table May 14 22:48:00 Added (spi=3831433829, protocol=ESP dst=195.x.x.178) entry to the peer hash table May 14 22:48:00 Phase-2 [initiator] done for p1_local=ipv4(udp:500,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) p2_local=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) p2_remote=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:48:00 Hardlife timer started for inbound vpn001 with 3600 seconds/0 kilobytes May 14 22:48:00 Softlife timer started for inbound vpn001 with 2981 seconds/0 kilobytes May 14 22:48:00 In iked_ipsec_sa_pair_add May 14 22:48:00 In iked_ipsec_sa_pair_add Adding GENCFG msg with key; Tunnel = 131073;SPI-In = 47379c4b May 14 22:48:00 Added dependency on SA config blob with tunnelid = 131073 May 14 22:48:00 Successfully added ipsec SA PAIR May 14 22:48:00 KMD_VPN_UP_ALARM_USER: VPN vpn001 from 195.x.x.178 is up. May 14 22:48:00 KMD_VPN_UP_ALARM_USER: VPN vpn001 from 195.x.x.178 is up. May 14 22:48:00 ike_st_o_qm_wait_done: Marking for waiting for done May 14 22:48:00 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 1df2a798, nego = 0 May 14 22:48:00 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:48:00 kmd_pm_ike_p2qm_notify_callback May 14 22:48:00 Quick mode negotiation succeeded for p1_local=ipv4(udp:0,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) p2_local=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) p2_remote=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:48:00 ike_send_notify: Connected, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:48:00 ike_get_sa: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } / 1df2a798, remote = 195.x.x.178:500 May 14 22:48:00 ike_sa_find: Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } May 14 22:48:00 ike_decode_packet: Start May 14 22:48:00 ike_decode_packet: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} / 1df2a798, nego = 0 May 14 22:48:00 ike_st_o_qm_done: Quick Mode negotiation done May 14 22:48:00 ike_send_notify: Connected, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:48:00 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:48:00 ike_free_negotiation_qm: Start, nego = 0 May 14 22:48:00 ike_free_negotiation: Start, nego = 0 May 14 22:48:00 ike_free_id_payload: Start, id type = 4 May 14 22:48:00 ike_free_id_payload: Start, id type = 4 May 14 22:48:00 ike_free_id_payload: Start, id type = 4 May 14 22:48:00 ike_free_id_payload: Start, id type = 4 May 14 22:49:51 Deleted (spi=1194826827, protocol=ESP dst=176.x.x.50) entry from the peer hash table May 14 22:49:51 Deleted (spi=1194826827, protocol=ESP dst=176.x.x.50) entry from the dynamic sa spi hash table May 14 22:49:51 jnp_ike_connect_delete: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:49:51 jnp_ike_create_delete_internal: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:49:51 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:49:51 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:49:51 jnp_ike_create_delete_internal: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:49:51 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 54ed70b2, nego = 0 May 14 22:49:51 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:49:51 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:49:51 ike_free_negotiation_info: Start, nego = 0 May 14 22:49:51 ike_free_negotiation: Start, nego = 0 May 14 22:49:51 Delete notification sent for 1 SPI's peer 195.x.x.178:500; IKE SA was found May 14 22:49:51 NHTB entry not found. Not deleting NHTB entry May 14 22:49:51 In iked_ipsec_sa_pair_delete Deleting GENCFG msg with key; Tunnel = 131073;SPI-In = 1194826827 May 14 22:49:51 Deleted SA pair for tunnel = 131073 with SPI-In = 1194826827 to kernel May 14 22:49:51 Deleted (spi=1194826827, protocol=ESP) entry from the inbound sa spi hash table May 14 22:49:51 Deleted (spi=3831433829, protocol=ESP dst=195.x.x.178) entry from the peer hash table May 14 22:49:51 Deleted (spi=3831433829, protocol=ESP dst=195.x.x.178) entry from the dynamic sa spi hash table May 14 22:49:51 jnp_ike_connect_delete: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:49:51 jnp_ike_create_delete_internal: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:49:51 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:49:51 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:49:51 jnp_ike_create_delete_internal: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:49:51 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / c15f6097, nego = 0 May 14 22:49:51 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:49:51 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:49:51 ike_free_negotiation_info: Start, nego = 0 May 14 22:49:51 ike_free_negotiation: Start, nego = 0 May 14 22:49:51 Delete notification sent for 1 SPI's peer 195.x.x.178:500; IKE SA was found May 14 22:49:51 KMD_VPN_DOWN_ALARM_USER: VPN vpn001 from 195.x.x.178 is down. May 14 22:49:51 KMD_VPN_DOWN_ALARM_USER: VPN vpn001 from 195.x.x.178 is down. May 14 22:50:01 kmd_pm_ike_start_p1 May 14 22:50:01 Phase-1 negotiation succeeded for p1_local=ipv4(udp:0,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) May 14 22:50:01 Phase-2 sa_cfg lookup with local_id=ipv4_subnet(any:0,[0..7]=192.168.10.0/24), remote_id=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:50:01 Negotiating IPsec SA with Phase-2 IDS: local_id=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) remote_id=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:50:01 jnp_ike_connect_ipsec: Start, remote_name = 195.x.x.178:500, flags = 00010000 May 14 22:50:01 ike_sa_find_ip_port: Remote = 195.x.x.178:500, Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:50:01 ike_alloc_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} May 14 22:50:01 jnp_ike_connect_ipsec: SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:50:01 ike_init_qm_negotiation: Start, initiator = 1, message_id = 20d16b32 May 14 22:50:01 ike_st_o_qm_hash_1: Start May 14 22:50:01 ike_st_o_qm_sa_proposals: Start May 14 22:50:01 ike_st_o_qm_nonce: Start May 14 22:50:01 ike_policy_reply_qm_nonce_data_len: Start May 14 22:50:01 ike_st_o_qm_optional_ke: Start May 14 22:50:01 ike_st_o_qm_optional_ids: Start May 14 22:50:01 ike_st_qm_optional_id: Start May 14 22:50:01 ike_st_qm_optional_id: Start May 14 22:50:01 ike_st_o_private: Start May 14 22:50:01 ike_policy_reply_private_payload_out: Start May 14 22:50:01 ike_st_o_encrypt: Marking encryption for packet May 14 22:50:01 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 20d16b32, nego = 0 May 14 22:50:01 ike_finalize_qm_hash_1: Hash[0..20] = ab8488fe f15d04fd ... May 14 22:50:01 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:50:01 ike_get_sa: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } / 20d16b32, remote = 195.x.x.178:500 May 14 22:50:01 ike_sa_find: Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } May 14 22:50:01 ike_decode_packet: Start May 14 22:50:01 ike_decode_packet: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} / 20d16b32, nego = 0 May 14 22:50:01 ike_decode_payload_sa: Start May 14 22:50:01 ike_decode_payload_t: Start, # trans = 1 May 14 22:50:01 ike_st_i_encrypt: Check that packet was encrypted succeeded May 14 22:50:01 ike_st_i_qm_hash_2: Start, hash[0..20] = b00dc3bb ecec636a ... May 14 22:50:01 ike_st_i_qm_sa_values: Start May 14 22:50:01 ike_st_i_qm_nonce: Nonce[0..20] = a0d6bcad 20ed08d4 ... May 14 22:50:01 ike_st_i_qm_ke: Ke[0..128] = f0dc7285 5e28a07c ... May 14 22:50:01 ike_st_i_private: Start May 14 22:50:01 ike_st_o_qm_hash_3: Start May 14 22:50:01 ike_st_o_private: Start May 14 22:50:01 ike_policy_reply_private_payload_out: Start May 14 22:50:01 ike_st_o_encrypt: Marking encryption for packet May 14 22:50:01 176.x.x.50:500 (Initiator) <-> 195.x.x.178:500 { 2afd72c6 817f649f - d7274263 c8f7e6ed [0] / 0x20d16b32 } QM; MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 May 14 22:50:01 ike_qm_call_callback: MESSAGE: Phase 2 connection succeeded, Using PFS, group = 2 May 14 22:50:01 176.x.x.50:500 (Initiator) <-> 195.x.x.178:500 { 2afd72c6 817f649f - d7274263 c8f7e6ed [0] / 0x20d16b32 } QM; MESSAGE: SA[0][0] = ESP 3des, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-96, key len = 0, key rounds = 0 May 14 22:50:01 ike_qm_call_callback: MESSAGE: SA[0][0] = ESP 3des, life = 0 kB/3600 sec, group = 2, tunnel, hmac-sha1-96, key len = 0, key rounds = 0 May 14 22:50:01 Added (spi=3197329303, protocol=ESP dst=176.x.x.50) entry to the dynamic sa spi hash table May 14 22:50:01 Added (spi=3197329303, protocol=ESP) entry to the inbound spi hash table May 14 22:50:01 Added (spi=3197329303, protocol=ESP dst=176.x.x.50) entry to the peer hash table May 14 22:50:01 Added (spi=1829165718, protocol=ESP dst=195.x.x.178) entry to the dynamic sa spi hash table May 14 22:50:01 Added (spi=1829165718, protocol=ESP dst=195.x.x.178) entry to the peer hash table May 14 22:50:01 Phase-2 [initiator] done for p1_local=ipv4(udp:500,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) p2_local=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) p2_remote=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:50:01 Hardlife timer started for inbound vpn001 with 3600 seconds/0 kilobytes May 14 22:50:01 Softlife timer started for inbound vpn001 with 3000 seconds/0 kilobytes May 14 22:50:01 In iked_ipsec_sa_pair_add May 14 22:50:01 In iked_ipsec_sa_pair_add Adding GENCFG msg with key; Tunnel = 131073;SPI-In = be935f97 May 14 22:50:01 Added dependency on SA config blob with tunnelid = 131073 May 14 22:50:01 Successfully added ipsec SA PAIR May 14 22:50:01 KMD_VPN_UP_ALARM_USER: VPN vpn001 from 195.x.x.178 is up. May 14 22:50:01 KMD_VPN_UP_ALARM_USER: VPN vpn001 from 195.x.x.178 is up. May 14 22:50:01 ike_st_o_qm_wait_done: Marking for waiting for done May 14 22:50:01 ike_encode_packet: Start, SA = { 0x2afd72c6 817f649f - d7274263 c8f7e6ed } / 20d16b32, nego = 0 May 14 22:50:01 ike_send_packet: Start, send SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0, src = 176.x.x.50:500, dst = 195.x.x.178:500, routing table id = 0 May 14 22:50:01 kmd_pm_ike_p2qm_notify_callback May 14 22:50:01 Quick mode negotiation succeeded for p1_local=ipv4(udp:0,[0..3]=176.x.x.50) p1_remote=ipv4(udp:500,[0..3]=195.x.x.178) p2_local=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) p2_remote=ipv4_subnet(any:0,[0..7]=172.17.0.0/16) May 14 22:50:01 ike_send_notify: Connected, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:50:01 ike_get_sa: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } / 20d16b32, remote = 195.x.x.178:500 May 14 22:50:01 ike_sa_find: Found SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed } May 14 22:50:01 ike_decode_packet: Start May 14 22:50:01 ike_decode_packet: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed} / 20d16b32, nego = 0 May 14 22:50:01 ike_st_o_qm_done: Quick Mode negotiation done May 14 22:50:01 ike_send_notify: Connected, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:50:01 ike_delete_negotiation: Start, SA = { 2afd72c6 817f649f - d7274263 c8f7e6ed}, nego = 0 May 14 22:50:01 ike_free_negotiation_qm: Start, nego = 0 May 14 22:50:01 ike_free_negotiation: Start, nego = 0 May 14 22:50:01 ike_free_id_payload: Start, id type = 4 May 14 22:50:01 ike_free_id_payload: Start, id type = 4 May 14 22:50:01 ike_free_id_payload: Start, id type = 4 May 14 22:50:01 ike_free_id_payload: Start, id type = 4