2024-11-15T11:10:40.292+0800: 2850.503: [GC (Allocation Failure) [PSYoungGen: 142705K->3472K(141312K)] 1403514K->1264289K(1543168K), 0.0170225 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
这一行日志来自Java的垃圾收集器(Garbage Collector, GC),并且是在使用Spark时产生的。下面会逐一解释这一行日志中的各个部分:
-
时间戳:
2024-11-15T11:10:40.292+0800
这表示垃圾收集事件发生在2024年11月15日,时间是11:10:40.292,时区是+0800(即东八区,通常是中国、台湾、香港、澳门等地的时区)。 -
GC事件:2850.503: [GC (Allocation Failure)
2850.503
:这是Java虚拟机(JVM)启动后的秒数,表示从JVM启动到这次GC事件发生已经过去了大约2850.503秒。
[GC (Allocation Failure)
:这表示发生了一次GC事件,原因是“分配失败”(Allocation Failure),即JVM在尝试为新对象分配内存时,发现没有足够的空间,从而触发了垃圾收集。
内存变化
:[PSYoungGen: 142705K->3472K(141312K)] 1403514K->1264289K(1543168K)
PSYoungGen
: 这是指“Parallel Scavenge Young Generation”,是Java堆内存中的年轻代部分。年轻代通常包含新创建的对象。
142705K->3472K(141312K)
: 这表示在GC之前,年轻代使用了142705K的内存,GC之后减少到了3472K。年轻代的总容量是141312K。
1403514K->1264289K(1543168K)
: 这表示整个Java堆在GC之前使用了1403514K的内存,GC之后减少到了1264289K。整个堆的总容量是1543168K。
耗时:0.0170225 secs -
这表示这次GC事件总共耗费了
0.0170225
秒。
时间细节:[Times: user=0.05 sys=0.00, real=0.01 secs]
user=0.05
: 这表示在用户模式下(即执行Java代码时)耗费了0.05秒。
sys=0.00
: 这表示在系统模式下(即执行操作系统代码,如垃圾收集器本身)耗费了0.00秒。
real=0.01
: 这表示从GC事件开始到结束实际经过的时间是0.01秒,这通常包括了等待时间和其他非计算开销。
2024-11-15T10:59:09.768+0800: 2159.978: [Full GC (Ergonomics) [PSYoungGen: 1952K->0K(123904K)] [ParOldGen: 1196156K->1165762K(1401856K)] 1198108K->1165762K(1525760K), [Metaspace: 161537K->161537K(1202176K)], 2.0533133 secs]
[Times: user=7.57 sys=0.01, real=2.05 secs]
-
时间戳: 2024-11-15T10:59:09.768+0800,发生在2024年11月15日 10:59:09。
-
GC类型: Full GC,表示发生了全局垃圾收集,这通常涉及到整个堆的清理。
-
触发原因: (Ergonomics),表明垃圾收集是基于JVM的自动调整策略触发的。
-
内存变化:
- PSYoungGen: 年轻代从1952K清理到0K。
- ParOldGen: 老年代从1196156K减少到1165762K。
- 总堆内存: 从1198108K减少到1165762K。
- Metaspace: 元空间大小未变,保持在161537K。
- 耗时: 2.0533133 secs,表明Full GC花费了大约2.05秒。
-
时间细节: 用户模式7.57秒,系统模式0.01秒,实际耗时2.05秒。这里的用户模式时间远大于实际耗时,可能是因为GC过程中多个线程并行工作。
2024-11-15T10:54:06.273+0800: 1856.484: [Full GC (System.gc()) [PSYoungGen: 2368K->0K(389632K)] [ParOldGen: 1052564K->1035143K(1197056K)] 1054932K->1035143K(1586688K), [Metaspace: 161469K->161469K(1202176K)], 2.7494377 secs] [Times: user=9.01 sys=0.03, real=2.75 secs]
- 时间戳: 2024-11-15T10:54:06.273+0800,发生在2024年11月15日 10:54:06。
- GC类型: Full GC,同样是全局垃圾收集。
- 触发原因: (System.gc()),表明垃圾收集是由System.gc()调用触发的,这通常是由应用程序或开发者显式调用的。
- 内存变化:
- PSYoungGen: 年轻代从2368K清理到0K。
- ParOldGen: 老年代从1052564K减少到1035143K。
- 总堆内存: 从1054932K减少到1035143K。
- Metaspace: 元空间大小未变,保持在161469K。
- 耗时: 2.7494377 secs,Full GC花费了大约2.75秒。
- 时间细节: 用户模式9.01秒,系统模式0.03秒,实际耗时2.75秒。这里的用户模式时间也远大于实际耗时。
2024-11-15T10:24:30.644+0800: 80.855: [GC (Metadata GC Threshold) [PSYoungGen: 87878K->7167K(194048K)] 115047K->44846K(422400K), 0.0238500 secs] [Times: user=0.08 sys=0.01, real=0.02 secs]
- 时间戳: 2024-11-15T10:24:30.644+0800,发生在2024年11月15日 10:24:30。
- GC类型: GC,这表明不是Full GC,可能是针对年轻代的垃圾收集。
- 触发原因: (Metadata GC Threshold),表明垃圾收集是由于元空间使用达到了某个阈值而触发的。
- 内存变化:
- PSYoungGen: 年轻代从87878K减少到7167K。
- 总堆内存: 从115047K减少到44846K(这里没有明确给出老年代的变化)。
- 耗时: 0.0238500 secs,这次GC事件非常快,仅耗时约0.02秒。
- 时间细节: 用户模式0.08秒,系统模式0.01秒,实际耗时0.02秒。这里的用户模式时间和实际耗时比较接近。