Performance issues on macOS

[kfreezen]

I'm currently having performance issues on .NET Core 2.1 on macOS.

There are no good profiling tools for .NET Core/macOS that I can find, but it appears that the problem goes all the way down to System.Net.NetworkStream

I've managed to get some times on StreamExtended.Network.CustomBufferedStream.ReadLineAsync() They vary between a fairly normal 130ms to a rather high 3000ms. The result is that sites load extremely slowly with the proxy.

Are there any optimizations that can be made to Titanium-Web-Proxy or StreamExtended to speed it up in macOS? Maybe I can get you guys more information on the macOS performance?

If you can give me some suggestions on where else to look for performance bottlenecks too, I would appreciate that.

[kfreezen]

Some more information:

I ran my application on Linux and did some profiling with the available tools. I don't have the perf report with me right now, but it looks like a large portion of the overhead is coming from BouncyCastle. I'm not sure why yet; I'll have to do more investigating on it.

[kfreezen]

Still trying to figure this one out. You have any thoughts @justcoding121 or @honfika? I'm willing to do research on it myself if one of you could point me in the right direction.

Maybe it's that I have something configured wrong in my usage of the project, I don't know.

[justcoding121]

I personally have never run the proxy in Linux or Mac. I don't have the environment setup. Sorry I can't help on this. One thing to keep in mind is that .Net core have different CLR implementations on each OSs, so it could be that some of the async delays you mentioned have something to do with .Net core itself especially because they started supporting non-Windows OSs only few years ago. Did you try running the project in Mono on Linux or MacOs? Mono in my understanding is a different implementation of CLR.

[kfreezen]

I'm still thinking about this one off and on.

I don't have a clear picture of the architecture of the system and all the potential "delays" that .NET Core might introduce.

I created a benchmark server to test socket performance on .NET core. My conclusion was that socket performance isn't really any worse on .NET Core than it is in C.

[kfreezen]

I built our filtering solution again using your proxy, and for some reason, it starts out much faster. But then, after a little bit of internet usage, the performance drops off.

@justcoding121 does the proxy have any arbitrary socket creation limits in place? I'm wondering if that's the issue I'm having.

[justcoding121]

We haven't set any limit on socket creation. I am not sure what is exactly causing the performance degradation over time. I see a high number of TCP connections in TIME_WAIT state when looking through TcpView.

This article may be worth looking about various parameters that may need tuning with trial and error.

http://hea-www.harvard.edu/~fine/Tech/addrinuse.html

[justcoding121]

I am adding links to location of relevant code that may need tuning.

Tcp server connection
https://github.com/justcoding121/Titanium-Web-Proxy/blob/master/Titanium.Web.Proxy/Network/Tcp/TcpConnectionFactory.cs#L270

Tcp client connection
https://github.com/justcoding121/Titanium-Web-Proxy/blob/master/Titanium.Web.Proxy/ProxyServer.cs#L679

And closing tcp connection.
https://github.com/justcoding121/Titanium-Web-Proxy/blob/master/Titanium.Web.Proxy/Extensions/TcpExtensions.cs#L25

[kfreezen]

I decided to wrap the ReadAsync here in a stopwatch. The output looks like this.

ReadAsync time 0ms - 8192 to read - 5 read
ReadAsync time 32ms - 8192 to read - 2335 read
ReadAsync time 24ms - 8192 to read - 279 read
ReadAsync time 132ms - 8192 to read - 1377 read
ReadAsync time 133ms - 8192 to read - 1314 read
ReadAsync time 0ms - 8192 to read - 5 read
ReadAsync time 100659ms - 8192 to read - 0 read
ReadAsync time 100660ms - 8192 to read - 0 read
ReadAsync time 26787ms - 8192 to read - 0 read
ReadAsync time 26788ms - 8192 to read - 0 read
ReadAsync time 86673ms - 8192 to read - 0 read
ReadAsync time 86673ms - 8192 to read - 0 read
ReadAsync time 86692ms - 8192 to read - 0 read
ReadAsync time 86693ms - 8192 to read - 0 read
ReadAsync time 86713ms - 8192 to read - 0 read
ReadAsync time 86708ms - 8192 to read - 0 read

I looked at this particular thing before and decided it wasn't the cause of the bottleneck, but could it possibly be?

It seems like the performance degradation is particularly noticeable on large sites like cnn.com and youtube.com. google.com search is very snappy, as is github navigation.

Maybe the above snippet doesn't affect small page loads, but does affect large page loads?

edit: I'm wondering if there's a process that's hanging because of those delayed ReadAsync() calls, but I don't know where to look to figure that out.

[justcoding121]

When you visit news sites like that they load tons of cross domain pages as part of ad services, which creates and terminates short lived tcp connections. This in turn causes a lot of connections on browser side with TIME_WAIT state. To test if its the browser that causes the delay due to socket exhaustion, you can perhaps browse from another machine when you see the degradation and see if its slow. I've added couple of parameters, TcpTimeWaitSeconds and ReuseSocket in latest master to adjust TCP_WAIT time and socket reuse option.

[justcoding121]

ReadAsync delay is not surprising to me. Since its reading from network stream with a buffer it will be quick (0 seconds) at times when data is available in buffer. But when data is not available it will wait until data is available.

https://github.com/justcoding121/StreamExtended/blob/master/StreamExtended/Network/CustomBufferedStream.cs#L181

[kfreezen]

Ya, that makes sense. The commit that references this bug, 41b0c95 is broken on Linux. It yields an ERR_EMPTY_RESPONSE on Google Chrome.

One thing I'm discovering as well, which should probably go into a different bug ticket, is that for some reason the following URLs are broken when running through the proxy.

https://app.satismeter.com/satismeter.js
https://www.gnu.org/software/wget/manual/html_node/Exit-Status.html

Do you have any diagnostics you can turn on in Titanium.Web.Proxy to see how the server request/response compares to the client request/response? Can I get that information just by using BeforeRequest / AfterResponse?

If I can't, I can build a diagnostics API and submit a PR if you're interested in that.

[justcoding121]

Can you let me know what specific line change in the referenced commit its breaking in linux?

You can create a diagnostics API, but I hope it will be written in such a way that it be creating additional delays. Inside the Session object we can add another class that would have properties with the milliseconds for each significant event throughout the life cycle.

Not sure if DateTime have enough precision. If so something like below should work as a property in SessionEventArgsBase class.

public Dictionary<string, DateTime> TimeLine { get; set; } = new Dictionary<string, DateTime>();

And then we can use it anywhere like below with various event names as key.

TimeLine.Add("Session Created", DateTime.Now);

[justcoding121]

I don't see any issues with the two urls you mentioned through the proxy in Windows.