ASP.NET Core MVC Slow response generation
Asked Answered
Q

1

13

I have an ASP.NET Core MVC web application that has an endpoint which returns some data as a json. The onlly issue is that my data is around 5 MBs of raw (non-idented) JSON, and the response takes a really long time.

I set up some metrics and found that, on average, the processing that my application does takes around 30ms. Yet the whole response is returned after over 250ms.

I am testing with a local instance of the app running on my machine and sending a get request with postman, so networking delay is minimal.

Here is what my controller looks like

    [HttpGet("getData")]
    public IActionResult GetData()
    {
        Stopwatch sw = Stopwatch.StartNew();
        long a, b, c;

        var data = this._cacheInternal.GetValidDataSet();
        a = sw.ElapsedMilliseconds;

        sw.Restart();
        var processedData = this.ProcessData(data, false);
        b = sw.ElapsedMilliseconds;

        sw.Restart();
        var serialized = JsonConvert.SerializeObject(processedData);
        c = sw.ElapsedMilliseconds;

        this._log.Info($"Data: {a} ms. Processing {b} ms. Serialization {c} ms.");

        return this.Ok(serialized);
    }

Here is what I have discovered when examining the AspNetCore logs.

info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      Request starting HTTP/1.1 GET http://localhost:5000/api/status/getData
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Route matched with {action = "GetData", controller = "Status"}. Executing action DemoApp.Controllers.StatusController.GetData (DemoApp)
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action method DemoApp.Controllers.StatusController.GetData (DemoApp) - Validation state: Valid
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action method DemoApp.Controllers.StatusController.GetData (DemoApp), returned result Microsoft.AspNetCore.Mvc.OkObjectResult in 31.4532ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
      Executing ObjectResult, writing value of type 'System.String'.
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action DemoApp.Controllers.StatusController.GetData (DemoApp) in 69.2546ms
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      Request finished in 175.2726ms 200 text/plain; charset=utf-8

The logging of the stopwatch for this request is the following :

Data: 1 ms. Processing 19 ms. Serialization 10 ms.

And as you can see from the logs for my controller:

... returned result Microsoft.AspNetCore.Mvc.OkObjectResult in 31.4532ms.
This matches what I have with my stopwatch metrics and is the amount of time that the app is actually executing my code.

From there on there are two more points that ASP takes over:

Executed action DemoApp.Controllers.StatusController.GetData (DemoApp) in 69.2546ms

Request finished in 175.2726ms 200 text/plain; charset=utf-8

So my question is how can I find out what is happening in those two time points after ASP takes the result I pass to this.Ok() that takes so much time (and fix it)

Again, the response I return is quite large (for this example 1.2MB raw JSON). But I don't understand what is causing such a long delay (given that the serialization I do only takes 10ms)

I am using ASP.NET Core MVC and targeting .NET Core 2.1. The app is hosted with Kestrel.

Quartered answered 22/7, 2018 at 11:20 Comment(8)
I would call 250ms for 5 MB of data a win. What sort of times are you looking for? Have you tried gzip compression?Fatherinlaw
You could also speed it up, since you are on Core, by bypassing controllers altogether. You can map then use a delegate that skips the controller pipeline and returns data itself but it may not be appropriate, especially if you need MVC stuff like authorization.Fatherinlaw
Those 250ms were for 1.2MB, I had to double check the results. I am okay with these numbers, but when the data gets quite large (30MB) it takes over a minute and this is a bit of an issue. My main concern is that my code manages to serialize the data in 10ms (Newtonsoft), and then ASP does some other stuff for 220+ ms. And I want to understand what is so slow about it. As for gzip - no I havent tried itQuartered
1.2MB in 250ms => 4.8MB/s => 38.4MBit/s => ~40MBit/s with TCP/IP/HTTP overheads. What latency and bandwidth is there between the client and server?Depot
Client and server are both the same machine in the example, latency should be pretty non-existentQuartered
I've just started playing around with AspNetCore and Kestrel with MVC porting an older service I previously wrote in WCF. My old server executes a full request/response down from Chrome in about 20-50ms when operating locally. With MVC in the pipeline I'm averaging about 200-900ms and I'm not even processing data - that's just for a request and hard-coded response. I'm going to try removing MVC from the pipeline to see if I can boost the speed. Is anyone else seeing the same thing with MVC? Is it just naturally "slow"?Ransom
We are seeing same issue. When the response is around 1MB the difference in action execution and whole request time is cca 250ms. When the response grows, the also the time grows linerally (up to 15 seconds for 30MB response). Did you @Quartered found the cause/solution or at least some idea how to diagnose where it is coming form?Stanleigh
Have seen the same issue. Processing big amount of data and have to return some ICollection<Data> with about 2000 records. Calculcations takes about 1 sec from start up to return Ok(ICollection<Data> result ) statement, but in swagger the response come in 3 or 4 seconds.Halitosis
D
0
  1. Disable Response Buffering

You can disable buffering by configuring the IHttpResponseBodyFeature in your controller action:

[HttpGet("getData")]
public async Task<IActionResult> GetData()
{
    // Disable response buffering
    var responseFeature = HttpContext.Features.Get<Microsoft.AspNetCore.Http.Features.IHttpResponseBodyFeature>();
    responseFeature?.DisableBuffering();

    Stopwatch sw = Stopwatch.StartNew();
    long a, b, c;

    var data = this._cacheInternal.GetValidDataSet();
    a = sw.ElapsedMilliseconds;

    sw.Restart();
    var processedData = this.ProcessData(data, false);
    b = sw.ElapsedMilliseconds;

    sw.Restart();
    var serialized = JsonConvert.SerializeObject(processedData);
    c = sw.ElapsedMilliseconds;

    this._log.Info($"Data: {a} ms. Processing {b} ms. Serialization {c} ms.");

    return this.Ok(serialized);
}
  1. Streaming JSON Responses
    If you are dealing with very large JSON objects, consider streaming the JSON response directly to the client without buffering the entire response in memory. This can be done by using System.Text.Json with JsonSerializer and HttpResponse.Body.

    using System.Text.Json;
    
    [HttpGet("getData")]
    public async Task GetData()
    {
        var data = this._cacheInternal.GetValidDataSet();
        var processedData = this.ProcessData(data, false);
        HttpContext.Response.ContentType = "application/json";
        await JsonSerializer.SerializeAsync(HttpContext.Response.Body, processedData);    
    

    }

  2. List item Use Gzip Compression

Compressing your response can significantly reduce the size of the payload sent over the network, which can improve transfer times.

Configure Compression You can enable response compression in your ASP.NET Core application by adding middleware in Startup.cs:

public void ConfigureServices(IServiceCollection services)
{
    services.AddResponseCompression(options =>
    {
        options.EnableForHttps = true;
    });
}

public void Configure(IApplicationBuilder app, IHostingEnvironment env)
{
    app.UseResponseCompression();
    // Other middleware
}
Dezhnev answered 7/8 at 13:35 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.