Java VisualVM为CPU分析提供了奇怪的结果 - 还有其他人遇到过这种情况吗？ [英] Java VisualVM giving bizarre results for CPU profiling - Has anyone else run into this?
问题描述
我编写了这个小型（并且效率低下）的类，并希望使用Java VisualVM对其进行分析。
I have written this small (and brutally inefficient) class and wanted to profile it using the Java VisualVM.
public class Test {
public static void main(String[] args) throws IOException {
BufferedReader br = new BufferedReader(new InputStreamReader(System.in));
br.readLine();
int n = Integer.parseInt(args[0]);
int fib = fib(n);
System.out.println(fib);
}
private static int fib(int n) {
if (n < 2) {
return n;
}
return fib(n-1)+fib(n-2);
}
}
结果很奇怪。调用ConnectionHandler.run（）完全支配结果。
The results are bizarre. The results are completely dominated by calls to ConnectionHandler.run().
（98.2％）sun.rmi.transport.tcp.TCPTransport $ ConnectionHandler.run（）
（1.7％）java.lang.Thread.join（long）
（0％）java.lang.String.equals（Object）
等.. 。
(98.2%) sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run()
(1.7%) java.lang.Thread.join(long)
(0%) java.lang.String.equals(Object)
etc...
可能有大约100种方法被分析，其中没有一种是fib（int）！
There are probably around one hundred methods profiled and not one of them is fib(int)!
我的计划实际上是把所有时间花在这些方法上，这是不可思议的。他们似乎是连接到我的jvm并做其事情的探查器。
It is inconceivable that my program is actually spending all of its time in these methods. They appear to be the profiler connecting to my jvm and doing its thing.
我做错了什么？
为了清晰度而编辑：如果您传入45作为n，则此应用程序运行20个简单的秒数。我最初分析的程序（不是斐波那契计算器）将我的cpu上的所有四个核心固定为100％并且我正在进行持续长达5分钟的分析运行。这些结果与我的应用程序中的方法相同并没有出现在热点方法列表中。
Edited for clarity: If you pass in 45 for the n this application runs for 20 well profiled seconds. The program I was profiling originally (not a fibonacci calculator) pegs all four cores on my cpu at 100% and I was doing profiling runs lasting up to 5 minutes. These had the same results and methods from my application did not appear high up on the hot spot method list.
它因运行而异，但ConnectionHandler.run（）是总是在顶部，通常约占个人资料时间的99％。
It varies from run to run but ConnectionHandler.run() is always at the top and usually accounts for ~99% of the profile time.
第二次编辑：我尝试过使用该采样器，我就是现在获得的结果与JProfiler正在生成的结果一致。这样做的缺点是我没有得到分析带来的堆栈跟踪信息。但是对于我的直接需求，这非常好。
Second I have tried using the sampler and I am now getting results that are consistent with what JProfiler is producing. The downside to this is that I don't get the stack trace information that comes with profiling. But for my immediate needs this is excellent.
我在玩游戏时发现的东西是VisualVM在分析它们时计算方法调用的挂钟时间。
Something I have discovered while playing around is that VisualVM counts wall-clock time for method calls while profiling them.
在我的特定情况下，我的应用程序有一个主线程，它启动工作线程并立即阻止等待队列中的消息。
In my specific case my application has a main thread which launches worker threads and immediately blocks waiting for a message on a queue.
这意味着阻塞方法似乎几乎占据了探查器的所有时间，尽管事实上这种方法不会占用我的CPU。
This means that the blocking method will appear to take up almost all of the time on the profiler despite the fact that it is not this method that is eating up my CPU.
我希望sun.rmi.transport.tcp.TCPTransport $ ConnectionHandler.run（）方法能够很好地完成它的工作 - 但是当它终止时它会变成运行时间最长的方法之一我的申请 - 反复。
I would expect that the same is true of the sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run() method which does its job nicely - but when it terminates it becomes one of the longest running methods in my application - repeatedly.
推荐答案
我认为这根本不可能。你有一个应用程序，其中有效载荷是相当微小的（虽然这当然取决于 n 的值），你必须接受所需的额外努力（至连接探查器并将所有信息移到它上面）将淹没那个有效载荷。
I don't think that's inconceivable at all. You have an application where the "payload" is fairly minuscule (though that of course depends on the value of n), and you have to accept that the extra effort required (to connect the profiler and shift all the information across to it) will swamp that payload.
这不是我想要分析的那种应用程序，因为它很漂亮很明显，无论如何，大部分时间将用于 fib （对于 n 的非平凡值），标记这是一个明显的优化目标。
This is not the sort of application I would be profiling in the first place since it's pretty obvious that the vast amount of time would be spent in fib anyway (for non-trivial values of n), marking that as an obvious target for optimisation.
我更倾向于将分析器用于更实质的应用程序，其中：
I would be more inclined to use the profiler for more substantial applications where:
- 优化工作应该去哪里并不明显;和
- 在有效载荷中有大量的工作要做。
如果你真的想测试那个代码，你可能需要通过（例如）替换来提高它的效果：
If you really want to test that code, you probably need to bump up its effect by (for example) replacing:
int fib = fib(n);
with：
for (int i = 0; i < 100000; i++) {
int fib = fib(n);
)
我会告诉你的一个要注意的事情。我不知道任何特定JVM的内部结构，但是使用递归方法，其中参数的减少通常是一个坏主意，这会导致堆栈空间很快耗尽。
I'll tell you one thing to watch out for though. I don't know the internals of any particular JVM but using a recursive method where the reduction of the argument is slow is usually a bad idea, one that leads to stack space being exhausted pretty quickly.
由此，我的意思是二进制搜索是一个很好的候选者，因为它会删除每个递归级别剩余搜索空间的一半（因此十亿个项目的搜索空间只有30个级别）。
By that, I mean a binary search is a good candidate since it removes half the remaining search space with each recursion level (so that a search space of a billion items is only 30 levels).
另一方面，对数量为1,000,000,000的Fibonacci序列使用递归将需要大约10亿个级别，并且大多数堆栈将很难包含该级别。
On the other hand, using recursion for a Fibonacci sequence on the number 1,000,000,000 would take about a billion levels and most stacks would have a hard time containing that.
尾部递归优化可以避免这个问题，但是如果没有进行优化，你需要小心。
Tail end recursion optimisation may avoid that problem but you need to be careful in case that optimisation isn't done.
这篇关于Java VisualVM为CPU分析提供了奇怪的结果 - 还有其他人遇到过这种情况吗？的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！
