3

我正在分析我的一个应用程序——它是一个建立在 Java 之上的宏系统。我正在使用hprof来分析一些基本示例，以下是花费时间的前 20 个函数：

rank   self  accum   count trace  method
   1 14.73% 14.73%     453 303755 java.lang.Object.<init>
   2  9.75% 24.48%     300 303754 java.lang.Object.<init>
   3  7.18% 31.66%     221 303641 java.lang.Object.<init>
   4  6.83% 38.49%     210 303621 java.util.ArrayList.<init>
   5  6.76% 45.25%     208 303620 java.util.ArrayList.<init>
   6  5.95% 51.20%     183 303833 java.lang.Character.toChars
   7  4.55% 55.75%     140 303809 java.lang.Object.<init>
   8  4.42% 60.18%     136 303791 java.lang.Object.<init>
   9  3.77% 63.95%     116 303756 java.lang.Object.<init>
  10  3.64% 67.59%     112 300509 java.lang.Object.<init>
  11  2.67% 70.25%      82 303789 java.lang.Object.<init>
  12  2.54% 72.79%      78 303790 java.lang.Object.<init>
  13  1.69% 74.48%      52 303688 java.lang.Object.<init>
  14  1.66% 76.14%      51 303644 java.lang.Object.<init>
  15  1.46% 77.60%      45 305935 java.lang.Object.<init>
  16  1.40% 79.00%      43 303758 java.lang.Object.<init>
  17  1.20% 80.20%      37 305324 java.lang.Object.<init>
  18  0.98% 81.18%      30 302559 java.lang.Object.<init>
  19  0.62% 81.79%      19 300006 java.util.Arrays.copyOf
  20  0.52% 82.31%      16 305214 java.lang.Object.<init>

如您所见，大部分时间都花在了Object.<init>. 这对我来说有点模糊。

我的直觉是，时间是由内存分配占用的。使用 C 语言工作让我强烈地感觉到动态内存分配（即malloc()）效率低下。然而，在 Java 中，福音似乎是 JVM 可以有效地处理短期对象。因此，从诸如对象池之类的模式中没有任何收获。

我应该补充一点，应用程序中最需要性能的部分是解析器，它确实创建了很多短期对象作为其操作的一部分。

你认为花费的时间Object.<init>是由于什么？它确实与内存分配有关吗？我可以从使用对象池或其他一些技巧来减少内存分配中受益吗？

编辑：

作为对 Mike Dunlavey 的回答的回应，这里是 JPerfAnal 对 hprof 输出的解释，给出了包容性的时间。

Method Times by Caller (times inclusive): 3076 ticks
  1: java.lang.Object.<init>: 71,26% (2192 inclusive / 2191 exclusive)
    2: com.sun.demo.jvmti.hprof.Tracker.ObjectInit: 0,03% (1 inclusive / 0 exclusive)
      3: java.lang.Thread.currentThread: 0,03% (1 inclusive / 1 exclusive)
  1: parser.ParseData.<init>: 34,33% (1056 inclusive / 0 exclusive)
    2: parser.ParseErrors.<init>: 13,98% (430 inclusive / 1 exclusive)
      3: java.lang.Object.<init>: 7,18% (221 inclusive / 221 exclusive)
      3: java.util.ArrayList.<init>: 6,76% (208 inclusive / 208 exclusive)
    2: java.lang.Object.<init>: 13,52% (416 inclusive / 416 exclusive)
    2: java.util.ArrayList.<init>: 6,83% (210 inclusive / 0 exclusive)
      3: java.util.ArrayList.<init>: 6,83% (210 inclusive / 210 exclusive)
  1: parser.Matcher.parse: 34,33% (1056 inclusive / 0 exclusive)
    2: parser.ParseData.<init>: 34,33% (1056 inclusive / 0 exclusive)
      3: parser.ParseErrors.<init>: 13,98% (430 inclusive / 1 exclusive)
        4: java.lang.Object.<init>: 7,18% (221 inclusive / 221 exclusive)
        4: java.util.ArrayList.<init>: 6,76% (208 inclusive / 208 exclusive)
      3: java.lang.Object.<init>: 13,52% (416 inclusive / 416 exclusive)
      3: java.util.ArrayList.<init>: 6,83% (210 inclusive / 0 exclusive)
        4: java.util.ArrayList.<init>: 6,83% (210 inclusive / 210 exclusive)
  1: java.util.ArrayList.<init>: 28,38% (873 inclusive / 419 exclusive)
    2: java.util.AbstractList.<init>: 14,76% (454 inclusive / 0 exclusive)
      3: java.util.AbstractCollection.<init>: 14,76% (454 inclusive / 0 exclusive)
        4: java.lang.Object.<init>: 14,76% (454 inclusive / 454 exclusive)

（JPerfAnal 还生成一个倒置树，其中子代是父代的调用者。为简洁起见，我没有复制它，但可以说大约 40% 的Object.<init>调用来自 和 的初始化。ArrayList）ParseDataParseErrors

现在，这并没有真正改变我对这个问题或我的问题的看法。我可以更改算法，使其实例化更少的对象；但目前，我正在寻找一个正交解决方案。那么：对象池可以帮助我吗？

4

2 回答 2

1

1）“自我”时间几乎总是无用的，因为真正的问题在于调用那些低级方法的代码 -获得包含时间（self + callees）。

2）“累加”列更无用，因为它所做的只是将“自我”时间相加。

其他列也告诉您没有任何帮助。

hprof获取堆栈跟踪。你需要的是让那些尽可能深入。
你不需要很多（与流行的统计错误信息相反）——十个可能绰绰有余。
但是，您确实需要查看它们并理解它们。

以下是有关分析的一些一般信息。

编辑以响应您显示 JPerfAnal 输出的编辑：

a) 看起来堆栈深度只有 4。您需要尽可能深地查看堆栈深度。我不在乎他们呈现输出的方式。我主要只是看堆栈样本本身。时间并不是真正重要的事情。重要的是发生了什么以及为什么。

b) 堆栈样本实际上包含行级信息。因此，它们将指向您例程中的精确行，例如parser.ParseData.<init>, parser.Matcher.parse，以及parrser.ParseErrors.<init>发生问题的调用的位置。这将准确地告诉您哪些分配一直在花费，然后您可以决定是否有更好的方法来执行它们。

我得到的印象是解析器运行数据结构表。我知道您不想重新设计它，但是如果您重新设计它，您将获得更好的性能。基本上，如果您可以将其表示为递归下降解析器，并且如果语言不经常更改，您可以直接在代码中编写解析器 - 没有表格 - 它将快 10-100 倍。

于 2013-08-15T13:01:55.650 回答
1

简短的回答：

花费的时间Object.<init>可能是由于 CPU 配置文件与堆配置文件一起生成的；后者检测所有内存分配，使分配变慢并导致它们出现在 CPU 配置文件的顶部。

长答案：

我怀疑问题中显示的配置文件是通过同时要求 CPU 配置文件和堆配置文件生成的。换句话说，它是通过执行以下操作生成的：

java -agentlib:hprof=heap=sites,cpu=samples,depth=20 MyProg

不幸的是，至少在涉及到 JVM 的内置 hprof 分析器时，CPU 采样在存在堆分析时毫无用处。堆分析检测所有内存分配，使程序运行速度变慢。在用于跟踪内存分配的程序中，分配确实是瓶颈，这就是为什么Object.<init>会出现在 CPU 配置文件的顶部。但在实际程序中，分配/垃圾收集可能是也可能不是瓶颈。

您通常希望一次只生成一个配置文件。首先通过运行类似的东西生成 CPU 配置文件java -agentlib:hprof=cpu=samples,depth=20，并分析其结果。如果 CPU 配置文件指向内存分配/垃圾收集作为瓶颈，那么并且只有在那时，生成和分析堆配置文件以查看大部分分配的来源。

另一个答案在分析 CPU 配置文件方面提出了很多要点。特别是，使用JPerfAnal比查看原始 hperf CPU 配置文件更容易查看发生了什么。此外，为了使包含百分比相当准确，您可能需要增加堆栈采样深度以匹配您的应用程序。

于 2015-12-10T22:20:11.297 回答