Skip to main content
tripley
New Member
December 11, 2019
Question

Two-Factor SSL VPN - Invalid HTTP Request

  • December 11, 2019
  • 4 replies
  • 24618 views

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.

    4 replies

    HarK0nNeN
    New Member
    December 19, 2019

     

    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
    New Member
    December 20, 2019

    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-authentication

     

    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
    New Member
    December 20, 2019

    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
    tripleyAuthor
    New Member
    December 31, 2019

    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
    Visitor III
    April 1, 2020

    I'm experiencing similar issues on 6.0.9

     

    rajan_rkv
    New Member
    September 20, 2021

    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
    New Member
    September 24, 2024

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

    image.png