none
HTTP connection idles out then times out when running more HttpClient.GetAsync() parallel tasks than ServicePointManager.DefaultConnectionLimit RRS feed

  • Question

  • Hi,

    This is a tough one, so please bear with me a bit (and please try the code) ;)

    Part of a bigger project, I need to locally download many images from different photo servers. To do so, I created 10 parallel tasks using `await`/`async`. In testing, I started to experience `TaskCancelledException` with Facebook, regardless of the HttpClient timeout (10s, 100s or 200s, no difference). I managed to create a small program to reproduce the problem (see below).

    I download 15 images with 10 tasks in parallel, but `ServicePointManager.DefaultConnectionLimit` is set to its default value of 2. So, HTTP request queuing is expected and tough this could lead to `TaskCancelledException` if `queue time + time to download the image > timeout`, but that's not the case here. The problem is that HTTP connections are, at one point, no longer reused, but remain `ESTABLISHED` and are only released after the `HttpClient` timeout. Then, new connections are created and the old ones are sent in `FIN_WAIT_2` for some time.

    If `ServicePointManager.DefaultConnectionLimit` is set the number of parallel tasks (to avoid HTTP Queuing), than HTTP connections are properly handled and reused and only the proper amount of HTTP connections are created and closed (i.e. after usage, they are not stuck in `FIN_WAIT_2`.

    I ran the my test app with an `HttpClient` timeout of 200s and ran `netstat` and a Wireshark trace. We clearly see a 200s idle time before a `FIN` is sent by the client, then the `netstat` shows 4 connections:

    Filter = (ip.dst == 31.13.80.12 || ip.src == 31.13.80.12) && !icmp

    ... 1360 4.308394 192.168.35.92 31.13.80.12 TCP 54 60439 → 443 [ACK] Seq=1872 Ack=259995 Win=135168 Len=0 1362 4.309961 31.13.80.12 192.168.35.92 TLSv1.2 63 Application Data 1363 4.309969 192.168.35.92 31.13.80.12 TCP 54 60438 → 443 [ACK] Seq=1679 Ack=259996 Win=135168 Len=0 6946 204.172439 192.168.35.92 31.13.80.12 TCP 54 60438 → 443 [FIN, ACK] Seq=1679 Ack=259996 Win=135168 Len=0 6947 204.172443 192.168.35.92 31.13.80.12 TCP 54 60439 → 443 [FIN, ACK] Seq=1872 Ack=259995 Win=135168 Len=0 6948 204.173143 192.168.35.92 31.13.80.12 TCP 66 60493 → 443 [SYN] Seq=0 Win=64240 Len=0 MSS=1460 WS=256 SACK_PERM=1 ...

    C:\> netstat -ano | findstr 31.13.80.12
      TCP    192.168.35.92:60438    31.13.80.12:443        ESTABLISHED     39968
      TCP    192.168.35.92:60439    31.13.80.12:443        ESTABLISHED     39968
    
    C:\> netstat -ano | findstr 31.13.80.12
      TCP    192.168.35.92:60438    31.13.80.12:443        FIN_WAIT_2      39968
      TCP    192.168.35.92:60439    31.13.80.12:443        FIN_WAIT_2      39968
      TCP    192.168.35.92:60440    31.13.80.12:443        ESTABLISHED      39968
      TCP    192.168.35.92:60441    31.13.80.12:443        ESTABLISHED      39968

    If I increase the total number of downloads the patterns repeats: connections are reused for a bit, then idle time, `TaskCancelledException` and new connections are created.

    Now, I've (unfortunately) only been able to reproduce with the Facebook CDN, so we could be inclined to think that it's a problem with Facebook, but if I set the number of concurrent connections to the same amount of parallel tasks, I can download hundred of images without any issue. It really appears that the HTTP queuing is the determining factor here.

    A potential workaround could be to set `HttpClient.DefaultRequestHeaders.ConnectionClose = true;`, but that's not recommended because I want to reuse the connection as much as possible.

    Do you have any idea what is going on here? Any idea what is happening that brings the HTTP connection to a stop, but only if HTTP queuing occurs?

    Below is the sample program is used to reproduce the problem, you can play with the number of tasks and download and uncomment the number of default connection to see that the problem disappears. 

    using System;
    using System.Collections.Concurrent;
    using System.Diagnostics;
    using System.Linq;
    using System.Net;
    using System.Net.Http;
    using System.Threading;
    using System.Threading.Tasks;
    
    namespace HttpClientFreezeBug
    {
    	class Program
    	{
    		private const int TotalTasks = 15;
    		private const int ParallelTasks = 10;
    		private static readonly TimeSpan HttpTimeout = TimeSpan.FromSeconds(10);
    
    		private static readonly string[] Urls = {
    			"https://scontent.xx.fbcdn.net/v/t31.0-0/p480x480/27164234_563426177350571_7138880092018594550_o.jpg?oh=9e545e3fd171d042ff4b75d4ffbc0b0e&oe=5B21363E" // 63563 bytes = PROBLEM
    			//"https://scontent.xx.fbcdn.net/v/t1.0-0/p320x320/26994227_563416774018178_2008476143013052807_n.jpg?oh=55f7f47df2a95edceab83c6d6f04c0e6&oe=5B090834" // 17984 bytes = OK
    		};
    
    		private static readonly ConcurrentQueue<string> Outputs = new ConcurrentQueue<string>();
    		private static HttpClient _httpClient;
    
    		static void Main()
    		{
    			var sw = new Stopwatch();
    			sw.Start();
    			var results = Run().GetAwaiter().GetResult();
    			Console.WriteLine(results);
    			Console.WriteLine($"Total time: {sw.ElapsedMilliseconds} ms");
    		}
    
    		private static async Task<string> Run()
    		{
    			ServicePointManager.Expect100Continue = false;
    			//ServicePointManager.DefaultConnectionLimit = ParallelTasks;
    
    			_httpClient = new HttpClient { Timeout = HttpTimeout };
    			//_httpClient.DefaultRequestHeaders.ConnectionClose = true;
    
    			var sem = new SemaphoreSlim(ParallelTasks);
    			using (_httpClient)
    			{
    				var swWhole = new Stopwatch();
    				swWhole.Start();
    
    				var cancellationTokenSource = new CancellationTokenSource();
    				var token = cancellationTokenSource.Token;
    				var tasks = Enumerable.Range(0, TotalTasks).Select(async idx =>
    				{
    					var sw = new Stopwatch();
    					long startTime = -1;
    
    					try
    					{
    						await sem.WaitAsync().ConfigureAwait(false);
    
    						sw.Start();
    						startTime = swWhole.ElapsedMilliseconds;
    						if (token.IsCancellationRequested)
    						{
    							Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} cancelled from token");
    							return;
    						}
    						var contentLength = await RunOnce(idx).ConfigureAwait(false);
    						Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} finished reading {contentLength} bytes");
    					}
    					catch (Exception ex)
    					{
    						Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} threw {ex.Message}");
    						//cancellationTokenSource.Cancel();
    					}
    					finally
    					{
    						sem.Release();
    					}
    				});
    
    				await Task.WhenAll(tasks).ConfigureAwait(false);
    				return string.Join("\n", Outputs);
    			}
    		}
    
    		private static async Task<long> RunOnce(int idx)
    		{
    			await Task.Delay(0);
    
    			var url = new Uri(Urls[idx % Urls.Length]);
    
    			using (var response = await _httpClient.GetAsync(url).ConfigureAwait(false))
    			{
    				if (!response.IsSuccessStatusCode)
    					throw new Exception($"Received: {response.StatusCode} - {response.ReasonPhrase} - {response.RequestMessage}");
    
    				using(response.Content)
    				using (var content = await response.Content.ReadAsStreamAsync().ConfigureAwait(false))
    				{
    					return content.Length;
    				}
    			}
    		}
    	}
    }






    • Edited by dstj Monday, February 19, 2018 9:48 PM Clarification
    Saturday, February 17, 2018 9:42 PM

All replies

  • Hi dstj,

    For your issue, I suggest you make a test with code below to check whether it meets your requirement.

        class Program
        {
            private const int TotalTasks = 15;
            private const int ParallelTasks = 10;
            private static readonly TimeSpan HttpTimeout = TimeSpan.FromSeconds(10);
    
            private static readonly string[] Urls = {
                "https://scontent.xx.fbcdn.net/v/t31.0-0/p480x480/27164234_563426177350571_7138880092018594550_o.jpg?oh=9e545e3fd171d042ff4b75d4ffbc0b0e&oe=5B21363E" // 63563 bytes = PROBLEM
    			//"https://scontent.xx.fbcdn.net/v/t1.0-0/p320x320/26994227_563416774018178_2008476143013052807_n.jpg?oh=55f7f47df2a95edceab83c6d6f04c0e6&oe=5B090834" // 17984 bytes = OK
    		};
    
            private static readonly ConcurrentQueue<string> Outputs = new ConcurrentQueue<string>();
            private static HttpClient _httpClient;
    
            static void Main()
            {
                var sw = new Stopwatch();
                sw.Start();
                var results = Run().GetAwaiter().GetResult();
                Console.WriteLine(results);
                Console.WriteLine($"Total time: {sw.ElapsedMilliseconds} ms");
                Console.ReadLine();
            }
    
            private static async Task<string> Run()
            {
                ServicePointManager.Expect100Continue = false;
                //ServicePointManager.DefaultConnectionLimit = ParallelTasks;
    
                //_httpClient = new HttpClient { Timeout = HttpTimeout };
                ////_httpClient.DefaultRequestHeaders.ConnectionClose = true;
    
                var sem = new SemaphoreSlim(ParallelTasks);
                //using (_httpClient)
                //{
                    var swWhole = new Stopwatch();
                    swWhole.Start();
    
                    var cancellationTokenSource = new CancellationTokenSource();
                    var token = cancellationTokenSource.Token;
                    var tasks = Enumerable.Range(0, TotalTasks).Select(async idx =>
                    {
                        var sw = new Stopwatch();
                        long startTime = -1;
    
                        try
                        {
                            await sem.WaitAsync().ConfigureAwait(false);
    
                            sw.Start();
                            startTime = swWhole.ElapsedMilliseconds;
                            if (token.IsCancellationRequested)
                            {
                                Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} cancelled from token");
                                return;
                            }
                            var contentLength = await RunOnce(idx).ConfigureAwait(false);
                            Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} finished reading {contentLength} bytes");
                        }
                        catch (Exception ex)
                        {
                            Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} threw {ex.Message}");
                            //cancellationTokenSource.Cancel();
                        }
                        finally
                        {
                            sem.Release();
                        }
                    });
    
                    await Task.WhenAll(tasks).ConfigureAwait(false);
                    return string.Join("\n", Outputs);
                //}
            }
    
            private static async Task<long> RunOnce(int idx)
            {
                await Task.Delay(0);
    
                var url = new Uri(Urls[idx % Urls.Length]);
                _httpClient = new HttpClient { Timeout = HttpTimeout };
                using (var response = await _httpClient.GetAsync(url).ConfigureAwait(false))
                {
                    if (!response.IsSuccessStatusCode)
                        throw new Exception($"Received: {response.StatusCode} - {response.ReasonPhrase} - {response.RequestMessage}");
    
                    using (response.Content)
                    using (var content = await response.Content.ReadAsStreamAsync().ConfigureAwait(false))
                    {
                        return content.Length;
                    }
                }
            }
        }
    

    Best Regards,

    Tao Zhou


    MSDN Community Support
    Please remember to click "Mark as Answer" the responses that resolved your issue, and to click "Unmark as Answer" if not. This can be beneficial to other community members reading this thread. If you have any compliments or complaints to MSDN Support, feel free to contact MSDNFSF@microsoft.com.

    Thursday, February 22, 2018 3:00 AM
  • Hi Tao,

    Thanks a lot for your reply. So you're suggesting creating a new HttpClient for every request. For the record, it does "avoid" the problem, but I've seen numerous references saying that this is not the proper way to use HttpClient, including this MSDN blog and Microsoft's official documentation saying:

    HttpClient is intended to be instantiated once and re-used throughout the life of an application. The following conditions can result in SocketException errors:

    * Creating a new HttpClient instance per request.
    * Server under heavy load.

    So even though your suggestion does "work" in my sample, it is not a solution for a real-life application.

    Tuesday, February 27, 2018 2:16 PM
  • Hi dstj,

    >> https://scontent.xx.fbcdn.net

    Is this your server? I made a test again with these code, and find exception did not happen again. Did you change anything?

    >> If I increase the total number of downloads the patterns repeats: connections are reused for a bit, then idle time, `TaskCancelledException` and new connections are created.

    How did you check the connections are reused?

    In addition, if you dispose the httpclient after the request is finished, I think it would not cause the SocketException.

    Best Regards,

    Tao Zhou


    MSDN Community Support
    Please remember to click "Mark as Answer" the responses that resolved your issue, and to click "Unmark as Answer" if not. This can be beneficial to other community members reading this thread. If you have any compliments or complaints to MSDN Support, feel free to contact MSDNFSF@microsoft.com.

    Wednesday, February 28, 2018 5:19 AM
  • Hi Tao,

    No, https://scontent.xx.fbcdn.net is the Facebook CDN. I still have the problem with a little as 15 total tasks and 10 in parallel (2 downloads fail with the TaskCancelledException due to the problem mention above).

    I cannot dispose the HttpClient after each request, because that would mean I need to create a new one after and that would against Microsoft recommendations in the article I listed.

    Using "netstat -ano", you see if connections are left in the FIN_WAIT_2 state and using Wireshark and counting the SSL handshakes (i.e. Client Hello), I could see that connections are reused or not (if "Nb Client Hello" < "Nb Requests", than connections are reused). Normally, you should see the same number of Client Hellos as ServicePointManager.DefaultConnectionLimit.

    Thanks.

    Thursday, March 1, 2018 6:26 PM
  • Hi dstj,

    I still fail to reproduce your issue.

    Is there any missing in my code below?

        class Program
        {
            private const int TotalTasks = 15;
            private const int ParallelTasks = 10;
            private static readonly TimeSpan HttpTimeout = TimeSpan.FromSeconds(10);
    
            private static readonly string[] Urls = {
                "https://scontent.xx.fbcdn.net/v/t31.0-0/p480x480/27164234_563426177350571_7138880092018594550_o.jpg?oh=9e545e3fd171d042ff4b75d4ffbc0b0e&oe=5B21363E" // 63563 bytes = PROBLEM
    			,"https://scontent.xx.fbcdn.net/v/t1.0-0/p320x320/26994227_563416774018178_2008476143013052807_n.jpg?oh=55f7f47df2a95edceab83c6d6f04c0e6&oe=5B090834" // 17984 bytes = OK
    		};
    
            private static readonly ConcurrentQueue<string> Outputs = new ConcurrentQueue<string>();
            private static HttpClient _httpClient;
    
            static void Main()
            {
                var sw = new Stopwatch();
                sw.Start();
                var results = Run().GetAwaiter().GetResult();
                Console.WriteLine(results);
                Console.WriteLine($"Total time: {sw.ElapsedMilliseconds} ms");
                Console.ReadLine();
            }
            private void Test()
            {
                var th = new Thread(ExecuteInForeground);
                th.Start();
                th.Join();
            }
            private static void ExecuteInForeground()
            {
                //clrnative2.CLRClass myObject = new clrnative2.CLRClass();
                Thread.Sleep(15000);
            }
            private static async Task<string> Run()
            {
                ServicePointManager.Expect100Continue = false;
                ServicePointManager.DefaultConnectionLimit = ParallelTasks;
    
                _httpClient = new HttpClient { Timeout = HttpTimeout };
                //_httpClient.DefaultRequestHeaders.ConnectionClose = true;
    
                var sem = new SemaphoreSlim(ParallelTasks);
                using (_httpClient)
                {
                    var swWhole = new Stopwatch();
                    swWhole.Start();
    
                    var cancellationTokenSource = new CancellationTokenSource();
                    var token = cancellationTokenSource.Token;
                    var tasks = Enumerable.Range(0, TotalTasks).Select(async idx =>
                    {
                        var sw = new Stopwatch();
                        long startTime = -1;
    
                        try
                        {
                            await sem.WaitAsync().ConfigureAwait(false);
    
                            sw.Start();
                            startTime = swWhole.ElapsedMilliseconds;
                            if (token.IsCancellationRequested)
                            {
                                Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} cancelled from token");
                                return;
                            }
                            var contentLength = await RunOnce(idx).ConfigureAwait(false);
                            Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} TaskID {Thread.CurrentThread.ManagedThreadId} finished reading {contentLength} bytes");
                        }
                        catch (Exception ex)
                        {
                            Outputs.Enqueue($"{startTime} {sw.ElapsedMilliseconds} ms - Task {idx} threw {ex.Message}");
                            //cancellationTokenSource.Cancel();
                        }
                        finally
                        {
                            sem.Release();
                        }
                    });
    
                    await Task.WhenAll(tasks).ConfigureAwait(false);
                    return string.Join("\n", Outputs);
                }
            }
    
            private static async Task<long> RunOnce(int idx)
            {
                await Task.Delay(0);
    
                var url = new Uri(Urls[idx % Urls.Length]);
    
                using (var response = await _httpClient.GetAsync(url).ConfigureAwait(false))
                {
                    if (!response.IsSuccessStatusCode)
                        throw new Exception($"Received: {response.StatusCode} - {response.ReasonPhrase} - {response.RequestMessage}");
    
                    using (response.Content)
                    using (var content = await response.Content.ReadAsStreamAsync().ConfigureAwait(false))
                    {
                        return content.Length;
                    }
                }
            }
    }
    

    Best Regards,

    Tao Zhou


    MSDN Community Support
    Please remember to click "Mark as Answer" the responses that resolved your issue, and to click "Unmark as Answer" if not. This can be beneficial to other community members reading this thread. If you have any compliments or complaints to MSDN Support, feel free to contact MSDNFSF@microsoft.com.

    Monday, March 5, 2018 2:43 AM
  • Hi again Tao,

    You have uncommented more URL than my version in the original post. But play with the number of total parallel tasks (put 200 for example), play with the timeout (put 200s for example). You should see the error clearly.

    The output should look like this, note the two "Task X threw A task was canceled."

    3 104 ms - Task 0 finished reading 63563 bytes
    24 84 ms - Task 7 finished reading 63563 bytes
    24 102 ms - Task 6 finished reading 63563 bytes
    23 104 ms - Task 2 finished reading 63563 bytes
    24 113 ms - Task 4 finished reading 63563 bytes
    23 115 ms - Task 3 finished reading 63563 bytes
    23 127 ms - Task 1 finished reading 63563 bytes
    24 129 ms - Task 5 finished reading 63563 bytes
    24 10003 ms - Task 9 threw A task was canceled.
    24 10003 ms - Task 8 threw A task was canceled.
    107 9975 ms - Task 10 finished reading 63563 bytes
    108 9975 ms - Task 11 finished reading 63563 bytes
    128 9973 ms - Task 13 finished reading 63563 bytes
    126 9977 ms - Task 12 finished reading 63563 bytes
    137 9980 ms - Task 14 finished reading 63563 bytes
    Total time: 10167 ms

    Tuesday, March 6, 2018 2:18 PM
  • Hi dstj,

    I have made a test with commenting the second URL, ParallelTasks as 200, and HttpTimeout as 200, I still fail to reproduce your issue.

    In general, the Official site will limit the number of request every second to avoid attack.

    I suggest you make a test with another computer.

    In addition, I have rechecked your issue and I am afraid there is no better way to resolve your current issue than recreating new HttpClient.

    Best Regards,

    Tao Zhou


    MSDN Community Support
    Please remember to click "Mark as Answer" the responses that resolved your issue, and to click "Unmark as Answer" if not. This can be beneficial to other community members reading this thread. If you have any compliments or complaints to MSDN Support, feel free to contact MSDNFSF@microsoft.com.

    Wednesday, March 7, 2018 1:55 AM
  • My apologies, but unfortunately, a suggestion that goes against Microsoft's own recommendations is not a viable solution...

    I did try an another computer and also got the same error. So that's interesting, it might be a .NET version issue.

    What .NET version did you run it on? I tried .NET 4.7.1 and the early access 4.7.2

    Wednesday, March 7, 2018 5:41 PM
  • I am testting with .NET 4.6.1.

    MSDN Community Support
    Please remember to click "Mark as Answer" the responses that resolved your issue, and to click "Unmark as Answer" if not. This can be beneficial to other community members reading this thread. If you have any compliments or complaints to MSDN Support, feel free to contact MSDNFSF@microsoft.com.

    Thursday, March 8, 2018 1:31 AM
  • Hi dstj,

    Thanks for this post, I have been fighting with a very similar issue for a few days, until your post points me to the right direction. 

    In my app a static httpclient instance calls an REST API periodically. If the interval is short, say every 30 seconds, the API call is fast, takes less than 1 second. But if the interval is longer like 2 mins, except the first call, every following API call takes about 100 seconds. From your network trace now I know it is because the http connection is re-created after the httpclient default timeout. The reason of the timeout for my case is not on client end, it is caused by NETWORK. I tested in different wifi network, the problem only happens for certain networks, e.g. it happens when use my office network or my cell phone hot spot, but never with my home wifi. It a sort of makes sense, the device constantly connects to the same wifi, and the http connection in the app's httpclient stays "established" after the first use. However the router might lost/close the socket connection to the remote API server in a short time depends on the router settings. It is something in the middle between the device and the API server broken, but the httpclient doesn't know about it, it still keeps the http connection as "established" until the request is timeout and create a new connection.

    I agree with you that creating new httpclient is not a viable solution. I use the workaround you mentioned in the post as the fix, set DefaultRequestHeaders.ConnectionClose = true.

    Hope it helps. Would be interesting to know if the root cause for your case is the NETWORK.

    Regards,

    lizimu



    • Edited by lizimu Wednesday, September 5, 2018 4:25 AM
    Wednesday, September 5, 2018 4:19 AM