Java GC日志解析

@高效码农  August 7, 2024
Java 

GC样例：

[GC (Allocation Failure) [DefNew: 8133K->645K(9216K), 0.0039312 secs] 8133K->6789K(29696K), 0.0039751 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [DefNew: 8028K->332K(9216K), 0.0023424 secs] 14172K->9156K(29696K), 0.0023701 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [DefNew: 6610K->331K(9216K), 0.0031335 secs] 15435K->15300K(29696K), 0.0031569 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[Full GC (System.gc()) [Tenured: 14968K->11203K(20480K), 0.0035525 secs] 17348K->11203K(29696K), [Metaspace: 3771K->3771K(1056768K)], 0.0036041 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [DefNew: 6451K->0K(9216K), 0.0015189 secs] 17654K->17347K(29696K), 0.0015472 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [DefNew: 6292K->6292K(9216K), 0.0000119 secs][Tenured: 17347K->3010K(20480K), 0.0025006 secs] 23639K->3010K(29696K), [Metaspace: 3771K->3771K(1056768K)], 0.0025664 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [DefNew: 6277K->0K(9216K), 0.0009455 secs] 9288K->9154K(29696K), 0.0009618 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 def new generation   total 9216K, used 2212K [0x00000000fe200000, 0x00000000fec00000, 0x00000000fec00000)
  eden space 8192K,  27% used [0x00000000fe200000, 0x00000000fe4290e0, 0x00000000fea00000)
  from space 1024K,   0% used [0x00000000feb00000, 0x00000000feb00000, 0x00000000fec00000)
  to   space 1024K,   0% used [0x00000000fea00000, 0x00000000fea00000, 0x00000000feb00000)
 tenured generation   total 20480K, used 9154K [0x00000000fec00000, 0x0000000100000000, 0x0000000100000000)
   the space 20480K,  44% used [0x00000000fec00000, 0x00000000ff4f0b40, 0x00000000ff4f0c00, 0x0000000100000000)
 Metaspace       used 3777K, capacity 4604K, committed 4864K, reserved 1056768K
  class space    used 418K, capacity 428K, committed 512K, reserved 1048576K

解析GC日志：

解析GC日志主要是为了了解垃圾收集器在Java应用程序运行期间的行为，帮助我们诊断和优化内存使用情况。下面是对你提供的GC日志的逐步分析：

1. GC日志格式

每一条GC日志包括几个重要的部分：

  • GC类型：如GC (Allocation Failure)或Full GC (System.gc())
  • 年轻代和老年代信息：如[DefNew: 8133K->645K(9216K)]
  • 堆使用情况：如8133K->6789K(29696K)
  • 耗时信息：如0.0039312 secs
  • 用户、系统和实际时间：如[Times: user=0.00 sys=0.00, real=0.00 secs]

2. 年轻代GC事件

[GC (Allocation Failure) [DefNew: 8133K->645K(9216K), 0.0039312 secs] 8133K->6789K(29696K), 0.0039751 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
  • GC类型：年轻代GC由于分配失败引发。
  • 年轻代变化：从8133K减少到645K，说明大部分对象被回收。
  • 堆内存总使用量：从8133K减少到6789K。
  • 耗时：GC总耗时约0.0039751秒。

类似的还有下面几条年轻代GC事件，可以看到年轻代GC事件频繁发生，通常在几毫秒内完成：

[GC (Allocation Failure) [DefNew: 8028K->332K(9216K), 0.0023424 secs] 14172K->9156K(29696K), 0.0023701 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
[GC (Allocation Failure) [DefNew: 6610K->331K(9216K), 0.0031335 secs] 15435K->15300K(29696K), 0.0031569 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

3. Full GC事件

[Full GC (System.gc()) [Tenured: 14968K->11203K(20480K), 0.0035525 secs] 17348K->11203K(29696K), [Metaspace: 3771K->3771K(1056768K)], 0.0036041 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
  • GC类型：Full GC，通常是手动调用System.gc()触发。
  • 老年代变化：从14968K减少到11203K。
  • 堆内存总使用量：从17348K减少到11203K。
  • Metaspace：元空间使用量保持不变。
  • 耗时：Full GC总耗时约0.0036041秒。

4. 堆信息

Heap
 def new generation   total 9216K, used 2212K [0x00000000fe200000, 0x00000000fec00000, 0x00000000fec00000)
  eden space 8192K,  27% used [0x00000000fe200000, 0x00000000fe4290e0, 0x00000000fea00000)
  from space 1024K,   0% used [0x00000000feb00000, 0x00000000feb00000, 0x00000000fec00000)
  to   space 1024K,   0% used [0x00000000fea00000, 0x00000000fea00000, 0x00000000feb00000)
 tenured generation   total 20480K, used 9154K [0x00000000fec00000, 0x0000000100000000, 0x0000000100000000)
   the space 20480K,  44% used [0x00000000fec00000, 0x00000000ff4f0b40, 0x00000000ff4f0c00, 0x0000000100000000)
 Metaspace       used 3777K, capacity 4604K, committed 4864K, reserved 1056768K
  class space    used 418K, capacity 428K, committed 512K, reserved 1048576K
  • 年轻代总大小：9216K，使用了2212K。
  • 老年代总大小：20480K，使用了9154K。
  • 元空间使用量：3777K，容量4604K，已提交4864K，保留1056768K。

总结

通过分析GC日志，我们可以得到以下结论：

  • GC频率：年轻代GC频率较高，说明对象生命周期较短，频繁创建和销毁。
  • Full GC：有一次Full GC，可能是手动调用触发的。
  • 性能影响：每次GC耗时都很短，对性能影响较小，但频繁的年轻代GC仍可能影响高并发应用程序的性能。
  • 优化建议：可以考虑增加年轻代空间大小，调整对象分配策略以减少GC频率。

通过持续监控GC日志并进行相应调整，可以有效优化Java应用程序的性能和稳定性。

评论已关闭