SRX

Hi,

Currently attempted to get an SRX240H connected via the internet to a Fortigate 60D

Gone through the normal troubleshooting guides, but seem to be getting a lot of different timeout issues, here's a sanitized version of the logs i got by setting the debug trace on the specific IP's:

Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] Triggering negotiation for IPSEC-VPN config block
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_pm_trigger_callback: non-natt case for gateway IKE-GATEWAY, lookup peer entry from loc
al_port=, remote_port=.
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_fetch_or_create_peer_entry: Create peer entry 0xa46a00 for local SITE-A-JUNOS:500 remote 2
02.176.14.242:500. gw IKE-GATEWAY, VR id 0
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_pm_trigger_callback: FOUND non-natt peer entry for gateway IKE-GATEWAY
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] Initiating new P1 SA for gateway IKE-GATEWAY
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] P1 SA 7104734 start timer. timer duration 30, reason 1.
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_peer_insert_p1sa_entry: Insert p1 sa 7104734 in peer entry 0xa46a00
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation c9a000
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] Parsing notification payload for local:SITE-A-JUNOS, remote:SITE-B-FORTIOS IKEv1
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_pm_ike_spd_notify_request: Sending Initial contact
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] IKE SA fill called for negotiation of local:SITE-A-JUNOS, remote:SITE-B-FORTIOS IKEv1
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ikev2_fallback_negotiation_free: Fallback negotiation c9a000 has still 1 references
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ssh_ike_connect: Start, remote_name = SITE-B-FORTIOS:500, xchg = 2, flags = 00090000
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_sa_allocate: Start, SA = { 72ea9f9f d1dffe33 - 00000000 00000000 }
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_init_isakmp_sa: Start, remote = SITE-B-FORTIOS:500, initiator = 1
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ssh_ike_connect: SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 2, auth_method = pre shared key, Initiator
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_st_o_sa_proposal: Start
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_policy_reply_isakmp_vendor_ids: Start
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_st_o_private: Start
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_policy_reply_private_payload_out: Start
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_state_step: All done, new state = MM SA I (3)
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_encode_packet: Start, SA = { 0x72ea9f9f d1dffe33 - 00000000 00000000 } / 00000000, nego = -1
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_encode_packet: Final length = 288
Aug 12 02:42:41 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_send_packet: Start, send SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1, dst = SITE-B-FORTIOS:500, routing table id = 0
Aug 12 02:42:51 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_retransmit_callback: Start, retransmit SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1
Aug 12 02:42:51 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_send_packet: Start, retransmit previous packet SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1, dst = SITE-B-FORTIOS:500 routing table id = 0
Aug 12 02:43:01 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_retransmit_callback: Start, retransmit SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1
Aug 12 02:43:01 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_send_packet: Start, retransmit previous packet SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1, dst = SITE-B-FORTIOS:500 routing table id = 0
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] P1 SA 7104734 timer expiry. ref cnt 2, timer reason Force delete timer expired (1), flags 0x0.
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] Initiate IKE P1 SA 7104734 delete. curr ref count 2, del flags 0x3
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_pm_ike_sa_delete_done_cb: For p1 sa index 7104734, ref cnt 2, status: Error ok
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_remove_callback: Start, delete SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] SITE-A-JUNOS:500 (Initiator) <-> SITE-B-FORTIOS:500 { 72ea9f9f d1dffe33 - 00000000 00000000 [-1] / 0x00000000 } IP; Connection timed out or error, calling callback
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ikev2_fb_v1_encr_id_to_v2_id: Unknown IKE encryption identifier -1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ikev2_fb_v1_hash_id_to_v2_prf_id: Unknown IKE hash alg identifier -1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ikev2_fb_v1_hash_id_to_v2_integ_id: Unknown IKE hash alg identifier -1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_pm_ike_sa_done: UNUSABLE p1_sa 7104734
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] IKEv1 Error : Timeout
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] IPSec SA done callback. ed c41028. status: Timed out
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] IPSec Rekey for SPI 0x0 failed
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] IPSec SA done callback called for sa-cfg IPSEC-VPN local:SITE-A-JUNOS, remote:SITE-B-FORTIOS IKEv1 with status Timed out
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ikev2_fallback_negotiation_free: Fallback negotiation c9a000 has still 1 references
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ikev2_fallback_negotiation_free: Freeing fallback negotiation c9a000
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_delete_negotiation: Start, SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_sa_delete: Start, SA = { 72ea9f9f d1dffe33 - 00000000 00000000 }
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_free_negotiation_isakmp: Start, nego = -1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_free_negotiation: Start, nego = -1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA b90400 is freed
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] IKE SA delete called for p1 sa 7104734 (ref cnt 1) local:SITE-A-JUNOS, remote:SITE-B-FORTIOS, IKEv1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] P1 SA 7104734 stop timer. timer duration 30, reason 0.
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_del_ha_blob: Error deleting blob with type = phase1 mod, tunnel id 0. Error: No such fileor directory
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_del_ha_blob: Error deleting blob with type = phase1, tunnel id 0. Error: No such file or directory
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_pm_p1_sa_destroy: p1 sa 7104734 (ref cnt 0), waiting_for_del 0x0
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_peer_remove_p1sa_entry: Remove p1 sa 7104734 from peer entry 0xa46a00
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] iked_peer_entry_patricia_delete:Peer entry a46a00 deleted for local SITE-A-JUNOS:1f4 and remote SITE-B-FORTIOS:1f4
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_free_id_payload: Start, id type = 1
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_free_sa: Start

Before anyone asks, yes i've bound the interface to the correct interface, and yes i've set family inet on it too.

For refrence, it's running: JUNOS 11.4R9.4

Thanks for reading, hopefully the problem is glaringly obvious to someone.

Hi,

From the messages below :-

Aug 12 02:43:01 [SITE-A-JUNOS <-> SITE-B-FORTIOS] ike_send_packet: Start, retransmit previous packet SA = { 72ea9f9f d1dffe33 - 00000000 00000000}, nego = -1, dst = SITE-B-FORTIOS:500 routing table id = 0
Aug 12 02:43:11 [SITE-A-JUNOS <-> SITE-B-FORTIOS] IPSec SA done callback called for sa-cfg IPSEC-VPN localSmiley FrustratedITE-A-JUNOS, remoteSmiley FrustratedITE-B-FORTIOS IKEv1 with status Timed out

We are nto even getting a response for the first packet of the Phase 1 negotiation, and hence the responder cookie is 000000.

Check on the remote side if it is replying to the first packet sent from the SRX.

Also check if there are any firewall filters on the SRX external or loopback interface which could be blocking these replies.

Regards,

Sahil Sharma

---------------------------------------------------

Please mark my solution as accepted if it helped, Kudos are appreciated as well.

Hi,

Thanks for the quick response.

So there's no filters going on on our end, Im trying to get debug info out of the Fortigate end, but it's not under my control, which is making it a tad dificult. 

Thanks for your suggestions, i was sure that the cookie of all 0's didn't seem right, so i'll go back to them with what you've suggested.

Thanks!

Also make sure that the zone where your gateway interface is configured has ike as a permitted connection.

set security zone security-zone untrust host-inbound-traffic system-services ike

Hi,

Thanks, yeah i'd already had the host-inbound-traffic system-services settings setup, but as it turns out it was the other end, they re-created their profiles over the weekend, and it's subsequently working now.

Cheers,