正在报告计算时间的 Visual Studio 诊断工具 [英] Visual Studio Diagnostic Tools under reporting compute time

问题描述

我无法共享整个代码库来重现该问题，但我正在使用

分析时间

此方法中的 CPU 示例仅表明执行时间约为 1000 毫秒:

执行时间

但是，断点之间需要近 50 秒

问题

• 什么可能导致如此长的执行时间在分析时不显示?

我尝试过的事情:

• 重启VS
• 重启机器
• 重新加载符号
• 缓存符号

解决方案

实际上我并不经常使用分析工具.但是，总 CPU 时间并不等于总执行时间，这听起来很有趣.我搜索了它，我想与我的思考过程分享我的发现.

官方文档对此有何评论?

我查看了

但即使这种情况是真的，也不能解释时间差1000ms - 50s.

继续寻找..

经过一点点搜索，我找到了

在使用率选项卡中显示Total CPU [unit, %].具体是什么单位?在上述相同的文档中，他们指出:

<块引用>

总 CPU [单位，%]在选定的时间范围内调用函数和函数调用的函数所使用的毫秒数和 CPU 百分比.这与 CPU 利用率时间线图不同，后者将时间范围内的总 CPU 活动与总可用 CPU 进行比较.

好的，以毫秒为单位，我们明白了.但它到底代表什么.

CPU 使用率指标

我搜索了很多，发现了 这篇文章 并将我重定向到 这个发霉的文档.它是关于 Profiler Instrumentation Data 的，他们指出:

<块引用>

Time 直接执行此函数所花费的时间，以毫秒 (msec) 或处理器周期 (ticks) 为单位，不包括此函数调用的子函数所花费的时间.

在那之后，我查看了更多更新的文档，但他们将其称为只有毫秒，就像上面的引用一样.但是这个旧文档给了我一个火花.如果他们指的是 cpu 周期数，这就说明了一切.它们不包括帐户中的空闲状态、中断、锁定和作业优先级.实际上，当您考虑它时，这是明智的做法.CPU 以离散方式处理功能.通过这种方式，您每次都能获得更一致的结果.

您的问题

如果我的研究是正确的，我认为当您开始执行时，它会捕获您的函数在 cpu 上花费的时间.它不会在捕获的时间内添加此事件的持续时间:函数相互等待、函数等待 I/O、操作系统决定接管进程、高优先级进程接管、线程锁、WINDOWS UPDATE...即使总捕获时间的功能是 1ms 根据计算机的不同，完成任务可能需要几分钟.CPU 执行时间是离散的，但断点之间的时间是连续的.这就是为什么您在它们之间留有余量.

I can't share the entire codebase to reproduce the issue, but I'm using Visual Studio Diagnostic Tools to inspect performance and operations are taking many times longer to execute that what's getting reported in CPU usage.

Example Code

Here's an example of the offending block of code between two breakpoints:

Profiling Time

The CPU samples inside this method only suggest it's spending about 1000 ms to execute:

Execution Time

However, it takes nearly 50 seconds between breakpoints

Question

• What could cause such a long execution timeline that doesn't show up when profiling?

Things I've Tried:

• Restarting VS
• Restarting Machine
• Reloading Symbols
• Caching Symbols

解决方案

Actually i do not use profiling tools that often. But it sound interesting that total CPU time does not sum up to total execution time. I searched it and i want to share my findings with my thought process.

What does official documentation say about it?

I looked at here, it doesn't says much. Then here and i found a quite interesting point. As you can see below the documentation includes a demo that shows CPU Usage tab like yours. But there are [External Call] tagged functions and they are not trivial. Documentation states:

External code are functions in system and framework components that are executed by the code you write. External code include functions that start and stop the app, draw the UI, control threading, and provide other low-level services to the app. In most cases, you won't be interested in external code, and so the CPU Usage tool gathers the external functions of a user method into one [External Code] node.

Since your examples does not include this functions, maybe they are creating this margin between exec time - total cpu time. You can check out this link view the call paths of external code in CPU Usage tab. They are disabled by default.

But even if this case is true, it do not explain the time difference 1000ms - 50s.

Keep looking..

After little bit of searching i found this. Another documentation about analyzing CPU Usage. The demo they are using was very similar to yours as you can se below. Even with the external code there is a nearly 60s difference. This is where i started to think Are we comparing apples with peanuts?.

In the usage tab it says Total CPU [unit, %]. What unit is exactly? In the same documentation above, they states:

Total CPU [unit, %] The milliseconds and CPU percentage used by calls to the function, and functions called by the function, in the selected time range. This is different from the CPU Utilization timeline graph, which compares the total CPU activity in a time range to the total available CPU.

Ok it is in milliseconds, we get it. But what is exactly it representing.

CPU Usage metrics

I searched it a lot and came across this post and it redirect me to this moldy documentation. It is about Profiler Instrumentation Data and they states that:

Time The time in milliseconds (msec) or processor cycles (ticks) that was spent in the direct execution of this function, excluding time spent in child functions called by this function.

After that i looked at much more newer documentation but they referred it as only milliseconds like the quote above. But this old documentation give me a spark. If they are referring the cpu cycle count, this explains it all. They are not including idle state, interrupts, locks and job priority in account. Actually it is a wise thing to do when you think about it. CPU processes functions in a discrete manner. In this way you can get more consistent results every time.

Your Question

If i did my research right, i think when you start execution, it captures the time your functions spend with cpu. It will not add this events duration in captured time: functions waiting for each other, functions waiting for I/O, os decides to take over process, high priority process take over, thread locks, WINDOWS UPDATE... Even if total captured time of the functions is 1ms it can take minutes to complete task depending on the computer. CPU execution time is discrete but time between breakpoints is continuous. This is why you have margin between them.

这篇关于正在报告计算时间的 Visual Studio 诊断工具的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！