ごみ回収G 1ログ解析

9430 ワード

G 1ごみ回収器の紹介

まずG 1ごみの回収過程を明らかにしなければならない.
主に次の4つのステップに分けられます.
初期タグ(Initial Marking)は、通常のタグオブジェクトがGC rootsに直接関連しているかどうかで、プロセスが簡単で、停止時間が短い
コンカレントマーク(Concurrent Marking)は、達成性分析のため、長い停止がある
最終マーキング(Final Marking)は、同時マーキング時に漏れたゴミメモリの一部をマーキングするため、比較的少なく、停止時間が短い
選別回収(Live Data Couting and Evaluation)マークしたゴミメモリを整理し、指定された計画通りに回収する.

次の例では,赤色部分はこの4段階を明確に示している.

G 1ゴミ収集器パラメータ説明

私のsparkパラメータを例に挙げます.
spark.executor.extraJavaOptions -Dtag=mobius.optimize -XX:+UseG1GC -XX:+PrintFlagsFinal -XX:+PrintReferenceGC -XX:+PrintGCDetails
-XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps-XX:+PrintAdaptiveSizePolicy -XX:+PrintGC -Xloggc:/tmp/spark.gc.log
-XX:+UnlockDiagnosticVMOptions -XX:+G1SummarizeConcMark -XX:InitiatingHeapOccupancyPercent=35 -XX:ConcGCThreads=15
-XX:+PrintGCApplicationConcurrentTime -XX:-UseGCOverheadLimit

以下に、分割後のコメントを示します.
spark.executor.extraJavaOptions入力javaパラメータspark個々のexcutorへ
-Dtag=mobius.optimizeタグ名
-X:+UseG 1 GCゴミ収集器の指定
-X:+PrintFlagsFinaljavaオブジェクトリファレンスは、強リファレンスFinalReference、ソフトリファレンスSoftReference、弱リファレンスWeakReference、虚リファレンスPhantomReferenceの4種類に分けられます.一般的には、newオブジェクトや付与などの強い参照です.
-X:+PrintReferenceGC印刷スパムオブジェクトの参照数
-X:+PrintGCDetails詳細GCログの印刷
-X:+PrintGCDateStamps印刷可能な日付タイムスタンプ例えば2018-11-12
-X:+PrintGctimeStamps印刷可読タイムスタンプ例えば09:10:11
-X:+PrintAdaptiveSizePolicy適応サイズを有効にします(fullGCを避けるためにeden空間とsurvivor空間のサイズを変更できます)
-X:+PrintGCGCログの印刷
-Xloggc:/tmp/spark.gc.logGCログパスの指定
-XX:+UnlockDiagnosticVMOptions\
-XX:+G1SummarizeConcMark\
-XX:InitiatingHeapOccupancyPercent=35\
-X:ParallelGCThreads=33ParallelとG 1コレクタのタグフェーズのスレッド数l量、デフォルト33、GCログ[GC Workers:33](パラレル:複数のゴミ収集スレッドが並行して動作し、このときユーザスレッドは待機状態、stop the world)
-X:ConcGCThreads=15CMSとG 1回収器の最初の3つのタグフェーズはマルチスレッドで、GC同時スレッド数を指定します.デフォルトは0です(同時:ユーザースレッドとゴミ収集スレッドが同時に実行され、必ずしも並列ではなく、交互に実行される場合があります).
-X:+P r i n t G C p p r i c ationConcurrentTime印刷アプリケーション実行時間
-X:-UseGCOverheadLimitゴミ回収時のメモリ制限を解除(マイナス記号)
-X:MaxGCPauseMillis=200ごみ回収停止最長時間、デフォルトは200 ms

ログ分析ケース

次のログは、sparkコンピューティングタスクで生成されたゴミ回収ログです.

2018-11-13T05:32:44.473+0800: 1.857: Application time: 0.2130324 seconds
2018-11-13T05:32:44.571+0800: 1.954: Application time: 0.0970449 seconds
2018-11-13T05:32:44.696+0800: 2.079: Application time: 0.1249397 seconds
2018-11-13T05:32:44.874+0800: 2.258: Application time: 0.1776871 seconds
 2.258: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: requested by GC cause, GC cause: Metadata GC Threshold]
 2.258: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested]
2018-11-13T05:32:44.875+0800: 2.259: [GC pause (Metadata GC Threshold) (young) (initial-mark) 2.260: 
[G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 0, predicted base time: 10.00 ms, 
remaining time: 190.00 ms, target pause time: 200.00 ms]
 2.260: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 60 regions, survivors: 0 regions, predicted young region time: 3605.71 ms]
 2.260: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 60 regions, survivors: 0 regions, old: 0 regions, 
predicted pause time: 3615.71 ms, target pause time: 200.00 ms]
2018-11-13T05:32:44.948+0800: 2.331: [SoftReference, 0 refs, 0.0002103 secs]2018-11-13T05:32:44.948+0800: 2.332: 
[WeakReference, 970 refs, 0.0005817 secs]2018-11-13T05:32:44.949+0800: 2.332: [FinalReference, 4265 refs, 0.0266394 secs]
2018-11-13T05:32:44.975+0800: 2.359: [PhantomReference, 0 refs, 3 refs, 0.0000585 secs]2018-11-13T05:32:44.976+0800: 2.359: 
[JNI Weak Reference, 0.0001374 secs], 0.1040572 secs]
   [Parallel Time: 29.1 ms, GC Workers: 33]
      [GC Worker Start (ms): Min: 2260.1, Avg: 2265.0, Max: 2265.9, Diff: 5.8]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 18.2, Max: 22.7, Diff: 22.5, Sum: 691.2]
      [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.1, Diff: 0.1, Sum: 0.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 8.6, Diff: 8.6, Sum: 10.0]
      [Object Copy (ms): Min: 0.0, Avg: 3.9, Max: 22.9, Diff: 22.9, Sum: 147.1]
      [Termination (ms): Min: 0.0, Avg: 1.3, Max: 2.3, Diff: 2.3, Sum: 50.3]
         [Termination Attempts: Min: 1, Avg: 3.0, Max: 17, Diff: 16, Sum: 115]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 1.6]
      [GC Worker Total (ms): Min: 22.7, Avg: 23.7, Max: 28.6, Diff: 5.9, Sum: 900.6]
      [GC Worker End (ms): Min: 2288.6, Avg: 2288.7, Max: 2288.8, Diff: 0.2]
   [Code Root Fixup: 1.0 ms]
   [Code Root Purge: 0.1 ms]
   [Clear CT: 1.0 ms]
   [Other: 72.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 68.9 ms]
      [Ref Enq: 0.2 ms]
      [Redirty Cards: 0.4 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.5 ms]
   [Eden: 240.0M(512.0M)->0.0B(496.0M) Survivors: 0.0B->16.0M Heap: 254.0M(10.0G)->31.7M(10.0G)]
 [Times: user=0.44 sys=0.09, real=0.11 secs]
2018-11-13T05:32:44.980+0800: 2.363: [GC concurrent-root-region-scan-start]
2018-11-13T05:32:44.996+0800: 2.380: [GC concurrent-root-region-scan-end, 0.0167701 secs]
2018-11-13T05:32:44.996+0800: 2.380: [GC concurrent-mark-start]
2018-11-13T05:32:45.013+0800: 2.396: [GC concurrent-mark-end, 0.0160995 secs]
2018-11-13T05:32:45.013+0800: 2.396: Application time: 0.0328728 seconds
2018-11-13T05:32:45.013+0800: 2.397: [GC remark 2018-11-13T05:32:45.013+0800: 2.397: 
[Finalize Marking, 0.0331140 secs] 2018-11-13T05:32:45.047+0800: 2.430: 
[GC ref-proc2018-11-13T05:32:45.047+0800: 2.430: 
[SoftReference, 0 refs, 0.0001959 secs]2018-11-13T05:32:45.047+0800: 2.430: 
[WeakReference, 0 refs, 0.0001148 secs]2018-11-13T05:32:45.047+0800: 2.430: 
[FinalReference, 0 refs, 0.0001158 secs]2018-11-13T05:32:45.047+0800: 2.430: 
[PhantomReference, 0 refs, 0 refs, 0.0002233 secs]2018-11-13T05:32:45.047+0800: 2.431: 
[JNI Weak Reference, 0.0000572 secs], 0.0008127 secs] 2018-11-13T05:32:45.047+0800: 2.431: [Unloading, 0.0078450 secs], 0.0442183 secs]
 [Times: user=0.36 sys=0.01, real=0.05 secs]
2018-11-13T05:32:45.058+0800: 2.441: Application time: 0.0001231 seconds
2018-11-13T05:32:45.058+0800: 2.442: [GC cleanup 35M->35M(10G), 0.0134109 secs]
 [Times: user=0.04 sys=0.00, real=0.01 secs]
2018-11-13T05:32:45.144+0800: 2.528: Application time: 0.0721037 seconds
2018-11-13T05:32:45.392+0800: 2.775: Application time: 0.2464978 seconds
2018-11-13T05:32:45.805+0800: 3.188: Application time: 0.4129881 seconds
2018-11-13T05:32:46.806+0800: 4.190: Application time: 1.0001058 seconds

 ：
Application time：  
。。。

転載先:https://www.cnblogs.com/geektcp/p/9951539.html

[スタンダード1057/PSython]トーナメント

[java]配列