Pozn.: Popis v článku vychází z FortiGate FG-300E s FortiOS verzí 6.2.8. Který je nakonfigurovaný jako FGCP cluster a využívá VDOM.

FortiClient navazování SSL VPN

Když se navazuje VPN tunel, tak probíhají různé kroky. Připojení ke vzdálenému serveru, ověření uživatele, vytvoření tunelu, konfigurace adres, směrování apod. Každému kroku by měla odpovídat nějaká část připojování (procento), bohužel jsem nenalezl žádný přehled, co se kdy děje.

Pokud dojde k běžnému problému, tak se zobrazí informace o chybě. Takže alespoň víme, že se něco děje. Ale když nastane dále popisovaný problém, tak se připojování zasekne a nic se neděje.

Například okolo 10 % se může zobrazit následující varování. Je to v případě, kdy není dostupná síťová konektivita na FortiGate (například nefunguje připojení k internetu). Stejná chyba se zobrazuje při pozdějších problémech, ale zde není na konci číslo chyby.

Unable to establish the VPN connection. The VPN server may be unreachable.

Okolo 40 % může být problém, pokud používáme počítačový certifikát pro ověření. I když je certifikát vybraný, tak se připojení nedaří. Problém je, že není v konfiguraci povoleno použití počítačových certifikátů allow_standard_user_use_system_cert, více FortiGate autentizace certifikátem do SSL VPN.

The server you want to connect to requests identification, please choose a certificate and try again. (-5)

Okolo 48 % to může být informace níže. Chyba je docela jasná, bylo zadáno špatné jméno nebo heslo.

Credential or SSLVPN configuration is wrong. (-7200)

Mám uloženu i trochu jinou chybu, která se také zobrazovala při špatném hesle (možná ve starší verzi FortiClienta).

Unable to logon to the server. Your user name or password may not be configured properly for this connection. (-12)

Asi nejrozšířenější chybové hlášení obsahuje dost málo informací a zobrazuje se při různých problémech. Vyskytuje se okolo 95 % (ale může být i jindy) a vypadá následně.

Unable to establish the VPN connection. The VPN server may be unreachable. (-14)

Důležité je číslo na konci v závorce, které asi specifikuje, o jakou chybu jde. Ale nepovedlo se mi nalézt žádné informace, co čísla znamenají. U Fortinetu jsem nalezl pár článků, ale moc nepomáhají.

• Technical Tip: Unable to establish the VPN connection. The VPN server may be unreachable (-30).
• Technical Tip: Error 'The VPN server may be unreachable (-14)' for FortiClient
• Technical Tip: Unable to establish the vpn connection. The vpn server is unreachable (-14)
• Technical Tip: Unable to establish the SSL VPN connection on Windows server

Setkal jsem se s chybou -8, -14 a -20199. Všude šlo o nějaký dočasný problém, asi na lince do internetu, u klienta a když se po chvíli zopakovalo připojení, tak spojení proběhlo.

Zjistil jsem, že chyba -8 se zobrazuje, pokud je dočasně zablokováno naše připojení (IP adresa). Je to ochrana proti útoku, když se několikrát nepovede přihlášení (nejčastěji chybným heslem). Pokud se připojíme na webové rozhraní, tak dostaneme jasnější chybu.

Too many bad login attempts. Please try again in a few minutes.

Na novějších verzích macOS (možná spolu s novějším FortiClient) se může objevit problém, že se připojování zastaví, aniž by začalo ukazovat procenta. Zobrazuje se

Status: Connecting

Pro fungování VPN, je po instalaci FortiClient, potřeba explicitně povolit síťová rozšíření. Více popisuje FortiClient 7.0.1 - (macOS) Release Notes.

• otevřeme System Preferences > Security & Privacy
• na záložce General se v dolní části nachází informace, že systémový SW určité aplikace byl zablokován, je zde možnost povolit Allow

Vypadá to, že název aplikace se může zobrazovat různě FortiTray, FortiClientNetwork, možná i jinak. Při vypsání systemextensionsctl list by zde měl být vpnprovider a FortiClientPacketFilter.

FortiClient připojení skončí na 98 %

Asi nejčastěji popisovaný problém v diskusích je, když se (občas) nedaří připojení do SSL VPN na FortiGate a zasekne se na 98 %. V praxi se nám problém projevoval u nemalého procenta uživatelů. U některých velmi často, u některých párkrát týdně. Vyzkoušeli jsme různé verze FortiClient 6.0.x, 6.2.x, 6.4.x a postupně upgrady FortiOS v řadě 6.2.x.

Průběh je takový, že se začne navazovat VPN spojení, procenta v klientovi postupně naskakují, ale když se dostanou na 98 %, tak se zde zastaví. V některých případech se po určité době (možná minuta) znovu zpřístupní přihlašovací dialog (vymaže se heslo a můžeme znovu zadat). Častěji zůstane stát a ani po několika minutách se nic neděje. Takže musíme ukončit tlačítkem Disconnect. Uživatel musí provést několik pokusů o přihlášení, až jedno projde. Většinou je nutné mezi pokusy ukončit FortiClient nebo restartovat počítač.

Je zde ještě související problém. Pokud se připojení zastaví na 98 procentech a uživatel jej ukončí kliknutím na tlačítko Disconnect. Tak se velmi často stane, že se sice zpřístupní přihlašovací dialog, ale když se zkusíme znovu přihlásit, tak přihlašování vůbec neprobíhá (po krátké době se vrátí na přihlašovací dialog). Musí se úplně ukončit FortiClient, na ikoně aplikace v hlavním panelu (vedle hodin) volba Shutdown FortiClient, a znovu nastartovat.

Řešení vypnutím DTLS protokolu

Po dlouhé době, a mnoho pokusech i debugování, se ukázalo, že problém v našem prostředí způsobuje využití DTLS místo TLS. Defaultně není DTLS ve FortiClient zapnuté, ale Fortinet na řadě míst jeho využití doporučuje.

Vypnutí DTLS v nastavení FortiClient

• odemkneme nastavení - klikneme na zámek vpravo nahoře
• přepneme se do nastavení (ozubené kolečko)
• v části VPN Options odškrtneme volbu Preferred DTLS Tunnel

Vypnutí DTLS na FortiGate

Pokud vypneme DTLS v nastavení FortiClienta, tak se mohou někteří uživatelé připojovat pomocí TLS a jiní pomocí DTLS. Druhá možnost je zakázat DTLS v konfiguraci FortiGate  (defaultně je povoleno), pak se budou všichni připojovat pomocí TLS (nezáleží na nastavení FortiClient).

config vpn ssl settings
    set dtls-tunnel disable
end

Pozn.: Změna nastavení neukončí navázané VPN tunely. Způsobí, že nově navazovaná spojení budou přes TLS.

Datagram Transport Layer Security (DTLS)

Protokol Datagram Transport Layer Security (DTLS) je založen na TLS (Transport Layer Security) protokolu (poskytuje stejnou bezpečnost), ale v transportní vrstvě využívá UDP (User Datagram Protocol). Díky tomu je efektivnější, výkonnější a rychlejší. Ale aplikace musí řešit spolehlivost, tedy ztrátu paketů, duplicitu, doručení mimo pořadí nebo velká data.

Fortinet doporučuje (stejně jako řada jiných výrobců) využití DTLS pro větší propustnost, a protože nemá problémy s opakovaným přenosem (TCP meltdown problem). Třeba v Technical Note: Using DTLS to improve SSL VPN performance

Standardně se pro SSL VPN využívá TLS (Transport Layer Security), které běží nad TCP (Transmission Control Protocol). Uvnitř tunelu většinou běží také TCP, takže se označuje jako TCP-in-TCP. Protokol TCP využívá spojení (connection / session) a garantuje spolehlivé doručování.

Podle testů, nemají uživatelé při využití TLS, žádné problémy při připojení. Při využití DTLS má část uživatelů problém s navázáním tunelu (a také jeho ukončením, jak je vidět při debugu). Pokud je tunel navázán, tak patrně vše funguje dobře.

Problémy při DTLS patrně nastávají, když dojde ke ztrátě nějakých datagramů nebo jejich špatnému doručení. To se může stát na méně kvalitních linkách do internetu, zarušených WiFi sítích nebo (podle určitých pokusů) může být problém na ovladači síťové karty. Problémy by měla řešit aplikace, a jelikož při navázaném DTLS tunelu vše funguje, tak asi řeší. Patrně tedy není dobře ošetřeno pouze navazování a ukončování tunelu.

Nutno poznamenat, že uživatelé, kteří měli problém s připojením pomocí FortiClient, se bez problémů připojili ke staré VPN na Cisco ASA pomocí Cisco AnyConnect Secure Mobility Client, kde se také využívá DTLS.

Jiné pokusy o řešení

Problém se zasekáváním připojení FortiClient na 98 % je na internetu hodně probírán. Obecně byl častý u starých verzí a měl být opraven ve FortiClient 5.6.0 díky novému ovladači (SSL VPN driver). Na starších verzích se často řešila oprava ovladače, například pomocí Wan miniport repair tool.

Ve FortiOS 6.2.4 Release Notes je uvedeno, že byl opraven problém Bug ID 596757 s popisem SSL VPN connection stuck at 95% or 98%.

Fortinet na různých místech uvádí, jako řešení problému zaseknutí na 98 %, zvětšit časový limit přihlášení (login timeout). To mi nijak nepomohlo. Troubleshooting Tip: Common SSL VPN

Vypadalo to, že u některých lidí pomohlo, když se na síťovém adaptéru (kterým je klient připojen do sítě) vypnulo IPv6. Ale rozhodně to nepomohlo všem. Ve chvíli, kdy dotčení uživatelé vypnuli DTLS, tak mohli IPv6 zapnout a vše fungovalo. Vypnutí IPv6 zmiňuje i řada diskusí.

V průběhu času to vypadalo, že se u lidí situace měnila po upgradu FortiClienta nebo FortiGate. Ale některým se problém opět vracel. Také některým lidem pomohlo, když se připojili kabelem místo domácí WiFi.

Jedno z diskusních vláken, které obsahuje hodně možných řešení, je VPN stuck at status 98%. Například tu uvádí, že někomu se problém vyřešil zapnutím DTLS.

Pokud se uživateli zastaví připojování na 98 %, tak v GUI FortiGate (Monitor) je vidět, jako korektně navázaný a s přidělenou adresou. U lidí, kde zlobí připojení, také nefunguje odpojení. Když použijí Disconnect ve FortiClient, tak se napíše, že došlo ke korektnímu odpojení. Ale na FortiGate je klientská session stále vidět. Session zmizí až po nějakém timeoutu patrně 100 vteřin.

Debug SSL VPN připojení

Debug na FortiGate

• SSL VPN troubleshooting
• Troubleshooting Tip: SSL VPN Troubleshooting
• Technical Tip: SSL VPN connectivity issue with Iphone

Pokud chceme vidět také průběh autentizace, tak můžeme zapnout debug režim pro Remote user authentication (fnbamd je Fortinet non-blocking authentication daemon). Ten zobrazuje zprávy ze všech metod vzdáleného ověření. Přidá nám to do výstupu mnoho zpráv (takže bych použil, pouze pokud je třeba).

diagnose debug application fnbamd -1 

Zapnutí debug režimu pro SSL VPN včetně zobrazení času u jednotlivých záznamů.

diagnose debug application sslvpn -1
diagnose debug console timestamp enable
diagnose debug enable

Pro vypnutí debug režimu můžeme použít

diagnose debug disable
diagnose debug reset

Událostí, které se zalogují při každém přihlášení nebo odhlášení uživatele do SSL VPN, je opravdu spousta. Patrně se zkouší různá připojení (různé parametry navázání šifrování) a pak se provádí velké množství kontrol pro určení skupin a autentizačních metod. Podmínky, zda je vyžadována autentizace certifikátem, dvou faktorové ověření apod. Nakonec, když je již přidělena i IP adresa z VPN rozsahu, tak to vypadá, že se naváže nové připojení, které se již dokončí. V případě DTLS to vypadá, že se nejprve naváže TLS spojení a až poté DTLS.

Porovnal jsem řadu logů, kdy bylo použito DTLS, a někde připojení prošlo korektně a někde se zaseklo na 98 %. Celý průběh je shodný a liší se až na úplném konci.

Korektní průběh

[23236:FW:1265]sslvpn_send_ctrl_msg:903 0x7fc8e9192600 message: svrhello ok 193.1.1.10
[23236:FW:0]RCV: LCP Configure_Request id(1) len(14) [Maximum_Received_Unit 1354] [Magic_Number 453A022A] 
[23236:FW:0]SND: LCP Configure_Request id(1) len(10) [Magic_Number 01084CD8] 
[23236:FW:0]lcp_reqci: returning CONFACK.
[23236:FW:0]SND: LCP Configure_Ack id(1) len(14) [Maximum_Received_Unit 1354] [Magic_Number 453A022A] 
[23236:FW:0]RCV: LCP Configure_Ack id(1) len(10) [Magic_Number 01084CD8] 
[23236:FW:0]lcp_up: with mtu 1354
[23236:FW:0]SND: IPCP Configure_Request id(1) [IP_Address 192.168.0.1] 
[23236:FW:0]RCV: IPCP Configure_Request id(0) [IP_Address 0.0.0.0] [Primary_DNS_IP_Address 0.0.0.0]
 [Secondary_DNS_IP_Address 0.0.0.0] 
[23236:FW:0]ipcp: returning Configure-NAK
[23236:FW:0]SND: IPCP Configure_Nak id(0) [IP_Address 10.254.0.10] [Primary_DNS_IP_Address 10.0.0.50]
 [Secondary_DNS_IP_Address 10.0.0.40] 
[23236:FW:0]RCV: IPCP Configure_Ack id(1) [IP_Address 192.168.0.1] 
[23236:FW:0]RCV: IPCP Configure_Request id(1) [IP_Address 10.254.0.10] [Primary_DNS_IP_Address 10.0.0.50]
 [Secondary_DNS_IP_Address 10.0.0.40] 
[23236:FW:0]ipcp: returning Configure-ACK
[23236:FW:0]SND: IPCP Configure_Ack id(1) [IP_Address 10.254.0.10] [Primary_DNS_IP_Address 10.0.0.50]
 [Secondary_DNS_IP_Address 10.0.0.40] 
[23236:FW:0]ipcp: up ppp:0x7fc8e715c000 caller:0x7fc8e9192600 tun:44
[23236:FW:0]Cannot determine ethernet address for proxy ARP
[23236:FW:0]local  IP address 192.168.0.1
[23236:FW:0]remote IP address 10.254.0.10
[23236:FW:1265]sslvpn_ppp_associate_fd_to_ipaddr:281 associate 10.254.0.10 to tun (ssl.FW:44)

Zaseknutí na 98 %

[265:FW:3fa5]sslvpn_send_ctrl_msg:903 0x7fc8e6defc00 message: svrhello ok 193.1.1.10
[265:FW:0]RCV: LCP Configure_Request id(1) len(14) [Maximum_Received_Unit 1354] [Magic_Number 3C4CC01B] 
[265:FW:0]SND: LCP Configure_Request id(1) len(10) [Magic_Number 53DCFE56] 
[265:FW:0]lcp_reqci: returning CONFACK.
[265:FW:0]SND: LCP Configure_Ack id(1) len(14) [Maximum_Received_Unit 1354] [Magic_Number 3C4CC01B] 
[265:FW:0]sslvpn_ppp_receive: Received non-LCP packet when LCP not open.
[265:FW:0]RCV: LCP Configure_Ack id(1) len(10) [Magic_Number 53DCFE56] 
[265:FW:0]lcp_up: with mtu 1354
[265:FW:0]SND: IPCP Configure_Request id(1) [IP_Address 192.168.0.1] 
[265:FW:0]RCV: IPCP Configure_Ack id(1) [IP_Address 192.168.0.1]

U lidí, kterým zlobí připojení, tak velmi často nefunguje odpojení. Na FortiGate patrně nedorazí korektní komunikace a session se ukončí na timeout.

[265:FW:3b8d]sslvpn_dtls_timeout_check:326 no heartbeat received for 100 seconds.
[265:FW:0]ipcp: down ppp:0x7fc8e70e5000 caller:0x7fc8e6df2600 tun:86
[265:FW:3b8d]sslvpn_ppp_deassociate_fd_to_ipaddr:318 deassociate 10.254.0.10 to tun (ssl.FW:86)
[265:FW:3b8d]session removed s: 0x7fc8e6df2600 (FW)
[265:FW:3b8d]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN Consultant],authserver=[PDC],
 portal=[VPN-Consultant],host=[193.1.1.10],realm=[company],idx=103,auth=2,sid=71fdf9c9,login=1623321538,access=1623321538,
 saml_logout_url=no
[265:FW:0]sslvpn_internal_remove_one_web_session:2882 web session (FW:bouska:G VPN Consultant:193.1.1.10 1) removed for
 Lost the connection
[265:FW:0]sslvpn_internal_remove_apsession_by_idx:2560 free app session, idx[103]
[265:FW:3b8d]Destroy sconn 0x7fc8e6df2600, connSize=38. (FW)

Logy (debug) ve FortiClient

Ve FortiClient v nastavení (ozubené kolečko) můžeme exportovat logy do souboru. Můžeme také zvýšit úroveň logování (Log Level) z výchozího Information na nejvyšší Debug (nejprve musíme odemknout nastavení). Ale v aktuálně řešeném problému se nám žádné nové zprávy v logu neobjeví.

V logu je jediná informace, že došlo k timeoutu, tedy klient nedostal zprávu z FortiGate.

6/9/2021 8:41:52 AM     info  sslvpn      FortiSslvpn: 2016: fortissl_connect: device=ftvnic
6/9/2021 8:41:52 AM     info  sslvpn      FortiSslvpn: 17444: PreferDtlsTunnel=1
6/9/2021 8:41:57 AM     error sslvpn      FortiSslvpn: 17444: error: SslBlockingRead() timeout. (tm=5000, n=-1)
6/9/2021 8:41:57 AM     error sslvpn      FortiSslvpn: 17444: error: ssl_connect:1
6/9/2021 8:41:57 AM     error sslvpn      FortiSslvpn: 17444: tunnel_to_fgt error
6/9/2021 8:42:00 AM     error sslvpn      FortiSslvpn: 21264: error: ras_loop(), waitResult=1.

Příklad debug výstupu kompletního připojení do SSL VPN na FortiGate

Připojení z veřejné IP adresy X.X.X.X uživatel bouska, dostane přidělenu adresu z VPN rozsahu Y.Y.Y.Y. Připojení je pomocí TLS (ve FortiClient vypnuto DTLS).

[263:FW:3f08]allocSSLConn:295 sconn 0x7fc8e6c46200 (3:FW)
[263:FW:3f08]SSL state:before SSL initialization (X.X.X.X)
[263:FW:3f08]SSL state:before SSL initialization (X.X.X.X)
[263:FW:3f08]got SNI server name: vpn.firma.cz realm noncompany
[263:FW:3f08]client cert requirement: no
[263:FW:3f08]SSL state:SSLv3/TLS read client hello (X.X.X.X)
[263:FW:3f08]SSL state:SSLv3/TLS write server hello (X.X.X.X)
[263:FW:3f08]SSL state:SSLv3/TLS write change cipher spec (X.X.X.X)
[263:FW:3f08]SSL state:SSLv3/TLS write finished (X.X.X.X)
[263:FW:3f08]SSL state:SSLv3/TLS write finished:system lib(X.X.X.X)
[263:FW:3f08]SSL state:SSLv3/TLS write finished (X.X.X.X)
[263:FW:3f08]SSL state:SSLv3/TLS read change cipher spec (X.X.X.X)
[263:FW:3f08]SSL state:SSLv3/TLS read finished (X.X.X.X)
[263:FW:3f08]SSL state:SSL negotiation finished successfully (X.X.X.X)
[263:FW:3f08]SSL established: TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384
[263:FW:3f08]req: /remote/info
[263:FW:3f08]req: /remote/login
[263:FW:3f08]rmt_web_auth_info_parser_common:452 no session id in auth info
[263:FW:3f08]rmt_web_get_access_cache:787 invalid cache, ret=4103
[263:FW:3f08]User Agent: FortiSSLVPN (Windows NT; SV1 [SV{v=02.01; f=07;}])
[263:FW:3f08]get_cust_page:125 saml_info 0
[263:FW:3f08]req: /remote/logincheck
[263:FW:3f08]rmt_web_auth_info_parser_common:452 no session id in auth info
[263:FW:3f08]rmt_web_access_check:706 access failed, uri=[/remote/logincheck],ret=4103,
[263:FW:3f08]User Agent: FortiSSLVPN (Windows NT; SV1 [SV{v=02.01; f=07;}])
[263:FW:3f08]sslvpn_auth_check_usrgroup:2179 forming user/group list from policy.
[263:FW:3f08]sslvpn_auth_check_usrgroup:2267 got user (0) group (10:0).
[263:FW:3f08]sslvpn_validate_user_group_list:1693 validating with SSL VPN authentication rules (11), realm (noncompany).
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 1 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 1 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1765 checking rule 1 source intf.
[263:FW:3f08]sslvpn_validate_user_group_list:1804 checking rule 1 vd source intf.
[263:FW:3f08]sslvpn_validate_user_group_list:1920 rule 1 done, got user (0:0) group (1:0) peer group (0).
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 2 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 2 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1765 checking rule 2 source intf.
[263:FW:3f08]sslvpn_validate_user_group_list:1920 rule 2 done, got user (0:0) group (2:0) peer group (0).
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 3 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 3 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 4 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 4 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1765 checking rule 4 source intf.
[263:FW:3f08]sslvpn_validate_user_group_list:1920 rule 4 done, got user (0:0) group (3:0) peer group (0).
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 5 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 5 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 6 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 6 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1765 checking rule 6 source intf.
[263:FW:3f08]sslvpn_validate_user_group_list:1920 rule 6 done, got user (0:0) group (4:0) peer group (0).
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 7 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 7 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 8 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 8 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 9 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 9 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1765 checking rule 9 source intf.
[263:FW:3f08]sslvpn_validate_user_group_list:1920 rule 9 done, got user (0:0) group (5:0) peer group (0).
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 10 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 10 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1765 checking rule 10 source intf.
[263:FW:3f08]sslvpn_validate_user_group_list:1920 rule 10 done, got user (0:0) group (6:0) peer group (0).
[263:FW:3f08]sslvpn_validate_user_group_list:1746 checking rule 11 cipher.
[263:FW:3f08]sslvpn_validate_user_group_list:1754 checking rule 11 realm.
[263:FW:3f08]sslvpn_validate_user_group_list:1765 checking rule 11 source intf.
[263:FW:3f08]sslvpn_validate_user_group_list:1920 rule 11 done, got user (0:0) group (7:0) peer group (0).
[263:FW:3f08]sslvpn_validate_user_group_list:2079 got user (0:0), group (7:0) peer group (0).
[263:FW:3f08]two factor check for bouska: off
[263:FW:3f08]sslvpn_authenticate_user:174 authenticate user: [bouska]
[263:FW:3f08]sslvpn_authenticate_user:181 create fam state
[263:FW:3f08][fam_auth_send_req_internal:425] Groups sent to FNBAM:
[263:FW:3f08]group_desc[0].grpname = G VPN 7 
[263:FW:3f08]group_desc[1].grpname = G VPN 6 
[263:FW:3f08]group_desc[2].grpname = G VPN 5 
[263:FW:3f08]group_desc[3].grpname = G VPN 4 
[263:FW:3f08]group_desc[4].grpname = G VPN 3 
[263:FW:3f08]group_desc[5].grpname = G VPN 2 
[263:FW:3f08]group_desc[6].grpname = G VPN 1 
[263:FW:3f08][fam_auth_send_req_internal:436] FNBAM opt = 0X421
[263:FW:3f08]fam_auth_send_req_internal:502 fnbam_auth return: 4
[263:FW:3f08]fam_auth_send_req:923 task finished with 4
[263:FW:3f08]fam_auth_proc_resp:1229 fnbam_auth_update_result return: 0
[263:FW:3f08][fam_auth_proc_resp:1305] Authenticated groups (1) by FNBAM:
[263:FW:3f08]Received: auth_rsp_data.grp_list[0] = 3 
[263:FW:3f08]Validated: auth_rsp_data.grp_list[0] = G VPN 1 
[263:FW:3f08]Auth successful for user bouska in group G VPN 1
[263:FW:3f08]fam_do_cb:657 fnbamd return auth success.
[263:FW:3f08]SSL VPN login matched rule (1).
[263:FW:3f08]User Agent: FortiSSLVPN (Windows NT; SV1 [SV{v=02.01; f=07;}])
[263:FW:3f08]rmt_web_session_create:829 create web session, idx[8]
[263:FW:3f08]login_succeeded:526 redirect to hostcheck
[263:FW:3f08]User Agent: FortiSSLVPN (Windows NT; SV1 [SV{v=02.01; f=07;}])
[263:FW:3f08]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1]
 ,host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=no
[263:FW:3f08]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1],
 host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=no
[263:FW:3f08]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1],
 host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=no
[263:FW:3f08]req: /remote/fortisslvpn
[263:FW:3f08]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1],
 host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=yes
[263:FW:3f08]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1],
 host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=no
[263:FW:3f08]User Agent: FortiSSLVPN (Windows NT; SV1 [SV{v=02.01; f=07;}])
[263:FW:3f08]req: /remote/fortisslvpn_xml
[263:FW:3f08]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1],
 host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=yes
[263:FW:3f08]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1],
 host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=no
[263:FW:3f08]sslvpn_reserve_dynip:1156 tunnel vd[FW] ip[Y.Y.Y.Y] app session idx[8]
[23236:FW:12d6]allocSSLConn:295 sconn 0x7fc8e70e7500 (3:FW)
[23236:FW:12d6]SSL state:before SSL initialization (X.X.X.X)
[23236:FW:12d6]SSL state:before SSL initialization (X.X.X.X)
[23236:FW:12d6]got SNI server name: vpn.firma.cz realm noncompany
[23236:FW:12d6]client cert requirement: no
[23236:FW:12d6]SSL state:SSLv3/TLS read client hello (X.X.X.X)
[23236:FW:12d6]SSL state:SSLv3/TLS write server hello (X.X.X.X)
[23236:FW:12d6]SSL state:SSLv3/TLS write change cipher spec (X.X.X.X)
[23236:FW:12d6]SSL state:TLSv1.3 early data (X.X.X.X)
[23236:FW:12d6]SSL state:TLSv1.3 early data:system lib(X.X.X.X)
[23236:FW:12d6]SSL state:TLSv1.3 early data (X.X.X.X)
[23236:FW:12d6]got SNI server name: vpn.firma.cz realm noncompany
[23236:FW:12d6]client cert requirement: no
[23236:FW:12d6]SSL state:SSLv3/TLS read client hello (X.X.X.X)
[23236:FW:12d6]SSL state:SSLv3/TLS write server hello (X.X.X.X)
[23236:FW:12d6]SSL state:TLSv1.3 write encrypted extensions (X.X.X.X)
[23236:FW:12d6]SSL state:SSLv3/TLS write certificate (X.X.X.X)
[23236:FW:12d6]SSL state:TLSv1.3 write server certificate verify (X.X.X.X)
[23236:FW:12d6]SSL state:SSLv3/TLS write finished (X.X.X.X)
[23236:FW:12d6]SSL state:TLSv1.3 early data (X.X.X.X)
[23236:FW:12d6]SSL state:TLSv1.3 early data:system lib(X.X.X.X)
[23236:FW:12d6]SSL state:TLSv1.3 early data (X.X.X.X)
[23236:FW:12d6]SSL state:SSLv3/TLS read finished (X.X.X.X)
[23236:FW:12d6]SSL state:SSLv3/TLS write session ticket (X.X.X.X)
[23236:FW:12d6]SSL state:SSLv3/TLS write session ticket (X.X.X.X)
[23236:FW:12d6]SSL established: TLSv1.3 TLS_AES_256_GCM_SHA384
[23236:FW:12d6]req: /remote/fortisslvpn_xml
[23236:FW:12d6]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1]
 ,host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=yes
[23236:FW:12d6]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1]
 ,host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=no
[23236:FW:12d6]req: /remote/sslvpn-tunnel?dns0=192.168.200.1
[23236:FW:12d6]sslvpn_tunnel_handler,52, Calling rmt_conn_access_ex.
[23236:FW:12d6]deconstruct_session_id:426 decode session id ok, user=[bouska],group=[G VPN 1],authserver=[PDC],portal=[VPN-1]
 ,host=[X.X.X.X],realm=[noncompany],idx=8,auth=16,sid=711de55e,login=1623602144,access=1623602144,saml_logout_url=yes
[23236:FW:12d6]sslvpn_tunnel_handler,148, Calling tunnel.
[23236:FW:12d6]tunnelEnter:432 0x7fc8e70e7500:0x7fc8e91fc000 sslvpn user[bouska],type 16,logintime 0 vd 3
[23236:FW:12d6]sconn 0x7fc8e70e7500 (3:FW) vfid=3 local=[192.168.0.1] remote=[X.X.X.X] dynamicip=[Y.Y.Y.Y]
[23236:FW:12d6]Prepare to launch ppp service...
[23236:FW:12d6]tun: ppp 0x7fc8e909b000 dev (ssl.FW) opened fd 48
[23236:FW:12d6]Will add auth policy for policy 24 for user bouska:G VPN 1
[23236:FW:12d6]Will add auth policy for policy 25 for user bouska:G VPN 1
[23236:FW:12d6]Will add auth policy for policy 29 for user bouska:G VPN 1
[23236:FW:12d6]Add auth logon for user bouska:G VPN 1, matched group number 1
[23236:FW:0]RCV: LCP Configure_Request id(1) len(14) [Maximum_Received_Unit 1354] [Magic_Number A778451F] 
[23236:FW:0]SND: LCP Configure_Request id(1) len(10) [Magic_Number D72C524A] 
[23236:FW:0]lcp_reqci: returning CONFACK.
[23236:FW:0]SND: LCP Configure_Ack id(1) len(14) [Maximum_Received_Unit 1354] [Magic_Number A778451F] 
[23236:FW:0]RCV: LCP Configure_Ack id(1) len(10) [Magic_Number D72C524A] 
[23236:FW:0]lcp_up: with mtu 1354
[23236:FW:0]SND: IPCP Configure_Request id(1) [IP_Address 192.168.0.1] 
[23236:FW:0]RCV: IPCP Configure_Request id(0) [IP_Address 0.0.0.0] [Primary_DNS_IP_Address 0.0.0.0]
 [Secondary_DNS_IP_Address 0.0.0.0] 
[23236:FW:0]ipcp: returning Configure-NAK
[23236:FW:0]SND: IPCP Configure_Nak id(0) [IP_Address Y.Y.Y.Y] [Primary_DNS_IP_Address 10.0.0.50]
 [Secondary_DNS_IP_Address 10.0.0.40] 
[23236:FW:0]RCV: IPCP Configure_Ack id(1) [IP_Address 192.168.0.1] 
[23236:FW:0]RCV: IPCP Configure_Request id(1) [IP_Address Y.Y.Y.Y] [Primary_DNS_IP_Address 10.0.0.50] 
[Secondary_DNS_IP_Address 10.0.0.40] 
[23236:FW:0]ipcp: returning Configure-ACK
[23236:FW:0]SND: IPCP Configure_Ack id(1) [IP_Address Y.Y.Y.Y] [Primary_DNS_IP_Address 10.0.0.50]
 [Secondary_DNS_IP_Address 10.0.0.40] 
[23236:FW:0]ipcp: up ppp:0x7fc8e909b000 caller:0x7fc8e70e7500 tun:48
[23236:FW:0]Cannot determine ethernet address for proxy ARP
[23236:FW:0]local  IP address 192.168.0.1
[23236:FW:0]remote IP address Y.Y.Y.Y
[23236:FW:12d6]sslvpn_ppp_associate_fd_to_ipaddr:281 associate Y.Y.Y.Y to tun (ssl.FW:48)