SRX

 View Only
last person joined: 18 hours ago 

Ask questions and share experiences about the SRX Series, vSRX, and cSRX.
Expand all | Collapse all

Certificates based IPSEC VPN tunnel not coming up

  • 1.  Certificates based IPSEC VPN tunnel not coming up

    Posted 02-21-2020 03:55

    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:

     

    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:

    Spoiler

    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 on the remote peer gateway:

    Spoiler
    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!

     

     


    #vpn
    #SRX
    #CiscoASA
    #certificate


  • 2.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 02-21-2020 11:48

    Hi nolotil,

     

    On the SRX we are seeing authentication failures:

     

    [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] 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 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

    And the ASA reports that it received a meesages from the SRX notifying that the authentication failed on the SRX:

     

    Feb 20 14:47:47 [IKEv1]Group = Conc_00067_Mnsn, IP = 111.111.111.111, Received an un-encrypted AUTH_FAILED notify message, dropping

     

    Can you share the following output from the SRX:

     

    > show security pki local-certificate Company_STG_cert detail

     

    Also can you look if there is a command on the ASA that will show the same information of the above command (the information of the local certificate installed on the device). I believe I will be able to help you if I can check the requested data.

     



  • 3.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 02-24-2020 06:50

    Hi @epaniagua, 

     

    Both the local certificate and the CA certificate looks fine, not expired, etc etc 

    root@MANGIITA-STGVPN01> show security pki local-certificate detail    
    Certificate identifier: Company_STG_cert
      Certificate version: 3
      Serial number: 01516b554235c734
      Issuer:
        Organization: [deleted], Country: UK, Common name: CA Company Test
      Subject:
        Organization: [deleted], Organizational unit: [deleted], Country: UK, Common name: VPN000671.COMPANY.COM
      Subject string: 
        C=UK, O=[deleted], OU=[deleted], CN=VPN000671.COMPANY.COM
      Validity:
        Not before: 01-10-2018 13:20 UTC
        Not after: 01-10-2021 13:20 UTC
      Public key algorithm: rsaEncryption(2048 bits)
       [deleted]
      Signature algorithm: sha256WithRSAEncryption
      Distribution CRL: 
        ldap://[deleted]?certificateRevocationList
      Use for key: Key encipherment, Digital signature, TLS Web Client Authentication, 1.3.6.1.5.5.7.3.2
      Fingerprint:
        [deleted] (md5)
      Auto-re-enrollment:
        Status: Disabled
        Next trigger time: Timer not started

    I have deleted some fields to anonymize the content. Also, the output of the command show security pki ca-certificate detail  looks also fine 



  • 4.  RE: Certificates based IPSEC VPN tunnel not coming up

     
    Posted 02-24-2020 11:53

    Hi,

     

    The SRX checks that the Subject field of the received cert (the one sent from the ASA) matches the IKE remote-identity configured on the SRX (under [edit security ike gateway] hierarchy). If no remote-ID is configured on the SRX, it will do the check against the "remote-address" configured under  [edit security ike gateway] .

     

    As of now you have configured the local-identity but not the remote-identity so the SRX will check the Subject field of the received cert against the"remote-address" configured under  [edit security ike gateway] .

     

    gateway 222_222_222_222_Company_STG-VPN {
        ike-policy Tunnel-Policy_STG-VPN;
        address 222.222.222.222;

     

     

    Can you make sure these two values match? If you can check the Subject field of the cert that will be sent fromt he ASA, you could confgure that as local-ID on the SRX.

     



  • 5.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 02-25-2020 06:01

    How can I see the certificate being sent by the ASA? in the debug logs above can't find it. Actually my main guess is that they are not sending their public key , but I don't know how to demonstrate it. 

     

    BR



  • 6.  RE: Certificates based IPSEC VPN tunnel not coming up

     
    Posted 02-25-2020 06:44

    nolotil,

     

    I was wondering if you could check on the ASA in a similar way as we do it in the SRX (with a command). Try running IKE traceoptions again on SRX but with level 15 so we could see more details:

     

    # set security ike traceoptions file IKE-TRACE
    # set security ike traceoptions flag all
    # commit
    # run request security ike debug-enable local [Public_IP_of_SRX] remote [Public_IP_of_ASA] level 15
    # run show security ike debug-status
    # run clear log IKE-TRACE

    [wait for the negotiation to be performed again]

    # run show log IKE-TRACE

     



  • 7.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 02-25-2020 08:38

    Hi again, Unfortunatelly I can't check anything on the ASA.

    Here the output of the debug, I've gone through the full log and haven't seen anything that may point to the problem. 

    Thanks!

     

     

    Spoiler

    [Feb 25 17:30:59][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 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_validate_certificate_expiry: Certificate is not expired
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_x509_cert_free: Decreasing reference count of certificate 12b8600 to 0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates_cb: Found 1 certificates
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_private_key: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = -1
    [Feb 25 17:30:59][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 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM KE I (5)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_certs
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_certs_base: Start
    [Feb 25 17:30:59][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=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates: Request certificates policy call entered, IKE SA 12b0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates: Returning cached certs
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_request_certificates: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[2] = ike_st_o_sig
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_sig: Start
    [Feb 25 17:30:59][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=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group type dl-modp
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group size 1024
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group 2
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dh_compute_synch: Requested DH group 2
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Peer public key has length 128

    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [2909]
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_calc_mac: Start, initiator = true, local = true
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Requested MIXED-MODE engine
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Real engine is OCTEON
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Secs [0] USecs [14909] Avg Secs [0] Avg Usecs [14806]
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[3] = ike_st_o_status_n
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_status_n: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[4] = ike_st_o_private
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 5 ike_sa 12b0000 (neg 117e000)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: NAT traversal disabled by policy
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[5] = ike_st_o_encrypt
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_encrypt: Marking encryption for packet
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM final I (7)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0xd0c6518b fb9be03e - 2b62479e eccbda43 } / 00000000, nego = -1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 91
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 1003
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 260
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 28
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 1412
    [Feb 25 17:30:59][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 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Encrypting packet
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 1412
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = -1, dst = 222.222.222.222:500
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 1692, on Interface: ge-0/0/3.0
    [Feb 25 17:30:59][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 ge-0/0/3.0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: [11fd400/0]
    ******** Processing received ************
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43 }
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { d0c6518b fb9be03e - 2b62479e eccbda43 }
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Found IKEv1 SA
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: [11fd400/deadbeee] Packet to existing v1 SA
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Packet from 222.222.222.222:500, use_natt=0 data[0..1692] = d0c6518b fb9be03e 2b62479e eccbda43 ...
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43 } / 00000000, remote = 222.222.222.222:500
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43 }
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { d0c6518b fb9be03e - 2b62479e eccbda43 }
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43} / 00000000, nego = -1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: first_payload_type:5.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Decrypting packet
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:6.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:9.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:0.
    [Feb 25 17:30:59][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 25 17:30:59][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 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 2, fields = 000c / 06c0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 2, fields = 000c / 0680
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM final I (7)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[0] = ike_st_i_encrypt
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_encrypt: Check that packet was encrypted succeeded
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[1] = ike_st_i_cert
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: Entered new certificate policy call, received a certificate of encoding 4 for IKE SA 12b0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: FB; Calling v2 policy function new_certificate
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[2] = ike_st_i_id
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_id: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[3] = ike_st_i_sig
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_sig: Start, sig[0..256] = 064ff862 9f77f248 ...
    [Feb 25 17:30:59][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=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = der_asn1_dn(any
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_public_key: Find pre-shared key policy call entered, IKE SA 12b0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_public_key: Taking reference to fallback negotiation 117e000 (now 3 references)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_find_public_key: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12b0000 ike_sa 0x0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Input function[3] = ike_st_i_sig asked retry later
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_process_packet: No output packet, returning
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_destroy: [11fd400/deadbeee] Destructor
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_free: [11fd400/deadbeee] Freeing
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_remove_callback: Start, delete SA = { 68d29431 c760ceb1 - 65417261 f37f60e5}, nego = -1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_delete_negotiation: Start, SA = { 68d29431 c760ceb1 - 65417261 f37f60e5}, nego = -1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
    [Feb 25 17:30:59][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 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_sa_delete: Start, SA = { 68d29431 c760ceb1 - 65417261 f37f60e5 }
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation_isakmp: Start, nego = -1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation: Start, nego = -1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:30:59][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 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_id_payload: Start, id type = 9
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_id_payload: Start, id type = 9
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_sa: Start
    [Feb 25 17:30:59][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 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_find_public_key: FB; Calling v2 policy function public_key
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_id_validate: General IKE-ID is enabled, skipping ID validation
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_policy_public_key
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 83, value = 3051310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 82, value = 3050310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..81]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPNRGVAL.COMPANY.uk)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_policy_find_public_key_send_ipc
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKED-PKID-IPC 1 cert, len1<1285> 1st<30> last<0c>
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pkid_send_packet
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_reference_exchange_data: Taking reference to exchange data efe028 (to 3)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 stop timer. timer duration 30, reason 1.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 start timer. timer duration 30, reason 1.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_public_key: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { d0c6518b fb9be03e - 2b62479e eccbda43 [-1] / 0x00000000 } IP; No public key found
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = -1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_negotiation_done_isakmp: Entered IKE error code Authentication failed (24), IKE SA 12b0000 (neg 117e000)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_ike_negotiation_cb: Connect IKE done callback, status Authentication failed (neg 117e000)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 1 references
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { d0c6518b fb9be03e - 2b62479e eccbda43 [-1] / 0x00000000 } IP; Error = Authentication failed (24)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_alloc_negotiation: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43}
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_alloc_negotiation: Found slot 0, max 1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: New informational negotiation message_id = 25c3f7ec initialized using slot 0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: Created random message id = 25c3f7ec
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: No phase 1 done, use only N or D payload
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 12 (0x000c), len = 2, value = 0001
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode V: type = 6 (0x0006), len = 19 (0x0013), value = 4e6f2070 ...
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 8 (0x0008), len = 2, value = 0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0xd0c6518b fb9be03e - 2b62479e eccbda43 } / 25c3f7ec, nego = 0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 59
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 87
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 87, mID=25c3f7ec, HDR, N(AUTHENTICATION_FAILED)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 87
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_notify: Sending notification to 222.222.222.222:500
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = 0, dst = 222.222.222.222:500
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_delete_negotiation: Start, SA = { d0c6518b fb9be03e - 2b62479e eccbda43}, nego = 0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation_info: Start, nego = 0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation: Start, nego = 0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: Phase I negotiation result
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: FB; Calling v2 policy function ike_sa_done
    [Feb 25 17:30:59][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 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_delete_slot_table_entry Slot released msg_id<0> cookie<d0c6518bfb9be03e>
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_tunnel_event_add_event_in_gw: Updating tunnel-event for gateway 217_175_53_26_company_STG-VPN with Internal error: Internal error occurred in PKID
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_tunnel_event_add_event_in_gw: tunnel-event Internal error: Internal error occurred in PKID count incremented to 40720
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKEv1 Error : Authentication failed
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: Phase I negotiation failed, error Authentication failed (neg 117e000)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback. ed efe028. status: Authentication failed
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Detach ed efe028 from P1 SA 5897396, slot 0.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Freeing exchange data from SA 12b0000, ED efe028 (2)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IPSec Rekey for SPI 0x0 failed
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback called for sa-cfg 217_175_53_26_company_STG-VPN local:111.111.111.111, remote:222.222.222.222 IKEv1 with status Authentication failed
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: FB; Calling v2 policy function ike_sa_delete
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKE SA delete called for p1 sa 5897396 (ref cnt 2) local:111.111.111.111, remote:222.222.222.222, IKEv1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 stop timer. timer duration 30, reason 1.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Freeing reference to P1 SA 5897396 to ref count 1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 reference count is not zero (1). Delaying deletion of SA
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing fallback negotiation 117e000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Freeing exchange data from SA 12b0000, ED efe028 (1)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 12b0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x12a8880, ref_cnt 1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x12a8960, ref_cnt 1
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 12b0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA 12b0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA 12b0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Notify call: exchange_data_free
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Freeing P2 Ed for sa-cfg 217_175_53_26_company_STG-VPN
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_unset_sa_cfg_p2_ed unset_sa_cfg_p2_ed, sa_cfg=217_175_53_26_company_STG-VPN
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 12b8200 from list for sa_cfg N/A
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Successfully freed exchange data from SA 12b0000
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing reference to IKE SA 12b0000 to ref count 0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_free: Notify call: ike_sa_free_ref
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Freeing reference to P1 SA 5897396 to ref count 0
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] No more references to IKE SA 5897396 and waiting for delete. Deleting IKE SA
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_p1_sa_destroy: p1 sa 5897396 (ref cnt 0), waiting_for_del 0x1206f80
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_peer_remove_p1sa_entry: Remove p1 sa 5897396 from peer entry 0x1279c00
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_delete_peer_entry: Requested for peer-entry 0x1279c00 deletion for local 111.111.111.111:500 and remote 222.222.222.222:500 reason:242
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_dist_table_entry_update : Dist table entry creation not needed

    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_peer_entry_patricia_delete:Peer entry 0x1279c00 deleted for local 111.111.111.111:500 and remote 222.222.222.222:500
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] Deleting p1 sa (5897396) node from IKE p1 SA P-tree
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] The tunnel id: 5897396 doesn't exist in P1 SA P-tree
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_uninit: Uninitialising transmit window 12b0180
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_flush: Transmit window 12b0180: Flushing.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_receive_window_uninit: Uninitialising receive window 12b0190
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Triggering negotiation for 217_175_53_26_company_STG-VPN config block
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_callback: lookup peer entry for gateway 217_175_53_26_company_STG-VPN, local_port=500, remote_port=500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_fetch_or_create_peer_entry: peer entry for gateway <217_175_53_26_company_STG-VPN> local 111.111.111.111:500 and remote 222.222.222.222:500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_lookup_peer_entry: Peer entry 0x0 Not FOUND for local 111.111.111.111:500 and remote 222.222.222.222:500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_create_peer_entry: Created peer entry 0x1279c00 for local 111.111.111.111:500 remote 222.222.222.222:500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_fetch_or_create_peer_entry: Create peer entry 0x1279c00 for local 111.111.111.111:500 remote 222.222.222.222:500. gw 217_175_53_26_company_STG-VPN, VR id 0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dist_table_entry_update : Dist table entry creation not needed

    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_callback: FOUND peer entry for gateway 217_175_53_26_company_STG-VPN
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_callback need p1 lifetime <30>
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Initiating new P1 SA for gateway 217_175_53_26_company_STG-VPN
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_allocate: Allocating IKE SA 222.222.222.222;500/4500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] chassis 0 fpc 0 pic 0 kmd-instance 0
    current tunnel id 5897396
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Allocated IKE SA index 5897397, ref cnt 0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] In iked_p1_sa_patricia_tree_fpc_pic_entry_add ADDED THE PATNODEike sa index 5897397
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 start timer. timer duration 30, reason 1.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_ike_sa_alloc_cb: Allocated IKE SA 12ae000 I60addd7f 37a39502 (222.222.222.222;500/4500)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_init: Transmit window 12ae180 initialised
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_receive_window_init: Receive window 12ae190 initialised
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_ike_sa_alloc_free_temp: Freeing temp context (222.222.222.222;500/4500)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data: Calling exchange_data_alloc
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_exchange_data_alloc: Successfully inserted pm_ed 12b8000 into list for sa_cfg N/A
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Exchange data allocated for IKE SA 5897397. VR 65535
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data: Successfully allocated exchange data for SA 12ae000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ipsec_create_sa: State = IKE_INIT_SA
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data_ike: Allocating IKE exchange data for SA 12ae000 ED efe028
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data_ike: Successfully allocated IKE exchange data for SA 12ae000 ED efe028
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data_ipsec: Allocating IPsec exchange data for SA 12ae000 ED efe028
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_allocate_exchange_data_ipsec: Successfully allocated IPsec exchange data for SA 12ae000 ED efe028
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ipsec_create_sa: Taking reference to IKE SA 12ae000 to ref count 1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_take_ref: Notify call: ike_sa_take_ref
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Taking reference to P1 SA 5897397 to ref count 1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_trigger_negotiation Set p2_ed in sa_cfg=217_175_53_26_company_STG-VPN
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_peer_insert_p1sa_entry: Insert p1 sa 5897397 in peer entry 0x1279c00
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_allocate: Allocated ts 0x1206f80, ref_cnt 1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_allocate: Allocated ts 0x12a8040, ref_cnt 1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_alloc: Taking reference to fallback negotiation 117e000 (now 1 references)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_alloc: Allocated fallback negotiation 117e000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_initiate_ipsec_sa: Taking reference to IKE SA 12ae000 to ref count 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_take_ref: Notify call: ike_sa_take_ref
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Taking reference to P1 SA 5897397 to ref count 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_initiate_ipsec_sa: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12ae000 ike_sa 0x0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Attach ed efe028 to P1 SA 5897397, slot 0. op handle efe318
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_reference_exchange_data: Taking reference to exchange data efe028 (to 2)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x1206f80, ref_cnt 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x12a8040, ref_cnt 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_start: Taking reference to fallback negotiation 117e000 (now 2 references)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_start: FSM_SET_NEXT:ikev2_fb_i_p1_negotiation_negotiate
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_i_p1_negotiation_start: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12ae000 ike_sa 0x0
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_local_address_request: FB; Calling v2 policy function get_local_address_list
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_id_request: FB; Calling v2 policy function id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_id_request_cb: Local id payload is IDa(type = dn (9), len = 83, value = 3051310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f6e 74692064
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 83, value = 3051310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk)
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_notify_request: FB; Calling v2 policy function notify_request
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_spd_notify_request Parse notification paylad in last received pkt
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Parsing notification payload for local:111.111.111.111, remote:222.222.222.222 IKEv1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_spd_notify_request: Sending Initial contact
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_psk_request: FB; Calling v2 policy function shared_key
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_pre_shared_key Start...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_pre_shared_key_cb: Found preshared key
    [Feb 25 17:31:59][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 25 17:31:59][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 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_ike_sa_request: FB; Calling v2 policy function fill_ike_sa
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Initiator's proposing IKE SA payload SA()
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_i_conf_request: FB; Calling v2 policy function conf_request
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_conf_request: enter
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_conf_request: ikev1 not use config-payload
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 1 references
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_negotiate: FSM_SET_NEXT:ikev2_fb_i_p1_negotiation_result
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_negotiate: Sending Initial Contact notification
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_negotiate: Taking reference to fallback negotiation 117e000 (now 2 references)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_connect: Start, remote_name = 222.222.222.222:500, xchg = 2, flags = 00090000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_allocate_half: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_allocate: Start, SA = { 60addd7f 37a39502 - 00000000 00000000 }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_init_isakmp_sa: Start, remote = 222.222.222.222:500, initiator = 1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 86400 (0x00015180), len = 4 (0x0004)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 3 (0x00000003), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_connect: SA = { 60addd7f 37a39502 - 00000000 00000000}, nego = -1
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = Start sa negotiation I (1)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[0] = ike_st_o_sa_proposal
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_sa_proposal: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_vids
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_request_vendor_ids: Request vendor ID's policy call entered, IKE SA 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_request_vendor_ids: FB; Calling v2 policy function vendor_id_request
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: Got a VID of length 16 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_request_vendor_id: Sending VID RFC 3706 (Dead Peer Detection)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: Got a VID of length 28 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_request_vendor_id: Sending VID NetScreen Technologies
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: Got a VID of length 8 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_request_vendor_id: Sending VID draft-ietf-ipsra-isakmp-xauth-06.txt
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: Got a VID of length 20 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_request_vendor_id: Sending VID Juniper Remote Access Head-End
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_vid_request_cb: No more VIDs
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_isakmp_vendor_ids: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[2] = ike_st_o_private
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 1 ike_sa 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: NAT traversal disabled by policy
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM SA I (3)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0x60addd7f 37a39502 - 00000000 00000000 } / 00000000, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 1 (0x0001), len = 2, value = 0005
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 4 (0x0004), len = 2, value = 0002
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 2 (0x0002), len = 2, value = 0002
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 11 (0x000b), len = 2, value = 0001
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode V: type = 12 (0x000c), len = 4 (0x0004), value = 00015180 ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 3 (0x0003), len = 2, value = 0003
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 64
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 20
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 32
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 12
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 24
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 180
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 180
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { 60addd7f 37a39502 - 00000000 00000000}, nego = -1, dst = 222.222.222.222:500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 108, on Interface: ge-0/0/3.0
    [Feb 25 17:31:59][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 ge-0/0/3.0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: [11fd800/0]
    ******** Processing received ************
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Not found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Failed to find IKEv1 SA for given spi
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_create_sa: [11fd800/0] No IKE SA for packet; requesting permission to create one.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_create_sa: FSM_SET_NEXT:ikev2_packet_st_connect_decision
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_rate_limit: Soft limit for p1 negotiation 100.Current active p1 negotiations 0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] New connection from 222.222.222.222:500 allowed
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_connect_decision: [11fd800/0] Pad allows connection
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Packet from 222.222.222.222:500, use_natt=0 data[0..108] = 60addd7f 37a39502 65b2346a 6bc6df3c ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, remote = 222.222.222.222:500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Not found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find_half: Start, SA = { 60addd7f 37a39502 - 00000000 00000000 }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find_half: Found half SA = { 60addd7f 37a39502 - 00000000 00000000 }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_get_sa: We are initiator, first response packet
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_upgrade: Start, SA = { 60addd7f 37a39502 - 00000000 00000000 } -> { ... - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c} / 00000000, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: first_payload_type:1.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:0.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_payload_sa: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_payload_sa: Found 1 proposals
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_payload_t: Start, # trans = 1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 1 (0x0001), value = 5 (0x0005), size = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 2 (0x0002), value = 2 (0x0002), size = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 4 (0x0004), value = 2 (0x0002), size = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 3 (0x0003), value = 3 (0x0003), size = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size B: type = 11 (0x000b), value = 1 (0x0001), size = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute_size: decode_size V: type = 12 (0x000c), len = 4 (0x0004), padding = 0, size = 8
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 1 (0x0001), value = 5 (0x0005), len = 2, used_bytes = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 2 (0x0002), value = 2 (0x0002), len = 2, used_bytes = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 4 (0x0004), value = 2 (0x0002), len = 2, used_bytes = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 3 (0x0003), value = 3 (0x0003), len = 2, used_bytes = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode B: type = 11 (0x000b), value = 1 (0x0001), len = 2, used_bytes = 4
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_decode_data_attribute: decode V: type = 12 (0x000c), len = 4 (0x0004), padding = 0, used_bytes = 8, value = 00015180 00000018 ...
    [Feb 25 17:31:59][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 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM SA I (3)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[0] = ike_st_i_sa_value
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_sa_value: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 86400 (0x00015180), len = 4 (0x0004)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 3 (0x00000003), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 3 (0x00000003), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 86400 (0x00015180), len = 4 (0x0004)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 1 (0x0001), value = 5 (0x00000005), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 2 (0x0002), value = 2 (0x00000002), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 4 (0x0004), value = 2 (0x00000002), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 3 (0x0003), value = 3 (0x00000003), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 11 (0x000b), value = 1 (0x00000001), len = 2 (0x0002)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_get_data_attribute_int: get_int: type = 12 (0x000c), value = 86400 (0x00015180), len = 4 (0x0004)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[1] = ike_st_i_cr
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cr: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[2] = ike_st_i_cert
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[3] = ike_st_i_status_n
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[4] = ike_st_i_vid
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..20] = 4048b7d5 6ebce885 ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 20, IKE SA 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[5] = ike_st_i_private
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_private: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[0] = ike_st_o_ke
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_ke: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group type dl-modp
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group size 1024
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_generate_sync: Requested DH group 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_generate: Generated DH keys using hardware for DH group 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_generate_async: DH Generate Secs [0] USecs [2905]
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_generate_async: Generated DH using hardware
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_nonce
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_nonce: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_nonce_data_len: Entered
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_isakmp_nonce_data_len: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[2] = ike_st_o_cr
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_get_certificate_authorities: Get certificate authorities policy call entered, IKE SA 12ae000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_get_certificate_authorities: FB; Calling v2 policy function get_cas
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Adding CAs: enc 4 len 55
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_get_cas_kid_cb: Got 1 CA's from the policy manager
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_get_cas: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[3] = ike_st_o_private
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 3 ike_sa 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: NAT traversal disabled by policy
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM KE I (5)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0x60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 132
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 20
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 60
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 240
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 240
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = -1, dst = 222.222.222.222:500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_destroy: [11fd800/0] Destructor
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_free: [11fd800/0] Freeing
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 397, on Interface: ge-0/0/3.0
    [Feb 25 17:31:59][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 ge-0/0/3.0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: [11fdc00/0]
    ******** Processing received ************
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Found IKEv1 SA
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: [11fdc00/deadbeee] Packet to existing v1 SA
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Packet from 222.222.222.222:500, use_natt=0 data[0..397] = 60addd7f 37a39502 65b2346a 6bc6df3c ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, remote = 222.222.222.222:500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c} / 00000000, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: first_payload_type:4.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:10.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:7.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:7.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:0.
    [Feb 25 17:31:59][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 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM KE I (5)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[0] = ike_st_i_nonce
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_nonce: Start, nonce[0..20] = fe1ad453 9fbd18e3 ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[1] = ike_st_i_ke
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_ke: Ke[0..128] = 1dbe9585 2de8c1cf ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[2] = ike_st_i_cr
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cr: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_certificate_request: Entered new certificate request policy call, IKE SA 12ae000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_certificate_request: FB; Calling v2 policy function new_certificate_request
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Received Peer CA Name Len 76 Enc 4 Total CAs 1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_certificate_request: Entered new certificate request policy call, IKE SA 12ae000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_certificate_request: FB; Calling v2 policy function new_certificate_request
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Received Peer CA Name Len 55 Enc 4 Total CAs 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[3] = ike_st_i_status_n
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[4] = ike_st_i_cert
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[5] = ike_st_i_vid
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = 12f5f28c 457168a9 ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..8] = 09002689 dfd6b712 ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 8, IKE SA 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = 90759377 6bc7df3c ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_vid: VID[0..16] = 1f07f70e aa6514d3 ...
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: Received vendor ID, length 16, IKE SA 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_isakmp_vendor_id: FB; Calling v2 policy function vendor_id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[6] = ike_st_i_private
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_i_private: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[0] = ike_st_o_id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_id: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_certs
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_certs_base: Start
    [Feb 25 17:31:59][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=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_private_key: Find find private key policy call entered, IKE SA 12ae000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_private_key: Taking reference to fallback negotiation 117e000 (now 3 references)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_find_private_key: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12ae000 ike_sa 0x0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Output function[1] = ike_st_o_certs asked retry later
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_process_packet: No output packet, returning
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_destroy: [11fdc00/deadbeee] Destructor
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_packet_free: [11fdc00/deadbeee] Freeing
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_request_certs: FSM_SET_NEXT:ikev2_fb_st_request_certs_result
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_request_certs: FB; Calling v2 policy function get_certificates
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM certificate callback invoked
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Requesting cert-chain for cert-id company_STG_cert
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Checking CAs: enc 4 len 55
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM trusted CA 1 found in device
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM cert-chain 1 for company_STG_cert found in local database
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM Adding cert: enc 4 len 998
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] IKED-PKI-PM: Cerificate found in local database
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_pm_validate_certificate_expiry: Certificate is not expired
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_x509_cert_free: Decreasing reference count of certificate 12b8800 to 0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates_cb: Found 1 certificates
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_private_key: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = -1
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM KE I (5)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[1] = ike_st_o_certs
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_certs_base: Start
    [Feb 25 17:31:59][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=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates: Request certificates policy call entered, IKE SA 12ae000
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_request_certificates: Returning cached certs
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_request_certificates: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[2] = ike_st_o_sig
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_sig: Start
    [Feb 25 17:31:59][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=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = No Id
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group type dl-modp
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group size 1024
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_get_group: DH Group 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] iked_dh_compute_synch: Requested DH group 2
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] Peer public key has length 128

    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: DH Compute Secs [0] USecs [2691]
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] juniper_dlp_diffie_hellman_final_async: Computed DH using hardware
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_calc_mac: Start, initiator = true, local = true
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Requested MIXED-MODE engine
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Real engine is OCTEON
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh2jsf_rsa_private_key_sign: Secs [0] USecs [14787] Avg Secs [0] Avg Usecs [14796]
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[3] = ike_st_o_status_n
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_status_n: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[4] = ike_st_o_private
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_private: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 5 ike_sa 12ae000 (neg 117e000)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase1_pending_natt_operations: Processing pending NAT-T operations
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: NAT traversal disabled by policy
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: FB; Calling v2 policy function private_payload_request
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_private_payload_out: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling output function[5] = ike_st_o_encrypt
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_st_o_encrypt: Marking encryption for packet
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_state_step: All done, new state = MM final I (7)
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0x60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 91
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 1003
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 260
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 28
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 1412
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Encrypting packet
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 1412
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = -1, dst = 222.222.222.222:500
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_remove_callback: Start, delete SA = { 38731d5e 5fd68e5a - b83fae92 7f7c2bb0}, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_delete_negotiation: Start, SA = { 38731d5e 5fd68e5a - b83fae92 7f7c2bb0}, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ssh_ike_tunnel_table_entry_delete: Deleting tunnel_id: 0 from IKE tunnel table
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_sa_delete: Start, SA = { 38731d5e 5fd68e5a - b83fae92 7f7c2bb0 }
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation_isakmp: Start, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation: Start, nego = -1
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:31:59][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 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_id_payload: Start, id type = 9
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_id_payload: Start, id type = 9
    [Feb 25 17:31:59][111.111.111.111 <-> 222.222.222.222] ike_free_sa: Start
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 1692, on Interface: ge-0/0/3.0
    [Feb 25 17:32:00][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 ge-0/0/3.0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: [11fe000/0]
    ******** Processing received ************
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_start: FSM_SET_NEXT:ikev2_packet_st_input_v1_get_sa
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Found IKEv1 SA
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: [11fe000/deadbeee] Packet to existing v1 SA
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_st_input_v1_get_sa: FSM_SET_NEXT:ikev2_packet_v1_start
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_v1_start: Passing IKE v1.0 packet to IKEv1 library
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Packet from 222.222.222.222:500, use_natt=0 data[0..1692] = 60addd7f 37a39502 65b2346a 6bc6df3c ...
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_get_sa: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c } / 00000000, remote = 222.222.222.222:500
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_sa_find: Found SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c }
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_udp_callback_common: Old negotiation message_id = 00000000, slot -1
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c} / 00000000, nego = -1
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: first_payload_type:5.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: Decrypting packet
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:6.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:9.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:13.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_decode_packet: next_payload_type:0.
    [Feb 25 17:32:00][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 25 17:32:00][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 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 2, auth = 0, fields = 0001 / 06c0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation R (2), xchg = 4, auth = 0, fields = 0017 / 06e0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 3, fields = 0000 / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 2, auth = 0, fields = 0000 / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 3, fields = 0000 / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 2, fields = 0000 / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = Start sa negotiation I (1), xchg = 4, auth = 4, fields = 0000 / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final R (8), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM done I (9), xchg = 2, auth = 0, fields = ffff / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM final I (12), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = AM done R (13), xchg = 4, auth = 0, fields = ffff / 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA I (3), xchg = 2, auth = 2, fields = 0001 / 06c0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM SA R (4), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE I (5), xchg = 2, auth = 2, fields = 0012 / 06c0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM KE R (6), xchg = 2, auth = 2, fields = 000c / 06c0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matching with state = MM final I (7), xchg = 2, auth = 2, fields = 000c / 0680
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Matched state = MM final I (7)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[0] = ike_st_i_encrypt
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_st_i_encrypt: Check that packet was encrypted succeeded
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[1] = ike_st_i_cert
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_st_i_cert: Start
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: Entered new certificate policy call, received a certificate of encoding 4 for IKE SA 12ae000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: FB; Calling v2 policy function new_certificate
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[2] = ike_st_i_id
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_st_i_id: Start
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Calling input function[3] = ike_st_i_sig
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_st_i_sig: Start, sig[0..256] = 78a42e70 986dae7b ...
    [Feb 25 17:32:00][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=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = der_asn1_dn(any
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_public_key: Find pre-shared key policy call entered, IKE SA 12ae000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_find_public_key: Taking reference to fallback negotiation 117e000 (now 3 references)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_set_thread_debug_info: ikev2_fb_find_public_key: set thread debug info - local 0x559f7a15 remote 0xd9af351aneg 0x117e000 neg->ike_sa 0x12ae000 ike_sa 0x0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_step: Input function[3] = ike_st_i_sig asked retry later
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_process_packet: No output packet, returning
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_destroy: [11fe000/deadbeee] Destructor
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_packet_free: [11fe000/deadbeee] Freeing
    [Feb 25 17:32:00][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 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_st_find_public_key: FB; Calling v2 policy function public_key
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_pm_id_validate: General IKE-ID is enabled, skipping ID validation
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_policy_public_key
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 83, value = 3051310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..82]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: Converting the IKEv2 payload ID IDa(type = dn (9), len = 82, value = 3050310b 30090603 55040613 02495431 0d300b06 0355040a 0c044141 4d533117 30150603 55040b0c 0e636f
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..81]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPNRGVAL.COMPANY.uk)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_policy_find_public_key_send_ipc
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKED-PKID-IPC 1 cert, len1<1285> 1st<30> last<0c>
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_pkid_send_packet
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_reference_exchange_data: Taking reference to exchange data efe028 (to 3)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 stop timer. timer duration 30, reason 1.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 start timer. timer duration 30, reason 1.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_public_key: Start
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { 60addd7f 37a39502 - 65b2346a 6bc6df3c [-1] / 0x00000000 } IP; No public key found
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 2 references
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_set_debug_gw_info: ssh_set_debug_gw_info: set gw debug info - local 111.111.111.111 remote 222.222.222.222
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_state_restart_packet: Start, restart packet SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = -1
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_negotiation_done_isakmp: Entered IKE error code Authentication failed (24), IKE SA 12ae000 (neg 117e000)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_ike_negotiation_cb: Connect IKE done callback, status Authentication failed (neg 117e000)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Fallback negotiation 117e000 has still 1 references
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { 60addd7f 37a39502 - 65b2346a 6bc6df3c [-1] / 0x00000000 } IP; Error = Authentication failed (24)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_alloc_negotiation: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_alloc_negotiation: Found slot 0, max 1
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: New informational negotiation message_id = aefc9f17 initialized using slot 0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: Created random message id = aefc9f17
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_init_info_exchange: No phase 1 done, use only N or D payload
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 12 (0x000c), len = 2, value = 0001
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode V: type = 6 (0x0006), len = 19 (0x0013), value = 4e6f2070 ...
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ike_encode_data_attribute: encode B: type = 8 (0x0008), len = 2, value = 0000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Start, SA = { 0x60addd7f 37a39502 - 65b2346a 6bc6df3c } / aefc9f17, nego = 0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 59
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Payload length = 87
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKEv1 packet S(<none>:500 -> 222.222.222.222:500): len= 87, mID=aefc9f17, HDR, N(AUTHENTICATION_FAILED)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_encode_packet: Final length = 87
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_send_notify: Sending notification to 222.222.222.222:500
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Start, send SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = 0, dst = 222.222.222.222:500
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_packet_free: Start
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_delete_negotiation: Start, SA = { 60addd7f 37a39502 - 65b2346a 6bc6df3c}, nego = 0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation_info: Start, nego = 0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ike_free_negotiation: Start, nego = 0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_phase_ii_sa_freed: Phase-II free Entered
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: Phase I negotiation result
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: FB; Calling v2 policy function ike_sa_done
    [Feb 25 17:32:00][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 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_delete_slot_table_entry Slot released msg_id<0> cookie<60addd7f37a39502>
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_tunnel_event_add_event_in_gw: Updating tunnel-event for gateway 217_175_53_26_company_STG-VPN with Internal error: Internal error occurred in PKID
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_tunnel_event_add_event_in_gw: tunnel-event Internal error: Internal error occurred in PKID count incremented to 40721
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKEv1 Error : Authentication failed
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: Phase I negotiation failed, error Authentication failed (neg 117e000)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback. ed efe028. status: Authentication failed
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Detach ed efe028 from P1 SA 5897397, slot 0.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Freeing exchange data from SA 12ae000, ED efe028 (2)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IPSec Rekey for SPI 0x0 failed
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IPSec SA done callback called for sa-cfg 217_175_53_26_company_STG-VPN local:111.111.111.111, remote:222.222.222.222 IKEv1 with status Authentication failed
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_i_p1_negotiation_result: FB; Calling v2 policy function ike_sa_delete
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] IKE SA delete called for p1 sa 5897397 (ref cnt 2) local:111.111.111.111, remote:222.222.222.222, IKEv1
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 stop timer. timer duration 30, reason 1.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Freeing reference to P1 SA 5897397 to ref count 1
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] P1 SA 5897397 reference count is not zero (1). Delaying deletion of SA
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fb_p1_negotiation_destructor: Freeing fallback negotiation context
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing fallback negotiation 117e000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Freeing exchange data from SA 12ae000, ED efe028 (1)
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ipsec: Freeing IPsec exchange data from SA 12ae000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x1206f80, ref_cnt 1
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ts_free: ts 0x12a8040, ref_cnt 1
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ipsec: Successfully freed IPsec exchange data from SA 12ae000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ike: Freeing IKE exchange data from SA 12ae000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data_ike: Successfully freed IKE exchange data from SA 12ae000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Notify call: exchange_data_free
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Freeing P2 Ed for sa-cfg 217_175_53_26_company_STG-VPN
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_unset_sa_cfg_p2_ed unset_sa_cfg_p2_ed, sa_cfg=217_175_53_26_company_STG-VPN
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_pm_ike_exchange_data_free: Successfully removed pm_ed 12b8000 from list for sa_cfg N/A
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_free_exchange_data: Successfully freed exchange data from SA 12ae000
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_fallback_negotiation_free: Freeing reference to IKE SA 12ae000 to ref count 0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ssh_ikev2_ike_sa_free: Notify call: ike_sa_free_ref
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Freeing reference to P1 SA 5897397 to ref count 0
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] No more references to IKE SA 5897397 and waiting for delete. Deleting IKE SA
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_pm_p1_sa_destroy: p1 sa 5897397 (ref cnt 0), waiting_for_del 0x12a8980
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_peer_remove_p1sa_entry: Remove p1 sa 5897397 from peer entry 0x1279c00
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_delete_peer_entry: Requested for peer-entry 0x1279c00 deletion for local 111.111.111.111:500 and remote 222.222.222.222:500 reason:242
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_dist_table_entry_update : Dist table entry creation not needed

    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] iked_peer_entry_patricia_delete:Peer entry 0x1279c00 deleted for local 111.111.111.111:500 and remote 222.222.222.222:500
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] Deleting p1 sa (5897397) node from IKE p1 SA P-tree
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] The tunnel id: 5897397 doesn't exist in P1 SA P-tree
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_uninit: Uninitialising transmit window 12ae180
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_transmit_window_flush: Transmit window 12ae180: Flushing.
    [Feb 25 17:32:00][111.111.111.111 <-> 222.222.222.222] ikev2_receive_window_uninit: Uninitialising receive window 12ae190

     

     



  • 8.  RE: Certificates based IPSEC VPN tunnel not coming up

     
    Posted 02-25-2020 14:23

    Please attach:

     

    > show security pki ca-certificate detail
    > request security pki local-certificate verify certificate-id Company_STG_cert
    # show security pki | display set

     

     At this point my theory is:

     

    +We see IKE message #5 is sent from the SRX:

     

    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_private_p_1_out: Phase-I output: packet_number 5 ike_sa 12b0000 (neg 117e000)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_send_packet: Inserting retransmission timer after 10.000000 seconds
    

     

    The the SRX receives IKE message #6:

     

    [SRX receives the packet]
    
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] *** Processing received packet from 222.222.222.222:500 to 111.111.111.111:0, VR 0, packet len: 1692, on Interface: ge-0/0/3.0
    
    [SRX triggers the processing of a new cert received]
    
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_new_certificate: Entered new certificate policy call, received a certificate of encoding 4 for IKE SA 12b0000
    
    [SRX found public key related to its local cert]
    
    [Feb 25 17:30:59][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=COMPANY, OU=description xxxxxx, CN=VPN000671.COMPANY.uk) -> 222.222.222.222:500, id = der_asn1_dn(any
    
    [SRX skips regular IKE-IDs validation as per the configuration ]
    
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pm_id_validate: General IKE-ID is enabled, skipping ID validation
    
    [We can see an IPC channel openining between the IKE daemon and the PKI daemon because the SRX tries to find the public key of its installed CA cert for validating the cert received from the ASA, but it is not able to find it]
    
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_fb_idv2_to_idv1: IKEv2 payload ID converted to IKEv1 payload ID der_asn1_dn(any:0,[0..81]=C=UK, O=COMPANY, OU=description xxxxxx, CN=VPNRGVAL.COMPANY.uk)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ssh_policy_find_public_key_send_ipc
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] IKED-PKID-IPC 1 cert, len1<1285> 1st<30> last<0c>
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] iked_pkid_send_packet
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ikev2_reference_exchange_data: Taking reference to exchange data efe028 (to 3)
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 stop timer. timer duration 30, reason 1.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] P1 SA 5897396 start timer. timer duration 30, reason 1.
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] ike_policy_reply_find_public_key: Start
    [Feb 25 17:30:59][111.111.111.111 <-> 222.222.222.222] 111.111.111.111:500 (Initiator) <-> 222.222.222.222:500 { d0c6518b fb9be03e - 2b62479e eccbda43 [-1] / 0x00000000 } IP; No public key found

     



  • 9.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 02-26-2020 03:03

    There you go:

    root@MANGIIA-STGVPN01> show security pki ca-certificate detail

     

    Spoiler
    root@MANGIIA-STGVPN01> show security pki ca-certificate detail
    Certificate identifier: Company_STG_CA
    Certificate version: 3
    Serial number: 00000001
    Issuer:
    Organization: Company, Country: UK, Common name: CA Company Test
    Subject:
    Organization: Company, Country: UK, Common name: CA Company Test
    Subject string:
    C=UK, O=Company, CN=CA Company Test
    Validity:
    Not before: 05-15-2013 16:10 UTC
    Not after: 05-15-2023 16:10 UTC
    Public key algorithm: rsaEncryption(2048 bits)
    30:82:01:0a:02:82:01:01:00:ce:5d:3d:ac:ee:67:35:b2:ad:30:49
    [PARTIALLY DELETED]
    Signature algorithm: sha1WithRSAEncryption
    Use for key: CRL signing, Certificate signing
    Fingerprint:
    [PARTIALLY DELETED]:3b:06:45:09:cd:8b:57:41:6c:67:7b (sha1)
    [PARTIALLY DELETED]:da:64:56:86:a5:76:d8:ca:2f (md5)

    root@MANGIIA-STGVPN01>request security pki local-certificate verify certificate-id Company_STG_cert

     

    Spoiler
    Local certificate Company_STG_cert verification success

    root@MANGIIA-STGVPN01# show security pki | display set 

    set security pki ca-profile Company_STG_CA ca-identity CompanyCA_STG_Identity
    set security pki ca-profile Company_STG_CA revocation-check disable

    Thanks a lot

     



  • 10.  RE: Certificates based IPSEC VPN tunnel not coming up

     
    Posted 02-26-2020 07:18

    Please run PKI traceoptions to gather further info:

     

    # set security pki traceoptions file PKI_TRACE

    # set security pki traceoptions flag all

    #commit   (wait for renegotiation of the tunnel)

    #run show log PKI_TRACE

     



  • 11.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 02-27-2020 03:01

    Unbelievable! Why "PKI, verify cert, cannot locate CA certificate"???

     

    Feb 27 11:28:06 pkid_conn_process_msg: PKId got IPC request from IKEd <1>
    Feb 27 11:28:06 Cert-Chain-Val> Find Public Key socket 15 request -169772772 length 1387
    Feb 27 11:28:06 Cert-Chain-Val> ID Type 9 Length 82 rc 90
    Feb 27 11:28:06 Cert-Chain-Val> Cert 0 ENC 4 Len 1285
    Feb 27 11:28:06 Cert-Chain-Val> 1 certificates found in request
    Feb 27 11:28:06 Cert-Chain-Val> Check for type <9> dn-len <82>
    Feb 27 11:28:06 Cert-Chain-Val> EE is the 0th cert
    0\x0v\x06\x03U\x04rt-Chain-Val> EE certificate found for id 0P1\x0v0    \x06\x03U\x04\x06\x13\x021
    19031317201\x170\x15\x06\x03U\x04\x0v\x0w\x0yDescription xxx1\x190\x17\x06\x03U\x04\x03\x0w\x10VPNRGVAL.COMPANY.UKCompany Certification Authority Test0\x1y\x17
    Feb 27 11:28:06 To verify EE cert: /C=UK/O=Company/OU=Description xxx/CN=VPNRGVAL.Company.uk
    Feb 27 11:28:06 Cert-Chain-Val> Building cert Chain
    Feb 27 11:28:06 Adding EE to the untrusted chain: /C=UK/O=Company/OU=Description xxx/CN=VPNRGVAL.Company.uk
    Feb 27 11:28:06 Cert-Chain-Val> No issuer found
    Feb 27 11:28:06 Cert-Chain-Val> 0 0 idx<0>, total<1>
    Feb 27 11:28:06 PKI, bad cert index <0>, total <1>
    Feb 27 11:28:06 Cert-Chain-Val> PKI, verify cert, cannot locate CA certificate
    Feb 27 11:28:06 ldapNotify_func: err_id<67190815>
    Feb 27 11:28:06 ldapIdleCleanup <203><88><43><05>
    Feb 27 11:28:06 pCert_no_buf: /C=UK/O=Company/OU=Description xxx/CN=VPNRGVAL.Company.uk
    Feb 27 11:28:06 pCert_with_buf: /C=UK/O=Company/OU=Description xxx/CN=VPNRGVAL.Company.uk
    Feb 27 11:28:06  p_cert_stack: /C=UK/O=Company/OU=Description xxx/CN=VPNRGVAL.Company.uk
    Feb 27 11:28:06 scep_http_release_all: releasing LDAP-STATE 58e900
    Feb 27 11:28:06 ldapIdleCleanup <203><88><43><05>
    Feb 27 11:28:06 ldapIdleCleanup: error released PLDAP_STATE
    Feb 27 11:28:06 pkid_ipc_send: Queued packet to IKED-Q, len 48
    Feb 27 11:28:06 pkid_ipc_write: Sending packet to IKED len 48, total packets sent 43238


  • 12.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 02-27-2020 03:43

    I've found something else I can't understand:

     

    root@MANGIITA-STGVPN01> request security pki verify-integrity-status 
    Local key-pair integrity verification failed: Looks Fine, but warning - could not find PKI file /var/db/certs/common/key-pair/Company_STG_cert.sha256
    

    So I deleted the CA and local certificates and created them again:

    root@MAIITA-STGVPN01> clear security pki ca-certificate
    root@MAIITA-STGVPN01> clear security pki local-certificate all
    root@MAIITA-STGVPN01> clear security pki key-pair
    
    root@MAIITA-STGVPN01> request security pki ca-certificate load ca-profile Company_STG_CA filename /var/tmp/Company_VPN_STG_root.cer 
    Do you want to load this CA certificate ? [yes,no] (no) yes 
    
    CA certificate for profile Company_STG_CA loaded successfully
    
    root@MAIITA-STGVPN01> request security pki local-certificate load certificate-id Company_STG_cert filename /var/tmp/Company_VPN_STG.cer key /var/tmp/Company_VPN_STG.key    
    Local certificate loaded successfully
    
    

    But still same message:

    root@MAIITA-STGVPN01> request security pki verify-integrity-status                 
    Local key-pair integrity verification failed: Looks Fine, but warning - could not find PKI file /var/db/certs/common/key-pair/Company_STG_cert.sha256

    I have checked that path an there is a single file, named Company_STG_cert.priv instead of .sha256 (????)



  • 13.  RE: Certificates based IPSEC VPN tunnel not coming up

     
    Posted 02-28-2020 08:17

    Can you get in contact with the ASA admin and confirm the local cert they are sending has as issuer "Organization: Company, Country: UK, Common name: CA Company Test"?

     



  • 14.  RE: Certificates based IPSEC VPN tunnel not coming up

     
    Posted 02-28-2020 08:32

    Also it looks like the command "request security pki verify-integrity-status" is only supported for SRX5K familiy:

     

    https://www.juniper.net/documentation/en_US/junos/topics/reference/command-summary/request-security-pki-verify-integrity-status.html

     

     



  • 15.  RE: Certificates based IPSEC VPN tunnel not coming up

     
    Posted 03-03-2020 08:10

    Hi Nolotil

     

    Were you able to get in contact with the ASA admin?

     



  • 16.  RE: Certificates based IPSEC VPN tunnel not coming up

     
    Posted 02-24-2020 20:47

    Hello,

     

    Seems like it is is not able to find the Public key for the local-certificate.

     

    [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

     

    Can you check if you followed this process to import the certificates?
    https://kb.juniper.net/InfoCenter/index?page=content&id=KB10176&actp=METADATA

     

    request security pki local-certificate verify certificate-id <certificate-id>
    request security pki ca-certificate verify ca-profile <ca-profile>

     

    > Perhaps you could try importing the certificate again.
    > Verify that the peer certificate is also valid and signed by the same CA imported on the firewall

     

    Regards,

     

    Nelumbo



  • 17.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 02-25-2020 03:44

    I followed that procedure to import the certificates indeed. 

     

    Don't you think the public key not found is the one that should be sent by the peer (its public key) , that for some reason is not sending? this is my main guess, but I don't know how to demonstrate it. 

     

    BR



  • 18.  RE: Certificates based IPSEC VPN tunnel not coming up

    Posted 06-01-2021 06:08
    Hi all.

    I have encountered some issues when uploading the certificate both local and root certificate.
    When I run the command for verification, it keep showing certificate not found in the database.
    But there is no issue when I load in the certificate according to the guide.
    Due to confidentiality, I was not able to provide details except using the public certificate loaded in for testing purposes.

    > request security pki ca-certificate verify ca-profile Entrust
    Error: CA Certificate for certificate /C=US/O=Entrust, Inc./OU=See www.entrust.net/legal-terms/OU=(c) 2012 Entrust, Inc. - for authorized use only/CN=Entrust Certification Authority - L1K not found in local database

    May I know what can be the cause?
    Thanks.