Two-Factor SSL VPN - Invalid HTTP Request

[tripley]

This isn't a production environment.  Just playing around at home, but I can't seem to get it to work.

I have a 30E with the two built in mobile Fortitokens.  I assigned a mobile token to a local user.  Loaded the App onto my Android phone and linked it via the QR code.  Configured a basic SSL VPN portal.

When I login it asks me for a user/pass, then I enter the token from my app.  It gives me an error "Invalid HTTP request".

If I disable two-factor for that local user I can login to the portal no problem and access resources.

I can't seem to find any logs indicating any issue.

What should I check?  FortiOS 6.2.2 on a FortiGate 30E.

[HarK0nNeN]

Hi,

I am also experiencing the same issue as above. I have been wrecking my brain over this for the past few days. It just doesn't make sense, even though following the forti guides.

eg https://docs.fortinet.com...le-push-authentication minus the FTM part, i just leave that part, but everything else is pretty much same/similar. For reference, i did implement the FTM part and it still fails anyways.

I used this to debug my logs https://kb.fortinet.com/k....do?externalID=FD38804

I am not running any LDAP or Radius or FortiAuthenticator, just a fortigate, local user and a mobile fortitoken.

User has already been assigned a fortitoken, i have deleted the user and recreated the user and deleted the trial tokens and imported it again, redid all my SSL VPN portal settings and firewall policies.

It works with a normal local user with NO 2FA/OTP, but as soon as I use the 2FA user it just pops up the HTTP INVALID Request. Absolutely driving me mad.

Logs below of the sslvpn/auth/fnbamd

2019-12-19 23:50:01 [610:root:31d]SSL state:before SSL initialization (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:before SSL initialization (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]client cert requirement: no
2019-12-19 23:50:01 [610:root:31d]SSL state:SSLv3/TLS read client hello (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:SSLv3/TLS write server hello (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:SSLv3/TLS write change cipher spec (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:SSLv3/TLS write finished (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:SSLv3/TLS write finished:system lib(1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:SSLv3/TLS write finished (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:SSLv3/TLS read change cipher spec (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:SSLv3/TLS read finished (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL state:SSL negotiation finished successfully (1.1.1.1)
2019-12-19 23:50:01 [610:root:31d]SSL established: TLSv1.2 ECDHE-RSA-AES256-SHA
2019-12-19 23:50:01 [610:root:31d]req: /remote/logincheck
2019-12-19 23:50:01 [610:root:31d]rmt_web_auth_info_parser_common:470 no session id in auth info
2019-12-19 23:50:01 [610:root:31d]rmt_web_access_check:720 access failed, uri=[/remote/logincheck],ret=4103,
2019-12-19 23:50:01 [610:root:31d]User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:42.0) Gecko/20100101 Firefox/42.0
2019-12-19 23:50:01 [610:root:31d]rmt_logincheck_cb_handler:1188 user 'user' has a matched local entry.
2019-12-19 23:50:01 [610:root:31d]sslvpn_auth_check_usrgroup:2035 forming user/group list from policy.
2019-12-19 23:50:01 [610:root:31d]sslvpn_auth_check_usrgroup:2141 got user (0) group (1:0).
2019-12-19 23:50:01 [610:root:31d]sslvpn_validate_user_group_list:1638 validating with SSL VPN authentication rules (0), realm ().
2019-12-19 23:50:01 [610:root:31d]sslvpn_validate_user_group_list:1959 got user (0:0), group (1:0) peer group (0).
2019-12-19 23:50:01 [610:root:31d]two factor check for user: off
2019-12-19 23:50:01 [610:root:31d]sslvpn_authenticate_user:191 authenticate user: [user]
2019-12-19 23:50:01 [610:root:31d]sslvpn_authenticate_user:198 create fam state
2019-12-19 23:50:01 [610:root:31d]fam_auth_send_req:583 with server blacklist:
2019-12-19 23:50:01 2019-12-19 23:50:01 [2343] handle_req-Rcvd auth_token req 1643548706 for user in SSLVPN_PORTAL_USERS
2019-12-19 23:50:01 [409] __compose_group_list_from_req-Group 'SSLVPN_PORTAL_USERS'
2019-12-19 23:50:01 [610:root:31d]2019-12-19 23:50:01 [712] create_auth_token_session-Created auth token session 1643548706
fam_auth_send_req_internal:461 fnbam_auth return: 7
2019-12-19 23:50:11 [610:root:31d]SSL state:warning close notify (1.1.1.1)
2019-12-19 23:50:11 [610:root:31d]sslConnGotoNextState:303 error (last state: 1, closeOp: 0)
2019-12-19 23:50:11 [610:root:31d]Destroy sconn 0x74f0c080, connSize=0. (root)
2019-12-19 23:50:15 authd_epoll_work: timeout 9910
2019-12-19 23:50:15 authd_epoll_work: timeout 9900
2019-12-19 23:50:25 authd_timer_run: 3 expired
2019-12-19 23:50:25 authd_epoll_work: timeout 60000
2019-12-19 23:50:25 authd_timer_run: 3 expired
2019-12-19 23:50:25 authd_epoll_work: timeout 60000
2019-12-19 23:50:25 authd_timer_run: 3 expired
2019-12-19 23:50:25 authd_epoll_work: timeout 60000
2019-12-19 23:50:28 [610:root:31e]allocSSLConn:289 sconn 0x74f0c080 (0:root)
2019-12-19 23:50:28 [610:root:31e]SSL state:before SSL initialization (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:before SSL initialization (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]client cert requirement: no
2019-12-19 23:50:28 [610:root:31e]SSL state:SSLv3/TLS read client hello (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:SSLv3/TLS write server hello (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:SSLv3/TLS write change cipher spec (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:SSLv3/TLS write finished (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:SSLv3/TLS write finished:system lib(1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:SSLv3/TLS write finished (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:SSLv3/TLS read change cipher spec (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:SSLv3/TLS read finished (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL state:SSL negotiation finished successfully (1.1.1.1)
2019-12-19 23:50:28 [610:root:31e]SSL established: TLSv1.2 ECDHE-RSA-AES256-SHA
2019-12-19 23:50:28 [610:root:31e]req: /remote/logincheck
2019-12-19 23:50:28 [610:root:31e]rmt_web_auth_info_parser_common:470 no session id in auth info
2019-12-19 23:50:28 [610:root:31e]rmt_web_access_check:720 access failed, uri=[/remote/logincheck],ret=4103,
2019-12-19 23:50:28 [610:root:31e]User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:42.0) Gecko/20100101 Firefox/42.0
2019-12-19 23:50:28 [610:root:31e]rmt_logincheck_cb_handler:1188 user 'user' has a matched local entry.
2019-12-19 23:50:28 [610:root:31e]got checking id %lx-0
2019-12-19 23:50:28 [610:root:31e]1389 magic checked failed.
2019-12-19 23:50:28 [610:root:31e]req: /remote/error?msg=400
2019-12-19 23:50:28 [610:root:0]sslvpn_find_err_msg_array:339 Can't find the value for key: 400
2019-12-19 23:50:28 [610:root:31e]rmt_error_cb_handler:126 Can't get corresponding message for key 400. Use the default error message.
2019-12-19 23:50:28 [610:root:31e]req: /sslvpn/css/ssl_style.css
2019-12-19 23:50:28 [610:root:31e]mza: 0x14a7de8 /sslvpn/css/ssl_style.css
2019-12-19 23:50:28 [610:root:31f]allocSSLConn:289 sconn 0x74f0c780 (0:root)
2019-12-19 23:50:28 [610:root:31f]SSL state:before SSL initialization (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:before SSL initialization (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]client cert requirement: no
2019-12-19 23:50:28 [610:root:31f]SSL state:SSLv3/TLS read client hello (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:SSLv3/TLS write server hello (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:SSLv3/TLS write change cipher spec (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:SSLv3/TLS write finished (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:SSLv3/TLS write finished:system lib(1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:SSLv3/TLS write finished (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:SSLv3/TLS read change cipher spec (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:SSLv3/TLS read finished (1.1.1.1)
2019-12-19 23:50:28 [610:root:31f]SSL state:SSL negotiation finished successfully (1.1.1.1)

For what ever reason, my session info or auth info is not passing through? Which I assume is my token and that is why my magic auth is failing. Frustrating!

Is this a bug? pls help :(

[HarK0nNeN]

Just to reply to my post,

Apparently is a possibility of a bug in 6.2.2 with the fortitoken on Soc3 Platforms with SSLVPN

https://docs.fortinet.com/document/fortigate/6.2.2/fortios-release-notes/501077/mobile-token-authent...

Also it was just announced today that 6.2.3 has been released and supposedly fixed this issue. 

I will download the new firmware and upgrade to see if this fixes it.

[cossairt]

Thanks for the post.  Was experiencing the same issue and did upgraded to 6.2.3 on a FWF 60E and it resolved the issue.

[tripley]

Update - I have upgraded to 6.2.3, however 2FA still does not work.

I get Error:Permission denied instead.  Logs indicate "sslvpn_login_unknown_user".  However, when I turn off 2FA for that user I can login fine.

So some progress has been made with 6.2.3, but I'm still running into issues.

[sfales]

I'm experiencing similar issues on 6.0.9

[sfales]

I opened a ticket with support.  They had me change remote auth timeout.  This appears to have resolved the issue for me.

config system global set remoteauthtimeout ? -----------------------> will see the possible range set remoteauthtimeout 60 ----------------------> Set to 60

end --------------------------------------------> save

[rajan_rkv]

Hi Guys 

Just wondering if someone is facing a same issue on 6.2.9 and are using 2FA with Azure SAML authentification for FortiGate SSL VPN

The above set up was working fine with 6.2.7 but after firmware upgrade getting the below error. As recommended by fortigate changed the  remoteauthtimeout  to 60 under global configuration to no luck. 

2021-09-20 07:16:02 [227:root:a0]SSL state:before SSL initialization (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:before SSL initialization (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]got SNI server name: <servername> realm (null) 2021-09-20 07:16:02 [227:root:a0]client cert requirement: no 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS read client hello (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write server hello (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write certificate (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write key exchange (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write server done (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write server done:system lib(public-ip-forticlient) 2021-09-20 07:16:02 [228:root:a0]allocSSLConn:295 sconn 0x7f9a08d900 (0:root) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write server done (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS read client key exchange (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS read change cipher spec (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS read finished (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write session ticket (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write change cipher spec (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSLv3/TLS write finished (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL state:SSL negotiation finished successfully (public-ip-forticlient) 2021-09-20 07:16:02 [227:root:a0]SSL established: TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384 2021-09-20 07:16:03 [227:root:a0]req: /remote/info 2021-09-20 07:16:03 [227:root:a0]req: /remote/saml/start 2021-09-20 07:16:03 [227:root:a0]rmt_web_auth_info_parser_common:452 no session id in auth info 2021-09-20 07:16:03 [227:root:a0]rmt_web_get_access_cache:787 invalid cache, ret=4103 2021-09-20 07:16:04 [227:root:a0]sslvpn_read_request_common,648, ret=-1 error=-1, sconn=0x7f9a08d900. 2021-09-20 07:16:04 [227:root:a0]Destroy sconn 0x7f9a08d900, connSize=0. (root) 2021-09-20 07:16:04 [228:root:a0]SSL state:before SSL initialization (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:before SSL initialization (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]got SNI server name: <servername> realm (null) 2021-09-20 07:16:04 [228:root:a0]client cert requirement: no 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS read client hello (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write server hello (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write certificate (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write key exchange (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write server done (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write server done:system lib(public-ip-forticlient) 2021-09-20 07:16:04 [227:root:a1]allocSSLConn:295 sconn 0x7f9a08d900 (0:root) 2021-09-20 07:16:04 [227:root:a1]SSL state:before SSL initialization (public-ip-forticlient) 2021-09-20 07:16:04 [227:root:a1]SSL state:before SSL initialization (public-ip-forticlient) 2021-09-20 07:16:04 [227:root:a1]got SNI server name: <servername> realm (null) 2021-09-20 07:16:04 [227:root:a1]client cert requirement: no 2021-09-20 07:16:04 [227:root:a1]SSL state:SSLv3/TLS read client hello (public-ip-forticlient) 2021-09-20 07:16:04 [227:root:a1]SSL state:SSLv3/TLS write server hello (public-ip-forticlient) 2021-09-20 07:16:04 [227:root:a1]SSL state:SSLv3/TLS write change cipher spec (public-ip-forticlient) 2021-09-20 07:16:04 [227:root:a1]SSL state:SSLv3/TLS write finished (public-ip-forticlient) 2021-09-20 07:16:04 [227:root:a1]SSL state:SSLv3/TLS write finished:system lib(public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write server done (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS read client key exchange (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS read change cipher spec (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS read finished (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write session ticket (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write change cipher spec (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSLv3/TLS write finished (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL state:SSL negotiation finished successfully (public-ip-forticlient) 2021-09-20 07:16:04 [228:root:a0]SSL established: TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384 2021-09-20 07:16:05 [227:root:a1]SSL state:SSLv3/TLS write finished (public-ip-forticlient) 2021-09-20 07:16:05 [227:root:a1]SSL state:SSLv3/TLS read change cipher spec (public-ip-forticlient) 2021-09-20 07:16:05 [227:root:a1]SSL state:SSLv3/TLS read finished (public-ip-forticlient) 2021-09-20 07:16:05 [227:root:a1]SSL state:SSL negotiation finished successfully (public-ip-forticlient) 2021-09-20 07:16:05 [227:root:a1]SSL established: TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384 2021-09-20 07:16:05 [228:root:a0]req: /remote/fgt_lang?lang=en 2021-09-20 07:16:05 [227:root:a1]req: /sslvpn/css/ssl_style.css 2021-09-20 07:16:05 [227:root:a1]mza: 0x269ebe8 /sslvpn/css/ssl_style.css 2021-09-20 07:16:09 authd_epoll_work: timeout 9910 2021-09-20 07:16:19 authd_timer_run: 3 expired 2021-09-20 07:16:19 authd_epoll_work: timeout 60000 2021-09-20 07:16:25 [227:root:a1]Timeout for connection 0x7f9a08d900.

2021-09-20 07:16:25 [227:root:a1]Destroy sconn 0x7f9a08d900, connSize=0. (root) 2021-09-20 07:16:35 [228:root:a0]Timeout for connection 0x7f9a08d900.

2021-09-20 07:16:35 [228:root:a0]Destroy sconn 0x7f9a08d900, connSize=0. (root) 2021-09-20 07:17:19 authd_epoll_work: timeout 9890 2021-09-20 07:17:29 authd_timer_run: 3 expired 2021-09-20 07:17:29 authd_epoll_work: timeout 60000

[image][/image]

Any pointers would be of great help. 

[Wimukthi_Bandara]

I also face the same issue, and change this value and it works for me