Search code examples
c#flaskhttprequestuwsgi.net-4.8

A task was canceled on the await call (POST) due to timeout when response from server (Python flask) is too quick


UPDATE 3: After reading this answer to a different post, I started a different experiment. If I change the answer coming from the Python (flask) server to 100, I can reproduce the error in my computer. In this case, all the calls get cancelled due to time out. So this made me thing about adding a delay in the API before sending back a 200. After adding 100 milliseconds of delay, now every single call gets completed. Calls that originally took 9 milliseconds, now are taking 109 milliseconds but are not Canceled anymore. They get RanToCompletion I ran this program simultaneously 15 times, and all the calls await correctly if the 100 miliseconds delay is in place before the API response. Without the delay, even running it once will result in many of the 10 calls being Cancelled. Still don't understand what's causing this.

UPDATE 2: I think I am into somethig now. I have created a much simpler program:

public class Program
{
    private static HttpClient client;
    public static async Task Main()
    {
        client = new HttpClient();
        client.Timeout = TimeSpan.FromSeconds(10);
        client.DefaultRequestHeaders.Add("Authorization", $"Basic {Convert.ToBase64String(Encoding.UTF8.GetBytes("someuser:somepass"))}");
        client.DefaultRequestHeaders.Accept.Add(new MediaTypeWithQualityHeaderValue("application/json"));
        client.DefaultRequestHeaders.Add("X-Requested-With", "XMLHttpRequest");

        for (int i = 0; i < 10; i++)
        {
            await PostSomething(i.ToString()).ContinueWith(x=> log(x.Status.ToString(), "0"));
        }
    }

    public static async Task<HttpResponseMessage> PostSomething(string tower)
    {
        var RequestUri = new Uri("someAPI");
        string json = "somejson";    
        var msg = new StringContent(json, Encoding.UTF8, "application/json");
        return
            await client.PostAsync(RequestUri, msg);
    }


    public static void log(string line, string where)
    {
        string logPath = $"{Path.GetDirectoryName(Application.ExecutablePath)}\\log";
        if (!Directory.Exists(logPath))
        {
            Directory.CreateDirectory(logPath);
        }
        string mnth = $"{logPath}\\" + DateTime.Now.ToString("yyyyMM") + "-" + where + ".txt";
        string time = Environment.NewLine + DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss");
        File.AppendAllText(mnth, time + " " + line);
    }
}

Which runs absolutelly normal in my computer:

Run 1:
    2022-11-30 11:27:33 RanToCompletion
    2022-11-30 11:27:33 RanToCompletion
    2022-11-30 11:27:33 RanToCompletion
    2022-11-30 11:27:33 RanToCompletion
    2022-11-30 11:27:33 RanToCompletion
    2022-11-30 11:27:33 RanToCompletion
    2022-11-30 11:27:33 RanToCompletion
    2022-11-30 11:27:34 RanToCompletion
    2022-11-30 11:27:34 RanToCompletion
    2022-11-30 11:27:34 RanToCompletion

Run 2:    
    2022-11-30 11:27:46 RanToCompletion
    2022-11-30 11:27:47 RanToCompletion
    2022-11-30 11:27:47 RanToCompletion
    2022-11-30 11:27:47 RanToCompletion
    2022-11-30 11:27:47 RanToCompletion
    2022-11-30 11:27:47 RanToCompletion
    2022-11-30 11:27:47 RanToCompletion
    2022-11-30 11:27:47 RanToCompletion
    2022-11-30 11:27:47 RanToCompletion
    2022-11-30 11:27:48 RanToCompletion

 Run 3:   
    2022-11-30 11:27:57 RanToCompletion
    2022-11-30 11:27:58 RanToCompletion
    2022-11-30 11:27:58 RanToCompletion
    2022-11-30 11:27:58 RanToCompletion
    2022-11-30 11:27:58 RanToCompletion
    2022-11-30 11:27:58 RanToCompletion
    2022-11-30 11:27:58 RanToCompletion
    2022-11-30 11:27:58 RanToCompletion
    2022-11-30 11:27:58 RanToCompletion
    2022-11-30 11:27:59 RanToCompletion

However, when I run the program multiple times in one of the computers I am having trouble with, the result varies:

Run 1:
    2022-11-30 03:19:26 RanToCompletion
    2022-11-30 03:19:36 Canceled
    2022-11-30 03:19:46 Canceled
    2022-11-30 03:19:56 Canceled
    2022-11-30 03:20:06 Canceled
    2022-11-30 03:20:16 Canceled
    2022-11-30 03:20:26 Canceled
    2022-11-30 03:20:28 RanToCompletion
    2022-11-30 03:20:38 Canceled

Run 2:    
    2022-11-30 03:22:55 RanToCompletion
    2022-11-30 03:23:05 Canceled
    2022-11-30 03:23:15 Canceled
    2022-11-30 03:23:25 Canceled
    2022-11-30 03:23:27 RanToCompletion
    2022-11-30 03:23:28 RanToCompletion
    2022-11-30 03:23:38 Canceled
    2022-11-30 03:23:48 Canceled
    2022-11-30 03:23:57 RanToCompletion
    2022-11-30 03:23:58 RanToCompletion

Run 3:   
    2022-11-30 03:29:43 RanToCompletion
    2022-11-30 03:29:44 RanToCompletion
    2022-11-30 03:29:54 Canceled
    2022-11-30 03:29:57 RanToCompletion
    2022-11-30 03:29:57 RanToCompletion
    2022-11-30 03:30:07 Canceled
    2022-11-30 03:30:17 Canceled
    2022-11-30 03:30:19 RanToCompletion
    2022-11-30 03:30:29 Canceled
    2022-11-30 03:30:39 Canceled
 
Run 4:   
    2022-11-30 03:35:57 Canceled
    2022-11-30 03:36:07 Canceled
    2022-11-30 03:36:17 Canceled
    2022-11-30 03:36:19 RanToCompletion
    2022-11-30 03:36:20 RanToCompletion
    2022-11-30 03:36:30 Canceled
    2022-11-30 03:36:39 RanToCompletion
    2022-11-30 03:36:49 Canceled
    2022-11-30 03:36:59 Canceled
    2022-11-30 03:37:01 RanToCompletion

For all those http requests, I can see on the server that they all came back 200.
How come some of those tasks weren't ran to completion? Where could I find more details about this?
They get canceled after 10 seconds, which is the set timeout on the HttpClient. But why a timeout? The request got back 200, so how can it timeout?


UPDATE 1: I have tried different methods, but it fails really often when awaiting for the http response. I could do 100 calls to the api, all of them will get through and POST correctly. However, if I await for the response in order to write this to a file, for example, it will fail sometimes after the first call is back, sometimes after the second, sometimes won't even get the first response back. Again, this doesn't happen ob my PC, only in some other PCs (Windows 10, Windows 7).

I tried:

for (int i = 0; i < 10; i++)
{
    var res4 = await PostAsync(i.ToString());   
    log(res4 + " in loop", "4"); 
}

public static async Task<string> PostAsync(string num)
{
    var httpClient = new HttpClient();
    ...some http header, uri,json...
    var msg = new StringContent(json, Encoding.UTF8, "application/json");
    //This next line is when it usually fails. I have tried without ConfigureAwait(false) too
    var resp = await httpClient.PostAsync(RequestUri, msg).ConfigureAwait(false);
    log($"POST Awaited {num}", "1");
    //I tried both with ConfigureAwait(false) and without
    var resp2 = await resp.Content.ReadAsStringAsync().ConfigureAwait(false);
    log($"Read Awaited {num}", "1");
    return resp2;
}


public static void log(string line, string where)
{
    string logPath = $"{Path.GetDirectoryName(Application.ExecutablePath)}\\log";
    if (!Directory.Exists(logPath))
    {
        Directory.CreateDirectory(logPath);
    }
    string mnth = $"{logPath}\\" + DateTime.Now.ToString("yyyyMM") + "-" + where + ".txt";
    string time = Environment.NewLine + DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss");
    File.AppendAllText(mnth, time + " " + line);
}



Original question:

As sugested by @Jodrell, I have tried a more appropriate approach. Now I have a class:

public class BaseApiController
{
    protected async Task<string> AsyncAwait_GetSomeDataAsync()
    {
        var httpClient = new HttpClient();
        httpClient.DefaultRequestHeaders.Add("Authorization", $"Basic {Convert.ToBase64String(Encoding.UTF8.GetBytes("someuser:somepass"))}");
        httpClient.DefaultRequestHeaders.Accept.Add(new MediaTypeWithQualityHeaderValue("application/json"));
        httpClient.DefaultRequestHeaders.Add("X-Requested-With", "XMLHttpRequest");
        var RequestUri = new Uri("someserver", "someAPI");

        string json = "somejson";

        var msg = new StringContent(json, Encoding.UTF8, "application/json");
        var result = await httpClient.PostAsync(RequestUri, msg);

        return result.ToString();
    }
}

Then I have:

public class TestController: BaseApiController
{
    public async Task<string> Post()
    {
        var data = await AsyncAwait_GetSomeDataAsync();

        return data;
    }
}

And a function that writes into a file:

private static async Task logASync(string line, string where)
{
    string logPath = $"{Path.GetDirectoryName(Application.ExecutablePath)}\\log";
    string path = $"{logPath}\\" + DateTime.Now.ToString("yyyyMM") + "-" + where + ".txt";

    if (string.IsNullOrWhiteSpace(path))
        throw new ArgumentOutOfRangeException(nameof(path), path, "Was null or whitepsace.");

    //If doesn't exist, CreateDirectory does nothing
    Directory.CreateDirectory(logPath);

    using (var file = File.Open(path, FileMode.Append, FileAccess.Write))
    using (var writer = new StreamWriter(file))
    {
        //Do we need ConfigureAwait?
        await writer.WriteLineAsync(line).ConfigureAwait(false);
        await writer.FlushAsync();
    }
}

And I call them like:

TestController testController = new TestController();
var res1 = await testController.Post();
await logASync("Some message", "1");
Thread.Sleep(100);
var res2 = await testController.Post();
await logASync("Some message", "1");
Thread.Sleep(100);
var res3 = await testController.Post();
await logASync("Some message", "1");
Thread.Sleep(100);

Again, this works perfectly in my computer. File gets created if doesn't exits, and 3 times "Some message" appears in the file. However, when I do this in a different computer, only the first message and call are successfully performed. Then I get this exception:

2022-11-29 01:06:24 System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at TestRequest.BaseApiController.<AsyncAwait_GetSomeDataAsync>d__1.MoveNext() in line 178
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at TestRequest.TestController.<Post>d__0.MoveNext() in line 230
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at TestRequest.Program.<Main>d__0.MoveNext() in line 44

line 178 is:

var result = await httpClient.PostAsync(RequestUri, msg);

line 230 is:

var data = await AsyncAwait_GetSomeDataAsync();

line 44 is:

var res2 = await testController.Post();

I don't understand why this is working in my computer but not in several other computers. I am using the same VPN they are using. Is this related to I/O? Is there anything I can do in Windows to get more information about why this is happening?

I have also tried writing each time in a different file like:

TestController testController = new TestController();
var res1 = await testController.Post();
await logASync("Some message", "1");
Thread.Sleep(100);
var res2 = await testController.Post();
await logASync("Some message", "2");
Thread.Sleep(100);
var res3 = await testController.Post();
await logASync("Some message", "3");
Thread.Sleep(100);

but the same happens.


Solution

  • Error localization

    HTTP uses TCP in order to transfer information, which in turn uses the syn / ack / syn-ack handshake.



    Error Description

    This means that when you send something, you wait the server to acknowledge the data that was sent, and then the server acknowledges you that the data was received. This means that your error occurs during the ack and/or syn-ack stage. This means that the receiver is either receiving the data and does not reply, which is extremely improbable, or the receiver isn't receiving the data at all or it received the data partially. This is because you are sending the data on a stream and streams don't have 100% guaranteed chances of success in their operations. The reason why, is because you are sending packets(which are some glorified chunks of binary data) on a stream(a glorified channel) that is using a protocol named HTTP which in turn uses TCP for data transmission and a fail safe mechanisms, and through which the packets sent could reach the destination intact, fragmented, or do not reach the destination at all. This is caused by the fact that the receiving or sending buffers of either the receiver or the sender, can be filled with bytes form previous requests that either the receiver or the sender can still process at the moment, making either the sender or the receiver drop the packets of its current HTTP get or post session, respectively. Another cause could be a combination of fluctuations within the data transmission speed of the network and the size of the packets sent, resulting again in either the sender or the receiver dropping the packets.

    enter image description here




    As you can see in the image above, 4 packets were sent, and from those 4, only 2 reached their destination. I used Cisco Packet Tracer, a network simulation software used for developing networks and other network engineering/backend engineering related tasks, for the scenario shown above.



        protected async Task<string> AsyncAwait_GetSomeDataAsync()
        {
            var httpClient = new HttpClient();
            httpClient.DefaultRequestHeaders.Add("Authorization", $"Basic {Convert.ToBase64String(Encoding.UTF8.GetBytes("someuser:somepass"))}");
            httpClient.DefaultRequestHeaders.Accept.Add(new MediaTypeWithQualityHeaderValue("application/json"));
            httpClient.DefaultRequestHeaders.Add("X-Requested-With", "XMLHttpRequest");
            var RequestUri = new Uri("someserver", "someAPI");
    
            string json = "somejson";
    
            var msg = new StringContent(json, Encoding.UTF8, "application/json");
            var result = await httpClient.PostAsync(RequestUri, msg);
    
            return result.ToString();
        }
    
    


    The reason why you get the below displayed error message is a combination of multiple factors.

       2022-11-29 01:06:24 System.Threading.Tasks.TaskCanceledException: A task was canceled.
       at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
       at TestRequest.BaseApiController.<AsyncAwait_GetSomeDataAsync>d__1.MoveNext() in line 178 
    


    Causes Within The Implementation

    1. You implemented the Task with the assumption that you will get a response every time, and as I shown earlier, packets could not be sent successfully 100% of the times, every time. Each time you send payloads, they have a certain degree of success depending on the situations, not a guaranteed chance of success.
        var msg = new StringContent(json, Encoding.UTF8, "application/json");
        var result = await httpClient.PostAsync(RequestUri, msg);
    
        return result.ToString();
    

    In the above shown section of the code you save the response value in a variable, and then return the result of the httpClient.PostAsync(RequestUri, msg); directly. This approach is wrong, because, as I mentioned before, payload transmission procedures can fail. It is not a guaranteed chance that the payload will be received/transmitted. A fix for this issue is to set a string variable that holds an error message as the return value and change its value if the httpClient.PostAsync(RequestUri, msg); succeeds.


        protected async Task<string> AsyncAwait_GetSomeDataAsync()
        {
            string return_value = "DESIRED ERROR MESSAGE";      
    
            var httpClient = new HttpClient();
            httpClient.DefaultRequestHeaders.Add("Authorization", $"Basic {Convert.ToBase64String(Encoding.UTF8.GetBytes("someuser:somepass"))}");
            httpClient.DefaultRequestHeaders.Accept.Add(new MediaTypeWithQualityHeaderValue("application/json"));
            httpClient.DefaultRequestHeaders.Add("X-Requested-With", "XMLHttpRequest");
            var RequestUri = new Uri("someserver", "someAPI");
    
            string json = "somejson";
    
            var msg = new StringContent(json, Encoding.UTF8, "application/json");
            var result = await httpClient.PostAsync(RequestUri, msg);
    
            if(result != null)
            {
               return_value = result.ToString();
            }
    
            return return_value ;
        }
    
    


    1. You need to increase the receive and/or send buffer sizes, https://www.ibm.com/docs/en/was/9.0.5?topic=environment-tuning-tcpip-buffer-sizes. A large buffer size means less chance for factors, such as network speed fluctuations and packets that were not sent/received on time and dropped to occur, due to the fact that more packet slots are available, and thus more packets can be sent and/or received in a shorter period of time. The downside of a larger buffer size is the fact that it can make your CPU work harder, set the buffer too high and the CPU will be clogged with packages and thus, the sender or receiver will drop the packets for the current session. Tune in your receive and send buffer sizes on both the sender and recipient. Use these link to set your buffer sizes:

    https://learn.microsoft.com/en-us/dotnet/api/system.net.http.httpclient.maxresponsecontentbuffersize?view=net-6.0



    1. Another good fix is to set in your program a request retry mechanism. A mechanism like this will try a set number of times to POST and/or RECEIVE requests if failure occurs.


    As you can see, a HttpClient HTTP socket, has a single option, the option to set the buffer size related to the receive buffer of the respective socket. Try to tune in the receive buffers on both the receiver and the sender.

    If this still did not help you, I recommend using Sockets. HttpClient is an abstraction over the Socket class, and thus it is hiding complexities and processes that happen under the hood. With sockets you have greater control over what is happening and how, but also a lot of complexities that you have to deal with.



    C#: How to execute a HTTP request using sockets?