GC日志格式

Parallel GC日志文件示例

  • server模式下模式的GC；
  • 相关参数：
    -XX:+PrintGCDetails
    -XX:+PrintGCTimeStamps
    -XX:+PrintGCDateStamps
    -Xloggc:C:\Users\LiXinlei\Desktop\gc.log
Java HotSpot(TM) 64-Bit Server VM (25.111-b14) for windows-amd64 JRE (1.8.0_111-b14), built on Sep 22 2016 19:24:05 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16687908k(9903672k free), swap 19178276k(11037860k free)
CommandLine flags: -XX:-BytecodeVerificationLocal -XX:-BytecodeVerificationRemote -XX:InitialHeapSize=267006528 -XX:+ManagementServer -XX:MaxHeapSize=4272104448 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:TieredStopAtLevel=1 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
2019-03-25T16:58:33.315+0800: 3.033: [GC (Allocation Failure) [PSYoungGen: 65536K->7580K(76288K)] 65536K->7596K(251392K), 0.0153422 secs] [Times: user=0.00 sys=0.00, real=0.02 secs] 
2019-03-25T16:58:33.765+0800: 3.477: [GC (Metadata GC Threshold) [PSYoungGen: 70343K->10745K(76288K)] 70359K->11100K(251392K), 0.0180741 secs] [Times: user=0.00 sys=0.01, real=0.02 secs] 
2019-03-25T16:58:33.784+0800: 3.496: [Full GC (Metadata GC Threshold) [PSYoungGen: 10745K->0K(76288K)] [ParOldGen: 355K->10609K(100864K)] 11100K->10609K(177152K), [Metaspace: 20538K->20535K(1067008K)], 0.0413057 secs] [Times: user=0.13 sys=0.02, real=0.04 secs] 
2019-03-25T16:58:34.739+0800: 4.451: [GC (Allocation Failure) [PSYoungGen: 65536K->7193K(76288K)] 76145K->17874K(177152K), 0.0057675 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
2019-03-25T16:58:35.452+0800: 5.164: [GC (Allocation Failure) [PSYoungGen: 72729K->10721K(113664K)] 83410K->24645K(214528K), 0.0102176 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

CMS GC日志文件示例

  • 相关参数：
    -XX:+UseConcMarkSweepGC
    -XX:+PrintGCDetails
    -XX:+PrintGCTimeStamps
    -XX:+PrintGCDateStamps
    -Xloggc:C:\Users\LiXinlei\Desktop\gc.log
Java HotSpot(TM) 64-Bit Server VM (25.111-b14) for windows-amd64 JRE (1.8.0_111-b14), built on Sep 22 2016 19:24:05 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16687908k(10303640k free), swap 19178276k(11517632k free)
CommandLine flags: -XX:-BytecodeVerificationLocal -XX:-BytecodeVerificationRemote -XX:InitialHeapSize=267006528 -XX:+ManagementServer -XX:MaxHeapSize=4272104448 -XX:MaxNewSize=697933824 -XX:MaxTenuringThreshold=6 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:TieredStopAtLevel=1 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
2019-03-25T17:32:16.566+0800: 2.514: [GC (Allocation Failure) 2019-03-25T17:32:16.566+0800: 2.515: [ParNew: 69952K->7959K(78656K), 0.0143885 secs] 69952K->7959K(253440K), 0.0147581 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2019-03-25T17:32:17.068+0800: 3.016: [GC (Allocation Failure) 2019-03-25T17:32:17.068+0800: 3.016: [ParNew: 77911K->8704K(78656K), 0.0262204 secs] 77911K->14095K(253440K), 0.0263544 secs] [Times: user=0.09 sys=0.03, real=0.03 secs] 
2019-03-25T17:32:17.094+0800: 3.043: [GC (CMS Initial Mark) [1 CMS-initial-mark: 5391K(174784K)] 16298K(253440K), 0.0011395 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2019-03-25T17:32:17.095+0800: 3.044: [CMS-concurrent-mark-start]
2019-03-25T17:32:17.102+0800: 3.051: [CMS-concurrent-mark: 0.007/0.007 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2019-03-25T17:32:17.102+0800: 3.051: [CMS-concurrent-preclean-start]
2019-03-25T17:32:17.104+0800: 3.052: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2019-03-25T17:32:17.104+0800: 3.052: [CMS-concurrent-abortable-preclean-start]
2019-03-25T17:32:17.447+0800: 3.396: [CMS-concurrent-abortable-preclean: 0.148/0.343 secs] [Times: user=0.61 sys=0.06, real=0.34 secs] 
2019-03-25T17:32:17.447+0800: 3.396: [GC (CMS Final Remark) [YG occupancy: 47765 K (78656 K)]2019-03-25T17:32:17.447+0800: 3.396: [Rescan (parallel) , 0.0050338 secs]2019-03-25T17:32:17.452+0800: 3.401: [weak refs processing, 0.0000939 secs]2019-03-25T17:32:17.452+0800: 3.401: [class unloading, 0.0023072 secs]2019-03-25T17:32:17.455+0800: 3.404: [scrub symbol table, 0.0026783 secs]2019-03-25T17:32:17.458+0800: 3.406: [scrub string table, 0.0002989 secs][1 CMS-remark: 5391K(174784K)] 53156K(253440K), 0.0110804 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2019-03-25T17:32:17.458+0800: 3.407: [CMS-concurrent-sweep-start]
2019-03-25T17:32:17.460+0800: 3.409: [CMS-concurrent-sweep: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2019-03-25T17:32:17.460+0800: 3.409: [CMS-concurrent-reset-start]
2019-03-25T17:32:17.490+0800: 3.439: [CMS-concurrent-reset: 0.029/0.029 secs] [Times: user=0.05 sys=0.03, real=0.03 secs] 
2019-03-25T17:32:17.798+0800: 3.747: [GC (Allocation Failure) 2019-03-25T17:32:17.798+0800: 3.747: [ParNew: 78656K->8704K(78656K), 0.0103221 secs] 84043K->19076K(253440K), 0.0104859 secs] [Times: user=0.00 sys=0.02, real=0.01 secs]

G1 GC日志文件示例

  • 相关参数：
    -XX:+UseG1GC
    -XX:+PrintGCDetails
    -XX:+PrintGCTimeStamps
    -XX:+PrintGCDateStamps
    -Xloggc:C:\Users\LiXinlei\Desktop\gc.log
Java HotSpot(TM) 64-Bit Server VM (25.111-b14) for windows-amd64 JRE (1.8.0_111-b14), built on Sep 22 2016 19:24:05 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16687908k(9814760k free), swap 19178276k(10655844k free)
CommandLine flags: -XX:-BytecodeVerificationLocal -XX:-BytecodeVerificationRemote -XX:InitialHeapSize=267006528 -XX:+ManagementServer -XX:MaxHeapSize=4272104448 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:TieredStopAtLevel=1 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation 
2019-03-25T17:44:07.997+0800: 2.184: [GC pause (G1 Evacuation Pause) (young), 0.0038326 secs]
   [Parallel Time: 2.5 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 2183.9, Avg: 2183.9, Max: 2184.0, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.5, Max: 1.2, Diff: 0.9, Sum: 4.4]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
      [Object Copy (ms): Min: 1.0, Avg: 1.5, Max: 1.7, Diff: 0.8, Sum: 12.1]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts: Min: 2, Avg: 33.6, Max: 43, Diff: 41, Sum: 269]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.6]
      [GC Worker Total (ms): Min: 2.1, Avg: 2.2, Max: 2.2, Diff: 0.1, Sum: 17.5]
      [GC Worker End (ms): Min: 2186.1, Avg: 2186.1, Max: 2186.1, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 1.1 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.8 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 12.0M(12.0M)->0.0B(22.0M) Survivors: 0.0B->2048.0K Heap: 12.0M(256.0M)->2548.0K(256.0M)]
 [Times: user=0.00 sys=0.00, real=0.01 secs] 
2019-03-25T17:44:08.329+0800: 2.516: [GC pause (G1 Evacuation Pause) (young), 0.0054060 secs]
   [Parallel Time: 3.2 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 2515.7, Avg: 2515.7, Max: 2515.7, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 0.5, Max: 1.2, Diff: 1.1, Sum: 3.6]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1]
         [Processed Buffers: Min: 0, Avg: 0.1, Max: 1, Diff: 1, Sum: 1]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 2.5, Diff: 2.5, Sum: 3.1]
      [Object Copy (ms): Min: 0.3, Avg: 2.1, Max: 2.7, Diff: 2.4, Sum: 16.9]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.5]
         [Termination Attempts: Min: 1, Avg: 26.6, Max: 42, Diff: 41, Sum: 213]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [GC Worker Total (ms): Min: 3.0, Avg: 3.0, Max: 3.1, Diff: 0.1, Sum: 24.2]
      [GC Worker End (ms): Min: 2518.7, Avg: 2518.7, Max: 2518.7, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 1.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.5 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 22.0M(22.0M)->0.0B(150.0M) Survivors: 2048.0K->3072.0K Heap: 24.5M(256.0M)->6169.5K(256.0M)]
 [Times: user=0.00 sys=0.00, real=0.01 secs] 
2019-03-25T17:44:08.981+0800: 3.167: [GC pause (Metadata GC Threshold) (young) (initial-mark), 0.0107070 secs]
   [Parallel Time: 5.0 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 3167.5, Avg: 3167.6, Max: 3167.9, Diff: 0.4]
      [Ext Root Scanning (ms): Min: 1.0, Avg: 1.2, Max: 1.4, Diff: 0.4, Sum: 9.5]
      [Update RS (ms): Min: 0.4, Avg: 0.6, Max: 0.9, Diff: 0.6, Sum: 4.5]
         [Processed Buffers: Min: 1, Avg: 1.8, Max: 4, Diff: 3, Sum: 14]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 3.0, Diff: 3.0, Sum: 3.4]
      [Object Copy (ms): Min: 0.1, Avg: 2.6, Max: 3.1, Diff: 3.0, Sum: 20.4]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.7]
         [Termination Attempts: Min: 1, Avg: 17.1, Max: 31, Diff: 30, Sum: 137]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 4.6, Avg: 4.8, Max: 4.9, Diff: 0.4, Sum: 38.7]
      [GC Worker End (ms): Min: 3172.4, Avg: 3172.4, Max: 3172.4, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 5.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 4.9 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 81.0M(150.0M)->0.0B(140.0M) Survivors: 3072.0K->13.0M Heap: 86.5M(256.0M)->15.3M(256.0M)]
 [Times: user=0.00 sys=0.00, real=0.01 secs] 
2019-03-25T17:44:08.992+0800: 3.178: [GC concurrent-root-region-scan-start]
2019-03-25T17:44:08.996+0800: 3.182: [GC concurrent-root-region-scan-end, 0.0037941 secs]
2019-03-25T17:44:08.996+0800: 3.182: [GC concurrent-mark-start]
2019-03-25T17:44:08.998+0800: 3.185: [GC concurrent-mark-end, 0.0025361 secs]
2019-03-25T17:44:08.999+0800: 3.185: [GC remark 2019-03-25T17:44:08.999+0800: 3.185: [Finalize Marking, 0.0002742 secs] 2019-03-25T17:44:08.999+0800: 3.185: [GC ref-proc, 0.0005143 secs] 2019-03-25T17:44:09.000+0800: 3.186: [Unloading, 0.0019702 secs], 0.0031572 secs]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
2019-03-25T17:44:09.002+0800: 3.189: [GC cleanup 16M->16M(256M), 0.0008155 secs]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
2019-03-25T17:44:09.003+0800: 3.189: [GC concurrent-cleanup-start]
2019-03-25T17:44:09.003+0800: 3.189: [GC concurrent-cleanup-end, 0.0000108 secs]
2019-03-25T17:44:10.766+0800: 4.952: [GC pause (G1 Evacuation Pause) (young), 0.0184160 secs]
   [Parallel Time: 9.2 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 4952.3, Avg: 4952.4, Max: 4952.5, Diff: 0.2]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.8, Max: 2.8, Diff: 2.5, Sum: 6.1]
      [Update RS (ms): Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.3, Sum: 0.8]
         [Processed Buffers: Min: 0, Avg: 1.6, Max: 4, Diff: 4, Sum: 13]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 0.6, Diff: 0.6, Sum: 2.6]
      [Object Copy (ms): Min: 6.0, Avg: 7.4, Max: 7.9, Diff: 1.9, Sum: 59.3]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts: Min: 1, Avg: 41.0, Max: 60, Diff: 59, Sum: 328]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
      [GC Worker Total (ms): Min: 8.6, Avg: 8.7, Max: 8.8, Diff: 0.2, Sum: 69.3]
      [GC Worker End (ms): Min: 4961.0, Avg: 4961.1, Max: 4961.1, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.1 ms]
   [Clear CT: 1.0 ms]
   [Other: 7.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 6.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 1.0 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 140.0M(140.0M)->0.0B(133.0M) Survivors: 13.0M->20.0M Heap: 155.2M(256.0M)->24.6M(256.0M)]
 [Times: user=0.11 sys=0.02, real=0.02 secs]
最后编辑于 ：
©著作权归作者所有,转载或内容合作请联系作者
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 215,294评论 6赞 497
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 91,780评论 3赞 391
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 161,001评论 0赞 351
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 57,593评论 1赞 289
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 66,687评论 6赞 388
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 50,679评论 1赞 294
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 39,667评论 3赞 415
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 38,426评论 0赞 270
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 44,872评论 1赞 307
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,180评论 2赞 331
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,346评论 1赞 345
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 35,019评论 5赞 340
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 40,658评论 3赞 323
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,268评论 0赞 21
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,495评论 1赞 268
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 47,275评论 2赞 368
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 44,207评论 2赞 352