如何分析高 CPU 和排队的 DebugDiag 分析?

Posted

技术标签:

【中文标题】如何分析高 CPU 和排队的 DebugDiag 分析?【英文标题】:How to analyze DebugDiag analysis for high CPU and queueing? 【发布时间】:2016-11-24 11:53:23 【问题描述】:

我的 .NET API(使用 Nancy/OWIN)上的 CPU 和 http 队列增加了。

它在 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 天吗?它们还出现在“运行时间”部分。

代码正在运行异步/等待,所以我想知道我是否没有正确处理取消等?

谁能给我一些关于如何分析内存转储以诊断高 CPU/队列的建议?

谢谢

【问题讨论】:

【参考方案1】:

报告告诉您,有 62 个请求在服务器上运行超过 90 秒,但它们仍未完成执行,因此这是一个需要调查的问题。报告的时间(1 天)似乎真的很高,所以我不确定这是否真的准确(尽管我会说我已经看到内存转储,我们看到请求卡住了一天)。 62 请求可能并不真正意味着排队。

 

该报告还包含 HTTP 上下文部分,它可能会告诉您运行长时间运行的请求的线程,单击该线程应该会为您提供有关该线程实际在做什么或它卡在什么上面的信息。

 

DebugDiag 报告还包含显示每个线程的调用堆栈的部分。您可能需要快速扫描整个报告,看看是否可以看到具有 .net 调用堆栈的线程,该调用堆栈指示正在处理的 HTTP 请求。

 

如果您可以分享完整的报告,我可以提供更多详细信息,或者随时通过 Microsoft 支持打开一个案例,应该有人可以提供帮助。

查看转储文件后

我花了一些时间尝试调试转储文件,所有请求都卡在 ASP.NET 的 OWIN 中间件中。基本上这个模块 - webengine4-__DynamicModule_Microsoft.Owin.Host.SystemWeb.OwinHttpModule,

这意味着您正在使用 Startup 类的配置方法中的 app.use 方法连接到 OWIN 中间件,其中一个方法正在异步等待需要很长时间才能执行的东西...找到一个数据库

我刚刚发现一个 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 代码中添加一些跟踪。

【讨论】:

感谢您的回复。我查看了您的建议,但仍然无法弄清楚:/我已在此处附上完整报告:filedropper.com/…。感谢您的帮助:) 有什么想法/建议吗? 该链接现在对我不起作用,我之前没有看到您的评论...抱歉...您可以通过 onedrive 分享吗? 所以在这种情况下,即使有很多长时间运行的请求,DebugDiag 报告也无济于事。发生这种情况的一个原因是如果代码使用异步编程模型,在这种情况下,如果请求执行是等待某个异步调用,它将不会出现在线程上。恐怕对于这种情况,需要仔细查看转储文件才能了解请求为何挂起。 是的,这都是异步/等待。我没有 VS 企业版,所以我无法轻松分析转储文件。有什么建议吗?

以上是关于如何分析高 CPU 和排队的 DebugDiag 分析?的主要内容,如果未能解决你的问题,请参考以下文章

转储文件上的 DebugDiag2 分析工具超时

高 CPU 使用率的 32 位进程的 Process Dump 分析

linux 性能优化-- cpu 切换以及cpu过高

Linux性能学习(1.5):CPU_如何找到CPU使用率高原因

Linux性能学习(1.5):CPU_如何找到CPU使用率高原因

性能实战分析-问题分析