Include a delay when sending the OTP

[ShogunPanda]

Hi all. The server I currently have to connect to seems to reject OTP with a simple EOF if the two authentication requests are too fast.

I solved it by adding a sleep(2); before the call to try_otp_auth in http.c.

Can you please include this in future release?

[DimitriPapadopoulos]

Thank you for reporting this issue. I am surprised the FortiGate device cannot handle this, and also surprised this issue had not been reported before. It might have been caused by recent changes. Which version of openfortivpn is this? Is this a recent FortiGate device? Could you send the error message in verbose mode (-v)?

[ShogunPanda]

I'm running openfortivpn 1.7.1 installed on macOS Mojave beta.

Here it is the output log:

$ sudo /usr/local/bin/openfortivpn -v -c /var/folders/kn/l2ltlxdn16535thd2t2dpt780000gn/T/129204509
DEBUG:  Loaded config file "/var/folders/kn/l2ltlxdn16535thd2t2dpt780000gn/T/129204509".
DEBUG:  Config host = <OMITTED>
DEBUG:  Config realm = ""
DEBUG:  Config port = "443"
DEBUG:  Config username = <OMITTED>
DEBUG:  Config password = <OMITTED>
DEBUG:  One-time password = <OMITTED>
DEBUG:  server_addr: <OMITTED>
DEBUG:  server_port: 443
DEBUG:  gateway_addr: <OMITTED>
DEBUG:  gateway_port: 443
DEBUG:  Gateway certificate validation failed.
DEBUG:  Gateway certificate digest found in white list.
INFO:   Connected to gateway.
DEBUG:  Error reading from SSL connection (Protocol violation with EOF).
DEBUG:  server_addr: <OMITTED>
DEBUG:  server_port: 443
DEBUG:  gateway_addr: <OMITTED>
DEBUG:  gateway_port: 443
DEBUG:  Gateway certificate validation failed.
DEBUG:  Gateway certificate digest found in white list.

With a patched client with the sleep fix, the Error reading from SSL connection (Protocol violation with EOF) doesn't occur and authentication goes on smoothly.

The fault is not on your client because I tried making the two /remote/login-check calls in a custom script and it also happens. I think it's some firewall flooding protection probably.

[DimitriPapadopoulos]

Ah, is there a firewall in front of the FortiGate device you're trying to connect to?

For now I am trying to better characterize this issue as this is the first time such an issue is reported.

[DimitriPapadopoulos]

If at all possible, it would be worth comparing with the behaviour of the official FortiClient SSL VPN.

[ShogunPanda]

I don't know if there is a firewall. It's a external entity I don't control.

Unfortunately on Mojave the client doesn't work properly. I do remember, that it was also freezing as well, which makes me think it was running in the same issue.

[DimitriPapadopoulos]

For the record, Fedora 27 Bug 1490874 might be related - or not. Updating FortiOS from v5.4.2 to v5.6.2 on the FortiGate device seems to have helped one of the users - but I know this isn't an option for you.

By the way, I would rather find the root cause of this issue instead of adding a delay of 2 seconds - why 2 and not 1 or 3? If we don't find anything, then perhaps we should add an option to kick in this delay only when needed.

Could you perhaps try to connect to the same FortiGate device from a different machine (Linux, older macOS, Windows)?

[ShogunPanda]

Unfortunately I only have a single Mac machine. I think a configurable option would also be acceptable, so that whoever is not affected doesn't have to worry about it, while people like me can fix the problem.

[DimitriPapadopoulos]

Then could you perhaps try with a non-Mac machine?

The thing here is that you're the only one having reporting this issue so far. Both this issue and the workaround might be very specific to macOS Mojave beta or to an old version of FortiOS or to a combination of both.

[ShogunPanda]

Ok, I'll let you know if it happens from a Windows machine as soon as I get it.

[DimitriPapadopoulos]

On Windows please make sure you try VPN SSL, not IPSec.

[ShogunPanda]

Yup, we were never talking about IPSec connections :)

[ShogunPanda]

Hi again, I couldn't try to reproduce on a Windows machine. Since I needed this, I decided to patch myself, making the delay optional and configurable.

See: #376

[mrbaseman]

Hi @ShogunPanda

with the recently released version 1.8.0 we have improved the debugging output. With -v the http response code is printed out, and with -v -v the full http traffic of the authentication process is displayed. This might help finding the root cause of the issue that you describe. Note that the debugging output probably contains sensitive data like clear text passwords. Make sure to anonymize it appropriately when posting it here.

[DimitriPapadopoulos]

@ShogunPanda Could you give openfortivpn 1.8.1 a try? We have improved debugging output (make sure to sanitize openfortivpn -v -v output before posting it as it may contain passwords).

[ShogunPanda]

Hi! I couldn't reproduce the problem for now. Maybe something changed on the VPN server and now everything is solved. If it happens again I'll let you know ASAP.

[ShogunPanda]

Hi again. I was actually able to reproduce the problem. It arises when several login are attempted quickly.

WARN:   You should not pass the password on the command line. Type it interactively or use a config file instead.
DEBUG:  openfortivpn 1.8.1
WARN:   Bad port in config file: "0".
DEBUG:  Loaded config file "/usr/local/Cellar/openfortivpn/1.8.1/etc/openfortivpn/config".
DEBUG:  Config host = "vpn.$VPN"
DEBUG:  Config realm = ""
DEBUG:  Config port = "443"
DEBUG:  Config username = "$USER"
DEBUG:  Config password = "********"
DEBUG:  One-time password = "022110"
DEBUG:  Resolving gateway host ip
DEBUG:  Establishing ssl connection
DEBUG:  server_addr: $IP
DEBUG:  server_port: 443
DEBUG:  gateway_addr: $IP
DEBUG:  gateway_port: 443
DEBUG:  Gateway certificate validation failed.
DEBUG:  Gateway certificate digest found in white list.
INFO:   Connected to gateway.
DEBUG:  http_send:
POST /remote/logincheck HTTP/1.1
Host: vpn.$VPN:443
User-Agent: Mozilla/5.0 SV1
Accept: text/plain
Accept-Encoding: identity
Content-Type: application/x-www-form-urlencoded
Cookie:
Content-Length: 121

username=$USER_ENCODED&credential=$PASSWORD%21&realm=&ajax=1&redir=%2Fremote%2Findex&just_logged_in=1
DEBUG:  http_receive:
HTTP/1.1 401 Authorization Required
Content-Length: 1357
Keep-Alive: timeout=5, max=100
Connection: Keep-Alive
Cache-Control: no-cache
Content-Type: text/html

<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
<meta http-equiv="Pragma" content="no-cache">
<meta http-equiv="cache-control" content="no-cache">
<meta http-equiv="cache-control" content="must-revalidate">
<meta http-equiv="cache-control" content="no-store">
<title>Authentication Required</title>
<link href="/sslvpn/css/ssl_style.css" rel="stylesheet" type="text/css">
<script type="text/javascript" src="/remote/fgt_lang?lang=en"></script></head>
<BODY class=main><CENTER>
<TABLE class=container align=center valign=middle width=100% height=100% cellpadding=0 cellspacing=0>
<TR align=center><TD>
<TABLE border=0 width=400 height=200 cellpadding=10 cellspacing=5 align=center>
<FORM ACTION="/remote/logincheck" method="POST">
<TR align=center valign=middle><TD colspan=2><b>Enter Your Microsoft verification code</b></TD></TR>
<INPUT TYPE="hidden" NAME="magic" VALUE="4tinet2095866">
<INPUT TYPE="hidden" NAME="username" VALUE="$USER">
<INPUT TYPE="hidden" NAME="reqid" VALUE="1789718320">
<INPUT TYPE="hidden" NAME="grpid" VALUE="2,304,0">
<TR><TD width=30%><b>Answer:</b></TD>
<TD width=70%>
<INPUT TYPE="password" NAME="credential">
</TD></TR>
<TR align=center><TD colspan=2>
<INPUT class="button" TYPE="submit" VALUE="OK">
</TD></TR>
</FORM>
</TABLE>
</TD></TR></TABLE>
</CENTER></BODY></HTML>
DEBUG:  http_send:
POST /remote/logincheck HTTP/1.1
Host: vpn.$VPN:443
User-Agent: Mozilla/5.0 SV1
Accept: text/plain
Accept-Encoding: identity
Content-Type: application/x-www-form-urlencoded
Cookie:
Content-Length: 111

magic=4tinet2095866&username=$USER_ENCODED&reqid=1789718320&grpid=2%2C304%2C0&credential=022110
DEBUG:  Error reading from SSL connection (Protocol violation with EOF).
DEBUG:  server_addr: $IP
DEBUG:  server_port: 443
DEBUG:  gateway_addr: $IP
DEBUG:  gateway_port: 443
DEBUG:  Gateway certificate validation failed.
DEBUG:  Gateway certificate digest found in white list.
DEBUG:  http_send:
POST /remote/logincheck HTTP/1.1
Host: vpn.$VPN:443
User-Agent: Mozilla/5.0 SV1
Accept: text/plain
Accept-Encoding: identity
Content-Type: application/x-www-form-urlencoded
Cookie:
Content-Length: 111

magic=4tinet2095866&username=$USER_ENCODED&reqid=1789718320&grpid=2%2C304%2C0&credential=022110

In the first request, I noticed the just_logged_in=1 parameter which is making everything stall.

[mrbaseman]

It is with verification code as token and with only if several login attempts happen quickly. So it might be a feature of the authentication system (active directory?) in the background.

Edit: The just_logged_in=1 parameter is part of the usual login procedure. It's always there.

[ShogunPanda]

@mrbaseman So as far as I understand there's nothing to fix in openfortivpn. So what about merging #376 people like me can bypass the problem if needed?

[mrbaseman]

I just came across this in the context of #427. I have cherry-picked your commit and merged it manually over there. Maybe we'll merge both new otp related options in one rush. Let's see what the others think about it.

[ShogunPanda]

Cool, thanks!

[mrbaseman]

I have merged the feature into the current master. It will be in the next release.

[ShogunPanda]

Nice! Thank you very much!