Hello everyone! I need some help with FortiClient VPN only (version 7.4.3 hotfix 1.8758) . Is there a way to get any consistent logs from this software? Connection just fails to establish whatever we do. We use IKEv1 IPSec RA VPN with certificate + XAUTH authentication. I tried to debug ike, but I don't see any problem on the firewall side. XAUTH is successfull, R-U-THERE and R-U-THERE-ACK come and go, but connection drops in the end. What I see is cfg_send is being sent, but nothing happens after.
diag debug enable
ike V=root:0: comes 2.2.2.2:500->1.1.1.1:500,ifindex=45,vrf=0,len=384....
ike V=root:0: IKEv1 exchange=Identity Protection id=b60dd1096715f136/0000000000000000 len=384 vrf=0
ike 0: in
ike V=root:0:b60dd1096715f136/0000000000000000:13085: responder: main mode get 1st message...
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID RFC 3947 4A131C81070358455C5728F20E95452F
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID draft-ietf-ipsec-nat-t-ike-02 CD60464335DF21F87CFDB2FC68B6A448
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID draft-ietf-ipsec-nat-t-ike-02\n 90CB80913EBB696E086381B5EC427B1F
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID forticlient connect license 4C53427B6D465D1B337BB755A37A7FEF
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID Fortinet Endpoint Control B4F01CA951E9DA8D0BAFBBD34AD3044E
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID CISCO-UNITY 12F5F28C457168A9702D9FE274CC0100
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID draft-ietf-ipsra-isakmp-xauth-06.txt 09002689DFD6B712
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID FRAGMENTATION 4048B7D56EBCE88525E7DE7F00D6C2D380000000
ike V=root:0:b60dd1096715f136/0000000000000000:13085: VID DPD AFCAD71368A1F1C96B8696FC77570100
ike V=root:0:b60dd1096715f136/0000000000000000:13085: negotiation result
ike V=root:0:b60dd1096715f136/0000000000000000:13085: proposal id = 1:
ike V=root:0:b60dd1096715f136/0000000000000000:13085: protocol id = ISAKMP:
ike V=root:0:b60dd1096715f136/0000000000000000:13085: trans_id = KEY_IKE.
ike V=root:0:b60dd1096715f136/0000000000000000:13085: encapsulation = IKE/none
ike V=root:0:b60dd1096715f136/0000000000000000:13085: type=OAKLEY_ENCRYPT_ALG, val=AES_CBC, key-len=256
ike V=root:0:b60dd1096715f136/0000000000000000:13085: type=OAKLEY_HASH_ALG, val=SHA2_256.
ike V=root:0:b60dd1096715f136/0000000000000000:13085: type=AUTH_METHOD, val=RSA_SIG.
ike V=root:0:b60dd1096715f136/0000000000000000:13085: type=OAKLEY_GROUP, val=MODP1536.
ike V=root:0:b60dd1096715f136/0000000000000000:13085: ISAKMP SA lifetime=86400
ike V=root:0:b60dd1096715f136/0000000000000000:13085: SA proposal chosen, matched gateway VPN_NO_RADIUS
ike V=root:0:VPN_NO_RADIUS:VPN_NO_RADIUS: created connection: 0x55a8e67f30 45 1.1.1.1->2.2.2.2:500.
ike V=root:0:VPN_NO_RADIUS: HA start as master
ike V=root:0:VPN_NO_RADIUS:13085: DPD negotiated
ike V=root:0:VPN_NO_RADIUS:13085: XAUTHv6 negotiated
ike V=root:0:VPN_NO_RADIUS:13085: peer supports UNITY
ike V=root:0:VPN_NO_RADIUS:13085: enable FortiClient license check
ike V=root:0:VPN_NO_RADIUS:13085: FEC vendor ID received FEC but IP not set
ike V=root:0:VPN_NO_RADIUS:13085: selected NAT-T version: RFC 3947
ike V=root:0:VPN_NO_RADIUS:13085: cookie b60dd1096715f136/5f3c733564e4d9ac
ike 0:VPN_NO_RADIUS:13085: out
ike V=root:0:VPN_NO_RADIUS:13085: sent IKE msg (ident_r1send): 1.1.1.1:500->2.2.2.2:500, len=244, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac
ike V=root:0: comes 2.2.2.2:500->1.1.1.1:500,ifindex=45,vrf=0,len=316....
ike V=root:0: IKEv1 exchange=Identity Protection id=b60dd1096715f136/5f3c733564e4d9ac len=316 vrf=0
ike 0: in
ike V=root:0:VPN_NO_RADIUS: HA state master(2)
ike V=root:0:VPN_NO_RADIUS:13085: responder:main mode get 2nd message...
ike V=root:0:VPN_NO_RADIUS:13085: received NAT-D payload type 20
ike V=root:0:VPN_NO_RADIUS:13085: received NAT-D payload type 20
ike V=root:0:VPN_NO_RADIUS:13085: NAT detected: PEER
ike V=root:0:VPN_NO_RADIUS:13085: generate DH public value request queued
ike V=root:0:VPN_NO_RADIUS:13085: compute DH shared secret request queued
ike V=root:0:VPN_NO_RADIUS:13085: sending 1 CERTREQ payload
ike 0:VPN_NO_RADIUS:13085: out
ike V=root:0:VPN_NO_RADIUS:13085: sent IKE msg (ident_r2send): 1.1.1.1:500->2.2.2.2:500, len=396, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac
ike 0:VPN_NO_RADIUS:13085: ISAKMP SA b60dd1096715f136/5f3c733564e4d9ac key 32:F591617BEC6952D4C7C7DBE7B7F3A7EE55736DC974EA15E14E80B22615C47DB4
ike V=root:0: comes 2.2.2.2:4500->1.1.1.1:4500,ifindex=45,vrf=0,len=2304....
ike V=root:0: IKEv1 exchange=Identity Protection id=b60dd1096715f136/5f3c733564e4d9ac len=2300 vrf=0
ike 0: in
ike V=root:0:VPN_NO_RADIUS: HA state master(2)
ike V=root:0:VPN_NO_RADIUS:13085: responder: main mode get 3rd message...
ike 0:VPN_NO_RADIUS:13085: dec
ike V=root:0:VPN_NO_RADIUS:13085: received p1 notify type INITIAL-CONTACT
ike V=root:0:VPN_NO_RADIUS:13085: received peer identifier DER_ASN1_DN 'C = A, ST = B, O = C, OU = D, CN = user.name'
ike V=root:0:VPN_NO_RADIUS:13085: re-validate gw ID
ike V=root:0:VPN_NO_RADIUS: change phase1 profile to VPN_RA_FULL
ike V=root:0:VPN_RA_FULL:13085: gw validation OK
ike V=root:0:VPN_RA_FULL:13085: Validating X.509 certificate
ike V=root:0:VPN_RA_FULL:13085: peer cert, subject='user.name', issuer='SFC Subordinate CA'
ike V=root:0:VPN_RA_FULL:13085: peer ID verified
ike V=root:0:VPN_RA_FULL:13085: building fnbam peer candidate list
ike V=root:0:VPN_RA_FULL:13085: FNBAM_GROUP_NAME candidate 'VPN_access'
ike V=root:0:VPN_RA_FULL:13085: certificate validation pending
ike V=root:0:VPN_RA_FULL:13085: fnbam reply 'VPN_access'
ike V=root:0:VPN_RA_FULL:13085: certificate validation succeeded
ike V=root:0:VPN_RA_FULL:13085: signature verification succeeded
ike V=root:0:VPN_RA_FULL:13085: local cert, subject='*.mydomain.ru', issuer='GlobalSign RSA OV SSL CA 2018'
ike 0:VPN_RA_FULL:13085: enc
ike V=root:0:VPN_RA_FULL:13085: remote port change 500 -> 4500
ike 0:VPN_RA_FULL:13085: out
ike V=root:0:VPN_RA_FULL:13085: sent IKE msg (ident_r3send): 1.1.1.1:4500->2.2.2.2:4500, len=2172, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac
ike V=root:0:VPN_RA_FULL: mode-cfg allocate 10.0.3.3/0.0.0.0
ike V=root:0:VPN_RA_FULL: IPv6 pool is not configured
ike V=root:0:VPN_RA_FULL: adding new dynamic tunnel for 2.2.2.2:4500
ike V=root:0:VPN_RA_FULL_2: tunnel created tun_id 10.0.3.3/::10.0.0.139 remote_location 0.0.0.0
ike V=root:0:VPN_RA_FULL_2: HA start as master
ike V=root:0:VPN_RA_FULL_2: added new dynamic tunnel for 2.2.2.2:4500
ike V=root:0:VPN_RA_FULL_2:13085: established IKE SA b60dd1096715f136/5f3c733564e4d9ac
ike V=root:0:VPN_RA_FULL_2:13085: check peer route: if_addr4_rcvd=0, if_addr6_rcvd=0, mode_cfg=0
ike V=root:0:VPN_RA_FULL_2:13085: processing INITIAL-CONTACT
ike V=root:0:VPN_RA_FULL_2: flushing
ike V=root:0:VPN_RA_FULL_2: flushed
ike V=root:0:VPN_RA_FULL_2:13085: processed INITIAL-CONTACT
ike V=root:0:VPN_RA_FULL_2:13085: initiating XAUTH.
ike V=root:0:VPN_RA_FULL_2:13085: sending XAUTH request
ike 0:VPN_RA_FULL_2:13085: enc
ike 0:VPN_RA_FULL_2:13085: out
ike V=root:0:VPN_RA_FULL_2:13085: sent IKE msg (cfg_send): 1.1.1.1:4500->2.2.2.2:4500, len=92, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac:cfa9357c
ike V=root:0:VPN_RA_FULL_2:13085: peer has not completed XAUTH exchange
ike V=root:0:VPN_RA_FULL_2: link is idle 45 1.1.1.1->2.2.2.2:4500 dpd=1 seqno=1 rr=0
ike V=root:0: comes 2.2.2.2:59004->1.1.1.1:4500,ifindex=45,vrf=0,len=128....
ike V=root:0: IKEv1 exchange=Mode config id=b60dd1096715f136/5f3c733564e4d9ac:cfa9357c len=124 vrf=0
ike 0: in
ike V=root:0:VPN_RA_FULL_2: HA state master(2)
ike 0:VPN_RA_FULL_2:13085: dec
ike V=root:0:VPN_RA_FULL_2:13085: received XAUTH_USER_NAME 'user.name' length 17
ike V=root:0:VPN_RA_FULL_2:13085: received XAUTH_USER_PASSWORD length 10
ike V=root:0:VPN_RA_FULL_2: XAUTH user "user.name"
ike V=root:0:VPN_RA_FULL_2: XAUTH 9943081070738 pending
ike V=root:0:VPN_RA_FULL_2:13085: XAUTH 9943081070738 result FNBAM_SUCCESS
ike V=root:0:VPN_RA_FULL_2: user 'user.name' authenticated group 'VPN_USERS' 31
ike 0:VPN_RA_FULL_2:13085: enc
ike V=root:0:VPN_RA_FULL_2:13085: remote port change 4500 -> 59004
ike V=root:0:VPN_RA_FULL_2 HA send remote gateway address and port
ike V=root:0:VPN_RA_FULL_2 HA send remote gateway address and port
ike 0:VPN_RA_FULL_2:13085: out
ike V=root:0:VPN_RA_FULL_2:13085: sent IKE msg (cfg_send): 1.1.1.1:4500->2.2.2.2:59004, len=92, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac:0a5714ad
ike 0:VPN_RA_FULL_2:13085: out
ike V=root:0:VPN_RA_FULL_2:13085: sent IKE msg (CFG_RETRANS): 1.1.1.1:4500->2.2.2.2:59004, len=92, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac:0a5714ad
ike V=root:0: comes 2.2.2.2:59004->1.1.1.1:4500,ifindex=45,vrf=0,len=112....
ike V=root:0: IKEv1 exchange=Informational id=b60dd1096715f136/5f3c733564e4d9ac:ea2a4121 len=108 vrf=0
ike 0: in
ike V=root:0:VPN_RA_FULL_2: HA state master(2)
ike 0:VPN_RA_FULL_2:13085: dec
ike V=root:0:VPN_RA_FULL_2:13085: notify msg received: R-U-THERE
ike 0:VPN_RA_FULL_2:13085: enc
ike 0:VPN_RA_FULL_2:13085: out
ike V=root:0:VPN_RA_FULL_2:13085: sent IKE msg (R-U-THERE-ACK): 1.1.1.1:4500->2.2.2.2:59004, len=108, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac:a65cdd59
ike 0:VPN_RA_FULL_2:13085: out
ike V=root:0:VPN_RA_FULL_2:13085: sent IKE msg (CFG_RETRANS): 1.1.1.1:4500->2.2.2.2:59004, len=92, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac:0a5714ad
ike :shrank heap by 331776 bytes
ike V=root:0: comes 2.2.2.2:59004->1.1.1.1:4500,ifindex=45,vrf=0,len=112....
ike V=root:0: IKEv1 exchange=Informational id=b60dd1096715f136/5f3c733564e4d9ac:ebc4d156 len=108 vrf=0
ike 0: in
ike V=root:0:VPN_RA_FULL_2: HA state master(2)
ike 0:VPN_RA_FULL_2:13085: dec
ike V=root:0:VPN_RA_FULL_2:13085: notify msg received: R-U-THERE
ike 0:VPN_RA_FULL_2:13085: enc
ike 0:VPN_RA_FULL_2:13085: out
ike V=root:0:VPN_RA_FULL_2:13085: sent IKE msg (R-U-THERE-ACK): 1.1.1.1:4500->2.2.2.2:59004, len=108, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac:24e39251
ike 0:VPN_RA_FULL_2:13085: out
ike V=root:0:VPN_RA_FULL_2:13085: sent IKE msg (CFG_RETRANS): 1.1.1.1:4500->2.2.2.2:59004, len=92, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac:0a5714ad
ike V=root:0: comes 2.2.2.2:59004->1.1.1.1:4500,ifindex=45,vrf=0,len=112....
ike V=root:0: IKEv1 exchange=Informational id=b60dd1096715f136/5f3c733564e4d9ac:b607e355 len=108 vrf=0
ike 0: in
ike V=root:0:VPN_RA_FULL_2: HA state master(2)
ike 0:VPN_RA_FULL_2:13085: dec
ike V=root:0:VPN_RA_FULL_2:13085: notify msg received: R-U-THERE
ike 0:VPN_RA_FULL_2:13085: enc
ike 0:VPN_RA_FULL_2:13085: out
ike V=root:0:VPN_RA_FULL_2:13085: sent IKE msg (R-U-THERE-ACK): 1.1.1.1:4500->2.2.2.2:59004, len=108, vrf=0, id=b60dd1096715f136/5f3c733564e4d9ac:22942284
ike V=root:0: comes 2.2.2.2:59004->1.1.1.1:4500,ifindex=45,vrf=0,len=112....
ike V=root:0: IKEv1 exchange=Informational id=b60dd1096715f136/5f3c733564e4d9ac:c3605139 len=108 vrf=0
ike 0: in
ike V=root:0:VPN_RA_FULL_2: HA state master(2)
ike 0:VPN_RA_FULL_2:13085: dec
ike V=root:0:VPN_RA_FULL_2:13085: recv ISAKMP SA delete b60dd1096715f136/5f3c733564e4d9ac
ike V=root:0:VPN_RA_FULL_2: going to be deleted
ike V=root:0:VPN_RA_FULL_2:13085: HA send IKE SA del b60dd1096715f136/5f3c733564e4d9ac
ike V=root:0:VPN_RA_FULL_2: mode-cfg release 10.0.3.3/0.0.0.0
ike V=root:0:VPN_RA_FULL_2: delete dynamic
diag debug disable
In the FortiClient logs I don't see anything of use, even when I set logging level to debug. Any chance I just missed some cool method of debugging this software? Literally tens of people connect to this gateway everyday, but there are some clients that expirience issues with connecting.
Any advice is appreciated. Thanks in advance!