search

adrienverge / openfortivpn

Client for PPP+TLS VPN tunnel services
GNU General Public License v3.0
2.7k stars 320 forks source link

Bad header from gateway (403 Forbidden) #191

Closed tim427 closed 7 years ago

tim427 commented 7 years ago

Running openfortivpn version 1.3 (also tried lates git pull + make + install = 1.5).

Running the latest version of FortiOS on my Fortigate 60D: v5.6.2 build1486

FortiClient binary application works fine, web version also.

Using openfortivpn resulting in a "HTTP/1.1 403 Forbidden." as "bad header".

Username and password are 100% correct. Any suggestions?

DEBUG:  Loaded config file "/etc/openfortivpn/config".
DEBUG:  Config host = "hostname"
DEBUG:  Config realm = ""
DEBUG:  Config port = "80"
DEBUG:  Config username = "username"
DEBUG:  Config password = "********"
DEBUG:  Gateway certificate validation failed.
DEBUG:  Gateway certificate digest found in white list.
INFO:   Connected to gateway.
INFO:   Authenticated.
DEBUG:  Cookie: SVPNCOOKIE=PxL+f+deWjHe6IsXDvmPd0AXnfrb8/1M32ta2ffQuI7j+YeKK2jOnv/mfkPRXtzKEqAx0YiHQgK20zhL6z/4elbsE2l8BzsmxmYVRZdGm9nCSpzfUKA+mbRhmj3mnFp2znxj6m2b/AGOJbY0QduwxRAe5uzUVBVRz/yZiWooo/5vp7i1RkN0CXsK1QyXOMCt
INFO:   Remote gateway has allocated a VPN.
DEBUG:  Gateway certificate validation failed.
DEBUG:  Gateway certificate digest found in white list.
DEBUG:  pppd_read_thread
DEBUG:  ssl_read_thread
DEBUG:  if_config thread
DEBUG:  ssl_write_thread
DEBUG:  pppd ---> gateway (16 bytes)
pppd:   c0 21 01 01 00 0e 01 04 05 4a 05 06 00 31 3e 37

DEBUG:  pppd_write thread
ERROR:  Received bad header from gateway:
  (hex) 48 54 54 50 2f 31 2e 31 20 34 30 33 20 46 6f 72 62 69 64 64 65 6e 0d 0a 44 61 74 65 3a 20 4d 6f 6e 2c 20 30 39 20 4f 63 74 20 32 30 31 37 20 31 31 3a 35 38 3a 33 36 20 47 4d 54 0d 0a 53 65 72 76 65 72 3a 20 78 78 78 78 78 78 78 78 2d 78 78 78 78 78 0d 0a 54 72 61 6e 73 66 65 72 2d 45 6e 63 6f 64 69 6e 67 3a 20 63 68 75 6e 6b 65 64 0d 0a 43 6f 6e 74 65 6e 74 2d 54 79 70 65 3a 20 74 65 78 74 2f 68 74 6d 6c 0d 0a 58 2d 46 72 61 6d 65 2d 4f 70 74 69 6f 6e 73 3a 20 53 41 4d 45 4f 52 49 47 49 4e 0d 0a 43 6f 6e 74 65 6e 74 2d 53 65 63 75 72 69 74 79 2d 50 6f 6c 69 63 79 3a 20 66 72 61 6d 65 2d 61 6e 63 65 73 74 6f 72 73 20 27 73 65 6c 66 27 0d 0a 0d 0a 36 35 64 20 20 20 0d 0a 3c 48 54 4d 4c 3e 0a 3c 48 45 41 44 3e 0a 3c 4d 45 54 41 20 68 74 74 70 2d 65 71 75 69 76

  (raw) HTTP/1.1 403 Forbidden.
Date: Mon, 09 Oct 2017 11:58:36 GMT.
Server: xxxxxxxx-xxxxx.
Transfer-Encoding: chunked.
Content-Type: text/html.
X-Frame-Options: SAMEORIGIN.
Content-Security-Policy: frame-ancestors 'self'.
.
65d   .
<HTML>
<HEAD>
<META http-equi
INFO:   Cancelling threads...
DEBUG:  Waiting for pppd to exit...
INFO:   Terminated pppd.
INFO:   Closed connection to gateway.
DEBUG:  Gateway certificate validation failed.
DEBUG:  Gateway certificate digest found in white list.
INFO:   Logged out.
DimitriPapadopoulos commented 7 years ago
tim427 commented 7 years ago

Did it work previously and stopped working after an upgrade to FortiOS v5.6.2?

Don't no; first time using the openfortivpn client

Also do you run the working FortiClient binary application from the same machine?

Yes!

DimitriPapadopoulos commented 7 years ago

That's the part of the code that generates the error in src/io.c:

        ret = safe_ssl_read_all(tunnel->ssl_handle, header, 6);
        [...]
        total = header[0] << 8 | header[1];
        magic = header[2] << 8 | header[3];
        size = header[4] << 8 | header[5];
        if (magic != 0x5050 || total != size + 6) {
            log_error("Received bad header from gateway:\n");
            debug_bad_packet(tunnel, header);
            break;
        }

Could you add some code to print total, magic and size in hexadecimal? Something like this:

            log_debug("total: %#x, magic: %#x, size: %#x\n", total, magic, size);
tim427 commented 7 years ago

total: 0x4854, magic: 0x5450, size: 0x2f31

DimitriPapadopoulos commented 7 years ago

Mmmh... Something's wrong here:

tim427 commented 7 years ago

So, do you expect this is a client-side problem or just a "too new firmware" of the Fortigate?

tim427 commented 7 years ago

Is there any analysis, I can do?

DimitriPapadopoulos commented 7 years ago

My feeling is that the new FortiOS comes with a new protocol.

It's hard to help remotely and I currently don't have much time. I guess a wireshark log would help if someone else can look into this.

tim427 commented 7 years ago

@DimitriPapadopoulos I've made an PCAP, filtered on my Firewall IP. How does this help, because this is all encrypted (I tried to decrypt the SSL-stream with the SSL-key, with no success)

DimitriPapadopoulos commented 7 years ago

Is all openfortivpn-related traffic towards port 443 of the FortiGate and encrypted? If so no need to look further. Perhaps it would be more useful to listen at the traffic in the PPP device (ppp0on my Ubuntu 16.04 machine) while running FortiClient.

mrbaseman commented 7 years ago

I think once the ssl threads are up, everything is encrypted. The debug output already shows what is sent on the ppp device: "HTTP/1.1 403 Forbidden." - which is strange, because authentication has worked and we have received a cookie just before.

DimitriPapadopoulos commented 7 years ago

@mrbaseman What about the value of magic which is unexpected? And total which is way larger than size + 6?

mrbaseman commented 7 years ago

Oh, right. magic with a different value looks like a protocol change. A much larger total also could be that other data is included in the packet now. Also the debug output shows only the first 255 bytes. There might be some more information hidden in the rest of the returned html document which a tcpdump on the ppp device may reveal. (is it possible to start the dump before the interface is there? Or maybe one has to use the 'any' interface?)

65d seems to be the size of the first chunk of the content, but even that is much smaller than size. So there are probably several chunks. If we have bad luck the whole login procedure works different with FortiOS 5.6

Another tcpdump from a working connection with the binary linux client might also be helpful for comparison.

tim427 commented 7 years ago

Ipsec Binary client now also comes with an error.. "Failed to parse fortisslvpn page."

I'm still trying to find a solution to tcpdump the "not yet existing ppp0 device" (trying to create a bond interface an do something with if-up scripts..)

mrbaseman commented 7 years ago

Oh, if the binary client doesn't work either now, is the client ip range restricted in some way, and you receive "403 Forbidden" when you are coming from the wrong network? In my setup the connection is just closed in such a case, but behavior in this case may depend on the OS version or on details how exactly such IP restrictions are imposed.

tim427 commented 7 years ago

This comes directly from the syslog of the Fortigate

Binary application from Fortinet:

Oct 17 14:40:25 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:40:25 devname=fw01 devid=FGT60D4613027668 logid="0101039943" type="event" subtype="vpn" level="information" vd="root" logtime=1508244025 logdesc="SSL VPN new connection" action="ssl-new-con" tunneltype="ssl" tunnelid=0 remip=<VPN CLIENT EXTERNAL IP> user="N/A" group="N/A" dst_host="N/A" reason="N/A" msg="SSL new connection"
Oct 17 14:40:25 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:40:25 devname=fw01 devid=FGT60D4613027668 logid="0101039424" type="event" subtype="vpn" level="information" vd="root" logtime=1508244025 logdesc="SSL VPN tunnel up" action="tunnel-up" tunneltype="ssl-web" tunnelid=1349550967 remip=<VPN CLIENT EXTERNAL IP> user="<USERNAME>" group="VPN" dst_host="N/A" reason="login successfully" msg="SSL tunnel established"
Oct 17 14:40:25 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:40:25 devname=fw01 devid=FGT60D4613027668 logid="0101039943" type="event" subtype="vpn" level="information" vd="root" logtime=1508244025 logdesc="SSL VPN new connection" action="ssl-new-con" tunneltype="ssl" tunnelid=0 remip=<VPN CLIENT EXTERNAL IP> user="N/A" group="N/A" dst_host="N/A" reason="N/A" msg="SSL new connection"
Oct 17 14:40:25 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:40:25 devname=fw01 devid=FGT60D4613027668 logid="0101039425" type="event" subtype="vpn" level="information" vd="root" logtime=1508244025 logdesc="SSL VPN tunnel down" action="tunnel-down" tunneltype="ssl-web" tunnelid=1349550967 remip=<VPN CLIENT EXTERNAL IP> user="<USERNAME>" group="VPN" dst_host="N/A" reason="User requested termination of service" duration=0 sentbyte=0 rcvdbyte=0 msg="SSL tunnel shutdown"

Openfortivpn:

Oct 17 14:43:43 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:43:42 devname=fw01 devid=FGT60D4613027668 logid="0101039943" type="event" subtype="vpn" level="information" vd="root" logtime=1508244222 logdesc="SSL VPN new connection" action="ssl-new-con" tunneltype="ssl" tunnelid=0 remip=<VPN CLIENT EXTERNAL IP> user="N/A" group="N/A" dst_host="N/A" reason="N/A" msg="SSL new connection"
Oct 17 14:43:43 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:43:42 devname=fw01 devid=FGT60D4613027668 logid="0101039424" type="event" subtype="vpn" level="information" vd="root" logtime=1508244222 logdesc="SSL VPN tunnel up" action="tunnel-up" tunneltype="ssl-web" tunnelid=1349550968 remip=<VPN CLIENT EXTERNAL IP> user="<USERNAME>" group="VPN" dst_host="N/A" reason="login successfully" msg="SSL tunnel established"
Oct 17 14:43:43 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:43:42 devname=fw01 devid=FGT60D4613027668 logid="0101039944" type="event" subtype="vpn" level="information" vd="root" logtime=1508244222 logdesc="SSL VPN alert" action="ssl-alert" tunneltype="ssl" tunnelid=0 remip=<VPN CLIENT EXTERNAL IP> user="N/A" group="N/A" dst_host="N/A" reason="warning" desc="close notify" msg="SSL alerts"
Oct 17 14:43:43 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:43:43 devname=fw01 devid=FGT60D4613027668 logid="0101039943" type="event" subtype="vpn" level="information" vd="root" logtime=1508244223 logdesc="SSL VPN new connection" action="ssl-new-con" tunneltype="ssl" tunnelid=0 remip=<VPN CLIENT EXTERNAL IP> user="N/A" group="N/A" dst_host="N/A" reason="N/A" msg="SSL new connection"
Oct 17 14:43:43 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:43:43 devname=fw01 devid=FGT60D4613027668 logid="0101039943" type="event" subtype="vpn" level="information" vd="root" logtime=1508244223 logdesc="SSL VPN new connection" action="ssl-new-con" tunneltype="ssl" tunnelid=0 remip=<VPN CLIENT EXTERNAL IP> user="N/A" group="N/A" dst_host="N/A" reason="N/A" msg="SSL new connection"
Oct 17 14:43:43 <FIREWALL EXTERNAL IP> date=2017-10-17 time=14:43:43 devname=fw01 devid=FGT60D4613027668 logid="0101039425" type="event" subtype="vpn" level="information" vd="root" logtime=1508244223 logdesc="SSL VPN tunnel down" action="tunnel-down" tunneltype="ssl-web" tunnelid=1349550968 remip=<VPN CLIENT EXTERNAL IP> user="<USERNAME>" group="VPN" dst_host="N/A" reason="User requested termination of service" duration=0 sentbyte=0 rcvdbyte=0 msg="SSL tunnel shutdown"
tim427 commented 7 years ago

Appeared to be an issue/bug in de FortiOS... Fixed right now (something with user mapping).

Conclusion: openfortivpn works perfect with the latest version!

DimitriPapadopoulos commented 7 years ago

@tim247 Thanks for the feedback - much appreciated! Does this mean Fortinet provided a new version / patch for FortiOS, or did they just suggest to work around the issue by modifying the user mapping? I'm asking for future reference, trying to understand whether the issue is specific to FortiOS v5.6.2 or other versions as well.

tim427 commented 7 years ago

@DimitriPapadopoulos By changing the "default mapping" to the "portal" you actual need.. It sounds stupid to me...

Before I changed it; specific group is in the "full-access"-portal and others in the "web-only"-portal. Now everybody comes in the "full-access"-portal..