Troubleshooting IPsec log messages Alan Gravett

Debugging IPsec logs can be time consuming operation. It’s like looking for a needle in a haystack. We offer you standard errors and example log outputs for the most common configuration errors in IPsec.

The diagram is simple. We used two devices to form a routed-based IPsec tunnel with option establish-tunnels immediately; under IPsec vpn configuration.
By altering their configuration we simulated various scenarios. The logs were caught using traceoptions configured under IKE and IPSEC container respectively.

The Junos version was 12.1X44-D10.4

1. IKE proposal mismatch
Situation when the devices have different proposals configured for IKE phase 1 and therefore cannot agree which one to use. This is one of the most common mistakes. Whether you use proposal-sets or custom proposals, always make sure the other side is configured to accept proposed parameters.

[Mar 25 14:20:03]iked_pm_ike_spd_notify_request: Sending Initial contact
[Mar 25 14:20:03]ssh_ike_connect: Start, remote_name = 192.168.10.3:500, xchg = 2, flags = 00090000
[Mar 25 14:20:03]ike_sa_allocate: Start, SA = { affba5bb 6e25b4e9 - 00000000 00000000 }
[Mar 25 14:20:03]ike_init_isakmp_sa: Start, remote = 192.168.10.3:500, initiator = 1
[Mar 25 14:20:03]192.168.10.1:500 (Initiator) <-> 192.168.10.3:500 { affba5bb 6e25b4e9 - 00000000 00000000 [-1] / 0x00000000 } IP; Warning: Number of proposals != 1 in ISAKMP SA, this is against draft!
[Mar 25 14:20:03]ssh_ike_connect: SA = { affba5bb 6e25b4e9 - 00000000 00000000}, nego = -1
[Mar 25 14:20:03]ike_st_o_sa_proposal: Start
[Mar 25 14:20:03]ike_policy_reply_isakmp_vendor_ids: Start
[Mar 25 14:20:03]ike_st_o_private: Start
[Mar 25 14:20:03]ike_policy_reply_private_payload_out: Start
[Mar 25 14:20:03]ike_encode_packet: Start, SA = { 0xaffba5bb 6e25b4e9 - 00000000 00000000 } / 00000000, nego = -1
[Mar 25 14:20:03]ike_send_packet: Start, send SA = { affba5bb 6e25b4e9 - 00000000 00000000}, nego = -1, dst = 192.168.10.3:500,  routing table id = 0
[Mar 25 14:20:03]kmd_rpd_cb_session_connect
[Mar 25 14:20:03]rpd session established
[Mar 25 14:20:03]kmd_rpd_db_read
[Mar 25 14:20:03]kmd_rpd_db_read: gw handle 20841984
[Mar 25 14:20:03]kmd_rpd_cb_protocol_register gw handle 20841984 return code 0
[Mar 25 14:20:03]ikev2_packet_allocate: Allocated packet d8fc00 from freelist
[Mar 25 14:20:03]ike_sa_find: Not found SA = { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 }
[Mar 25 14:20:03]ikev2_packet_st_input_v1_get_sa: Checking if unauthenticated IKEv1 notify is for an IKEv2 SA
[Mar 25 14:20:03]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Mar 25 14:20:03]ike_get_sa: Start, SA = { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 } / e2678dbd, remote = 192.168.10.3:500
[Mar 25 14:20:03]ike_sa_find: Not found SA = { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 }
[Mar 25 14:20:03]ike_sa_find_half: Found half SA = { affba5bb 6e25b4e9 - 00000000 00000000 }
[Mar 25 14:20:03]ike_sa_upgrade: Start, SA = { affba5bb 6e25b4e9 - 00000000 00000000 } -> { ... - bd9341ee 1fd376b1 }
[Mar 25 14:20:03]ike_alloc_negotiation: Start, SA = { affba5bb 6e25b4e9 - bd9341ee 1fd376b1}
[Mar 25 14:20:03]ike_decode_packet: Start
[Mar 25 14:20:03]ike_decode_packet: Start, SA = { affba5bb 6e25b4e9 - bd9341ee 1fd376b1} / e2678dbd, nego = 0
[Mar 25 14:20:03]ike_st_i_n: Start, doi = 1, protocol = 1, code = No proposal chosen (14), spi[0..16] = affba5bb 6e25b4e9 ..., data[0..46] = 800c0001 00060022 ...
[Mar 25 14:20:03]<none>:500 (Responder) <-> 192.168.10.3:500 { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 [0] / 0xe2678dbd } Info; Notification data has attribute list
[Mar 25 14:20:03]<none>:500 (Responder) <-> 192.168.10.3:500 { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 [0] / 0xe2678dbd } Info; Notify message version = 1
[Mar 25 14:20:03]<none>:500 (Responder) <-> 192.168.10.3:500 { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 [0] / 0xe2678dbd } Info; Error text = Could not find acceptable proposal
[Mar 25 14:20:03]<none>:500 (Responder) <-> 192.168.10.3:500 { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 [0] / 0xe2678dbd } Info; Offending message id = 0x00000000
[Mar 25 14:20:03]<none>:500 (Responder) <-> 192.168.10.3:500 { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 [0] / 0xe2678dbd } Info; Received notify err = No proposal chosen (14) to isakmp sa, delete it
[Mar 25 14:20:03]ike_st_i_private: Start
[Mar 25 14:20:03]ike_send_notify: Connected, SA = { affba5bb 6e25b4e9 - bd9341ee 1fd376b1}, nego = 0
[Mar 25 14:20:03]ike_delete_negotiation: Start, SA = { affba5bb 6e25b4e9 - bd9341ee 1fd376b1}, nego = 0
[Mar 25 14:20:03]ike_free_negotiation_info: Start, nego = 0
[Mar 25 14:20:03]ike_free_negotiation: Start, nego = 0
[Mar 25 14:20:03]ike_remove_callback: Start, delete SA = { affba5bb 6e25b4e9 - bd9341ee 1fd376b1}, nego = -1
[Mar 25 14:20:03]192.168.10.1:500 (Initiator) <-> 192.168.10.3:500 { affba5bb 6e25b4e9 - bd9341ee 1fd376b1 [-1] / 0x00000000 } IP; Connection got error = 14, calling callback
[Mar 25 14:20:03]ikev2_fb_v1_encr_id_to_v2_id: Unknown IKE encryption identifier -1
[Mar 25 14:20:03]ikev2_fb_v1_hash_id_to_v2_prf_id: Unknown IKE hash alg identifier -1
[Mar 25 14:20:03]ikev2_fb_v1_hash_id_to_v2_integ_id: Unknown IKE hash alg identifier -1
[Mar 25 14:20:03]IKE negotiation fail for local:192.168.10.1, remote:192.168.10.3 IKEv1 with status: No proposal chosen
[Mar 25 14:20:03]  IKEv1 Error : No proposal chosen
[Mar 25 14:20:03]IPSec Rekey for SPI 0x0 failed
[Mar 25 14:20:03]IPSec SA done callback called for sa-cfg srxA-1-to-spoke-1 local:192.168.10.1, remote:192.168.10.3 IKEv1 with status No proposal chosen
...

2. IKE authentication mismatch

Mismatch in the configured preshared keys – typically a typo. The traceoptions output is a bit longer, because the error happened later (after agreeing on proposal) during the negotiations.

[Mar 25 14:52:22]iked_pm_ike_spd_notify_request: Sending Initial contact
[Mar 25 14:52:22]ssh_ike_connect: Start, remote_name = 192.168.10.3:500, xchg = 2, flags = 00090000
[Mar 25 14:52:22]ike_sa_allocate: Start, SA = { 62c7569c cecc5e6a - 00000000 00000000 }
[Mar 25 14:52:22]ike_init_isakmp_sa: Start, remote = 192.168.10.3:500, initiator = 1
[Mar 25 14:52:22]192.168.10.1:500 (Initiator) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - 00000000 00000000 [-1] / 0x00000000 } IP; Warning: Number of proposals != 1 in ISAKMP SA, this is against draft!
[Mar 25 14:52:22]ssh_ike_connect: SA = { 62c7569c cecc5e6a - 00000000 00000000}, nego = -1
[Mar 25 14:52:22]ike_st_o_sa_proposal: Start
[Mar 25 14:52:22]ike_policy_reply_isakmp_vendor_ids: Start
[Mar 25 14:52:22]ike_st_o_private: Start
[Mar 25 14:52:22]ike_policy_reply_private_payload_out: Start
[Mar 25 14:52:22]ike_encode_packet: Start, SA = { 0x62c7569c cecc5e6a - 00000000 00000000 } / 00000000, nego = -1
[Mar 25 14:52:22]ike_send_packet: Start, send SA = { 62c7569c cecc5e6a - 00000000 00000000}, nego = -1, dst = 192.168.10.3:500,  routing table id = 0
[Mar 25 14:52:22]kmd_rpd_cb_session_connect
[Mar 25 14:52:22]rpd session established
[Mar 25 14:52:22]kmd_rpd_db_read
[Mar 25 14:52:22]kmd_rpd_db_read: gw handle 20841984
[Mar 25 14:52:22]kmd_rpd_cb_protocol_register gw handle 20841984 return code 0
[Mar 25 14:52:22]ikev2_packet_allocate: Allocated packet d8fc00 from freelist
[Mar 25 14:52:22]ike_sa_find: Not found SA = { 62c7569c cecc5e6a - caec2bba b53d8896 }
[Mar 25 14:52:22]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Mar 25 14:52:22]ike_get_sa: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896 } / 00000000, remote = 192.168.10.3:500
[Mar 25 14:52:22]ike_sa_find: Not found SA = { 62c7569c cecc5e6a - caec2bba b53d8896 }
[Mar 25 14:52:22]ike_sa_find_half: Found half SA = { 62c7569c cecc5e6a - 00000000 00000000 }
[Mar 25 14:52:22]ike_sa_upgrade: Start, SA = { 62c7569c cecc5e6a - 00000000 00000000 } -> { ... - caec2bba b53d8896 }
[Mar 25 14:52:22]ike_decode_packet: Start
[Mar 25 14:52:22]ike_decode_packet: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896} / 00000000, nego = -1
[Mar 25 14:52:22]ike_decode_payload_sa: Start
[Mar 25 14:52:22]ike_decode_payload_t: Start, # trans = 1
[Mar 25 14:52:22]ike_st_i_sa_value: Start
[Mar 25 14:52:22]ike_st_i_cr: Start
[Mar 25 14:52:22]ike_st_i_cert: Start
[Mar 25 14:52:22]ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ...
[Mar 25 14:52:22]ike_st_i_vid: VID[0..16] = 27bab5dc 01ea0760 ...
[Mar 25 14:52:22]ike_st_i_vid: VID[0..16] = 6105c422 e76847e4 ...
[Mar 25 14:52:22]ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ...
[Mar 25 14:52:22]ike_st_i_vid: VID[0..16] = cd604643 35df21f8 ...
[Mar 25 14:52:22]ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ...
[Mar 25 14:52:22]ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ...
[Mar 25 14:52:22]ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ...
[Mar 25 14:52:22]ike_st_i_vid: VID[0..28] = 69936922 8741c6d4 ...
[Mar 25 14:52:22]ike_st_i_private: Start
[Mar 25 14:52:22]ike_st_o_ke: Start
[Mar 25 14:52:22]ike_st_o_nonce: Start
[Mar 25 14:52:22]ike_policy_reply_isakmp_nonce_data_len: Start
[Mar 25 14:52:22]ike_st_o_private: Start
[Mar 25 14:52:22]ike_policy_reply_private_payload_out: Start
[Mar 25 14:52:22]ike_policy_reply_private_payload_out: Start
[Mar 25 14:52:22]ike_policy_reply_private_payload_out: Start
[Mar 25 14:52:22]ike_encode_packet: Start, SA = { 0x62c7569c cecc5e6a - caec2bba b53d8896 } / 00000000, nego = -1
[Mar 25 14:52:22]ike_send_packet: Start, send SA = { 62c7569c cecc5e6a - caec2bba b53d8896}, nego = -1, dst = 192.168.10.3:500,  routing table id = 0
[Mar 25 14:52:22]kmd_rpd_cb_protocol_unregister
[Mar 25 14:52:22]kmd_rpd_db_write
[Mar 25 14:52:22]ikev2_packet_allocate: Allocated packet da2000 from freelist
[Mar 25 14:52:22]ike_sa_find: Found SA = { 62c7569c cecc5e6a - caec2bba b53d8896 }
[Mar 25 14:52:22]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Mar 25 14:52:22]ike_get_sa: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896 } / 00000000, remote = 192.168.10.3:500
[Mar 25 14:52:22]ike_sa_find: Found SA = { 62c7569c cecc5e6a - caec2bba b53d8896 }
[Mar 25 14:52:22]ike_decode_packet: Start
[Mar 25 14:52:22]ike_decode_packet: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896} / 00000000, nego = -1
[Mar 25 14:52:22]ike_st_i_nonce: Start, nonce[0..16] = 3fe8a65a fad26553 ...
[Mar 25 14:52:22]ike_st_i_ke: Ke[0..128] = a8b6d84a 73691fcf ...
[Mar 25 14:52:22]ike_st_i_cr: Start
[Mar 25 14:52:22]ike_st_i_cert: Start
[Mar 25 14:52:22]ike_st_i_private: Start
[Mar 25 14:52:22]ike_st_o_id: Start
[Mar 25 14:52:22]ike_st_o_hash: Start
[Mar 25 14:52:22]ike_find_pre_shared_key: Find pre shared key key for 192.168.10.1:500, id = ipv4(any:0,[0..3]=192.168.10.1) -> 192.168.10.3:500, id = No Id
[Mar 25 14:52:22]ike_policy_reply_find_pre_shared_key: Start
[Mar 25 14:52:22]ike_calc_mac: Start, initiator = true, local = true
[Mar 25 14:52:22]ike_st_o_status_n: Start
[Mar 25 14:52:22]ike_st_o_private: Start
[Mar 25 14:52:22]ike_policy_reply_private_payload_out: Start
[Mar 25 14:52:22]ike_st_o_encrypt: Marking encryption for packet
[Mar 25 14:52:22]ike_encode_packet: Start, SA = { 0x62c7569c cecc5e6a - caec2bba b53d8896 } / 00000000, nego = -1
[Mar 25 14:52:22]ike_send_packet: Start, send SA = { 62c7569c cecc5e6a - caec2bba b53d8896}, nego = -1, dst = 192.168.10.3:500,  routing table id = 0
[Mar 25 14:52:22]kmd_rpd_cb_protocol_register gw handle 20841984 return code 0
[Mar 25 14:52:22]kmd_rpd_db_write
[Mar 25 14:52:22]kmd_rpd_refresh_routes
[Mar 25 14:52:22]ikev2_packet_allocate: Allocated packet da2400 from freelist
[Mar 25 14:52:22]ike_sa_find: Found SA = { 62c7569c cecc5e6a - caec2bba b53d8896 }
[Mar 25 14:52:22]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Mar 25 14:52:22]ike_get_sa: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896 } / d2534ada, remote = 192.168.10.3:500
[Mar 25 14:52:22]ike_sa_find: Found SA = { 62c7569c cecc5e6a - caec2bba b53d8896 }
[Mar 25 14:52:22]ike_alloc_negotiation: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896}
[Mar 25 14:52:22]ike_decode_packet: Start
[Mar 25 14:52:22]ike_decode_packet: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896} / d2534ada, nego = 0
[Mar 25 14:52:22]ike_st_i_n: Start, doi = 1, protocol = 1, code = Invalid payload type (1), spi[0..16] = 62c7569c cecc5e6a ..., data[0..141] = 800c0001 80030060 ...
[Mar 25 14:52:22]<none>:500 (Responder) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - caec2bba b53d8896 [0] / 0xd2534ada } Info; Notification data has attribute list
[Mar 25 14:52:22]<none>:500 (Responder) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - caec2bba b53d8896 [0] / 0xd2534ada } Info; Notify message version = 1
[Mar 25 14:52:22]<none>:500 (Responder) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - caec2bba b53d8896 [0] / 0xd2534ada } Info; Offending payload type = 96
[Mar 25 14:52:22]<none>:500 (Responder) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - caec2bba b53d8896 [0] / 0xd2534ada } Info; Offending payload data offset = 0
[Mar 25 14:52:22]<none>:500 (Responder) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - caec2bba b53d8896 [0] / 0xd2534ada } Info; Error text = Incorrect pre-shared key (Invalid next payload value)
[Mar 25 14:52:22]<none>:500 (Responder) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - caec2bba b53d8896 [0] / 0xd2534ada } Info; Offending message id = 0x00000000
[Mar 25 14:52:22]<none>:500 (Responder) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - caec2bba b53d8896 [0] / 0xd2534ada } Info; Received notify err = Invalid payload type (1) to isakmp sa, delete it
[Mar 25 14:52:22]ike_st_i_private: Start
[Mar 25 14:52:22]ike_send_notify: Connected, SA = { 62c7569c cecc5e6a - caec2bba b53d8896}, nego = 0
[Mar 25 14:52:22]ike_delete_negotiation: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896}, nego = 0
[Mar 25 14:52:22]ike_free_negotiation_info: Start, nego = 0
[Mar 25 14:52:22]ike_free_negotiation: Start, nego = 0
[Mar 25 14:52:22]ike_remove_callback: Start, delete SA = { 62c7569c cecc5e6a - caec2bba b53d8896}, nego = -1
[Mar 25 14:52:22]192.168.10.1:500 (Initiator) <-> 192.168.10.3:500 { 62c7569c cecc5e6a - caec2bba b53d8896 [-1] / 0x00000000 } IP; Connection got error = 1, calling callback
[Mar 25 14:52:22]ike_delete_negotiation: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896}, nego = -1
[Mar 25 14:52:22]ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
[Mar 25 14:52:22]ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table
[Mar 25 14:52:22]ike_sa_delete: Start, SA = { 62c7569c cecc5e6a - caec2bba b53d8896 }
[Mar 25 14:52:22]ike_free_negotiation_isakmp: Start, nego = -1
[Mar 25 14:52:22]ike_free_negotiation: Start, nego = -1
[Mar 25 14:52:22]ike_free_id_payload: Start, id type = 1
[Mar 25 14:52:22]ike_free_sa: Start     
[Mar 25 14:52:22]IKE negotiation fail for local:192.168.10.1, remote:192.168.10.3 IKEv1 with status: Invalid syntax
[Mar 25 14:52:22]  IKEv1 Error : Invalid payload type
[Mar 25 14:52:22]IPSec Rekey for SPI 0x0 failed
[Mar 25 14:52:22]IPSec SA done callback called for sa-cfg srxA-1-to-spoke-1 local:192.168.10.1, remote:192.168.10.3 IKEv1 with status Invalid syntax
[Mar 25 14:52:22]IKE SA delete called for p1 sa 5191021 (ref cnt 2) local:192.168.10.1, remote:192.168.10.3, IKEv1
[Mar 25 14:52:22]P1 SA 5191021 reference count is not zero (1). Delaying deletion of SA
[Mar 25 14:52:22]iked_pm_p1_sa_destroy:  p1 sa 5191021 (ref cnt 0), waiting_for_del 0xd714c0
[Mar 25 14:52:22]iked_peer_entry_delete_from_id_table: Deleted peer entry 0xdf2400 for local 192.168.10.1:500 remote 192.168.10.3:500. gw spoke-1, VR id 0 from ID hash table
...

The above log was collected on the Initiator side (see above). On Responder side you wont see the reason as incorrect pre-shared key, but as Invalid payload. (see below).

[Apr  2 09:47:40]ikev2_packet_allocate: Allocated packet dba800 from freelist
[Apr  2 09:47:40]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 09:47:40]ike_get_sa: Start, SA = { a76e6af8 18de9b8a - 00000000 00000000 } / 00000000, remote = 172.16.123.1:500
[Apr  2 09:47:40]ike_sa_allocate: Start, SA = { a76e6af8 18de9b8a - adc60576 a03a9c29 }
[Apr  2 09:47:40]ike_init_isakmp_sa: Start, remote = 172.16.123.1:500, initiator = 0
[Apr  2 09:47:40]ike_decode_packet: Start
[Apr  2 09:47:40]ike_decode_packet: Start, SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767} / 00000000, nego = -1
[Apr  2 09:47:40]ike_decode_payload_sa: Start
[Apr  2 09:47:40]ike_decode_payload_t: Start, # trans = 1
[Apr  2 09:47:40]ike_decode_payload_t: Start, # trans = 1
[Apr  2 09:47:40]ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ...
[Apr  2 09:47:40]ike_st_i_vid: VID[0..16] = 27bab5dc 01ea0760 ...
[Apr  2 09:47:40]ike_st_i_vid: VID[0..16] = 6105c422 e76847e4 ...
[Apr  2 09:47:40]ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ...
[Apr  2 09:47:40]ike_st_i_vid: VID[0..16] = cd604643 35df21f8 ...
[Apr  2 09:47:40]ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ...
[Apr  2 09:47:40]ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ...
[Apr  2 09:47:40]ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ...
[Apr  2 09:47:40]ike_st_i_vid: VID[0..28] = 69936922 8741c6d4 ...
[Apr  2 09:47:40]ike_st_i_sa_proposal: Start
[Apr  2 09:47:40]ike_isakmp_sa_reply: Start
[Apr  2 09:47:40]ike_state_restart_packet: Start, restart packet SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767}, nego = -1
[Apr  2 09:47:40]ike_st_i_sa_proposal: Start
[Apr  2 09:47:40]ike_st_i_cr: Start
[Apr  2 09:47:40]ike_st_i_cert: Start
[Apr  2 09:47:40]ike_st_i_private: Start
[Apr  2 09:47:40]ike_st_o_sa_values: Start
[Apr  2 09:47:40]ike_policy_reply_isakmp_vendor_ids: Start
[Apr  2 09:47:40]ike_st_o_private: Start
[Apr  2 09:47:40]ike_policy_reply_private_payload_out: Start
[Apr  2 09:47:40]ike_encode_packet: Start, SA = { 0xa76e6af8 18de9b8a - 37a3ef6b 6f332767 } / 00000000, nego = -1
[Apr  2 09:47:40]ike_send_packet: Start, send SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767}, nego = -1, dst = 172.16.123.1:500,  routing table id = 0
[Apr  2 09:47:40]ikev2_packet_allocate: Allocated packet d8fc00 from freelist
[Apr  2 09:47:40]ike_sa_find: Found SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767 }
[Apr  2 09:47:40]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 09:47:40]ike_get_sa: Start, SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767 } / 00000000, remote = 172.16.123.1:500
[Apr  2 09:47:40]ike_sa_find: Found SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767 }
[Apr  2 09:47:40]ike_decode_packet: Start
[Apr  2 09:47:40]ike_decode_packet: Start, SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767} / 00000000, nego = -1
[Apr  2 09:47:40]ike_st_i_nonce: Start, nonce[0..16] = 721a21e6 82fd4f59 ...
[Apr  2 09:47:40]ike_st_i_ke: Ke[0..128] = 7936315b 71257eb2 ...
[Apr  2 09:47:40]ike_st_i_cr: Start
[Apr  2 09:47:40]ike_st_i_cert: Start
[Apr  2 09:47:40]ike_st_i_private: Start
[Apr  2 09:47:40]ike_st_o_ke: Start
[Apr  2 09:47:40]ike_st_o_nonce: Start
[Apr  2 09:47:40]ike_policy_reply_isakmp_nonce_data_len: Start
[Apr  2 09:47:40]ike_find_pre_shared_key: Find pre shared key key for 172.16.123.2:500, id = No Id -> 172.16.123.1:500, id = No Id
[Apr  2 09:47:40]ike_policy_reply_find_pre_shared_key: Start
[Apr  2 09:47:40]ike_state_restart_packet: Start, restart packet SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767}, nego = -1
[Apr  2 09:47:40]ike_find_pre_shared_key: Find pre shared key key for 172.16.123.2:500, id = No Id -> 172.16.123.1:500, id = No Id
[Apr  2 09:47:40]ike_st_o_private: Start
[Apr  2 09:47:40]ike_policy_reply_private_payload_out: Start
[Apr  2 09:47:40]ike_policy_reply_private_payload_out: Start
[Apr  2 09:47:40]ike_policy_reply_private_payload_out: Start
[Apr  2 09:47:40]ike_st_o_calc_skeyid: Calculating skeyid
[Apr  2 09:47:40]ike_find_pre_shared_key: Find pre shared key key for 172.16.123.2:500, id = No Id -> 172.16.123.1:500, id = No Id
[Apr  2 09:47:40]ike_encode_packet: Start, SA = { 0xa76e6af8 18de9b8a - 37a3ef6b 6f332767 } / 00000000, nego = -1
[Apr  2 09:47:40]ike_send_packet: Start, send SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767}, nego = -1, dst = 172.16.123.1:500,  routing table id = 0
[Apr  2 09:47:40]ikev2_packet_allocate: Allocated packet da2000 from freelist
[Apr  2 09:47:40]ike_sa_find: Found SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767 }
[Apr  2 09:47:40]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 09:47:40]ike_get_sa: Start, SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767 } / 00000000, remote = 172.16.123.1:500
[Apr  2 09:47:40]ike_sa_find: Found SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767 }
[Apr  2 09:47:40]ike_decode_packet: Start
[Apr  2 09:47:40]ike_decode_packet: Start, SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767} / 00000000, nego = -1
[Apr  2 09:47:40]172.16.123.2:500 (Responder) <-> 172.16.123.1:500 { a76e6af8 18de9b8a - 37a3ef6b 6f332767 [-1] / 0x00000000 } IP; Invalid next payload type = 33
[Apr  2 09:47:40]172.16.123.2:500 (Responder) <-> 172.16.123.1:500 { a76e6af8 18de9b8a - 37a3ef6b 6f332767 [-1] / 0x00000000 } IP; Error = Invalid payload type (1)
[Apr  2 09:47:40]ike_alloc_negotiation: Start, SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767}
[Apr  2 09:47:40]ike_encode_packet: Start, SA = { 0xa76e6af8 18de9b8a - 37a3ef6b 6f332767 } / 7936110c, nego = 0
[Apr  2 09:47:40]ike_send_packet: Start, send SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767}, nego = 0, dst = 172.16.123.1:500,  routing table id = 0
[Apr  2 09:47:40]ike_delete_negotiation: Start, SA = { a76e6af8 18de9b8a - 37a3ef6b 6f332767}, nego = 0
[Apr  2 09:47:40]ike_free_negotiation_info: Start, nego = 0
[Apr  2 09:47:40]ike_free_negotiation: Start, nego = 0
[Apr  2 09:47:40]IKE negotiation fail for local:172.16.123.2, remote:172.16.123.1 IKEv1 with status: Invalid syntax
[Apr  2 09:47:40]  IKEv1 Error : Invalid payload type

3. IKE mode mismatch
Another common mistake is mode mismatch. Aggressive mode is used when endpoints with dynamically assigned IP addresses wants to join the VPN. If two endpoinst have statical IP address assigment, they should use main mode instead. If one node is configured for main mode and the other for aggressive, you will see following error in IPsec logs.

[Apr  2 09:37:01]ikev2_packet_allocate: Allocated packet db9c00 from freelist
[Apr  2 09:37:01]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 09:37:01]ike_get_sa: Start, SA = { ddba910f d3b8e6f2 - 00000000 00000000 } / 00000000, remote = 172.16.123.1:500
[Apr  2 09:37:01]ike_sa_allocate: Start, SA = { ddba910f d3b8e6f2 - 711f9e7c fb604f9e }
[Apr  2 09:37:01]ike_init_isakmp_sa: Start, remote = 172.16.123.1:500, initiator = 0
[Apr  2 09:37:01]ike_decode_packet: Start
[Apr  2 09:37:01]ike_decode_packet: Start, SA = { ddba910f d3b8e6f2 - 3cc35d26 0e77fc93} / 00000000, nego = -1
[Apr  2 09:37:01]ike_decode_payload_sa: Start
[Apr  2 09:37:01]ike_decode_payload_t: Start, # trans = 1
[Apr  2 09:37:01]ike_decode_payload_t: Start, # trans = 1
[Apr  2 09:37:01]ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ...
[Apr  2 09:37:01]ike_st_i_vid: VID[0..16] = 27bab5dc 01ea0760 ...
[Apr  2 09:37:01]ike_st_i_vid: VID[0..16] = 6105c422 e76847e4 ...
[Apr  2 09:37:01]ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ...
[Apr  2 09:37:01]ike_st_i_vid: VID[0..16] = cd604643 35df21f8 ...
[Apr  2 09:37:01]ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ...
[Apr  2 09:37:01]ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ...
[Apr  2 09:37:01]ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ...
[Apr  2 09:37:01]ike_st_i_vid: VID[0..28] = 69936922 8741c6d4 ...
[Apr  2 09:37:01]ike_st_i_id: Start
[Apr  2 09:37:01]ike_st_i_sa_proposal: Start
[Apr  2 09:37:01]ike_free_id_payload: Start, id type = 1
[Apr  2 09:37:01]Exchange type mismatch (configured 2, proposed by peer 4) for tunnel local:172.16.123.2 remote:172.16.123.1 IKEv1
[Apr  2 09:37:01]iked_pm_ike_spd_select_ike_sa failed. rc 1, error_code: No proposal chosen
[Apr  2 09:37:01]ikev2_fb_spd_select_sa_cb: IKEv2 SA select failed with error No proposal chosen (neg df6800)
[Apr  2 09:37:01]ike_isakmp_sa_reply: Start
[Apr  2 09:37:01]ike_state_restart_packet: Start, restart packet SA = { ddba910f d3b8e6f2 - 3cc35d26 0e77fc93}, nego = -1
[Apr  2 09:37:01]ike_st_i_sa_proposal: Start
[Apr  2 09:37:01]ike_st_i_nonce: Start, nonce[0..16] = dc4485ee 4dd5eb3e ...
[Apr  2 09:37:01]ike_st_i_cert: Start
[Apr  2 09:37:01]ike_st_i_hash_key: Start, no key_hash
[Apr  2 09:37:01]ike_st_i_ke: Ke[0..128] = 664fdf06 5953ac2d ...
[Apr  2 09:37:01]ike_st_i_cr: Start
[Apr  2 09:37:01]ike_st_i_private: Start
[Apr  2 09:37:01]ike_st_o_sa_values: Start
[Apr  2 09:37:01]172.16.123.2:500 (Responder) <-> 172.16.123.1:500 { ddba910f d3b8e6f2 - 3cc35d26 0e77fc93 [-1] / 0x00000000 } Aggr; Error = No proposal chosen (14)
[Apr  2 09:37:01]ike_alloc_negotiation: Start, SA = { ddba910f d3b8e6f2 - 3cc35d26 0e77fc93}
[Apr  2 09:37:01]ike_encode_packet: Start, SA = { 0xddba910f d3b8e6f2 - 3cc35d26 0e77fc93 } / 78963771, nego = 0
[Apr  2 09:37:01]ike_send_packet: Start, send SA = { ddba910f d3b8e6f2 - 3cc35d26 0e77fc93}, nego = 0, dst = 172.16.123.1:500,  routing table id = 0
[Apr  2 09:37:01]ike_delete_negotiation: Start, SA = { ddba910f d3b8e6f2 - 3cc35d26 0e77fc93}, nego = 0
[Apr  2 09:37:01]ike_free_negotiation_info: Start, nego = 0
[Apr  2 09:37:01]ike_free_negotiation: Start, nego = 0
[Apr  2 09:37:01]IKE negotiation fail for local:172.16.123.2, remote:172.16.123.1 IKEv1 with status: No proposal chosen
[Apr  2 09:37:01]  IKEv1 Error : No proposal chosen

Be aware of the fact, that this log is collected on the responder side (see above). On Initiator side you wont see the reason as type mismatch, but simply only as proposals mismatch (see below).

[Apr  2 09:37:01]iked_pm_ike_spd_notify_request: Sending Initial contact
[Apr  2 09:37:01]ssh_ike_connect: Start, remote_name = 172.16.123.2:500, xchg = 4, flags = 00040000
[Apr  2 09:37:01]ike_sa_allocate: Start, SA = { 8e37c0a1 79c82529 - 00000000 00000000 }
[Apr  2 09:37:01]ike_init_isakmp_sa: Start, remote = 172.16.123.2:500, initiator = 1
[Apr  2 09:37:01]172.16.123.1:500 (Initiator) <-> 172.16.123.2:500 { 8e37c0a1 79c82529 - 00000000 00000000 [-1] / 0x00000000 } Aggr; Warning: Number of proposals != 1 in ISAKMP SA, this is against draft!
[Apr  2 09:37:01]ssh_ike_connect: SA = { 8e37c0a1 79c82529 - 00000000 00000000}, nego = -1
[Apr  2 09:37:01]ike_st_o_sa_proposal: Start
[Apr  2 09:37:01]ike_st_o_ke: Start
[Apr  2 09:37:01]ike_st_o_nonce: Start
[Apr  2 09:37:01]ike_policy_reply_isakmp_nonce_data_len: Start
[Apr  2 09:37:01]ike_st_o_id: Start
[Apr  2 09:37:01]ike_policy_reply_isakmp_vendor_ids: Start
[Apr  2 09:37:01]ike_st_o_private: Start
[Apr  2 09:37:01]ike_policy_reply_private_payload_out: Start
[Apr  2 09:37:01]ike_encode_packet: Start, SA = { 0x8e37c0a1 79c82529 - 00000000 00000000 } / 00000000, nego = -1
[Apr  2 09:37:01]ike_send_packet: Start, send SA = { 8e37c0a1 79c82529 - 00000000 00000000}, nego = -1, dst = 172.16.123.2:500,  routing table id = 0
[Apr  2 09:37:01]ikev2_packet_allocate: Allocated packet da1400 from freelist
[Apr  2 09:37:01]ike_sa_find: Not found SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 }
[Apr  2 09:37:01]ikev2_packet_st_input_v1_get_sa: Checking if unauthenticated IKEv1 notify is for an IKEv2 SA
[Apr  2 09:37:01]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 09:37:01]ike_get_sa: Start, SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 } / bee2f398, remote = 172.16.123.2:500
[Apr  2 09:37:01]ike_sa_find: Not found SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 }
[Apr  2 09:37:01]ike_sa_find_half: Found half SA = { 8e37c0a1 79c82529 - 00000000 00000000 }
[Apr  2 09:37:01]ike_sa_upgrade: Start, SA = { 8e37c0a1 79c82529 - 00000000 00000000 } -> { ... - e9fe56a6 5d3bba78 }
[Apr  2 09:37:01]ike_alloc_negotiation: Start, SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78}
[Apr  2 09:37:01]ike_decode_packet: Start
[Apr  2 09:37:01]ike_decode_packet: Start, SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78} / bee2f398, nego = 0
[Apr  2 09:37:01]ike_st_i_n: Start, doi = 1, protocol = 1, code = No proposal chosen (14), spi[0..16] = 8e37c0a1 79c82529 ..., data[0..46] = 800c0001 00060022 ...
[Apr  2 09:37:01]<none>:500 (Responder) <-> 172.16.123.2:500 { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 [0] / 0xbee2f398 } Info; Notification data has attribute list
[Apr  2 09:37:01]<none>:500 (Responder) <-> 172.16.123.2:500 { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 [0] / 0xbee2f398 } Info; Notify message version = 1
[Apr  2 09:37:01]<none>:500 (Responder) <-> 172.16.123.2:500 { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 [0] / 0xbee2f398 } Info; Error text = Could not find acceptable proposal
[Apr  2 09:37:01]<none>:500 (Responder) <-> 172.16.123.2:500 { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 [0] / 0xbee2f398 } Info; Offending message id = 0x00000000
[Apr  2 09:37:01]<none>:500 (Responder) <-> 172.16.123.2:500 { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 [0] / 0xbee2f398 } Info; Received notify err = No proposal chosen (14) to isakmp sa, delete it
[Apr  2 09:37:01]ike_st_i_private: Start
[Apr  2 09:37:01]ike_send_notify: Connected, SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78}, nego = 0
[Apr  2 09:37:01]ike_delete_negotiation: Start, SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78}, nego = 0
[Apr  2 09:37:01]ike_free_negotiation_info: Start, nego = 0
[Apr  2 09:37:01]ike_free_negotiation: Start, nego = 0
[Apr  2 09:37:01]ike_remove_callback: Start, delete SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78}, nego = -1
[Apr  2 09:37:01]172.16.123.1:500 (Initiator) <-> 172.16.123.2:500 { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 [-1] / 0x00000000 } Aggr; Connection got error = 14, calling callback
[Apr  2 09:37:01]ikev2_fb_v1_encr_id_to_v2_id: Unknown IKE encryption identifier -1
[Apr  2 09:37:01]ikev2_fb_v1_hash_id_to_v2_prf_id: Unknown IKE hash alg identifier -1
[Apr  2 09:37:01]ikev2_fb_v1_hash_id_to_v2_integ_id: Unknown IKE hash alg identifier -1
[Apr  2 09:37:01]IKE negotiation fail for local:172.16.123.1, remote:172.16.123.2 IKEv1 with status: No proposal chosen
[Apr  2 09:37:01]  IKEv1 Error : No proposal chosen
[Apr  2 09:37:01]IPSec Rekey for SPI 0x0 failed
[Apr  2 09:37:01]IPSec SA done callback called for sa-cfg to-srx2 local:172.16.123.1, remote:172.16.123.2 IKEv1 with status No proposal chosen
[Apr  2 09:37:01]ike_delete_negotiation: Start, SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78}, nego = -1
[Apr  2 09:37:01]ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
[Apr  2 09:37:01]ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table
[Apr  2 09:37:01]ike_sa_delete: Start, SA = { 8e37c0a1 79c82529 - e9fe56a6 5d3bba78 }
[Apr  2 09:37:01]ike_free_negotiation_isakmp: Start, nego = -1
[Apr  2 09:37:01]ike_free_negotiation: Start, nego = -1
[Apr  2 09:37:01]IKE SA delete called for p1 sa 6327627 (ref cnt 1) local:172.16.123.1, remote:172.16.123.2, IKEv1
[Apr  2 09:37:01]iked_pm_p1_sa_destroy:  p1 sa 6327627 (ref cnt 0), waiting_for_del 0x0
[Apr  2 09:37:01]iked_peer_entry_delete_from_id_table: Deleted peer entry 0x9d6400 for local 172.16.123.1:500 remote 172.16.123.2:500. gw to-srx2, VR id 0 from ID hash table
[Apr  2 09:37:01]ike_free_id_payload: Start, id type = 1
[Apr  2 09:37:01]ike_free_sa: Start
[Apr  2 09:37:01]iked_deferred_free_inactive_peer_entry: Free 1 peer_entry(s)

4. IPsec proposal mismatch
The IKE phase 1 is done, the phase 2 takes place. Suddenly, phase 2 fails because of not matching proposals.

This is the longest log, because we see all logs from IKE phase 1 first. If you don’t see the whole log, e.g. customer coppied only the error messages to you, you are able to distinguish the IKE phase 1 proposal mismatch and IPsec phase 2 proposal mismatch by the QM letters that stands for Quick Mode, which takes part in phase 2.

[Mar 25 14:04:59]iked_pm_ike_spd_notify_request: Sending Initial contact
 [Mar 25 14:04:59]ssh_ike_connect: Start, remote_name = 192.168.10.3:500, xchg = 2, flags = 00090000
 [Mar 25 14:04:59]ike_sa_allocate: Start, SA = { 39f3b0e3 1fef8aa7 - 00000000 00000000 }
 [Mar 25 14:04:59]ike_init_isakmp_sa: Start, remote = 192.168.10.3:500, initiator = 1
 [Mar 25 14:04:59]192.168.10.1:500 (Initiator) <-> 192.168.10.3:500 { 39f3b0e3 1fef8aa7 - 00000000 00000000 [-1] / 0x00000000 } IP; Warning: Number of proposals != 1 in ISAKMP SA, this is against draft!
 [Mar 25 14:04:59]ssh_ike_connect: SA = { 39f3b0e3 1fef8aa7 - 00000000 00000000}, nego = -1
 [Mar 25 14:04:59]ike_st_o_sa_proposal: Start
 [Mar 25 14:04:59]ike_policy_reply_isakmp_vendor_ids: Start
 [Mar 25 14:04:59]ike_st_o_private: Start
 [Mar 25 14:04:59]ike_policy_reply_private_payload_out: Start
 [Mar 25 14:04:59]ike_encode_packet: Start, SA = { 0x39f3b0e3 1fef8aa7 - 00000000 00000000 } / 00000000, nego = -1
 [Mar 25 14:04:59]ike_send_packet: Start, send SA = { 39f3b0e3 1fef8aa7 - 00000000 00000000}, nego = -1, dst = 192.168.10.3:500,  routing table id = 0
 [Mar 25 14:04:59]kmd_rpd_cb_session_connect
 [Mar 25 14:04:59]rpd session established
 [Mar 25 14:04:59]kmd_rpd_db_read
 [Mar 25 14:04:59]kmd_rpd_db_read: gw handle 20841984
 [Mar 25 14:04:59]kmd_rpd_cb_protocol_register gw handle 20841984 return code 0
 [Mar 25 14:04:59]ikev2_packet_allocate: Allocated packet d8fc00 from freelist
 [Mar 25 14:04:59]ike_sa_find: Not found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
 [Mar 25 14:04:59]ike_get_sa: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 } / 00000000, remote = 192.168.10.3:500
 [Mar 25 14:04:59]ike_sa_find: Not found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ike_sa_find_half: Found half SA = { 39f3b0e3 1fef8aa7 - 00000000 00000000 }
 [Mar 25 14:04:59]ike_sa_upgrade: Start, SA = { 39f3b0e3 1fef8aa7 - 00000000 00000000 } -> { ... - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ike_decode_packet: Start
 [Mar 25 14:04:59]ike_decode_packet: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529} / 00000000, nego = -1
 [Mar 25 14:04:59]ike_decode_payload_sa: Start
 [Mar 25 14:04:59]ike_decode_payload_t: Start, # trans = 1
 [Mar 25 14:04:59]ike_st_i_sa_value: Start
 [Mar 25 14:04:59]ike_st_i_cr: Start
 [Mar 25 14:04:59]ike_st_i_cert: Start
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ...
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..16] = 27bab5dc 01ea0760 ...
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..16] = 6105c422 e76847e4 ...
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ...
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..16] = cd604643 35df21f8 ...
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ...
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ...
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ...
 [Mar 25 14:04:59]ike_st_i_vid: VID[0..28] = 69936922 8741c6d4 ...
 [Mar 25 14:04:59]ike_st_i_private: Start
 [Mar 25 14:04:59]ike_st_o_ke: Start
 [Mar 25 14:04:59]ike_st_o_nonce: Start
 [Mar 25 14:04:59]ike_policy_reply_isakmp_nonce_data_len: Start
 [Mar 25 14:04:59]ike_st_o_private: Start
 [Mar 25 14:04:59]ike_policy_reply_private_payload_out: Start
 [Mar 25 14:04:59]ike_policy_reply_private_payload_out: Start
 [Mar 25 14:04:59]ike_policy_reply_private_payload_out: Start
 [Mar 25 14:04:59]ike_encode_packet: Start, SA = { 0x39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 } / 00000000, nego = -1
 [Mar 25 14:04:59]ike_send_packet: Start, send SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = -1, dst = 192.168.10.3:500,  routing table id = 0
 [Mar 25 14:04:59]kmd_rpd_cb_protocol_unregister
 [Mar 25 14:04:59]kmd_rpd_db_write
 [Mar 25 14:04:59]kmd_rpd_cb_protocol_register gw handle 20841984 return code 0
 [Mar 25 14:04:59]kmd_rpd_db_write
 [Mar 25 14:04:59]kmd_rpd_refresh_routes
 [Mar 25 14:04:59]ikev2_packet_allocate: Allocated packet da2000 from freelist
 [Mar 25 14:04:59]ike_sa_find: Found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
 [Mar 25 14:04:59]ike_get_sa: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 } / 00000000, remote = 192.168.10.3:500
 [Mar 25 14:04:59]ike_sa_find: Found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ike_decode_packet: Start
 [Mar 25 14:04:59]ike_decode_packet: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529} / 00000000, nego = -1
 [Mar 25 14:04:59]ike_st_i_nonce: Start, nonce[0..16] = 2db5a6fe b7ce1b58 ...
 [Mar 25 14:04:59]ike_st_i_ke: Ke[0..128] = d56f835c 62fcc53a ...
 [Mar 25 14:04:59]ike_st_i_cr: Start
 [Mar 25 14:04:59]ike_st_i_cert: Start
 [Mar 25 14:04:59]ike_st_i_private: Start
 [Mar 25 14:04:59]ike_st_o_id: Start
 [Mar 25 14:04:59]ike_st_o_hash: Start
 [Mar 25 14:04:59]ike_find_pre_shared_key: Find pre shared key key for 192.168.10.1:500, id = ipv4(any:0,[0..3]=192.168.10.1) -> 192.168.10.3:500, id = No Id
 [Mar 25 14:04:59]ike_policy_reply_find_pre_shared_key: Start
 [Mar 25 14:04:59]ike_calc_mac: Start, initiator = true, local = true
 [Mar 25 14:04:59]ike_st_o_status_n: Start
 [Mar 25 14:04:59]ike_st_o_private: Start
 [Mar 25 14:04:59]ike_policy_reply_private_payload_out: Start
 [Mar 25 14:04:59]ike_st_o_encrypt: Marking encryption for packet
 [Mar 25 14:04:59]ike_encode_packet: Start, SA = { 0x39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 } / 00000000, nego = -1
 [Mar 25 14:04:59]ike_send_packet: Start, send SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = -1, dst = 192.168.10.3:500,  routing table id = 0
 [Mar 25 14:04:59]KMD_INTERNAL_ERROR: iked_ifstate_eoc_handler: EOC msg received
 [Mar 25 14:04:59]ikev2_packet_allocate: Allocated packet da2400 from freelist
 [Mar 25 14:04:59]ike_sa_find: Found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
 [Mar 25 14:04:59]ike_get_sa: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 } / 00000000, remote = 192.168.10.3:500
 [Mar 25 14:04:59]ike_sa_find: Found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ike_decode_packet: Start
 [Mar 25 14:04:59]ike_decode_packet: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529} / 00000000, nego = -1
 [Mar 25 14:04:59]ike_st_i_encrypt: Check that packet was encrypted succeeded
 [Mar 25 14:04:59]ike_st_i_id: Start
 [Mar 25 14:04:59]ike_st_i_hash: Start, hash[0..20] = 400ca365 ddfa7d15 ...
 [Mar 25 14:04:59]ike_calc_mac: Start, initiator = true, local = false
 [Mar 25 14:04:59]ike_st_i_cert: Start
 [Mar 25 14:04:59]ike_st_i_private: Start
 [Mar 25 14:04:59]ike_st_o_wait_done: Marking for waiting for done
 [Mar 25 14:04:59]ike_st_o_all_done: MESSAGE: Phase 1 { 0x39f3b0e3 1fef8aa7 - 0x2c3ac38a 8ba01529 } / 00000000, version = 1.0, xchg = Identity protect, auth_method = Pre shared keys, Initiator, cipher = 3des-cbc, hash = sha1, prf = hmac-sha1
 [Mar 25 14:04:59]192.168.10.1:500 (Initiator) <-> 192.168.10.3:500 { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 [-1] / 0x00000000 } IP; MESSAGE: Phase 1 version = 1.0, auth_method = Pre shared keys, cipher = 3des-cbc, hash = sha1, prf = hmac-sha
 [Mar 25 14:04:59]ike_send_notify: Connected, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = -1
 [Mar 25 14:04:59]iked_pm_ike_sa_done: local:192.168.10.1, remote:192.168.10.3 IKEv1
 [Mar 25 14:04:59]IKE negotiation done for local:192.168.10.1, remote:192.168.10.3 IKEv1 with status: Error ok
 [Mar 25 14:04:59]Added (spi=0x6cc4bdb1, protocol=0) entry to the spi table
 [Mar 25 14:04:59]Added (spi=0xc4f279f2, protocol=0) entry to the spi table
 [Mar 25 14:04:59]ssh_ike_connect_ipsec: Start, remote_name = :500, flags = 00000000
 [Mar 25 14:04:59]ike_sa_find_ip_port: Remote = all:500, Found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}
 [Mar 25 14:04:59]ike_alloc_negotiation: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}
 [Mar 25 14:04:59]ssh_ike_connect_ipsec: SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = 0
 [Mar 25 14:04:59]ike_init_qm_negotiation: Start, initiator = 1, message_id = 86cf6007
 [Mar 25 14:04:59]ike_st_o_qm_hash_1: Start
 [Mar 25 14:04:59]ike_st_o_qm_sa_proposals: Start
 [Mar 25 14:04:59]ike_st_o_qm_nonce: Start
 [Mar 25 14:04:59]ike_policy_reply_qm_nonce_data_len: Start
 [Mar 25 14:04:59]ike_st_o_qm_optional_ke: Start
 [Mar 25 14:04:59]ike_st_o_qm_optional_ids: Start
 [Mar 25 14:04:59]ike_st_qm_optional_id: Start
 [Mar 25 14:04:59]ike_st_qm_optional_id: Start
 [Mar 25 14:04:59]ike_st_o_private: Start
 [Mar 25 14:04:59]Construction NHTB payload for  local:192.168.10.1, remote:192.168.10.3 IKEv1 P1 SA index 1136404 sa-cfg srxA-1-to-spoke-1
 [Mar 25 14:04:59]ike_policy_reply_private_payload_out: Start
 [Mar 25 14:04:59]ike_policy_reply_private_payload_out: Start
 [Mar 25 14:04:59]ike_st_o_encrypt: Marking encryption for packet
 [Mar 25 14:04:59]ike_encode_packet: Start, SA = { 0x39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 } / 86cf6007, nego = 0
 [Mar 25 14:04:59]ike_finalize_qm_hash_1: Hash[0..20] = 8766529f 0af521a6 ...
 [Mar 25 14:04:59]ike_send_packet: Start, send SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = 0, dst = 192.168.10.3:500,  routing table id = 0
 [Mar 25 14:04:59]ikev2_packet_allocate: Allocated packet da2800 from freelist
 [Mar 25 14:04:59]ike_sa_find: Found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
 [Mar 25 14:04:59]ike_get_sa: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 } / 94c219e5, remote = 192.168.10.3:500
 [Mar 25 14:04:59]ike_sa_find: Found SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 }
 [Mar 25 14:04:59]ike_st_o_done: ISAKMP SA negotiation done
 [Mar 25 14:04:59]ike_send_notify: Connected, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = -1
 [Mar 25 14:04:59]ike_free_negotiation_isakmp: Start, nego = -1
 [Mar 25 14:04:59]ike_free_negotiation: Start, nego = -1
 [Mar 25 14:04:59]ike_alloc_negotiation: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}
 [Mar 25 14:04:59]ike_decode_packet: Start
 [Mar 25 14:04:59]ike_decode_packet: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529} / 94c219e5, nego = 1
 [Mar 25 14:04:59]ike_st_i_encrypt: Check that packet was encrypted succeeded
 [Mar 25 14:04:59]ike_st_i_gen_hash: Start, hash[0..20] = 82ef1e84 0c773c0f ...
 [Mar 25 14:04:59]ike_st_i_n: Start, doi = 1, protocol = 3, code = No proposal chosen (14), spi[0..4] = 6cc4bdb1 00000000 ..., data[0..50] = 800c0001 00060022 ...
 [Mar 25 14:04:59]<none>:500 (Responder) <-> 192.168.10.3:500 { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 [1] / 0x94c219e5 } Info; Notification data has attribute list
 [Mar 25 14:04:59]<none>:500 (Responder) <-> 192.168.10.3:500 { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 [1] / 0x94c219e5 } Info; Notify message version = 1
 [Mar 25 14:04:59]<none>:500 (Responder) <-> 192.168.10.3:500 { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 [1] / 0x94c219e5 } Info; Error text = Could not find acceptable proposal
 [Mar 25 14:04:59]<none>:500 (Responder) <-> 192.168.10.3:500 { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 [1] / 0x94c219e5 } Info; Offending message id = 0x86cf6007
 [Mar 25 14:04:59]ike_remove_callback: Start, delete SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = 0
 [Mar 25 14:04:59]<none>:500 (Initiator) <-> 192.168.10.3:500 { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529 [0] / 0x86cf6007 } QM; Connection got error = 14, calling callback
 [Mar 25 14:04:59]ike_delete_negotiation: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = 0
 [Mar 25 14:04:59]ike_free_negotiation_qm: Start, nego = 0
 [Mar 25 14:04:59]ike_free_negotiation: Start, nego = 0
 [Mar 25 14:04:59]ike_free_id_payload: Start, id type = 4
 [Mar 25 14:04:59]ike_free_id_payload: Start, id type = 4
 [Mar 25 14:04:59]ike_st_i_private: Start
 [Mar 25 14:04:59]ike_send_notify: Connected, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = 1
 [Mar 25 14:04:59]ike_delete_negotiation: Start, SA = { 39f3b0e3 1fef8aa7 - 2c3ac38a 8ba01529}, nego = 1
 [Mar 25 14:04:59]ike_free_negotiation_info: Start, nego = 1
 [Mar 25 14:04:59]ike_free_negotiation: Start, nego = 1
 [Mar 25 14:05:00]IPSec negotiation failed for SA-CFG srxA-1-to-spoke-1 for local:192.168.10.1, remote:192.168.10.3 IKEv1. status: No proposal chosen
 [Mar 25 14:05:00]   P2 ed info: flags 0xc2, P2 error: Error ok
 [Mar 25 14:05:00]  IKEv1 Error : No proposal chosen
 [Mar 25 14:05:00]IPSec SA done callback with sa-cfg NULL in p2_ed. status: No proposal chosen

5. IKE proxy-id mismatch

Proxy-id or Proxy Identity is historical term coming from ScreenOS. The keyword vanished from the early draft RFCs for Phase 2 Quick mode.

Reading a ScreenOS documentation we can find that: “A proxy-ID is used during phase 2 of Internet Key Exchange (IKE) Virtual Private Network (VPN) negotiations. Both ends of a VPN tunnel either have a proxy-ID manually configured (route-based VPN) or just use a combination of source IP, destination IP, and service in a tunnel policy. When phase 2 of IKE is negotiated, each end compares the configured local and remote proxy-ID with what is actually received. The configured proxy ID must match with what is received from the other device that is negotiating an IKE/IPsec tunnel.”

Saying it shortly, proxy-id says what kind of traffic is being alowed to transit via VPN tunnel. We used manual configuration for proxy-identity under [edit security ipsec vpn name ike proxy-identity].

Again, the log messages differ depending on recording site. The following log shows error messages generated by initiator:

[Apr  2 10:57:44]iked_pm_ike_spd_notify_request: Sending Initial contact
[Apr  2 10:57:44]ssh_ike_connect: Start, remote_name = 172.16.123.2:500, xchg = 2, flags = 00090000
[Apr  2 10:57:44]ike_sa_allocate: Start, SA = { 12ae0b5c 700a67c1 - 00000000 00000000 }
[Apr  2 10:57:44]ike_init_isakmp_sa: Start, remote = 172.16.123.2:500, initiator = 1
[Apr  2 10:57:44]172.16.123.1:500 (Initiator) <-> 172.16.123.2:500 { 12ae0b5c 700a67c1 - 00000000 00000000 [-1] / 0x00000000 } IP; Warning: Number of proposals != 1 in ISAKMP SA, this is against draft!
[Apr  2 10:57:44]ssh_ike_connect: SA = { 12ae0b5c 700a67c1 - 00000000 00000000}, nego = -1
[Apr  2 10:57:44]ike_st_o_sa_proposal: Start
[Apr  2 10:57:44]ike_policy_reply_isakmp_vendor_ids: Start
[Apr  2 10:57:44]ike_st_o_private: Start
[Apr  2 10:57:44]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:44]ike_encode_packet: Start, SA = { 0x12ae0b5c 700a67c1 - 00000000 00000000 } / 00000000, nego = -1
[Apr  2 10:57:44]ike_send_packet: Start, send SA = { 12ae0b5c 700a67c1 - 00000000 00000000}, nego = -1, dst = 172.16.123.2:500,  routing table id = 0
[Apr  2 10:57:44]ikev2_packet_allocate: Allocated packet da5000 from freelist
[Apr  2 10:57:44]ike_sa_find: Not found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 10:57:44]ike_get_sa: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, remote = 172.16.123.2:500
[Apr  2 10:57:44]ike_sa_find: Not found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:44]ike_sa_find_half: Found half SA = { 12ae0b5c 700a67c1 - 00000000 00000000 }
[Apr  2 10:57:44]ike_sa_upgrade: Start, SA = { 12ae0b5c 700a67c1 - 00000000 00000000 } -> { ... - f46ac6af 642602a2 }
[Apr  2 10:57:44]ike_decode_packet: Start
[Apr  2 10:57:44]ike_decode_packet: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2} / 00000000, nego = -1
[Apr  2 10:57:44]ike_decode_payload_sa: Start
[Apr  2 10:57:44]ike_decode_payload_t: Start, # trans = 1
[Apr  2 10:57:44]ike_st_i_sa_value: Start
[Apr  2 10:57:44]ike_st_i_cr: Start
[Apr  2 10:57:44]ike_st_i_cert: Start
[Apr  2 10:57:44]ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ...
[Apr  2 10:57:44]ike_st_i_vid: VID[0..16] = 27bab5dc 01ea0760 ...
[Apr  2 10:57:44]ike_st_i_vid: VID[0..16] = 6105c422 e76847e4 ...
[Apr  2 10:57:44]ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ...
[Apr  2 10:57:44]ike_st_i_vid: VID[0..16] = cd604643 35df21f8 ...
[Apr  2 10:57:44]ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ...
[Apr  2 10:57:44]ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ...
[Apr  2 10:57:44]ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ...
[Apr  2 10:57:44]ike_st_i_vid: VID[0..28] = 69936922 8741c6d4 ...
[Apr  2 10:57:44]ike_st_i_private: Start
[Apr  2 10:57:44]ike_st_o_ke: Start
[Apr  2 10:57:44]ike_st_o_nonce: Start
[Apr  2 10:57:44]ike_policy_reply_isakmp_nonce_data_len: Start
[Apr  2 10:57:44]ike_st_o_private: Start
[Apr  2 10:57:44]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:44]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:44]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:44]ike_encode_packet: Start, SA = { 0x12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, nego = -1
[Apr  2 10:57:44]ike_send_packet: Start, send SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1, dst = 172.16.123.2:500,  routing table id = 0
[Apr  2 10:57:44]ikev2_packet_allocate: Allocated packet da5400 from freelist
[Apr  2 10:57:44]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 10:57:44]ike_get_sa: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, remote = 172.16.123.2:500
[Apr  2 10:57:44]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:44]ike_decode_packet: Start
[Apr  2 10:57:44]ike_decode_packet: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2} / 00000000, nego = -1
[Apr  2 10:57:44]ike_st_i_nonce: Start, nonce[0..16] = d5825645 19e53bfa ...
[Apr  2 10:57:44]ike_st_i_ke: Ke[0..128] = 86d56237 00d9c81d ...
[Apr  2 10:57:44]ike_st_i_cr: Start     
[Apr  2 10:57:44]ike_st_i_cert: Start
[Apr  2 10:57:44]ike_st_i_private: Start
[Apr  2 10:57:44]ike_st_o_id: Start
[Apr  2 10:57:44]ike_st_o_hash: Start
[Apr  2 10:57:44]ike_find_pre_shared_key: Find pre shared key key for 172.16.123.1:500, id = ipv4(any:0,[0..3]=172.16.123.1) -> 172.16.123.2:500, id = No Id
[Apr  2 10:57:44]ike_policy_reply_find_pre_shared_key: Start
[Apr  2 10:57:44]ike_calc_mac: Start, initiator = true, local = true
[Apr  2 10:57:44]ike_st_o_status_n: Start
[Apr  2 10:57:44]ike_st_o_private: Start
[Apr  2 10:57:44]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:44]ike_st_o_encrypt: Marking encryption for packet
[Apr  2 10:57:44]ike_encode_packet: Start, SA = { 0x12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, nego = -1
[Apr  2 10:57:44]ike_send_packet: Start, send SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1, dst = 172.16.123.2:500,  routing table id = 0
[Apr  2 10:57:44]ikev2_packet_allocate: Allocated packet da5800 from freelist
[Apr  2 10:57:44]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 10:57:44]ike_get_sa: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, remote = 172.16.123.2:500
[Apr  2 10:57:44]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:44]ike_decode_packet: Start
[Apr  2 10:57:44]ike_decode_packet: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2} / 00000000, nego = -1
[Apr  2 10:57:44]ike_st_i_encrypt: Check that packet was encrypted succeeded
[Apr  2 10:57:44]ike_st_i_id: Start
[Apr  2 10:57:44]ike_st_i_hash: Start, hash[0..20] = 8e0a3bbf cca6e0e0 ...
[Apr  2 10:57:44]ike_calc_mac: Start, initiator = true, local = false
[Apr  2 10:57:44]ike_st_i_cert: Start
[Apr  2 10:57:44]ike_st_i_private: Start
[Apr  2 10:57:44]ike_st_o_wait_done: Marking for waiting for done
[Apr  2 10:57:44]ike_st_o_all_done: MESSAGE: Phase 1 { 0x12ae0b5c 700a67c1 - 0xf46ac6af 642602a2 } / 00000000, version = 1.0, xchg = Identity protect, auth_method = Pre shared keys, Initiator, cipher = 3des-cbc, hash = sha1, prf = hmac-sha1
[Apr  2 10:57:44]172.16.123.1:500 (Initiator) <-> 172.16.123.2:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [-1] / 0x00000000 } IP; MESSAGE: Phase 1 version = 1.0, auth_method = Pre shared keys, cipher = 3des-cbc, hash = sha1, prf = hmac-sha
[Apr  2 10:57:44]ike_send_notify: Connected, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1
[Apr  2 10:57:44]iked_pm_ike_sa_done: local:172.16.123.1, remote:172.16.123.2 IKEv1
[Apr  2 10:57:44]IKE negotiation done for local:172.16.123.1, remote:172.16.123.2 IKEv1 with status: Error ok
[Apr  2 10:57:44]Added (spi=0xeb7bb2b4, protocol=0) entry to the spi table
[Apr  2 10:57:44]Added (spi=0x298c7e38, protocol=0) entry to the spi table
[Apr  2 10:57:44]ssh_ike_connect_ipsec: Start, remote_name = :500, flags = 00010000
[Apr  2 10:57:44]ike_sa_find_ip_port: Remote = all:500, Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}
[Apr  2 10:57:44]ike_alloc_negotiation: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}
[Apr  2 10:57:44]ssh_ike_connect_ipsec: SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 0
[Apr  2 10:57:44]ike_init_qm_negotiation: Start, initiator = 1, message_id = 5bc189d6
[Apr  2 10:57:44]ike_st_o_qm_hash_1: Start
[Apr  2 10:57:44]ike_st_o_qm_sa_proposals: Start
[Apr  2 10:57:44]ike_st_o_qm_nonce: Start
[Apr  2 10:57:44]ike_policy_reply_qm_nonce_data_len: Start
[Apr  2 10:57:44]ike_st_o_qm_optional_ke: Start
[Apr  2 10:57:44]ike_st_o_qm_optional_ids: Start
[Apr  2 10:57:44]ike_st_qm_optional_id: Start
[Apr  2 10:57:44]ike_st_qm_optional_id: Start
[Apr  2 10:57:44]ike_st_o_private: Start
[Apr  2 10:57:44]Construction NHTB payload for  local:172.16.123.1, remote:172.16.123.2 IKEv1 P1 SA index 6327634 sa-cfg to-srx2
[Apr  2 10:57:44]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:44]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:44]ike_st_o_encrypt: Marking encryption for packet
[Apr  2 10:57:44]ike_encode_packet: Start, SA = { 0x12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 5bc189d6, nego = 0
[Apr  2 10:57:44]ike_finalize_qm_hash_1: Hash[0..20] = 948de022 9b5c2aa7 ...
[Apr  2 10:57:44]ike_send_packet: Start, send SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 0, dst = 172.16.123.2:500,  routing table id = 0
[Apr  2 10:57:44]ikev2_packet_allocate: Allocated packet da5c00 from freelist
[Apr  2 10:57:44]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:44]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 10:57:44]ike_get_sa: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 943e4910, remote = 172.16.123.2:500
[Apr  2 10:57:44]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:44]ike_st_o_done: ISAKMP SA negotiation done
[Apr  2 10:57:44]ike_send_notify: Connected, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1
[Apr  2 10:57:44]ike_free_negotiation_isakmp: Start, nego = -1
[Apr  2 10:57:44]ike_free_negotiation: Start, nego = -1
[Apr  2 10:57:44]ike_alloc_negotiation: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}
[Apr  2 10:57:44]ike_decode_packet: Start
[Apr  2 10:57:44]ike_decode_packet: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2} / 943e4910, nego = 1
[Apr  2 10:57:44]ike_st_i_encrypt: Check that packet was encrypted succeeded
[Apr  2 10:57:44]ike_st_i_gen_hash: Start, hash[0..20] = 8083c62a 67986b4e ...
[Apr  2 10:57:44]ike_st_i_n: Start, doi = 1, protocol = 3, code = No proposal chosen (14), spi[0..4] = eb7bb2b4 00000000 ..., data[0..50] = 800c0001 00060022 ...
[Apr  2 10:57:44]<none>:500 (Responder) <-> 172.16.123.2:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [1] / 0x943e4910 } Info; Notification data has attribute list
[Apr  2 10:57:44]<none>:500 (Responder) <-> 172.16.123.2:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [1] / 0x943e4910 } Info; Notify message version = 1
[Apr  2 10:57:44]<none>:500 (Responder) <-> 172.16.123.2:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [1] / 0x943e4910 } Info; Error text = Could not find acceptable proposal
[Apr  2 10:57:44]<none>:500 (Responder) <-> 172.16.123.2:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [1] / 0x943e4910 } Info; Offending message id = 0x5bc189d6
[Apr  2 10:57:44]ike_remove_callback: Start, delete SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 0
[Apr  2 10:57:44]<none>:500 (Initiator) <-> 172.16.123.2:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [0] / 0x5bc189d6 } QM; Connection got error = 14, calling callback
[Apr  2 10:57:44]ike_delete_negotiation: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 0
[Apr  2 10:57:44]ike_free_negotiation_qm: Start, nego = 0
[Apr  2 10:57:44]ike_free_negotiation: Start, nego = 0
[Apr  2 10:57:44]ike_free_id_payload: Start, id type = 4
[Apr  2 10:57:44]ike_free_id_payload: Start, id type = 4
[Apr  2 10:57:44]ike_st_i_private: Start
[Apr  2 10:57:44]ike_send_notify: Connected, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 1
[Apr  2 10:57:44]ike_delete_negotiation: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 1
[Apr  2 10:57:44]ike_free_negotiation_info: Start, nego = 1
[Apr  2 10:57:44]ike_free_negotiation: Start, nego = 1
[Apr  2 10:57:44]IPSec negotiation failed for SA-CFG to-srx2 for local:172.16.123.1, remote:172.16.123.2 IKEv1. status: No proposal chosen
[Apr  2 10:57:44]   P2 ed info: flags 0xc2, P2 error: Error ok
[Apr  2 10:57:44]  IKEv1 Error : No proposal chosen
[Apr  2 10:57:44]IPSec SA done callback with sa-cfg NULL in p2_ed. status: No proposal chosen

and responder:

[Apr  2 10:57:34]ikev2_packet_allocate: Allocated packet da4800 from freelist
[Apr  2 10:57:34]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 10:57:34]ike_get_sa: Start, SA = { 12ae0b5c 700a67c1 - 00000000 00000000 } / 00000000, remote = 172.16.123.1:500
[Apr  2 10:57:34]ike_sa_allocate: Start, SA = { 12ae0b5c 700a67c1 - b765aec6 7a722a34 }
[Apr  2 10:57:34]ike_init_isakmp_sa: Start, remote = 172.16.123.1:500, initiator = 0
[Apr  2 10:57:34]ike_decode_packet: Start
[Apr  2 10:57:34]ike_decode_packet: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2} / 00000000, nego = -1
[Apr  2 10:57:34]ike_decode_payload_sa: Start
[Apr  2 10:57:34]ike_decode_payload_t: Start, # trans = 1
[Apr  2 10:57:34]ike_decode_payload_t: Start, # trans = 1
[Apr  2 10:57:34]ike_st_i_vid: VID[0..16] = afcad713 68a1f1c9 ...
[Apr  2 10:57:34]ike_st_i_vid: VID[0..16] = 27bab5dc 01ea0760 ...
[Apr  2 10:57:34]ike_st_i_vid: VID[0..16] = 6105c422 e76847e4 ...
[Apr  2 10:57:34]ike_st_i_vid: VID[0..16] = 4485152d 18b6bbcd ...
[Apr  2 10:57:34]ike_st_i_vid: VID[0..16] = cd604643 35df21f8 ...
[Apr  2 10:57:34]ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ...
[Apr  2 10:57:34]ike_st_i_vid: VID[0..16] = 7d9419a6 5310ca6f ...
[Apr  2 10:57:34]ike_st_i_vid: VID[0..16] = 4a131c81 07035845 ...
[Apr  2 10:57:34]ike_st_i_vid: VID[0..28] = 69936922 8741c6d4 ...
[Apr  2 10:57:34]ike_st_i_sa_proposal: Start
[Apr  2 10:57:34]ike_isakmp_sa_reply: Start
[Apr  2 10:57:34]ike_state_restart_packet: Start, restart packet SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1
[Apr  2 10:57:34]ike_st_i_sa_proposal: Start
[Apr  2 10:57:34]ike_st_i_cr: Start
[Apr  2 10:57:34]ike_st_i_cert: Start
[Apr  2 10:57:34]ike_st_i_private: Start
[Apr  2 10:57:34]ike_st_o_sa_values: Start
[Apr  2 10:57:34]ike_policy_reply_isakmp_vendor_ids: Start
[Apr  2 10:57:34]ike_st_o_private: Start
[Apr  2 10:57:34]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:34]ike_encode_packet: Start, SA = { 0x12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, nego = -1
[Apr  2 10:57:34]ike_send_packet: Start, send SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1, dst = 172.16.123.1:500,  routing table id = 0
[Apr  2 10:57:34]ikev2_packet_allocate: Allocated packet da4c00 from freelist
[Apr  2 10:57:34]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:34]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 10:57:34]ike_get_sa: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, remote = 172.16.123.1:500
[Apr  2 10:57:34]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:34]ike_decode_packet: Start
[Apr  2 10:57:34]ike_decode_packet: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2} / 00000000, nego = -1
[Apr  2 10:57:34]ike_st_i_nonce: Start, nonce[0..16] = f77bec4c 1281f64e ...
[Apr  2 10:57:34]ike_st_i_ke: Ke[0..128] = 20d42abe 01c00e0a ...
[Apr  2 10:57:34]ike_st_i_cr: Start
[Apr  2 10:57:34]ike_st_i_cert: Start
[Apr  2 10:57:34]ike_st_i_private: Start
[Apr  2 10:57:34]ike_st_o_ke: Start
[Apr  2 10:57:34]ike_st_o_nonce: Start
[Apr  2 10:57:34]ike_policy_reply_isakmp_nonce_data_len: Start
[Apr  2 10:57:34]ike_find_pre_shared_key: Find pre shared key key for 172.16.123.2:500, id = No Id -> 172.16.123.1:500, id = No Id
[Apr  2 10:57:34]ike_policy_reply_find_pre_shared_key: Start
[Apr  2 10:57:34]ike_state_restart_packet: Start, restart packet SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1
[Apr  2 10:57:34]ike_find_pre_shared_key: Find pre shared key key for 172.16.123.2:500, id = No Id -> 172.16.123.1:500, id = No Id
[Apr  2 10:57:34]ike_st_o_private: Start
[Apr  2 10:57:34]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:34]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:34]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:34]ike_st_o_calc_skeyid: Calculating skeyid
[Apr  2 10:57:34]ike_find_pre_shared_key: Find pre shared key key for 172.16.123.2:500, id = No Id -> 172.16.123.1:500, id = No Id
[Apr  2 10:57:34]ike_encode_packet: Start, SA = { 0x12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, nego = -1
[Apr  2 10:57:34]ike_send_packet: Start, send SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1, dst = 172.16.123.1:500,  routing table id = 0
[Apr  2 10:57:34]ikev2_packet_allocate: Allocated packet da5000 from freelist
[Apr  2 10:57:34]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:34]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 10:57:34]ike_get_sa: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, remote = 172.16.123.1:500
[Apr  2 10:57:34]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:34]ike_decode_packet: Start
[Apr  2 10:57:34]ike_decode_packet: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2} / 00000000, nego = -1
[Apr  2 10:57:34]ike_st_i_encrypt: Check that packet was encrypted succeeded
[Apr  2 10:57:34]ike_st_i_id: Start
[Apr  2 10:57:34]ike_st_i_hash: Start, hash[0..20] = 1019d0a6 57ffa805 ...
[Apr  2 10:57:34]ike_calc_mac: Start, initiator = false, local = false
[Apr  2 10:57:34]ike_st_i_cert: Start
[Apr  2 10:57:34]ike_st_i_status_n: Start, doi = 1, protocol = 1, code = Initial contact notification (24578), spi[0..16] = 12ae0b5c 700a67c1 ..., data[0..0] = 00000000 00000000 ...
[Apr  2 10:57:34]Received authenticated notification payload unknown from local:172.16.123.2 remote:172.16.123.1 IKEv1 for P1 SA 4563822
[Apr  2 10:57:34]ike_st_i_private: Start
[Apr  2 10:57:34]ike_st_o_id: Start
[Apr  2 10:57:34]ike_policy_reply_isakmp_id: Start
[Apr  2 10:57:34]ike_state_restart_packet: Start, restart packet SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1
[Apr  2 10:57:34]ike_st_o_id: Start
[Apr  2 10:57:34]ike_st_o_hash: Start
[Apr  2 10:57:34]ike_calc_mac: Start, initiator = false, local = true
[Apr  2 10:57:34]ike_st_o_status_n: Start
[Apr  2 10:57:34]ike_st_o_private: Start
[Apr  2 10:57:34]ike_policy_reply_private_payload_out: Start
[Apr  2 10:57:34]ike_st_o_encrypt: Marking encryption for packet
[Apr  2 10:57:34]ike_st_o_wait_done: Marking for waiting for done
[Apr  2 10:57:34]ike_st_o_all_done: MESSAGE: Phase 1 { 0x12ae0b5c 700a67c1 - 0xf46ac6af 642602a2 } / 00000000, version = 1.0, xchg = Identity protect, auth_method = Pre shared keys, Responder, cipher = 3des-cbc, hash = sha1, prf = hmac-sha1
[Apr  2 10:57:34]172.16.123.2:500 (Responder) <-> 172.16.123.1:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [-1] / 0x00000000 } IP; MESSAGE: Phase 1 version = 1.0, auth_method = Pre shared keys, cipher = 3des-cbc, hash = sha1, prf = hmac-sha
[Apr  2 10:57:34]ike_encode_packet: Start, SA = { 0x12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 00000000, nego = -1
[Apr  2 10:57:34]ike_send_packet: Start, send SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1, dst = 172.16.123.1:500,  routing table id = 0
[Apr  2 10:57:34]ike_send_notify: Connected, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1
[Apr  2 10:57:34]iked_pm_ike_sa_done: local:172.16.123.2, remote:172.16.123.1 IKEv1
[Apr  2 10:57:34]IKE negotiation done for local:172.16.123.2, remote:172.16.123.1 IKEv1 with status: Error ok
[Apr  2 10:57:34]ikev2_packet_allocate: Allocated packet da5400 from freelist
[Apr  2 10:57:34]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:34]ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Apr  2 10:57:34]ike_get_sa: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 5bc189d6, remote = 172.16.123.1:500
[Apr  2 10:57:34]ike_sa_find: Found SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2 }
[Apr  2 10:57:34]ike_st_o_done: ISAKMP SA negotiation done
[Apr  2 10:57:34]ike_send_notify: Connected, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = -1
[Apr  2 10:57:34]ike_free_negotiation_isakmp: Start, nego = -1
[Apr  2 10:57:34]ike_free_negotiation: Start, nego = -1
[Apr  2 10:57:34]ike_alloc_negotiation: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}
[Apr  2 10:57:34]ike_init_qm_negotiation: Start, initiator = 0, message_id = 5bc189d6
[Apr  2 10:57:34]ike_decode_packet: Start
[Apr  2 10:57:34]ike_decode_packet: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2} / 5bc189d6, nego = 0
[Apr  2 10:57:34]ike_decode_payload_sa: Start
[Apr  2 10:57:34]ike_decode_payload_t: Start, # trans = 1
[Apr  2 10:57:34]ike_decode_payload_t: Start, # trans = 1
[Apr  2 10:57:34]ike_st_i_encrypt: Check that packet was encrypted succeeded
[Apr  2 10:57:34]ike_st_i_qm_hash_1: Start, hash[0..20] = 948de022 9b5c2aa7 ...
[Apr  2 10:57:34]ike_st_i_qm_nonce: Nonce[0..16] = c35f300e c3252d55 ...
[Apr  2 10:57:34]ike_st_i_qm_ke: Ke[0..128] = 3c2f2a66 ff179d15 ...
[Apr  2 10:57:34]ike_st_i_qm_sa_proposals: Start
[Apr  2 10:57:34]Added (spi=0x8060ed26, protocol=0) entry to the spi table
[Apr  2 10:57:34]Added (spi=0xec6a187d, protocol=0) entry to the spi table
[Apr  2 10:57:34]SA-CFG lookup for Phase 2 failed for local:172.16.123.2, remote:172.16.123.1 IKEv1
[Apr  2 10:57:34]ikev2_fb_spd_select_qm_sa_cb: IKEv2 SA select failed with error TS unacceptable
[Apr  2 10:57:34]ikev2_fb_spd_select_qm_sa_cb: SA selection failed, no matching proposal (neg df6800)
[Apr  2 10:57:34]ike_qm_sa_reply: Start
[Apr  2 10:57:34]ike_state_restart_packet: Start, restart packet SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 0
[Apr  2 10:57:34]ike_st_i_qm_sa_proposals: Start
[Apr  2 10:57:34]ike_st_i_status_n: Start, doi = 1, protocol = 0, code = unknown (40001), spi[0..4] = eb7bb2b4 00000000 ..., data[0..8] = 00010004 0a010101 ...
[Apr  2 10:57:34]<none>:500 (Responder) <-> 172.16.123.1:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [0] / 0x5bc189d6 } QM; Invalid protocol_id = 0
[Apr  2 10:57:34]Received authenticated notification payload unknown from local:172.16.123.2 remote:172.16.123.1 IKEv1 for P1 SA 4563822
[Apr  2 10:57:34]iked_pm_ike_spd_notify_received: Negotiation is already failed. Reason: TS unacceptable.
[Apr  2 10:57:34]QM notification `(null)' (40001) (size 8 bytes) from 172.16.123.1 for protocol Reserved spi[0...3]=eb 7b b2 b4
[Apr  2 10:57:34]ike_st_i_private: Start
[Apr  2 10:57:34]ike_st_o_qm_hash_2: Start
[Apr  2 10:57:34]ike_st_o_qm_sa_values: Start
[Apr  2 10:57:34]<none>:500 (Responder) <-> 172.16.123.1:500 { 12ae0b5c 700a67c1 - f46ac6af 642602a2 [0] / 0x5bc189d6 } QM; Error = No proposal chosen (14)
[Apr  2 10:57:34]ike_alloc_negotiation: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}
[Apr  2 10:57:34]ike_encode_packet: Start, SA = { 0x12ae0b5c 700a67c1 - f46ac6af 642602a2 } / 943e4910, nego = 1
[Apr  2 10:57:34]ike_send_packet: Start, send SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 1, dst = 172.16.123.1:500,  routing table id = 0
[Apr  2 10:57:34]ike_delete_negotiation: Start, SA = { 12ae0b5c 700a67c1 - f46ac6af 642602a2}, nego = 1
[Apr  2 10:57:34]ike_free_negotiation_info: Start, nego = 1
[Apr  2 10:57:34]ike_free_negotiation: Start, nego = 1
[Apr  2 10:57:34]IPSec negotiation failed for SA-CFG Unknown for local:172.16.123.2, remote:172.16.123.1 IKEv1. status: TS unacceptable
[Apr  2 10:57:34]   P2 ed info: flags 0x0, P2 error: TS unacceptable

6. Quiz question for you

What do you think this output stands for? Which side is it from? Write us in comments under this article.

[Apr  7 08:38:27]iked_pm_ike_spd_notify_request: Sending Initial contact
[Apr  7 08:38:27]ssh_ike_connect: Start, remote_name = 172.18.2.2:500, xchg = 2, flags = 00090000
[Apr  7 08:38:27]ike_sa_allocate: Start, SA = { 7886b771 1231916e - 00000000 00000000 }
[Apr  7 08:38:27]ike_init_isakmp_sa: Start, remote = 172.18.2.2:500, initiator = 1
[Apr  7 08:38:27]172.18.1.2:500 (Initiator) <-> 172.18.2.2:500 { 7886b771 1231916e - 00000000 00000000 [-1] / 0x00000000 } IP; Warning: Number of proposals != 1 in ISAKMP SA, this is against draft!
[Apr  7 08:38:27]ssh_ike_connect: SA = { 7886b771 1231916e - 00000000 00000000}, nego = -1
[Apr  7 08:38:27]ike_st_o_sa_proposal: Start
[Apr  7 08:38:27]ike_policy_reply_isakmp_vendor_ids: Start
[Apr  7 08:38:27]ike_st_o_private: Start
[Apr  7 08:38:27]ike_policy_reply_private_payload_out: Start
[Apr  7 08:38:27]ike_encode_packet: Start, SA = { 0x7886b771 1231916e - 00000000 00000000 } / 00000000, nego = -1
[Apr  7 08:38:27]ike_send_packet: Start, send SA = { 7886b771 1231916e - 00000000 00000000}, nego = -1, dst = 172.18.2.2:500,  routing table id = 0
[Apr  7 08:38:37]ike_retransmit_callback: Start, retransmit SA = { 7886b771 1231916e - 00000000 00000000}, nego = -1
[Apr  7 08:38:37]ike_send_packet: Start, retransmit previous packet SA = { 7886b771 1231916e - 00000000 00000000}, nego = -1, dst = 172.18.2.2:500 routing table id = 0
[Apr  7 08:38:47]ike_retransmit_callback: Start, retransmit SA = { 7886b771 1231916e - 00000000 00000000}, nego = -1
[Apr  7 08:38:47]ike_send_packet: Start, retransmit previous packet SA = { 7886b771 1231916e - 00000000 00000000}, nego = -1, dst = 172.18.2.2:500 routing table id = 0
[Apr  7 08:38:57]P1 SA 6327673 timer expiry. ref cnt 2, timer reason Force delete timer expired (1), flags 0x0.
[Apr  7 08:38:57]iked_pm_ike_sa_delete_done_cb: For p1 sa index 6327673, ref cnt 2, status: Error ok
[Apr  7 08:38:57]ike_remove_callback: Start, delete SA = { 7886b771 1231916e - 00000000 00000000}, nego = -1
[Apr  7 08:38:57]172.18.1.2:500 (Initiator) <-> 172.18.2.2:500 { 7886b771 1231916e - 00000000 00000000 [-1] / 0x00000000 } IP; Connection timed out or error, calling callback
[Apr  7 08:38:57]ikev2_fb_v1_encr_id_to_v2_id: Unknown IKE encryption identifier -1
[Apr  7 08:38:57]ikev2_fb_v1_hash_id_to_v2_prf_id: Unknown IKE hash alg identifier -1
[Apr  7 08:38:57]ikev2_fb_v1_hash_id_to_v2_integ_id: Unknown IKE hash alg identifier -1
[Apr  7 08:38:57]iked_pm_ike_sa_done: UNUSABLE p1_sa 6327673
[Apr  7 08:38:57]  IKEv1 Error : Timeout
[Apr  7 08:38:57]IPSec Rekey for SPI 0x0 failed
[Apr  7 08:38:57]IPSec SA done callback called for sa-cfg to-srxA2 local:172.18.1.2, remote:172.18.2.2 IKEv1 with status Timed out
[Apr  7 08:38:57]ike_delete_negotiation: Start, SA = { 7886b771 1231916e - 00000000 00000000}, nego = -1
[Apr  7 08:38:57]ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
[Apr  7 08:38:57]ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table
[Apr  7 08:38:57]ike_sa_delete: Start, SA = { 7886b771 1231916e - 00000000 00000000 }
[Apr  7 08:38:57]ike_free_negotiation_isakmp: Start, nego = -1
[Apr  7 08:38:57]ike_free_negotiation: Start, nego = -1
[Apr  7 08:38:57]IKE SA delete called for p1 sa 6327673 (ref cnt 1) local:172.18.1.2, remote:172.18.2.2, IKEv1
[Apr  7 08:38:57]iked_pm_p1_sa_destroy:  p1 sa 6327673 (ref cnt 0), waiting_for_del 0x0
[Apr  7 08:38:57]iked_peer_entry_delete_from_id_table: Deleted peer entry 0xdfb900 for local 172.18.1.2:500 remote 172.18.2.2:500. gw to-srxA2, VR id 0 from ID hash table
[Apr  7 08:38:57]ike_free_id_payload: Start, id type = 1
[Apr  7 08:38:57]ike_free_sa: Start
[Apr  7 08:38:57]iked_deferred_free_inactive_peer_entry: Free 1 peer_entry(s)

We showed the most common log messages when troubleshooting IPsec. If you experienced different log messages, feel free to share your logs in comments on this page.