c# - Azure 应用服务简单端点的响应非常慢

Question

我在 .net 5 中有一个非常简单的应用程序，来自 react 模板(带有身份验证)。在这个应用程序中，我有一个具有非常简单端点的 Controller :

[HttpGet("[action]")]
public async Task<IActionResult> GetTest()
{
    Testing result = await Task.Run(() => new Testing
    {
        Id = long.MaxValue,
        TestBool = true,
        TestDateTime = DateTime.MaxValue,
        TestDecimal = decimal.MaxValue,
        TestFloat = float.MaxValue,
        TestInt = int.MaxValue,
        TestSqlMoney = SqlMoney.MaxValue,
        TestText = "Zażółć gęślą jaźń",
        TestGuid = Guid.NewGuid(),
        TestInnerType = new InnerType
        {
            Id = int.MinValue,
            InnerTekst = "This is only special characters: “@#$&%!~”"
        }
    });
    return Ok(result);
}

我将此应用程序部署到使用 Linux 平台(使用默认设置)的 azure 应用程序服务(B2 计划)。

问题是该端点在每个请求中的响应非常慢(超过 5 秒)。

请求日志也没有告诉我太多信息。

2021-01-08T13:13:38.201415475Z 2021-01-08 13:13:38.2008 Microsoft.AspNetCore.Server.Kestrel.Core.Internal.ConnectionDispatcher`1.StartAcceptingConnectionsCore Debug Connection id "0HM5JQQ28000A" accepted.
2021-01-08T13:13:38.505599672Z 2021-01-08 13:13:38.5046 Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure.KestrelConnection`1.ExecuteAsync Debug Connection id "0HM5JQQ28000A" started.
2021-01-08T13:13:38.716831901Z 2021-01-08 13:13:38.7159 Microsoft.AspNetCore.Hosting.HostingApplicationDiagnostics.LogRequestStarting Info Request starting HTTP/1.1 GET http://*****.azurewebsites.net/api/Testing/GetTest - -
2021-01-08T13:13:39.060675784Z 2021-01-08 13:13:39.0596 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke Debug The request path /api/Testing/GetTest does not match a supported file type
2021-01-08T13:13:39.249331221Z 2021-01-08 13:13:39.2460 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke Debug The request path /api/Testing/GetTest does not match a supported file type
2021-01-08T13:13:39.382874876Z 2021-01-08 13:13:39.3819 Microsoft.AspNetCore.Routing.Matching.DfaMatcher+Logger.CandidatesFound Debug 1 candidate(s) found for the request path '/api/Testing/GetTest'
2021-01-08T13:13:39.562471016Z 2021-01-08 13:13:39.5612 Microsoft.AspNetCore.Routing.Matching.DfaMatcher+Logger.CandidateValid Debug Endpoint 'TestApp.WebApp.Controllers.TestingController.GetTest (TestApp.WebApp)' with route pattern 'api/Testing/GetTest' is valid for the request path '/api/Testing/GetTest'
2021-01-08T13:13:39.714616065Z 2021-01-08 13:13:39.7136 Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware.Invoke Debug Request matched endpoint 'TestApp.WebApp.Controllers.TestingController.GetTest (TestApp.WebApp)'
2021-01-08T13:13:39.803919435Z 2021-01-08 13:13:39.8017 Microsoft.AspNetCore.Authentication.AuthenticationHandler`1.AuthenticateAsync Debug AuthenticationScheme: Cookies was successfully authenticated.
2021-01-08T13:13:39.998992570Z 2021-01-08 13:13:39.9980 Microsoft.AspNetCore.Routing.EndpointMiddleware.Invoke Info Executing endpoint 'TestApp.WebApp.Controllers.TestingController.GetTest (TestApp.WebApp)'
2021-01-08T13:13:40.328963460Z 2021-01-08 13:13:40.3284 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.ExecutingAction Info Route matched with {action = "GetTest", controller = "Testing"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] GetTest() on controller TestApp.WebApp.Controllers.TestingController (TestApp.WebApp).
2021-01-08T13:13:40.641328456Z 2021-01-08 13:13:40.6402 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.LogFilterExecutionPlan Debug Execution plan of authorization filters (in the following order): None
2021-01-08T13:13:40.742806622Z 2021-01-08 13:13:40.7419 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.LogFilterExecutionPlan Debug Execution plan of resource filters (in the following order): None
2021-01-08T13:13:40.930851560Z 2021-01-08 13:13:40.9297 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.LogFilterExecutionPlan Debug Execution plan of action filters (in the following order): Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000), Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter (Order: -2000)
2021-01-08T13:13:41.174980779Z 2021-01-08 13:13:41.1739 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.LogFilterExecutionPlan Debug Execution plan of exception filters (in the following order): None
2021-01-08T13:13:41.269866248Z 2021-01-08 13:13:41.2688 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.LogFilterExecutionPlan Debug Execution plan of result filters(in the following order): Microsoft.AspNetCore.Mvc.Infrastructure.ClientErrorResultFilter (Order: -2000)
2021-01-08T13:13:41.564338451Z 2021-01-08 13:13:41.5583 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.ExecutingControllerFactory Debug Executing controller factory for controller TestApp.WebApp.Controllers.TestingController (TestApp.WebApp)
2021-01-08T13:13:41.840241163Z 2021-01-08 13:13:41.8377 Microsoft.EntityFrameworkCore.Diagnostics.EventDefinition`4.Log Info Entity Framework Core 5.0.0 initialized 'ApplicationDbContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
2021-01-08T13:13:42.188242159Z 2021-01-08 13:13:42.1869 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.ExecutedControllerFactory Debug Executed controller factory for controller TestApp.WebApp.Controllers.TestingController (TestApp.WebApp)
2021-01-08T13:13:42.379574903Z 2021-01-08 13:13:42.3790 Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector.SelectFormatter Debug List of registered output formatters, in the following order: Microsoft.AspNetCore.Mvc.Formatters.HttpNoContentOutputFormatter, Microsoft.AspNetCore.Mvc.Formatters.StringOutputFormatter, Microsoft.AspNetCore.Mvc.Formatters.StreamOutputFormatter, Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonOutputFormatter
2021-01-08T13:13:42.707099106Z 2021-01-08 13:13:42.7061 Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector.SelectFormatter Debug Attempting to select an output formatter based on Accept header 'application/json'.
2021-01-08T13:13:42.825564470Z 2021-01-08 13:13:42.8243 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.FormatterSelected Debug Selected output formatter 'Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonOutputFormatter' and content type 'application/json' to write the response.
2021-01-08T13:13:42.959891731Z 2021-01-08 13:13:42.9586 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.ObjectResultExecuting Info Executing OkObjectResult, writing value of type 'TestApp.DataModel.Model.Testing'.
2021-01-08T13:13:43.131044980Z 2021-01-08 13:13:43.1306 Microsoft.AspNetCore.Mvc.MvcCoreLoggerExtensions.ExecutedAction Info Executed action TestApp.WebApp.Controllers.TestingController.GetTest (TestApp.WebApp) in 1568.1317ms
2021-01-08T13:13:43.290329933Z 2021-01-08 13:13:43.2896 Microsoft.AspNetCore.Routing.EndpointMiddleware+<<Invoke>g__AwaitRequestTask|6_0>d.MoveNext Info Executed endpoint 'TestApp.WebApp.Controllers.TestingController.GetTest (TestApp.WebApp)'
2021-01-08T13:13:43.441913089Z 2021-01-08 13:13:43.4399 Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.ProcessReceives Debug Connection id "0HM5JQQ28000A" received FIN.
2021-01-08T13:13:43.442662189Z 2021-01-08 13:13:43.4399 Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.WriteSuffix Debug Connection id "0HM5JQQ28000A" completed keep alive response.
2021-01-08T13:13:43.714143709Z 2021-01-08 13:13:43.7138 Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal.SocketConnection.Shutdown Debug Connection id "0HM5JQQ28000A" sending FIN because: "The client closed the connection."
2021-01-08T13:13:44.103589595Z 2021-01-08 13:13:44.1024 Microsoft.EntityFrameworkCore.Diagnostics.EventDefinition`1.Log Debug 'ApplicationDbContext' disposed.
2021-01-08T13:13:44.396677010Z 2021-01-08 13:13:44.3955 Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1OutputProducer.Abort Debug Connection id "0HM5JQQ28000A" disconnecting.
2021-01-08T13:13:44.626454743Z 2021-01-08 13:13:44.6246 Microsoft.AspNetCore.Hosting.HostingApplicationDiagnostics.LogRequestFinished Info Request finished HTTP/1.1 GET http://*****.azurewebsites.net/api/Testing/GetTest - - - 200 - application/json;+charset=utf-8 5908.6104ms
2021-01-08T13:13:45.110271802Z 2021-01-08 13:13:45.1097 Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure.KestrelConnection`1+<ExecuteAsync>d__6.MoveNext Debug Connection id "0HM5JQQ28000A" stopped.

我不知道到哪里去寻找这个问题的原因。该应用程序非常简单，该端点不使用数据库或授权。其他端点需要更长的时间才能响应。 在本地计算机上应用程序运行速度非常快。请帮助我。

Answer 1

我已经成功解决了这个问题。问题是日志记录级别(Trace)太低。我不认为将跟踪级别更改为信息会将响应时间从 15 秒更改为 80 毫秒。