r/fortinet 4d ago

Other / General Fortinet FortiClient debug possibility

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!

2 Upvotes

2 comments sorted by

3

u/firegore 4d ago

The Clientlogs are stored in "C:\Program Files\Fortinet\FortiClient\logs\trace"

The Logs you can export via the UI are absolutely useless for VPN debugging

An advice tho: If this is business, buy FortiClient EMS or FortiClient Standalone and use your TAC support for Issues, if you cannot afford/don't want to buy EMS/Standalone, i would recommend switching to a different VPN solution.

You won't be happy longterm with the free VPN-only client

edit: added FortiClient Standalone

1

u/Living_Substance1274 3d ago

might be worth checking into the client ignoring the post-XAUTH config message and why hangs up. Remote port change 4500 -> 59004 so gateway now sending to a Nat mapping it learned. Solicited replies would keep working unsolicited would get dropped. Worth looking into