CODEWITHSUNDEEP
elasticsearch
zhuguowei
zhuguowei

Reputation: 8487

Does exist some official document to introduce the gc log?

Today there was an indexing slow log, 

[2020-02-12T15:52:37,418][WARN ][i.i.s.index              ] [node-1] [company/KTngnM6ASD-_KdU0FFAWRA] took[22.7s], took_millis[22703], type[_doc], id[20080943028], routing[], source[{...}]

then to check gc.log to find out why is so, 

[2020-02-12T07:52:37.417+0000][22539][safepoint      ] Total time for which application threads were stopped: 0.0004935 seconds, Stopping threads took: 0.0001389 seconds
[2020-02-12T07:52:37.586+0000][22539][safepoint      ] Application time: 0.1682439 seconds
[2020-02-12T07:52:37.586+0000][22539][safepoint      ] Entering safepoint region: GenCollectForAllocation
[2020-02-12T07:52:37.586+0000][22539][gc,start       ] GC(315124) Pause Young (Allocation Failure)
[2020-02-12T07:52:37.586+0000][22539][gc,task        ] GC(315124) Using 8 workers of 8 for evacuation
[2020-02-12T07:52:37.641+0000][22539][gc,age         ] GC(315124) Desired survivor size 34865152 bytes, new threshold 3 (max threshold 6)
[2020-02-12T07:52:37.641+0000][22539][gc,age         ] GC(315124) Age table with threshold 3 (max threshold 6)
[2020-02-12T07:52:37.641+0000][22539][gc,age         ] GC(315124) - age   1:   22998672 bytes,   22998672 total
[2020-02-12T07:52:37.641+0000][22539][gc,age         ] GC(315124) - age   2:    4966112 bytes,   27964784 total
[2020-02-12T07:52:37.641+0000][22539][gc,age         ] GC(315124) - age   3:   10219520 bytes,   38184304 total
[2020-02-12T07:52:37.641+0000][22539][gc,age         ] GC(315124) - age   4:    4875304 bytes,   43059608 total
[2020-02-12T07:52:37.641+0000][22539][gc,heap        ] GC(315124) ParNew: 597611K->52614K(613440K)
[2020-02-12T07:52:37.641+0000][22539][gc,heap        ] GC(315124) CMS: 4992477K->4998973K(16095680K)
[2020-02-12T07:52:37.641+0000][22539][gc,metaspace   ] GC(315124) Metaspace: 103488K->103488K(1144832K)
[2020-02-12T07:52:37.641+0000][22539][gc             ] GC(315124) Pause Young (Allocation Failure) 5459M->4933M(16317M) 54.724ms
[2020-02-12T07:52:37.641+0000][22539][gc,cpu         ] GC(315124) User=0.35s Sys=0.00s Real=0.06s
[2020-02-12T07:52:37.641+0000][22539][safepoint      ] Leaving safepoint region

it seems gc is ok, but some log do not understand, e.g.

Entering safepoint region: Cleanup
Entering safepoint region: RevokeBias
Entering safepoint region: GenCollectForAllocation

what are Cleanup, RevokeBias, GenCollectForAllocation meaning? and What Application time meaning? why are so different?

Application time: 0.1382641 seconds
Application time: 13.2106552 seconds
Application time: 106.3031188 seconds

Upvotes: 1

Views: 894

Answers (1)

Eugene
Eugene

Reputation: 120978

It's funny that you mention some things, but do not provide logs for them. Anyway:

RevokeBias is when revoking of biased locking happens or when "fat" locks from biased locking are deflated.

GenCollectForAllocation - this is the reason why the safepoint was triggered. You can read it as : "generational collector for allocation failure". There are many more other reasons, FYI.

Cleanup is whatever safepoint cleanup tasks are.

AFAIK, if you want more details, you need to enable tracing log level.

Upvotes: 1

Related Questions