Http CONNECT fails due to fragmented client stream

[gt5700]

I have a situation where the Proxy is used by a process on the same host, and is listening on local loopback.

I have found the proxy sometimes fails for SSL connections.

I am using explicit clients, and the WebProxy in not decrypting SSL.

Looking deeper, I found that the initial "CONNECT" method is not being received by the WebProxy in a single "request". Only the first byte (the letter 'C') is being read. This may be because the Nagle algorithm is disabled for local TCP traffic....but I can't confirm if this is the root cause of the fragmentation.

The HttpHelper.cs code has a method that seems to assume the entire "CONNECT" string will be available in the receive buffer, but since there is only 1 byte available, it fails to detect the http CONNECT method.

I have hacked in a temporary work around to get my system up and going. I have modified the "IsConnectMethod" in HttpHelper.cs to only check for a single character "C". This appears to work, but its obviously not a permanent fix. I'm lucky that CONNECT appears to be the only http method that starts with a C.

I think the code needs to be updated to read in at least 10 bytes from the incoming client stream before it attempts to test for the "CONNECT" string, but I don't know what other impacts that might have. I mentioned 10 bytes because I can see 10 bytes is used in the "startsWith" method.

[ByronAP]

do you have a reproduction case?
I disabled nagle system wide... I can not think of any reason why the initial connect would be across multiple packets except maybe an mtu issue, do you know what your mtu is set at?

[gt5700]

Its difficult for me to replicate in my test system, as the issue only appears in my production systems. I can't deny that theoretically the entire initial connection should normally be contained in a single connection, so I will try my hardest to stop this from happening. But I may not be able to do this, as the original connection from the browser to the web proxy is undergoing an additional layer of processing and encryption, and its entirely possible that some additional processing delay and packet encapsulation is causing this issue.

The rest of the proxy works fine, as it seems to handle the "fragmented" stream fine. A note on MTU...I've read that loopback has an extremely large MTU, so I don't think that's the issue...all other MTU's I'm working with are default value (1500 I assume), but I will keep MTU in mind too.

So whilst I can't provide a self contained duplicate of the entire issue, it can be simulated with a simple TcpClient connection. Something like...

    static async Task Main(string[] args)
    {
        var webProxyServer = new Titanium.Web.Proxy.ProxyServer(false, false, false);
        var endPoint = new Titanium.Web.Proxy.Models.ExplicitProxyEndPoint(System.Net.IPAddress.Parse("127.0.0.1"), 6000, false);
        webProxyServer.AddEndPoint(endPoint);
        webProxyServer.Start();

        var connectString = "CONNECT github.com:443 HTTP/1.1";
        var bytes = Encoding.ASCII.GetBytes(connectString);

        var tcpClient = new TcpClient();
        tcpClient.Connect("127.0.0.1", 6000);

        await tcpClient.Client.SendAsync(new ArraySegment<byte>(bytes, 0, 1), SocketFlags.None);
        await Task.Delay(100);
        await tcpClient.Client.SendAsync(new ArraySegment<byte>(bytes, 1, bytes.Length - 1), SocketFlags.None);

        Console.ReadLine();
    }

`

The above code causes the "IsConnectMethod" method in HttpHelper.cs to return -1.

I understand that this may not be considered a Web Proxy issue as what I'm presenting is probably not a normal circumstance, but I'm hoping a fix would be relatively simple, in that the IsConnectMethod could be called only after at least 10 bytes have been received.

[jgilbert2017]

+1 for addressing this issue. i've seen sporadic errors that result in reconnects and this could be a reason for it.

In the test client code above I'd recommend adding tcpclient.NoDelay = true; to ensure that the 2 calls 2 Send don't get combined by the networking layer.

[honfika]

Please try the latest beta package.

[gt5700]

I've tried the latest beta package in my production system, and it doesn't seem to work. I added some additional Debug code to get an understanding of what's happening. I added Debug statements in the IsConnectMethod method in HttpHelper.cs as follows... I also have some debug in the code that "feeds" the data to the proxy server (not shown here).

internal static async Task<int> IsConnectMethod(ICustomStreamReader clientStreamReader, IBufferPool bufferPool, CancellationToken cancellationToken = default)
{
    System.Diagnostics.Debug.WriteLine($"ProxyDebug: IsConnectMethod called.");
    var iRet = await startsWith(clientStreamReader, bufferPool, "CONNECT", cancellationToken);
    System.Diagnostics.Debug.WriteLine($"ProxyDebug: IsConnectMethod: startsWith returned {iRet}");
    return iRet;
}

What I found was the first debug line was emitted immediately on the Tcp connection. I then have the debug output from the code that feeds the data to the proxy, and I never get the second debug line from the above code snip....ie…I never see the return value from "startsWith", which I interpret as the startsWith method never returning.

Here's the screen snip of the debug output. You can see the call to IsConnectMethod highlighted and the fragmented data being sent with the "ClientStreamDebug" prefix.

I also added a "catch" in the try/finally in the startsWith method (writing the exception message to debug) to see if there was an exception being thrown, but I got nothing from that.

Here's the last section of "startsWith" with the exception handler added...

        // only letters
        return 0;
    }
    catch (Exception ex)
    {
        System.Diagnostics.Debug.WriteLine($"ProxyDebug: startsWith exception: {ex.Message}");
        throw;
    }
    finally
    {
        bufferPool.ReturnBuffer(buffer);
    }

I then checked the CPU utilization of the process, and it was very high. I found that for each attempted request, the process effectively consumed 100% of one of the servers logical processors. So on my 4 core server, after the 4th connection attempt, the CPU was running at 100%...

My assumption is the "startsWith" method is stuck in an infinite loop somehow.

[honfika]

Please try the latest beta. And if it is still not OK, then pelase add a logging to this line:

[gt5700]

Latest beta seems to have fixed the issue. Awesome :) Thanks.

I was also working on a fix from my side. I added an additional layer of buffering to force at least 10 bytes to be available before sending to the web proxy. I am hoping for some advice on this, as my knowledge/experience of the HTTP protocol (or lack of) to this low level makes me nervous about doing this. I don't know if I can apply this approach to every connection, and I don't know if "Keep-Alive" connections will cause issues.

My small "buffering layer" is not interpreting the contents of the stream....it's just holding the stream back until at least 10 bytes have been collected. After that, it transparently pipes all data though.

I think it should be ok because I believe all HTTP connections should have at least 10 bytes.

And for Keep-Alives, perhaps that is not relevant for the CONNECT method, because they would not be re-used for a second HTTP request anyhow.

For non-CONNECT methods, if there is a second request, that would be passed to the web proxy as normal, and it would be up to the web proxy to handle possible fragmentation again.

Now that you have fixed the web proxy, I'm not sure if I should leave my fix in place too.