天天看点

linux查看gc日志,将GC日志输出到文件

将GC日志输出到文件:不同JDK设置的参数不同,参考JDK官方文档

SUN:-Xloggc:filename (例如:-Xloggc:D:/gc.log)  linux windows

IBM:-Xverbosegc:file=filename 或 -Xverbosegclog:filename

HP :-Xverbosegc=filename

jrockit:

-server -Xms1024m -Xmx1536m -Xverboselog:gc.log -Xverbose:memory-Xgcprio:throughput

清单 1 是由 Sun 1.4.2_03 JVM 以 -Xloggc:filename 运行默认的标记-清除收集器所生成的日志记录的例子。可以看到,日志项非常精确地记录了每次所做的事情。

清单 1. 使用 -Xloggc:filename 旗标的 GC 日志记录

69.713: [GC 11536K->11044K(12016K), 0.0032621 secs]

69.717: [Full GC 11044K->5143K(12016K), 0.1429698 secs]

69.865: [GC 5958K->5338K(11628K), 0.0021492 secs]

69.872: [GC 6169K->5418K(11628K), 0.0021718 secs]

69.878: [GC 6248K->5588K(11628K), 0.0029761 secs]

69.886: [GC 6404K->5657K(11628K), 0.0017877 secs]

首先注意到的可能是每一项日志记录是写在一组方括号内的。其他 GC 算法,如并发收集器, 可能将一些值分解为更细的信息。如果是这种情况,这些被分解的值会由包围在嵌入的一组方括号中的细节所替代,这使工具可以更容易地处理详细 GC 输出。

我们的研究首先从分析清单 1 中标记为 69.713 的记录开始。这个标记是 JVM 开始后的秒数和毫秒数的时间戳。在这个例子中,JVM 在这个 GC 周期开始之前运行了 69.713 秒。从左到右的字段为:执行的收集的类型、GC 之前的堆使用、总的堆能力和 GC 事件的持续时间。从这个描述中我们可以看出第一个 GC 事件是一个小的收集。在 GC 开始之前,使用了 11536 Kb 的堆空间。在完成时,使用了 11044 Kb,堆能力为 12016 Kb,而整个收集用了 .0032621 秒。下一个事件,一个完全的 GC,在 69.717 秒时或者上一个小 GC 事件之后 0.003 秒时开始。注意,如果将小 GC 事件的持续时间加到其开始时间上,就会看到它在完全的 GC 开始之前不到 1毫秒结束。因此我们可以得出结论:小收集没有恢复足够的空间,这种失败触发了完全的 GC。对应用程序来说,这像是一个持续了 0.1462319 秒的事件。让我们继续确定如何计算其他值。

GC 日志记录的参数确定

我们通过确定每个 GC 日志记录中的值的参数来开始分析:

R(n) = T(n): [ HB->HE(HC), D]

n  清单中记录的索引,1 是第一个,m 是最后一个

R(n)  GC 记录

T(n)  第 n 个 GC 发生的时间

HB  GC 之前堆的数量

HE  GC 之后使用的堆数量

HC  堆空间的总量

D  GC 周期的持续时间

有了这些定义,我们现在可以推导出用于计算前面描述的值的公式。