Как проанализировать анализ DebugDiag для высокой загрузки ЦП и очередей?

Question

Я вижу увеличение загрузки ЦП и очередей http в моем.NET API (с использованием Nancy/OWIN).

Он работает на Azure, поэтому я взял дамп памяти.

Я пытаюсь понять, как читать отчет об анализе DebugDiag.

Вот раздел предупреждения:

Я предполагаю, что "62 клиентских соединения" является причиной очереди, поэтому я углубился в этот раздел.

Есть несколько распространенных запросов на один URL, которые выглядят так:

Host Header MyApi:80 GET request for /companies/list HTTP Version HTTP/1.1 SSL Request True Time alive 1 day(s) 03:43:21 QueryString
Request mapped to
HTTP Request State HTR_READING_CLIENT_REQUEST Native Request State NREQ_STATE_PROCESS Client Connection State CCS_STARTUP

Но я не знаю, что это значит. Это говорит о том, что запрос все еще открыт и занимает 1 день? Они также представлены в разделе "Работает с".

Код работает async / await, поэтому мне интересно, правильно ли я обрабатываю отмены и т. Д.?

Может кто-нибудь дать мне несколько советов о том, как анализировать дамп памяти для диагностики высокой производительности процессора / очередей?

Спасибо

Answer 1

В отчете сообщается, что на сервере выполняется 62 запроса, которые выполняются более 90 секунд, но они еще не завершены, так что это проблема, которую обязательно нужно исследовать. Указанное время (1 день) кажется очень высоким, хотя я не уверен, является ли оно действительно точным (хотя я бы сказал, что я видел дампы памяти, где мы видим запросы, застрявшие в течение дня). 62 запрос может не означать очереди.

В отчете также есть раздел HTTP Context, в котором можно указать поток, в котором выполняется длительный запрос, и щелчок по потоку должен дать вам информацию о том, что этот поток действительно делает или на чем он застрял.

Отчеты DebugDiag также имеют разделы, в которых они отображают стек вызовов каждого потока. вам, возможно, придется быстро просканировать весь отчет и посмотреть, видите ли вы потоки, в которых есть стек вызовов.net, который указывает на обработку HTTP-запроса.

Если вы можете поделиться полным отчетом, я могу предоставить более подробную информацию или не стесняйтесь открыть дело при поддержке Microsoft, и кто-то должен быть в состоянии помочь.

После просмотра файла дампа

Я потратил некоторое время, пытаясь отладить файл дампа, и все запросы застряли в промежуточном программном обеспечении OWIN в ASP.NET. В основном этот модуль - webengine4-__DynamicModule_Microsoft.Owin.Host.SystemWeb.OwinHttpModule,

Это означает, что вы подключаетесь к промежуточному программному обеспечению OWIN с помощью метода app.use внутри метода конфигурации класса Startup, и один из этих методов асинхронно ожидает выполнения чего-то, что занимает много времени... Найдена БД

Я только что нашел одно исключение тайм-аута SQL, которое, возможно, вызвано из кода промежуточного программного обеспечения, и это может быть связано, но не уверен на 100 %

000> !pe 0x000000cbe3d71e18 
Exception object: 000000cbe3d71e18
Exception type:   System.Data.SqlClient.SqlException
Message:          Connection Timeout Expired.  The timeout period elapsed during the post-login phase.  The connection could have timed out while waiting for server to complete the login process and respond; Or it could have timed out while attempting to create multiple active connections.  The duration spent while attempting to connect to this server was - [Pre-Login] initialization=2859; handshake=11534; [Login] initialization=0; authentication=0; [Post-Login] complete=3510; 
InnerException:   System.ComponentModel.Win32Exception, Use !PrintException 000000cbe3d71ce8 to see more.
StackTrace (generated):
    SP               IP               Function
    000000CB896582C0 000007FE9E4DCC82 System_Data_ni!System.Data.SqlClient.SqlInternalConnectionTds..ctor(System.Data.ProviderBase.DbConnectionPoolIdentity, System.Data.SqlClient.SqlConnectionString, System.Data.SqlClient.SqlCredential, System.Object, System.String, System.Security.SecureString, Boolean, System.Data.SqlClient.SqlConnectionString, System.Data.SqlClient.SessionData, System.Data.ProviderBase.DbConnectionPool, System.String, Boolean)+0x572
    000000CB8965EC10 000007FE9E019480 System_Data_ni!System.Data.SqlClient.SqlConnectionFactory.CreateConnection(System.Data.Common.DbConnectionOptions, System.Data.Common.DbConnectionPoolKey, System.Object, System.Data.ProviderBase.DbConnectionPool, System.Data.Common.DbConnection, System.Data.Common.DbConnectionOptions)+0x460
    000000CB8965ED00 000007FE9E019006 System_Data_ni!System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(System.Data.ProviderBase.DbConnectionPool, System.Data.Common.DbConnection, System.Data.Common.DbConnectionOptions, System.Data.Common.DbConnectionPoolKey, System.Data.Common.DbConnectionOptions)+0x46
    000000CB8965ED60 000007FE9E018FB4 System_Data_ni!System.Data.ProviderBase.DbConnectionPool.CreateObject(System.Data.Common.DbConnection, System.Data.Common.DbConnectionOptions, System.Data.ProviderBase.DbConnectionInternal)+0x3c4
    000000CB8965EDE0 000007FE9E018942 System_Data_ni!System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(System.Data.Common.DbConnection, System.Data.Common.DbConnectionOptions, System.Data.ProviderBase.DbConnectionInternal)+0x72
    000000CB8965EE30 000007FE9E01866F System_Data_ni!System.Data.ProviderBase.DbConnectionPool.TryGetConnection(System.Data.Common.DbConnection, UInt32, Boolean, Boolean, System.Data.Common.DbConnectionOptions, System.Data.ProviderBase.DbConnectionInternal ByRef)+0x65f
    000000CB8965EEB0 000007FE9E5A58A9 System_Data_ni!System.Data.ProviderBase.DbConnectionPool.WaitForPendingOpen()+0x159
    000000CB9A7DE920 000007FEAA21E814 mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task)+0xd34d54
    000000CB9A7DE960 000007FEA94E9A0D mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task)+0x3d
    000000CB9A7DE990 000007FE4C714BF0 AppianMedia_XWing_Application_Web_Api_Homely!AppianMedia.XWing.Application.Web.Api.Homely.Repository.DapperRepository+<FindListingsAsync>d__50.MoveNext()+0x290
    000000CB9A7DC2A0 000007FEAA21E814 mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task)+0xd34d54
    000000CB9A7DC2E0 000007FEA94E9A0D mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task)+0x3d
    000000CB9A7DC310 000007FEAA21E795 mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(System.Threading.Tasks.Task)+0xd34de5
    000000CB9A7DC340 000007FE4C6DEF8F AppianMedia_XWing_Application_Web_Api_Homely!AppianMedia.XWing.Application.Web.Api.Homely.Services.Caching.Listing.ListingCache+<FindListingsForLocationsAsync>d__39.MoveNext()+0xd9f
    000000CB9A7D9DD0 000007FEAA21E814 mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task)+0xd34d54
    000000CB9A7D9E10 000007FEA94E9A0D mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task)+0x3d
    000000CB9A7D9E40 000007FE4C6DA757 AppianMedia_XWing_Application_Web_Api_Homely!AppianMedia.XWing.Application.Web.Api.Homely.Services.Caching.Listing.ListingCache+<FindAllListingResultsAsync>d__24.MoveNext()+0x167
    000000CB9A7D7900 000007FEAA21E814 mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task)+0xd34d54
    000000CB9A7D7940 000007FEA94E9A0D mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task)+0x3d
    000000CB9A7D7970 000007FE4CA4E50E AppianMedia_XWing_Application_Web_Api_Homely!AppianMedia.XWing.Application.Web.Api.Homely.Services.Caching.Listing.ListingCache+<GetSimilarListingIdsAsync>d__26.MoveNext()+0x26e
    000000CB9A7D53B0 000007FEAA21E814 mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task)+0xd34d54
    000000CB9A7D53F0 000007FEA94E9A0D mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task)+0x3d
    000000CB9A7D5420 000007FE4CA46F0C AppianMedia_XWing_Application_Web_Api_Homely!AppianMedia.XWing.Application.Web.Api.Homely.Services.Caching.Listing.ListingCache+<GetListingDetailsAsync>d__25.MoveNext()+0x8bc
    000000CB9A7D2EF0 000007FEAA21E814 mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task)+0xd34d54
    000000CB9A7D2F30 000007FEA94E9A0D mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task)+0x3d
    000000CB9A7D2F60 000007FE4CA46396 AppianMedia_XWing_Application_Web_Api_Homely!AppianMedia.XWing.Application.Web.Api.Homely.Modules.Listing.ListingModule+<DetailsAsync>d__2.MoveNext()+0x106
    000000CB9A7D09D0 000007FEAA21E814 mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task)+0xd34d54
    000000CB9A7D0A10 000007FEA94E9A0D mscorlib_ni!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task)+0x3d
    000000CB9A7D0A40 000007FE4CBD4635 UNKNOWN!DynamicClass.CallSite.Target(System.Runtime.CompilerServices.Closure, System.Runtime.CompilerServices.CallSite, System.Object)+0x65
    000000CB9A7D0A80 000007FE4CA45C01 AppianMedia_XWing_Application_Web_Api_Homely!AppianMedia.XWing.Application.Web.Api.Homely.Modules.Listing.ListingModule+<<-ctor>b__1_0>d.MoveNext()+0x5f1

StackTraceString: <none>

Если это не помогает, то вам нужно использовать некоторые профилировщики уровня CLR (PerfView, NewRelic и т. Д.) Или использовать такие инструменты, как Glimpse, чтобы получить больше деталей или добавить некоторые трассировки в наш код MiddleWare.