02-21-2020 04:00 AM - edited 02-21-2020 09:51 PM
Hi guys,
I've been strugling a few days with an issue with a new certificate based VPN tunnel I need to set up but I can't get it work. On my side the gateway is a Juniper SRX300 standalone while on the peer's side the device is a Cisco ASA (don't know model or software version).
I have installed the CA and local certificate and key on my GW, and both are valid and not expired.
The configuration on my side (Juniper SRX):
root@MANGIITA-STGVPN01> show configuration security ike traceoptions { file vpn-ike; flag ike; } proposal Company_STG_proposal { authentication-method rsa-signatures; dh-group group2; authentication-algorithm sha1; encryption-algorithm 3des-cbc; lifetime-seconds 86400; } policy Tunnel-Policy_STG-VPN { mode main; proposals Company_STG_proposal; certificate { local-certificate Company_STG_cert; } } gateway 222_222_222_222_Company_STG-VPN { ike-policy Tunnel-Policy_STG-VPN; address 222.222.222.222; no-nat-traversal; local-identity distinguished-name; external-interface ge-0/0/3; general-ikeid; } root@MANGIITA-STGVPN01> show configuration security ipsec proposal Proposal-STG_phase-2 { protocol esp; authentication-algorithm hmac-sha1-96; encryption-algorithm 3des-cbc; lifetime-seconds 36000; } policy Policy_STG-VPN { perfect-forward-secrecy { keys group2; } proposals Proposal-STG_phase-2; } vpn Tunnel_STG-VPN { bind-interface st0.1; ike { gateway 222_222_222_222_Company_STG-VPN; proxy-identity { local 10.210.241.96/32; remote 10.70.78.0/23; } ipsec-policy Policy_STG-VPN; } establish-tunnels immediately; } root@MANGIITA-STGVPN01> show configuration security zones security-zone VPN-Zone interfaces { st0.1 { host-inbound-traffic { system-services { all; } protocols { all; } } } }
And this is what I see on the SRX logs:
Feb 21 11:45:49 MANGIITA-STGVPN01 kmd[1716]: KMD_PEER_CERT_VERIFY_FAILED: Failed peer certificate verification for Gateway: 222_222_222_222_RemotePeerName_STG-VPN, Local: 111.111.111.111/500, Remote: 222.222.222.222/500, Local IKE-ID: C=UK, O=ABCD, OU=organization, CN=VPN000671.ABCD.com, Remote IKE-ID: C=UK, O=ABCD, OU=organization, CN=VPNRGVAL.ABCD.com, VR id: 0
Feb 21 11:45:49 MANGIITA-STGVPN01 kmd[1716]: IKE negotiation failed with error: Internal error: Internal error occurred in PKID. IKE Version: 1, VPN: 222_222_222_222_RemotePeerName_STG-VPN Gateway: 222_222_222_222_RemotePeerName_STG-VPN, Local: 111.111.111.111/500, Remote: 222.222.222.222/500, Local IKE-ID: Not-Available, Remote IKE-ID: Not-Available, VR-ID: 0: Role: Initiator
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] Triggering negotiation for 222_222_222_222_RemotePeerName_STG-VPN config block
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_callback: lookup peer entry for gateway 222_222_222_222_RemotePeerName_STG-VPN, local_port=500, remote_port=500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_create_peer_entry: Created peer entry 0x1288200 for local 111.111.111.111:500 remote 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_fetch_or_create_peer_entry: Create peer entry 0x1288200 for local 111.111.111.111:500 remote 222.222.222.222:500. gw 222_222_222_222_RemotePeerName_STG-VPN, VR id 0
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_callback: FOUND peer entry for gateway 222_222_222_222_RemotePeerName_STG-VPN
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] Initiating new P1 SA for gateway 222_222_222_222_RemotePeerName_STG-VPN
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] P1 SA 5876938 start timer. timer duration 30, reason 1.
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_negotiation Set p2_ed in sa_cfg=222_222_222_222_RemotePeerName_STG-VPN
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_peer_insert_p1sa_entry: Insert p1 sa 5876938 in peer entry 0x1288200
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_negotiation Convert traffic selectors from V1 format to V2 format for narrowing/matching selectors
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation 117e000
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_start: FSM_SET_NEXT:ikev2_fb_i_p1_negotiation_negotiate
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_local_address_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_id_request
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_id_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_notify_request
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_notify_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_psk_request
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_spd_notify_request Parse notification paylad in last received pkt
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_spd_notify_request: Sending Initial contact
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_psk_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_psk_result
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_psk_result: FSM_SET_NEXT:ikev2_fb_st_i_ike_sa_request
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_sa_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_sa_result
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_sa_request: FSM_SET_NEXT:ikev2_fb_st_i_conf_request
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKE SA fill called for negotiation of local:111.111.111.111, remote:222.222.222.222 IKEv1
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_conf_request: FSM_SET_NEXT:ikev2_fb_st_i_ike_sa_result
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 1 references
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_negotiate: FSM_SET_NEXT:ikev2_fb_i_p1_negotiation_result
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ssh_ike_connect: Start, remote_name = 222.222.222.222:500, xchg = 2, flags = 00090000
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_allocate: Start, SA = { f5956744 f662ef53 - 00000000 00000000 }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_init_isakmp_sa: Start, remote = 222.222.222.222:500, initiator = 1
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ssh_ike_connect: SA = { f5956744 f662ef53 - 00000000 00000000}, nego = -1
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 00000000 00000000 [-1] / 0x00000000 } IP; Start isakmp sa negotiation
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 00000000 00000000 [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0000
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = Start sa negotiation I (1)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_sa_proposal: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_isakmp_vendor_ids: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM SA I (3)
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 180, mID=00000000, HDR, SA, Vid, Vid, Vid, Vid
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { f5956744 f662ef53 - 00000000 00000000}, nego = -1, dst = 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ---------> Received from 222.222.222.222:500 to 111.111.111.111:0, VR 0, length 108 on IF
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Not found SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_st_input_v1_create_sa
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_create_sa: [1224800/0] No IKE SA for packet; requesting permission to create one.
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_create_sa: FSM_SET_NEXT:ikev2_packet_st_connect_decision
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c } / 00000000, remote = 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Not found SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_find_half: Found half SA = { f5956744 f662ef53 - 00000000 00000000 }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_get_sa: We are initiator, first response packet
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_upgrade: Start, SA = { f5956744 f662ef53 - 00000000 00000000 } -> { ... - 4cbb2d06 89c54b6c }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Packet to old negotiation
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKEv1 packet R(<none>:500 <- 222.222.222.222:500): len= 108, mID=00000000, HDR, SA, Vid
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0401 SA VID
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM SA I (3)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_sa_value: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_cr: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..20] = 4048b7d5 6ebce885 ...
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_private: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_ke: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [3160]
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_nonce: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_isakmp_nonce_data_len: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Adding CAs: enc 4 len 55
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_get_cas: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM KE I (5)
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 240, mID=00000000, HDR, KE, Nonce, CR
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c}, nego = -1, dst = 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ---------> Received from 222.222.222.222:500 to 111.111.111.111:0, VR 0, length 397 on IF
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c } / 00000000, remote = 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Packet to old negotiation
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKEv1 packet R(<none>:500 <- 222.222.222.222:500): len= 397, mID=00000000, HDR, KE, Nonce, CR, CR, Vid, Vid, Vid, Vid
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0452 KE CR NONCE VID
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM KE I (5)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_nonce: Start, nonce[0..20] = 9760e0b4 70845318 ...
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_ke: Ke[0..128] = 9d1a6c2a ae4230bb ...
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_cr: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Received Peer CA Name Len 76 Enc 4 Total CAs 1
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Received Peer CA Name Len 55 Enc 4 Total CAs 2
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = 12f5f28c 457168a9 ...
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..8] = 09002689 dfd6b712 ...
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = b97c8a1b 89c44b6c ...
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = 1f07f70e aa6514d3 ...
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_private: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_id: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_certs_base: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_find_private_key: Find private key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=AAMS, OU=contoso company, CN=VPN000671.company.com) -> 222.222.222.222:500, id = No Id
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_process_packet: No output packet, returning
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_request_certs: FSM_SET_NEXT:ikev2_fb_st_request_certs_result
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM certificate callback invoked
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Requesting cert-chain for cert-id RemotePeerName_STG_cert
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Checking CAs: enc 4 len 55
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM trusted CA 1 found in device
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM cert-chain 1 for RemotePeerName_STG_cert found in local database
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Adding cert: enc 4 len 998
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM: Cerificate found in local database
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] Certificate valid from 2018 Jan 10th, 13:20:22 GMT to 2021 Jan 10th, 13:20:22 GMT
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pm_validate_certificate_expiry: Certificate is not expired
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ssh_x509_cert_free: Decreasing reference count of certificate 12ab000 to 0
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_private_key: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Restart packet
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c}, nego = -1
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 0452 KE CR NONCE VID
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM KE I (5)/257, exchange = 2, auth_method = signatures, Initiator
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_certs_base: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_find_private_key: Find private key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=CONTOSO, OU=contoso company, CN=VPN000671.company.com) -> 222.222.222.222:500, id = No Id
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_request_certificates: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_sig: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_find_private_key: Find private key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=CONTOSO, OU=contoso company, CN=VPN000671.company.com) -> 222.222.222.222:500, id = No Id
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [2725]
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Diffie-hellman secret g^xy[128] = 0x69800db6 9c787fd6 c2da015a 62507713
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Hash algorithm = hmac-sha1
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Prf key[36] = 0x6f01ed42 1c6aa1fb 53e9abaa 61ed81f0 9760e0b4 70845318 57
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Calculating SKEYID
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Output of SKEYID hash[20] = 0x5bae5426 31cbde78 c99dac6f f9d15e12 854eb9
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Output of SKEYID_d hash[20] = 0xcaaebf55 64d60c99 40899fdf b3ca0544 e7c7
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Output of SKEYID_a hash[20] = 0x72b62be4 67a5d24f 0847c0da 82d79b5c 5a4f
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Output SKEYID_e hash[20] = 0xaf5a3ffb fd057e6a 595a575a a153c3cc f23a30c
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Final encryption key[24] = 0x71c5c540 f19c19a3 ae311017 dba6f224 5f8970e
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_calc_mac: Start, initiator = true, local = true
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Output of HASH_I hash[20] = 0xecb407e7 d0b0649c e296ad57 6474a9b0 8a42aa
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Secs [0] USecs [14978] Avg Secs [0] Avg Usecs [14887]
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_status_n: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_o_encrypt: Marking encryption for packet
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM final I (7)
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 1412, mID=00000000, HDR, ID, CERT, SIG, N(INITIAL_CONTACT)
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c}, nego = -1, dst = 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { 0790193c e13210a3 - 8880979e b6c81458 [-1] / 0x00000000 } IP; Removing negotiation
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { 0790193c e13210a3 - 8880979e b6c81458 [-1] / 0x00000000 } IP; Deleting negotiation
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ssh_ike_tunnel_table_entry_delete: The tunnel id: 0 doesn't exist in IKE tunnel table
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_delete: Start, SA = { 0790193c e13210a3 - 8880979e b6c81458 }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_sa_freed: Received notification from the ISAKMP library that the IKE SA 0 is freed
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ---------> Received from 222.222.222.222:500 to 111.111.111.111:0, VR 0, length 1692 on IF
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c } / 00000000, remote = 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c }
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Packet to old negotiation
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKEv1 packet R(<none>:500 <- 222.222.222.222:500): len= 1692, mID=00000000, HDR, ID, CERT, SIG, Vid
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Version = 1.0, Input packet fields = 048c ID CERT SIG VID
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_step: Current state = MM final I (7)/-1, exchange = 2, auth_method = signatures, Initiator
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_encrypt: Check that packet was encrypted succeeded
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_id: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_st_i_sig: Start, sig[0..256] = 03afba23 f6423355 ...
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_find_public_key: Find public key for 111.111.111.111:500, id = der_asn1_dn(any:0,[0..82]=C=UK, O=CONTOSO, OU=contoso company, CN=VPN000671.company.com) -> 222.222.222.222:500, id = der_asn1_dn(any
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_process_packet: No output packet, returning
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_find_public_key: FSM_SET_NEXT:ikev2_fb_st_find_public_key_result
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_policy_public_key
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ssh_policy_find_public_key_send_ipc
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKED-PKID-IPC 1 cert, len1<1285> 1st<30> last<0c>
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pkid_send_packet
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] P1 SA 5876938 stop timer. timer duration 30, reason 1.
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] P1 SA 5876938 start timer. timer duration 30, reason 1.
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_public_key: Start
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; No public key found
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Restart packet
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c}, nego = -1
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 1 references
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [-1] / 0x00000000 } IP; Error = Authentication failed (24)
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: No phase 1 done, use only N or D payload
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] <none>:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [0] / 0x23b8d0cd } Info; Sending negotiation back, error = 24
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 87, mID=23b8d0cd, HDR, N(AUTHENTICATION_FAILED)
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_send_notify: Sending notification to 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { f5956744 f662ef53 - 4cbb2d06 89c54b6c}, nego = 0, dst = 222.222.222.222:500
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] <none>:500 (Initiator) <-> 222.222.222.222:500 { f5956744 f662ef53 - 4cbb2d06 89c54b6c [0] / 0x23b8d0cd } Info; Deleting negotiation
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKE negotiation fail for local:111.111.111.111, remote:222.222.222.222 IKEv1 with status: Authentication failed
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKEv1 Error : Authentication failed
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback. ed efe028. status: Authentication failed
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IPSec Rekey for SPI 0x0 failed
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback called for sa-cfg 222_222_222_222_RemotePeerName_STG-VPN local:111.111.111.111, remote:222.222.222.222 IKEv1 with status Authentication failed
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] IKE SA delete called for p1 sa 5876938 (ref cnt 2) local:111.111.111.111, remote:222.222.222.222, IKEv1
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] P1 SA 5876938 stop timer. timer duration 30, reason 1.
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] P1 SA 5876938 reference count is not zero (1). Delaying deletion of SA
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing fallback negotiation 117e000
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_pm_p1_sa_destroy: p1 sa 5876938 (ref cnt 0), waiting_for_del 0x1206fe0
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_peer_remove_p1sa_entry: Remove p1 sa 5876938 from peer entry 0x1288200
[Feb 11 12:49:23][111.111.111.111 <-> 222.222.222.222] iked_peer_entry_patricia_delete:Peer entry 0x1288200 deleted for local 111.111.111.111:500 and remote 222.222.222.222:500
Finally, these are the logs from the ASA:
Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, PHASE 1 COMPLETED
Feb 20 14:47:47 [IKEv1]IP = 111.111.111.111, Keep-alive type for this connection: DPD
Feb 20 14:47:47 [IKEv1 DEBUG]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Starting P1 rekey timer: 64800 seconds.
Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Add to IKEv1 Tunnel Table succeeded for SA with logical ID 75255808
Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Add to IKEv1 MIB Table succeeded for SA with logical ID 75255808
Feb 20 14:47:47 [IKEv1]IP = 111.111.111.111, IKE_DECODE RECEIVED Message (msgid=e712801b) with payloads : HDR + NOTIFY (11) + NONE (0) total length : 87
Feb 20 14:47:47 [IKEv1]IP = 111.111.111.111, IKE_DECODE RECEIVED Message (msgid=e712801b) with payloads : HDR + NOTIFY (11) + NONE (0) total length : 87
Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Received an un-encrypted AUTH_FAILED notify message, dropping
Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Information Exchange processing failed
They insist the problem must be on our side as they highlight that Phase1 completes but in Phase2 they receive a non-encrypted message that makes the connection to drop.
Any help?
Thanks in advance!
02-22-2020 09:38 AM
why dont you change the tunnel from certificate to preshared key to rule out where the problem is. I am not expert/no knowlege on Juniper network. cant much advise here unless you asked the remote site to share the ASA firewall configuration and hide the sensitive/change it and upload it here so we can see both side configuration and advise you.
02-24-2020 01:04 AM
Unfortunately that's not an option, as the peer is a very strict institution and it's impossible to ask them to change anything or event to send us the configuration on their side. Whatever we have to do, we have to do it based on the logs I've pasted, and only from our side.
It looks to me according to the logs that their GW is not presenting their certificate to our GW properly, but I'm not sure about that.
Thanks
02-24-2020 02:49 AM
Could you check the phase 1 status on your end:
show security ike security-associations
Also, while you are at it, check the ipsec status:
show security ipsec security-associations detail
02-24-2020 02:54 AM
I run those commands every time, and every minute when my device retries the connection, it shows the following for a moment:
root@MANGIITA-STGVPN01> show security ike security-associations
Index State Initiator cookie Responder cookie Mode Remote Address
5895615 DOWN bbabeb8c358e429e 0000000000000000 Main 222.222.222.222
BR
02-23-2020 12:52 PM
Since phase 1 is being completed, the issue is most likely with phase 2
authentication-algorithm hmac-sha1-96
I suspect that the remote side doesn't support hmac-sha1-96 and is using something else. Ask them for their phase 2 configuration (or better yet, their full VPN configuration) and then compair your config to theirs.
02-24-2020 02:52 AM
Ask them for their phase 2 configuration (or better yet, their full VPN configuration) and then compair your config to theirs.
I wish to be able to ask them anything, but they won't share anything. However we had the same tunnel a few months ago and the authentication-algorithm value was the same as now.
Thanks
02-24-2020 09:12 AM
we need logs (debugs) from juniper and from the ASA. otherwise it very hard to pin point where is the issue is. did you tried to setup tunnel with pre-shared key?
02-24-2020 11:01 AM
I know it's hard, that's what I have included the full debug logs I have from the Juniper, and the portion of the logs the remote peer sent me from the ASA. I thought with that would be enough to, at least, find out where the issue is (phase 1 or phase 2 at least), because the problem here is that I can't expect collaboration from the other side. Otherwise, I'd request them the actual configuration on their side...
I think what can provide more information is the debug log I've attached from the Juniper side.
Thanks
02-24-2020 11:31 AM
Sorry mate but seem you at the dead end. unless otherwise no configuration/no debug log from other side in that case its really difficult to dig/pin out where the problem is. I am not a juniper expert,actually never used Juniper myself.
02-24-2020 11:34 AM
I've provided with the log's I've got from the other side:
Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, PHASE 1 COMPLETED Feb 20 14:47:47 [IKEv1]IP = 111.111.111.111, Keep-alive type for this connection: DPD Feb 20 14:47:47 [IKEv1 DEBUG]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Starting P1 rekey timer: 64800 seconds. Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Add to IKEv1 Tunnel Table succeeded for SA with logical ID 75255808 Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Add to IKEv1 MIB Table succeeded for SA with logical ID 75255808 Feb 20 14:47:47 [IKEv1]IP = 111.111.111.111, IKE_DECODE RECEIVED Message (msgid=e712801b) with payloads : HDR + NOTIFY (11) + NONE (0) total length : 87 Feb 20 14:47:47 [IKEv1]IP = 111.111.111.111, IKE_DECODE RECEIVED Message (msgid=e712801b) with payloads : HDR + NOTIFY (11) + NONE (0) total length : 87 Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Received an un-encrypted AUTH_FAILED notify message, dropping Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Information Exchange processing failed
02-24-2020 11:33 AM
Since the ASA claims that phase 1 completes, I believe the issue is in phase 2 as I stated earlier.
02-24-2020 11:37 AM
agree with @Marius Gunnerud but as stated need more data to understand what happening. and you have no control and other side is not very cooperative.
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide