Java VisualVM 为 CPU 分析提供了奇怪的结果 - 还有其他人遇到过这个吗？

Question

我编写了这个小(而且效率极低)的类，并希望使用 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() 的调用支配。

(98.2%) sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run()
(1.7%) java.lang.Thread.join(long)
(0%) java.lang.String.equals(Object)
等等……

大概有大约一百种方法被分析，其中没有一个是 fib(int)!

令人难以置信的是，我的程序实际上将所有时间都花在了这些方法上。他们似乎是连接到我的 jvm 并做它的事情的分析器。

我做错了什么？

为清楚起见进行了编辑:如果您为 n 传递 45，则此应用程序将运行 20 秒。我最初分析的程序(不是斐波那契计算器)将我的 cpu 上的所有四个内核都固定在 100% 上，而我的分析运行持续时间长达 5 分钟。这些具有相同的结果，并且我的应用程序中的方法没有出现在热点方法列表中。

它因运行而异，但 ConnectionHandler.run() 始终位于顶部，通常占分析时间的约 99%。

第二次编辑:我尝试使用采样器，现在得到的结果与 JProfiler 产生的结果一致。这样做的缺点是我没有得到分析附带的堆栈跟踪信息。但对于我的迫切需要，这非常好。

我在玩游戏时发现的一点是，VisualVM 在分析方法调用时会计算挂钟时间。

在我的具体情况下，我的应用程序有一个主线程，它启动工作线程并立即阻塞等待队列中的消息。

这意味着阻塞方法似乎会占用分析器上的几乎所有时间，尽管事实上并不是这种方法占用了我的 CPU。

我希望 sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run() 方法也是如此，它可以很好地完成工作 - 但是当它终止时，它会成为我的应用程序中运行时间最长的方法之一- 反复。

Answer 1

我不认为这是不可思议的。您有一个应用程序，其中“有效负载”非常小(尽管这当然取决于 n 的值)，并且您必须接受所需的额外工作(连接分析器并将所有信息转移到它) 将淹没该有效载荷。

这不是我首先要分析的那种应用程序，因为很明显大量时间将花费在 fib 上。无论如何(对于 n 的重要值)，将其标记为明显的优化目标。

我更倾向于将分析器用于更重要的应用程序，其中:

• 优化工作应该去哪里并不明显；和
• payload 中有大量工作要做。

如果你真的想测试那个代码，你可能需要通过(例如)替换来提高它的效果:

int fib = fib(n);

与:

for (int i = 0; i < 100000; i++) {
    int fib = fib(n);
)

---

我会告诉你一件需要注意的事情。我不知道任何特定 JVM 的内部结构，但是使用递归方法来减少参数的速度很慢通常是一个坏主意，这会导致堆栈空间很快耗尽。

我的意思是，二分搜索是一个很好的候选，因为它在每个递归级别中删除了一半的剩余搜索空间(因此十亿个项目的搜索空间只有 30 个级别)。

另一方面，对数字 1,000,000,000 的斐波那契数列使用递归将需要大约 10 亿个级别，而大多数堆栈都很难包含这些。

尾端递归优化可能会避免该问题，但您需要小心以防优化未完成。