如何为IIS上托管的REST API调试客户端的高延迟

xmd2e60i  于 2023-10-19  发布在  其他
关注(0)|答案(1)|浏览(113)

我有一个在IIS上运行的OData REST API应用程序,使用http.sys作为Web服务器。我注意到大约5-10%的请求,我的客户端注意到高延迟(> 300 ms),但当我查看服务器端应用程序日志时,我发现我在不到50 ms的时间内处理了请求。我的客户端在地理上离Web服务器不远。我想有一些非网络瓶颈,但我不知道去哪里找。
到目前为止,我在机器上运行了一个Http.Sys ETW跟踪,以捕获具有高客户端报告延迟的单个请求。结果如下:

Client Reported Latency: 323 ms
Server application reported processing time: 38 ms                           

Http.Sys trace:

1.RecvReq: 2023-08-14T22:33:39.653675000Z (“Request received”)

2.Parse:   2023-08-14T22:33:39.653723100Z (“Parsed request with URI …”)

3.Deliver: 2023-08-14T22:33:39.653755300Z (“Delivered request to server application from request queue IISPOOL_<AppName>”)

4.Deliver: 2023-08-14T22:33:39.653811300Z (“Delivered request to server application from request queue IISPOOL_<AppName>”)

5.RecvResp: 2023-08-14T22:33:39.697113000Z (“Server application passed response”) (EntityChunkCount: 23, HeaderLength: 329, StatusCode: 200)
                                                                                                                                                                                                                                            
6.RecvBody: 2023-08-14T22:33:39.701603000Z (“Server application passed entity body”)

7.FastRespLast: 2023-08-14T22:33:39.859224500Z (“Server Application passed the last response”)

8.FastSend: 2023-08-14T22:33:39.859284800Z (“Queued last response for sending. Status code is 200”)

我不知道如何解释这些日志,所以我觉得它们没有帮助。(如果你知道我在哪里可以找到帮助解释这些日志的资源,请分享)。
这些日志是否揭示了一些有洞察力的东西,比如在我的应用程序逻辑中有一些瓶颈,或者可能在客户端?你建议我接下来再看什么?我还检查了我的机器上的性能计数器(CPU/内存),它很低。

kh212irz

kh212irz1#

您可以使用ETW记录CPU和网络跟踪。下载ETWController:

**注:**ETWController和ETWAnalyzer是我写的。

以管理员身份启动并选择预设CSWitch

然后给予记录文件一个描述性文件名,如下所示

C:\temp\SlowHttpSys_%TS%_%COMPUTERNAME%.etl

之后,选择手动编辑以调整记录设置

更改配置文件以使用此命令行记录网络分析

xxwpr -start "MultiProfile.wprp!CSwitch" -start "MultiProfile.wprp!Network" -start HookEvents.wprp

现在按开始,让您的客户端有缓慢的响应时间。这会在高达4 GB的环形缓冲区中生成相当多的数据(1-2 GB/分钟),因此录制的时间范围不超过1-2分钟。确保在发生不好的事情后尽快停止记录。
记录完成后,您可以使用名为ETWAnalyzer的命令行工具分析ETW数据。

下载并解压缩到一个文件夹中,然后将PATH添加到文件夹中,这样您就可以从任何地方执行该工具。
现在,您可以使用

EtwAnalyzer -extract all -fd "C:\Temp\SlowHttpSys_2023-10-03_212630_MAGNON.etl" -symserver ms

第一次,您应该使用-symsver ms选项下载所有Windows代码的Microsoft符号。当你没有补丁/更新Windows之间,你可以省略这将更快地提取数据的下一次。
现在,您可以使用客户端IP的IP过滤器检查TCP指标

EtwAnalyzer -dump tcp -fd C:\Temp\Extract\SlowHttpSys_2023-10-03_212630_MAGNON.json -topn 5 -ipport *8b87*

如果显示Retrans Count/%/Delay,则TCP重传确实发生,这表明网络过载。您报告的300毫秒数是连接到Internet的Windows TCP套接字的默认TCP重新传输延迟。有关更多信息,请参见https://github.com/Siemens-Healthineers/ETWAnalyzer/blob/main/ETWAnalyzer/Documentation/DumpTCPCommand.md
如果它不是网络,你应该考虑使用WPA(Windows性能分析器)来更深入地查看IIS内部,如果有一些等待,例如。AV解决方案。一个通用的查询也可以帮助,

EtwAnalyzer -fd C:\Temp\Extract\SlowHttpSys_2023-10-03_212630_MAGNON.json -dump cpu -stacktags *virus* -minmaxwaitms 100  -pn w3wp

如果某些防病毒解决方案正在干扰您的w3wp.exe进程之一,请首先获取一些迹象。

相关问题