问题描述

我在 .net 5 中有一个来自 react 模板的非常简单的应用程序（带身份验证）。在这个应用程序中，我有一个带有非常简单端点的控制器：

[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.

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

解决方法

我已经成功解决了这个问题。问题是日志级别（Trace）太低了。我不认为将 Trace level 更改为 Information 会将响应时间从 15s 更改为 80ms。

你可以read the official documents to troubleshoot the problem yourself，如果你能解出最好的。

建议：

尝试在 Linux 下部署并再次测试（B2 计划），看看是否存在问题。
建议在门户网站上提出支持，让微软官方工程师进行调查。

asp.net-core asp.net5 azure azure-web-app-service c#c#

Azure 应用服务来自简单端点的响应非常慢

问题描述

解决方法

建议：

相关问答