-
Bug
-
Resolution: Fixed
-
P2
-
18
-
b06
-
b07
-
Verified
I get the impression that G1 veriffication got turned on by default?
Before the change:
[1.418s][info][gc,task ] GC(7) Using 1 workers of 48 for full compaction
[1.418s][info][gc,start ] GC(7) Pause Full (System.gc())
[1.418s][info][gc,phases,start] GC(7) Phase 1: Mark live objects
[1.424s][info][gc,phases ] GC(7) Phase 1: Mark live objects 5.746ms
[1.424s][info][gc,phases,start] GC(7) Phase 2: Prepare for compaction
[1.425s][info][gc,phases ] GC(7) Phase 2: Prepare for compaction 0.720ms
[1.425s][info][gc,phases,start] GC(7) Phase 3: Adjust pointers
[1.428s][info][gc,phases ] GC(7) Phase 3: Adjust pointers 3.534ms
[1.428s][info][gc,phases,start] GC(7) Phase 4: Compact heap
[1.429s][info][gc,phases ] GC(7) Phase 4: Compact heap 0.536ms
[1.430s][info][gc ] GC(7) Pause Full (System.gc()) 3M->3M(160M) 11.715ms
[1.430s][info][gc,heap ] GC(7) Eden regions: 1->0(1)
[1.430s][info][gc,heap ] GC(7) Survivor regions: 0->0(0)
[1.430s][info][gc,heap ] GC(7) Old regions: 1->1
[1.430s][info][gc,heap ] GC(7) Archive regions: 2->2
[1.430s][info][gc,heap ] GC(7) Humongous regions: 0->0
[1.430s][info][gc,metaspace ] GC(7) Metaspace: 14041K(14272K)->14041K(14272K) NonClass: 12686K(12800K)->12686K(12800K) Class: 1355K(1472K)->1355K(1472K)
[1.430s][info][gc,cpu ] GC(7) User=0.03s Sys=0.00s Real=0.01s
After the change:
[1.968s][info][gc,task ] GC(7) Using 1 workers of 48 for full compaction
[1.968s][info][gc,start ] GC(7) Pause Full (System.gc())
[1.968s][info][gc,verify,start] GC(7) Verifying Before GC
[2.006s][info][gc,verify ] GC(7) Verifying Before GC 38.124ms
[2.006s][info][gc,phases,start] GC(7) Phase 1: Mark live objects
[2.012s][info][gc,phases ] GC(7) Phase 1: Mark live objects 5.912ms
[2.012s][info][gc,phases,start] GC(7) Phase 2: Prepare for compaction
[2.013s][info][gc,phases ] GC(7) Phase 2: Prepare for compaction 0.723ms
[2.013s][info][gc,phases,start] GC(7) Phase 3: Adjust pointers
[2.016s][info][gc,phases ] GC(7) Phase 3: Adjust pointers 3.399ms
[2.016s][info][gc,phases,start] GC(7) Phase 4: Compact heap
[2.017s][info][gc,phases ] GC(7) Phase 4: Compact heap 0.549ms
[2.018s][info][gc,verify,start] GC(7) Verifying After GC
[2.057s][info][gc,verify ] GC(7) Verifying After GC 38.438ms
[2.057s][info][gc ] GC(7) Pause Full (System.gc()) 3M->3M(160M) 88.347ms
[2.057s][info][gc,heap ] GC(7) Eden regions: 1->0(1)
[2.057s][info][gc,heap ] GC(7) Survivor regions: 0->0(0)
[2.057s][info][gc,heap ] GC(7) Old regions: 1->1
[2.057s][info][gc,heap ] GC(7) Archive regions: 2->2
[2.057s][info][gc,heap ] GC(7) Humongous regions: 0->0
[2.057s][info][gc,metaspace ] GC(7) Metaspace: 14060K(14336K)->14060K(14336K) NonClass: 12706K(12864K)->12706K(12864K) Class: 1354K(1472K)->1354K(1472K)
[2.057s][info][gc,cpu ] GC(7) User=0.10s Sys=0.00s Real=0.09s
We run this test with -Xlog:gc*
Is it the intent that verification runs at INFO level or using gc* is caveat emptor? It could be a surprise to add this relatively long phase.
Before the change:
[1.418s][info][gc,task ] GC(7) Using 1 workers of 48 for full compaction
[1.418s][info][gc,start ] GC(7) Pause Full (System.gc())
[1.418s][info][gc,phases,start] GC(7) Phase 1: Mark live objects
[1.424s][info][gc,phases ] GC(7) Phase 1: Mark live objects 5.746ms
[1.424s][info][gc,phases,start] GC(7) Phase 2: Prepare for compaction
[1.425s][info][gc,phases ] GC(7) Phase 2: Prepare for compaction 0.720ms
[1.425s][info][gc,phases,start] GC(7) Phase 3: Adjust pointers
[1.428s][info][gc,phases ] GC(7) Phase 3: Adjust pointers 3.534ms
[1.428s][info][gc,phases,start] GC(7) Phase 4: Compact heap
[1.429s][info][gc,phases ] GC(7) Phase 4: Compact heap 0.536ms
[1.430s][info][gc ] GC(7) Pause Full (System.gc()) 3M->3M(160M) 11.715ms
[1.430s][info][gc,heap ] GC(7) Eden regions: 1->0(1)
[1.430s][info][gc,heap ] GC(7) Survivor regions: 0->0(0)
[1.430s][info][gc,heap ] GC(7) Old regions: 1->1
[1.430s][info][gc,heap ] GC(7) Archive regions: 2->2
[1.430s][info][gc,heap ] GC(7) Humongous regions: 0->0
[1.430s][info][gc,metaspace ] GC(7) Metaspace: 14041K(14272K)->14041K(14272K) NonClass: 12686K(12800K)->12686K(12800K) Class: 1355K(1472K)->1355K(1472K)
[1.430s][info][gc,cpu ] GC(7) User=0.03s Sys=0.00s Real=0.01s
After the change:
[1.968s][info][gc,task ] GC(7) Using 1 workers of 48 for full compaction
[1.968s][info][gc,start ] GC(7) Pause Full (System.gc())
[1.968s][info][gc,verify,start] GC(7) Verifying Before GC
[2.006s][info][gc,verify ] GC(7) Verifying Before GC 38.124ms
[2.006s][info][gc,phases,start] GC(7) Phase 1: Mark live objects
[2.012s][info][gc,phases ] GC(7) Phase 1: Mark live objects 5.912ms
[2.012s][info][gc,phases,start] GC(7) Phase 2: Prepare for compaction
[2.013s][info][gc,phases ] GC(7) Phase 2: Prepare for compaction 0.723ms
[2.013s][info][gc,phases,start] GC(7) Phase 3: Adjust pointers
[2.016s][info][gc,phases ] GC(7) Phase 3: Adjust pointers 3.399ms
[2.016s][info][gc,phases,start] GC(7) Phase 4: Compact heap
[2.017s][info][gc,phases ] GC(7) Phase 4: Compact heap 0.549ms
[2.018s][info][gc,verify,start] GC(7) Verifying After GC
[2.057s][info][gc,verify ] GC(7) Verifying After GC 38.438ms
[2.057s][info][gc ] GC(7) Pause Full (System.gc()) 3M->3M(160M) 88.347ms
[2.057s][info][gc,heap ] GC(7) Eden regions: 1->0(1)
[2.057s][info][gc,heap ] GC(7) Survivor regions: 0->0(0)
[2.057s][info][gc,heap ] GC(7) Old regions: 1->1
[2.057s][info][gc,heap ] GC(7) Archive regions: 2->2
[2.057s][info][gc,heap ] GC(7) Humongous regions: 0->0
[2.057s][info][gc,metaspace ] GC(7) Metaspace: 14060K(14336K)->14060K(14336K) NonClass: 12706K(12864K)->12706K(12864K) Class: 1354K(1472K)->1354K(1472K)
[2.057s][info][gc,cpu ] GC(7) User=0.10s Sys=0.00s Real=0.09s
We run this test with -Xlog:gc*
Is it the intent that verification runs at INFO level or using gc* is caveat emptor? It could be a surprise to add this relatively long phase.
- duplicates
-
JDK-8271082 gc/arguments/TestVerifyBeforeAndAfterGCFlags.java failed with "RuntimeException: 'Verifying Before GC' found in stdout: 'Verifying Before GC'"
-
- Closed
-
- relates to
-
JDK-8269295 Verification time before/after young collection only covers parts of the verification
-
- Resolved
-