2

Need help to understand why first request always takes longer than others. Test case: send binary data via POST request.

This is a typical picture from Azure Application Insights, firing 2 series of 4 requests, within the same minute:

Request Duration

Server side

Simply reading the binary data into byte array.

with Azure Function:

    [FunctionName("TestSpeed")]
    public static HttpResponseMessage Run([HttpTrigger(AuthorizationLevel.Anonymous, "get", "post", Route = "TestSpeed")]HttpRequestMessage req,
        Binder binder,
        ILogger log)
    {
        Stopwatch sw = new Stopwatch();
        sw.Start();

        byte[] binaryData = req.Content.ReadAsByteArrayAsync().Result;

        sw.Stop();
        
        return req.CreateResponse(HttpStatusCode.OK, $"Received {binaryData.Length} bytes. Data Read in: {sw.ElapsedMilliseconds} ms");
    }

Or with ASP.NET web app API:

public class MyController : ControllerBase
{
    private readonly ILogger<MyController> _logger;

    public MyController(ILogger<MyController> logger)
    {
        _logger = logger;
    }

    [HttpPost]
    public IActionResult PostBinary()
    {
        _logger.LogInformation(" - TestSpeed");
        var sw = new Stopwatch();
        sw.Start();

        var body = Request.Body.ToByteArray();

        sw.Stop();
        return Ok($"Received {body.Length} bytes. Data Read in: {sw.ElapsedMilliseconds} ms");
    }
}

Client (for testing only)

Using .NET Framework, C# console application...

    private static void TestSpeed()
    {
        Console.WriteLine($"- Test Speed - ");

        string requestUrl = "https://*******.azurewebsites.net/api/TestSpeed";

        string path = "/Users/temp/Downloads/1mb.zip";

        byte[] fileToSend = File.ReadAllBytes(path);

        var sw = new Stopwatch();
        for (int i = 0; i < 4; i++)
        {
            sw.Reset();
            sw.Start();
            var response = SendFile(fileToSend, requestUrl);
            sw.Stop();
            Console.WriteLine($"{i}: {sw.ElapsedMilliseconds} ms. {response}");
        }
    }

    private static string SendFile(byte[] bytesToSend, string requestUrl)
    {
        HttpWebRequest request = (HttpWebRequest)WebRequest.Create(requestUrl);
        request.Method = "POST";
        request.ContentType = "application/octet-stream";
        request.ContentLength = bytesToSend.Length;

        using (Stream requestStream = request.GetRequestStream())
        {
            // Send the file as body request. 
            requestStream.Write(bytesToSend, 0, bytesToSend.Length);
            requestStream.Close();
        }

        try
        {
            using (HttpWebResponse response = (HttpWebResponse)request.GetResponse())
            {
                using (var sr = new StreamReader(response.GetResponseStream()))
                {
                    var responseString = sr.ReadToEnd();
                    return responseString;
                }
            }
        }
        catch (Exception e)
        {
            return "ERROR:" + e.Message;
        }
    }

Suspects I've tried:

  • Its not a cold start/warmup thing because the behavior repeats within the same minute.. and I have "Always On" enabled as well.
  • Compare HTTP and HTTPS - same behavior.
  • Azure functions vs ASP.NET core web API app - same behavior. The only difference I noticed is that with functions, request content is already fully received on server side before invocation:

ASP.NET web API: 5512 ms. Received 1044397 bytes. Data Read in: 3701 ms
Function App: 5674 ms. Received 1044397 bytes. Data Read in: 36 ms

  • Sending 1Kb vs 1Mb - same behavior, first call take much more.
  • Running server on Localhost - similar behavior, but much smaller difference than with distant servers! (looks like network distance matters here... )

Is there some session creation overhead? If so, why is it so huge? Anything I can do about it?

Dima G
  • 1,945
  • 18
  • 22
  • You can have a look at this: https://stackoverflow.com/questions/16086045/first-call-to-a-net-webservice-is-slow – Doris Lv Oct 07 '20 at 01:39
  • Thanks @DorisLv, that page didn't come up in my searching, but unfortunately this didn't help me ( changing proxy configuration ). Also in my case the long first request is also visible on server side, not just on client. – Dima G Oct 07 '20 at 10:50
  • @DimaG We can only observe the phenomenon and make guesses. For applications deployed on iis, the first request after deployment is relatively slow. As for what happens to the application after the always on switch in the portal is turned on, it is recommended that Raise a support ticket and let the official assist you in troubleshooting. – Jason Pan Oct 15 '20 at 07:20
  • @DimaG any solution to this? Facing the same issue – Anita George Nov 17 '21 at 10:21
  • @AnitaGeorge, unfortunately no... I would post it here. – Dima G Nov 30 '21 at 06:57
  • @DimaG, same issue here (slow first response time on Azure Function v4 isolated and ASP.NET Core web api). Did MS support help you? – Joost Apr 24 '23 at 08:42
  • No, @Joost , I didn't talk to them as fortunately for me, requirements changed :) But, I'm sorry I can't be helpful to you now – Dima G May 15 '23 at 05:57

1 Answers1

0

Because your test interface is in the web program, even if you turn on the always on switch, what happens to the program or whether it can be kept active, you need to raise a support ticket to confirm with the official. From a developer's perspective, it is recommended that you test like this:

  1. After redeploying the web interface, first use the function app to test, and then use the webapi interface to test to compare the test time.

  2. Re-deploy again, first use webapi for testing and then use function app for testing. Compare test time.

  3. No deployment is required. On the basis of the second test, test again after 5 minutes. The order of using function app or webapi does not matter. Look at the test time data.

I think the problem should be on IIS. IIS itself has a recycling mechanism. The application will not be used for a long time or there will be a delay after deployment. It is recommended to confirm with the official.

Jason Pan
  • 15,263
  • 1
  • 14
  • 29
  • Thanks, Jason. After deployment, there is warm-up delay (it can take about 10 seconds), but the behavior I describe above has a bit different pattern, as I invoke the same API within the same minute and yet first call is slower. I'll try to check with the support. – Dima G Nov 01 '20 at 07:29