1 # HG changeset patch
2 # User brutisso
3 # Date 1426775154 -3600
4 # Thu Mar 19 15:25:54 2015 +0100
5 # Node ID b8448a4717da948b02f073dd274a94b50f095838
6 # Parent b31893aea8834508c334f4cef3b1d3bf410b4ac7
7 8027962: Per-phase timing measurements for strong roots processing
8 Reviewed-by: tschatzl, ecaspole
9
10 diff --git a/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp b/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp
11 --- a/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp
12 +++ b/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp
13 @@ -249,7 +249,24 @@
14
15 _gc_par_phases[GCWorkerStart] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Start (ms)", false, G1Log::LevelFiner, 2);
16 _gc_par_phases[ExtRootScan] = new WorkerDataArray<double>(max_gc_threads, "Ext Root Scanning (ms)", true, G1Log::LevelFiner, 2);
17 - _gc_par_phases[SATBFiltering] = new WorkerDataArray<double>(max_gc_threads, "SATB Filtering (ms)", true, G1Log::LevelFiner, 2);
18 +
19 + // Root scanning phases
20 + _gc_par_phases[ThreadRoots] = new WorkerDataArray<double>(max_gc_threads, "Thread Roots (ms)", true, G1Log::LevelFinest, 3);
21 + _gc_par_phases[StringTableRoots] = new WorkerDataArray<double>(max_gc_threads, "StringTable Roots (ms)", true, G1Log::LevelFinest, 3);
22 + _gc_par_phases[UniverseRoots] = new WorkerDataArray<double>(max_gc_threads, "Universe Roots (ms)", true, G1Log::LevelFinest, 3);
23 + _gc_par_phases[JNIRoots] = new WorkerDataArray<double>(max_gc_threads, "JNI Handles Roots (ms)", true, G1Log::LevelFinest, 3);
24 + _gc_par_phases[ObjectSynchronizerRoots] = new WorkerDataArray<double>(max_gc_threads, "ObjectSynchronizer Roots (ms)", true, G1Log::LevelFinest, 3);
25 + _gc_par_phases[FlatProfilerRoots] = new WorkerDataArray<double>(max_gc_threads, "FlatProfiler Roots (ms)", true, G1Log::LevelFinest, 3);
26 + _gc_par_phases[ManagementRoots] = new WorkerDataArray<double>(max_gc_threads, "Management Roots (ms)", true, G1Log::LevelFinest, 3);
27 + _gc_par_phases[SystemDictionaryRoots] = new WorkerDataArray<double>(max_gc_threads, "SystemDictionary Roots (ms)", true, G1Log::LevelFinest, 3);
28 + _gc_par_phases[CLDGRoots] = new WorkerDataArray<double>(max_gc_threads, "CLDG Roots (ms)", true, G1Log::LevelFinest, 3);
29 + _gc_par_phases[JVMTIRoots] = new WorkerDataArray<double>(max_gc_threads, "JVMTI Roots (ms)", true, G1Log::LevelFinest, 3);
30 + _gc_par_phases[CodeCacheRoots] = new WorkerDataArray<double>(max_gc_threads, "CodeCache Roots (ms)", true, G1Log::LevelFinest, 3);
31 + _gc_par_phases[CMRefRoots] = new WorkerDataArray<double>(max_gc_threads, "CM RefProcessor Roots (ms)", true, G1Log::LevelFinest, 3);
32 + _gc_par_phases[WaitForStrongCLD] = new WorkerDataArray<double>(max_gc_threads, "Wait For Strong CLD (ms)", true, G1Log::LevelFinest, 3);
33 + _gc_par_phases[WeakCLDRoots] = new WorkerDataArray<double>(max_gc_threads, "Weak CLD Roots (ms)", true, G1Log::LevelFinest, 3);
34 + _gc_par_phases[SATBFiltering] = new WorkerDataArray<double>(max_gc_threads, "SATB Filtering (ms)", true, G1Log::LevelFinest, 3);
35 +
36 _gc_par_phases[UpdateRS] = new WorkerDataArray<double>(max_gc_threads, "Update RS (ms)", true, G1Log::LevelFiner, 2);
37 _gc_par_phases[ScanRS] = new WorkerDataArray<double>(max_gc_threads, "Scan RS (ms)", true, G1Log::LevelFiner, 2);
38 _gc_par_phases[CodeRoots] = new WorkerDataArray<double>(max_gc_threads, "Code Root Scanning (ms)", true, G1Log::LevelFiner, 2);
39 @@ -282,8 +299,6 @@
40 _gc_par_phases[i]->reset();
41 }
42
43 - _gc_par_phases[SATBFiltering]->set_enabled(mark_in_progress);
44 -
45 _gc_par_phases[StringDedupQueueFixup]->set_enabled(G1StringDedup::is_enabled());
46 _gc_par_phases[StringDedupTableFixup]->set_enabled(G1StringDedup::is_enabled());
47 }
48 diff --git a/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp b/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp
49 --- a/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp
50 +++ b/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp
51 @@ -41,6 +41,20 @@
52 enum GCParPhases {
53 GCWorkerStart,
54 ExtRootScan,
55 + ThreadRoots,
56 + StringTableRoots,
57 + UniverseRoots,
58 + JNIRoots,
59 + ObjectSynchronizerRoots,
60 + FlatProfilerRoots,
61 + ManagementRoots,
62 + SystemDictionaryRoots,
63 + CLDGRoots,
64 + JVMTIRoots,
65 + CodeCacheRoots,
66 + CMRefRoots,
67 + WaitForStrongCLD,
68 + WeakCLDRoots,
69 SATBFiltering,
70 UpdateRS,
71 ScanRS,
72 diff --git a/src/share/vm/gc_implementation/g1/g1RootProcessor.cpp b/src/share/vm/gc_implementation/g1/g1RootProcessor.cpp
73 --- a/src/share/vm/gc_implementation/g1/g1RootProcessor.cpp
74 +++ b/src/share/vm/gc_implementation/g1/g1RootProcessor.cpp
75 @@ -128,6 +128,7 @@
76 uint worker_i) {
77 // First scan the shared roots.
78 double ext_roots_start = os::elapsedTime();
79 + G1GCPhaseTimes* phase_times = _g1h->g1_policy()->phase_times();
80
81 BufferingOopClosure buf_scan_non_heap_roots(scan_non_heap_roots);
82 BufferingOopClosure buf_scan_non_heap_weak_roots(scan_non_heap_weak_roots);
83 @@ -142,7 +143,9 @@
84 trace_metadata ? scan_strong_clds : NULL,
85 scan_strong_clds,
86 trace_metadata ? NULL : scan_weak_clds,
87 - &root_code_blobs);
88 + &root_code_blobs,
89 + phase_times,
90 + worker_i);
91
92 // This is the point where this worker thread will not find more strong CLDs/nmethods.
93 // Report this so G1 can synchronize the strong and weak CLDs/nmethods processing.
94 @@ -150,24 +153,34 @@
95 worker_has_discovered_all_strong_classes();
96 }
97
98 - process_vm_roots(strong_roots, weak_roots);
99 + process_vm_roots(strong_roots, weak_roots, phase_times, worker_i);
100
101 - // Now the CM ref_processor roots.
102 - if (!_process_strong_tasks->is_task_claimed(G1RP_PS_refProcessor_oops_do)) {
103 - // We need to treat the discovered reference lists of the
104 - // concurrent mark ref processor as roots and keep entries
105 - // (which are added by the marking threads) on them live
106 - // until they can be processed at the end of marking.
107 - _g1h->ref_processor_cm()->weak_oops_do(&buf_scan_non_heap_roots);
108 + {
109 + // Now the CM ref_processor roots.
110 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::CMRefRoots, worker_i);
111 + if (!_process_strong_tasks->is_task_claimed(G1RP_PS_refProcessor_oops_do)) {
112 + // We need to treat the discovered reference lists of the
113 + // concurrent mark ref processor as roots and keep entries
114 + // (which are added by the marking threads) on them live
115 + // until they can be processed at the end of marking.
116 + _g1h->ref_processor_cm()->weak_oops_do(&buf_scan_non_heap_roots);
117 + }
118 }
119
120 if (trace_metadata) {
121 - // Barrier to make sure all workers passed
122 - // the strong CLD and strong nmethods phases.
123 - wait_until_all_strong_classes_discovered();
124 + {
125 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::WaitForStrongCLD, worker_i);
126 + // Barrier to make sure all workers passed
127 + // the strong CLD and strong nmethods phases.
128 + wait_until_all_strong_classes_discovered();
129 + }
130
131 // Now take the complement of the strong CLDs.
132 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::WeakCLDRoots, worker_i);
133 ClassLoaderDataGraph::roots_cld_do(NULL, scan_weak_clds);
134 + } else {
135 + phase_times->record_time_secs(G1GCPhaseTimes::WaitForStrongCLD, worker_i, 0.0);
136 + phase_times->record_time_secs(G1GCPhaseTimes::WeakCLDRoots, worker_i, 0.0);
137 }
138
139 // Finish up any enqueued closure apps (attributed as object copy time).
140 @@ -177,7 +190,6 @@
141 double obj_copy_time_sec = buf_scan_non_heap_roots.closure_app_seconds()
142 + buf_scan_non_heap_weak_roots.closure_app_seconds();
143
144 - G1GCPhaseTimes* phase_times = _g1h->g1_policy()->phase_times();
145 phase_times->record_time_secs(G1GCPhaseTimes::ObjCopy, worker_i, obj_copy_time_sec);
146
147 double ext_root_time_sec = os::elapsedTime() - ext_roots_start - obj_copy_time_sec;
148 @@ -201,8 +213,8 @@
149 CLDClosure* clds,
150 CodeBlobClosure* blobs) {
151
152 - process_java_roots(oops, clds, clds, NULL, blobs);
153 - process_vm_roots(oops, NULL);
154 + process_java_roots(oops, clds, clds, NULL, blobs, NULL, 0);
155 + process_vm_roots(oops, NULL, NULL, 0);
156
157 _process_strong_tasks->all_tasks_completed();
158 }
159 @@ -211,8 +223,8 @@
160 CLDClosure* clds,
161 CodeBlobClosure* blobs) {
162
163 - process_java_roots(oops, NULL, clds, clds, NULL);
164 - process_vm_roots(oops, oops);
165 + process_java_roots(oops, NULL, clds, clds, NULL, NULL, 0);
166 + process_vm_roots(oops, oops, NULL, 0);
167
168 if (!_process_strong_tasks->is_task_claimed(G1RP_PS_CodeCache_oops_do)) {
169 CodeCache::blobs_do(blobs);
170 @@ -225,60 +237,95 @@
171 CLDClosure* thread_stack_clds,
172 CLDClosure* strong_clds,
173 CLDClosure* weak_clds,
174 - CodeBlobClosure* strong_code) {
175 + CodeBlobClosure* strong_code,
176 + G1GCPhaseTimes* phase_times,
177 + uint worker_i) {
178 assert(thread_stack_clds == NULL || weak_clds == NULL, "There is overlap between those, only one may be set");
179 // Iterating over the CLDG and the Threads are done early to allow us to
180 // first process the strong CLDs and nmethods and then, after a barrier,
181 // let the thread process the weak CLDs and nmethods.
182 -
183 - if (!_process_strong_tasks->is_task_claimed(G1RP_PS_ClassLoaderDataGraph_oops_do)) {
184 - ClassLoaderDataGraph::roots_cld_do(strong_clds, weak_clds);
185 + {
186 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::CLDGRoots, worker_i);
187 + if (!_process_strong_tasks->is_task_claimed(G1RP_PS_ClassLoaderDataGraph_oops_do)) {
188 + ClassLoaderDataGraph::roots_cld_do(strong_clds, weak_clds);
189 + }
190 }
191
192 - Threads::possibly_parallel_oops_do(strong_roots, thread_stack_clds, strong_code);
193 + {
194 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::ThreadRoots, worker_i);
195 + Threads::possibly_parallel_oops_do(strong_roots, thread_stack_clds, strong_code);
196 + }
197 }
198
199 void G1RootProcessor::process_vm_roots(OopClosure* strong_roots,
200 - OopClosure* weak_roots) {
201 -
202 - if (!_process_strong_tasks->is_task_claimed(G1RP_PS_Universe_oops_do)) {
203 - Universe::oops_do(strong_roots);
204 + OopClosure* weak_roots,
205 + G1GCPhaseTimes* phase_times,
206 + uint worker_i) {
207 + {
208 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::UniverseRoots, worker_i);
209 + if (!_process_strong_tasks->is_task_claimed(G1RP_PS_Universe_oops_do)) {
210 + Universe::oops_do(strong_roots);
211 + }
212 }
213
214 - if (!_process_strong_tasks->is_task_claimed(G1RP_PS_JNIHandles_oops_do)) {
215 - JNIHandles::oops_do(strong_roots);
216 + {
217 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::JNIRoots, worker_i);
218 + if (!_process_strong_tasks->is_task_claimed(G1RP_PS_JNIHandles_oops_do)) {
219 + JNIHandles::oops_do(strong_roots);
220 + }
221 }
222
223 - if (!_process_strong_tasks-> is_task_claimed(G1RP_PS_ObjectSynchronizer_oops_do)) {
224 - ObjectSynchronizer::oops_do(strong_roots);
225 + {
226 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::ObjectSynchronizerRoots, worker_i);
227 + if (!_process_strong_tasks-> is_task_claimed(G1RP_PS_ObjectSynchronizer_oops_do)) {
228 + ObjectSynchronizer::oops_do(strong_roots);
229 + }
230 }
231
232 - if (!_process_strong_tasks->is_task_claimed(G1RP_PS_FlatProfiler_oops_do)) {
233 - FlatProfiler::oops_do(strong_roots);
234 + {
235 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::FlatProfilerRoots, worker_i);
236 + if (!_process_strong_tasks->is_task_claimed(G1RP_PS_FlatProfiler_oops_do)) {
237 + FlatProfiler::oops_do(strong_roots);
238 + }
239 }
240
241 - if (!_process_strong_tasks->is_task_claimed(G1RP_PS_Management_oops_do)) {
242 - Management::oops_do(strong_roots);
243 + {
244 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::ManagementRoots, worker_i);
245 + if (!_process_strong_tasks->is_task_claimed(G1RP_PS_Management_oops_do)) {
246 + Management::oops_do(strong_roots);
247 + }
248 }
249
250 - if (!_process_strong_tasks->is_task_claimed(G1RP_PS_jvmti_oops_do)) {
251 - JvmtiExport::oops_do(strong_roots);
252 + {
253 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::JVMTIRoots, worker_i);
254 + if (!_process_strong_tasks->is_task_claimed(G1RP_PS_jvmti_oops_do)) {
255 + JvmtiExport::oops_do(strong_roots);
256 + }
257 }
258
259 - if (!_process_strong_tasks->is_task_claimed(G1RP_PS_SystemDictionary_oops_do)) {
260 - SystemDictionary::roots_oops_do(strong_roots, weak_roots);
261 + {
262 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::SystemDictionaryRoots, worker_i);
263 + if (!_process_strong_tasks->is_task_claimed(G1RP_PS_SystemDictionary_oops_do)) {
264 + SystemDictionary::roots_oops_do(strong_roots, weak_roots);
265 + }
266 }
267
268 - // All threads execute the following. A specific chunk of buckets
269 - // from the StringTable are the individual tasks.
270 - if (weak_roots != NULL) {
271 - StringTable::possibly_parallel_oops_do(weak_roots);
272 + {
273 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::StringTableRoots, worker_i);
274 + // All threads execute the following. A specific chunk of buckets
275 + // from the StringTable are the individual tasks.
276 + if (weak_roots != NULL) {
277 + StringTable::possibly_parallel_oops_do(weak_roots);
278 + }
279 }
280 }
281
282 void G1RootProcessor::scan_remembered_sets(G1ParPushHeapRSClosure* scan_rs,
283 OopClosure* scan_non_heap_weak_roots,
284 uint worker_i) {
285 + G1GCPhaseTimes* phase_times = _g1h->g1_policy()->phase_times();
286 + G1GCParPhaseTimesTracker x(phase_times, G1GCPhaseTimes::CodeCacheRoots, worker_i);
287 +
288 // Now scan the complement of the collection set.
289 G1CodeBlobClosure scavenge_cs_nmethods(scan_non_heap_weak_roots);
290
291 diff --git a/src/share/vm/gc_implementation/g1/g1RootProcessor.hpp b/src/share/vm/gc_implementation/g1/g1RootProcessor.hpp
292 --- a/src/share/vm/gc_implementation/g1/g1RootProcessor.hpp
293 +++ b/src/share/vm/gc_implementation/g1/g1RootProcessor.hpp
294 @@ -32,6 +32,7 @@
295 class CLDClosure;
296 class CodeBlobClosure;
297 class G1CollectedHeap;
298 +class G1GCPhaseTimes;
299 class G1ParPushHeapRSClosure;
300 class Monitor;
301 class OopClosure;
302 @@ -74,10 +75,14 @@
303 CLDClosure* thread_stack_clds,
304 CLDClosure* scan_strong_clds,
305 CLDClosure* scan_weak_clds,
306 - CodeBlobClosure* scan_strong_code);
307 + CodeBlobClosure* scan_strong_code,
308 + G1GCPhaseTimes* phase_times,
309 + uint worker_i);
310
311 void process_vm_roots(OopClosure* scan_non_heap_roots,
312 - OopClosure* scan_non_heap_weak_roots);
313 + OopClosure* scan_non_heap_weak_roots,
314 + G1GCPhaseTimes* phase_times,
315 + uint worker_i);
316
317 public:
318 G1RootProcessor(G1CollectedHeap* g1h);
319 diff --git a/test/gc/g1/TestGCLogMessages.java b/test/gc/g1/TestGCLogMessages.java
320 --- a/test/gc/g1/TestGCLogMessages.java
321 +++ b/test/gc/g1/TestGCLogMessages.java
322 @@ -1,5 +1,5 @@
323 /*
324 - * Copyright (c) 2014, Oracle and/or its affiliates. All rights reserved.
325 + * Copyright (c) 2014, 2015 Oracle and/or its affiliates. All rights reserved.
326 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
327 *
328 * This code is free software; you can redistribute it and/or modify it
329 @@ -23,7 +23,7 @@
330
331 /*
332 * @test TestGCLogMessages
333 - * @bug 8035406 8027295 8035398 8019342 8027959
334 + * @bug 8035406 8027295 8035398 8019342 8027959 8027962
335 * @summary Ensure that the PrintGCDetails output for a minor GC with G1
336 * includes the expected necessary messages.
337 * @key gc
338 @@ -34,128 +34,158 @@
339 import com.oracle.java.testlibrary.OutputAnalyzer;
340
341 public class TestGCLogMessages {
342 - public static void main(String[] args) throws Exception {
343 - testNormalLogs();
344 - testWithToSpaceExhaustionLogs();
345 - }
346
347 - private static void testNormalLogs() throws Exception {
348 + private enum Level {
349 + OFF, FINER, FINEST;
350 + public boolean lessOrEqualTo(Level other) {
351 + return this.compareTo(other) < 0;
352 + }
353 + }
354
355 - ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
356 - "-Xmx10M",
357 - GCTest.class.getName());
358 + private class LogMessageWithLevel {
359 + String message;
360 + Level level;
361
362 - OutputAnalyzer output = new OutputAnalyzer(pb.start());
363 + public LogMessageWithLevel(String message, Level level) {
364 + this.message = message;
365 + this.level = level;
366 + }
367 + };
368
369 - output.shouldNotContain("[Redirty Cards");
370 - output.shouldNotContain("[Parallel Redirty");
371 - output.shouldNotContain("[Redirtied Cards");
372 - output.shouldNotContain("[Code Root Purge");
373 - output.shouldNotContain("[String Dedup Fixup");
374 - output.shouldNotContain("[Young Free CSet");
375 - output.shouldNotContain("[Non-Young Free CSet");
376 - output.shouldNotContain("[Humongous Reclaim");
377 - output.shouldHaveExitValue(0);
378 + private LogMessageWithLevel allLogMessages[] = new LogMessageWithLevel[] {
379 + // Ext Root Scan
380 + new LogMessageWithLevel("Thread Roots (ms)", Level.FINEST),
381 + new LogMessageWithLevel("StringTable Roots (ms)", Level.FINEST),
382 + new LogMessageWithLevel("Universe Roots (ms)", Level.FINEST),
383 + new LogMessageWithLevel("JNI Handles Roots (ms)", Level.FINEST),
384 + new LogMessageWithLevel("ObjectSynchronizer Roots (ms)", Level.FINEST),
385 + new LogMessageWithLevel("FlatProfiler Roots", Level.FINEST),
386 + new LogMessageWithLevel("Management Roots", Level.FINEST),
387 + new LogMessageWithLevel("SystemDictionary Roots", Level.FINEST),
388 + new LogMessageWithLevel("CLDG Roots", Level.FINEST),
389 + new LogMessageWithLevel("JVMTI Roots", Level.FINEST),
390 + new LogMessageWithLevel("CodeCache Roots", Level.FINEST),
391 + new LogMessageWithLevel("SATB Filtering", Level.FINEST),
392 + new LogMessageWithLevel("CM RefProcessor Roots", Level.FINEST),
393 + new LogMessageWithLevel("Wait For Strong CLD", Level.FINEST),
394 + new LogMessageWithLevel("Weak CLD Roots", Level.FINEST),
395 + // Redirty Cards
396 + new LogMessageWithLevel("Redirty Cards", Level.FINER),
397 + new LogMessageWithLevel("Parallel Redirty", Level.FINEST),
398 + new LogMessageWithLevel("Redirtied Cards", Level.FINEST),
399 + // Misc Top-level
400 + new LogMessageWithLevel("Code Root Purge", Level.FINER),
401 + new LogMessageWithLevel("String Dedup Fixup", Level.FINER),
402 + // Free CSet
403 + new LogMessageWithLevel("Young Free CSet", Level.FINEST),
404 + new LogMessageWithLevel("Non-Young Free CSet", Level.FINEST),
405 + // Humongous Eager Reclaim
406 + new LogMessageWithLevel("Humongous Reclaim", Level.FINER),
407 + };
408
409 - pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
410 - "-XX:+UseStringDeduplication",
411 - "-Xmx10M",
412 - "-XX:+PrintGCDetails",
413 - GCTest.class.getName());
414 + void checkMessagesAtLevel(OutputAnalyzer output, LogMessageWithLevel messages[], Level level) throws Exception {
415 + for (LogMessageWithLevel l : messages) {
416 + if (level.lessOrEqualTo(l.level)) {
417 + output.shouldNotContain(l.message);
418 + } else {
419 + output.shouldContain(l.message);
420 + }
421 + }
422 + }
423
424 - output = new OutputAnalyzer(pb.start());
425 + public static void main(String[] args) throws Exception {
426 + new TestGCLogMessages().testNormalLogs();
427 + new TestGCLogMessages().testWithToSpaceExhaustionLogs();
428 + }
429
430 - output.shouldContain("[Redirty Cards");
431 - output.shouldNotContain("[Parallel Redirty");
432 - output.shouldNotContain("[Redirtied Cards");
433 - output.shouldContain("[Code Root Purge");
434 - output.shouldContain("[String Dedup Fixup");
435 - output.shouldNotContain("[Young Free CSet");
436 - output.shouldNotContain("[Non-Young Free CSet");
437 - output.shouldContain("[Humongous Reclaim");
438 - output.shouldNotContain("[Humongous Total");
439 - output.shouldNotContain("[Humongous Candidate");
440 - output.shouldNotContain("[Humongous Reclaimed");
441 - output.shouldHaveExitValue(0);
442 + private void testNormalLogs() throws Exception {
443
444 - pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
445 - "-XX:+UseStringDeduplication",
446 - "-Xmx10M",
447 - "-XX:+PrintGCDetails",
448 - "-XX:+UnlockExperimentalVMOptions",
449 - "-XX:G1LogLevel=finest",
450 - GCTest.class.getName());
451 + ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
452 + "-Xmx10M",
453 + GCTest.class.getName());
454
455 - output = new OutputAnalyzer(pb.start());
456 + OutputAnalyzer output = new OutputAnalyzer(pb.start());
457 + checkMessagesAtLevel(output, allLogMessages, Level.OFF);
458 + output.shouldHaveExitValue(0);
459
460 - output.shouldContain("[Redirty Cards");
461 - output.shouldContain("[Parallel Redirty");
462 - output.shouldContain("[Redirtied Cards");
463 - output.shouldContain("[Code Root Purge");
464 - output.shouldContain("[String Dedup Fixup");
465 - output.shouldContain("[Young Free CSet");
466 - output.shouldContain("[Non-Young Free CSet");
467 - output.shouldContain("[Humongous Reclaim");
468 - output.shouldContain("[Humongous Total");
469 - output.shouldContain("[Humongous Candidate");
470 - output.shouldContain("[Humongous Reclaimed");
471 - output.shouldHaveExitValue(0);
472 - }
473 + pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
474 + "-XX:+UseStringDeduplication",
475 + "-Xmx10M",
476 + "-XX:+PrintGCDetails",
477 + GCTest.class.getName());
478
479 - private static void testWithToSpaceExhaustionLogs() throws Exception {
480 - ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
481 - "-Xmx10M",
482 - "-Xmn5M",
483 - "-XX:+PrintGCDetails",
484 - GCTestWithToSpaceExhaustion.class.getName());
485 + output = new OutputAnalyzer(pb.start());
486 + checkMessagesAtLevel(output, allLogMessages, Level.FINER);
487
488 - OutputAnalyzer output = new OutputAnalyzer(pb.start());
489 - output.shouldContain("[Evacuation Failure");
490 - output.shouldNotContain("[Recalculate Used");
491 - output.shouldNotContain("[Remove Self Forwards");
492 - output.shouldNotContain("[Restore RemSet");
493 - output.shouldHaveExitValue(0);
494 + pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
495 + "-XX:+UseStringDeduplication",
496 + "-Xmx10M",
497 + "-XX:+PrintGCDetails",
498 + "-XX:+UnlockExperimentalVMOptions",
499 + "-XX:G1LogLevel=finest",
500 + GCTest.class.getName());
501
502 - pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
503 - "-Xmx10M",
504 - "-Xmn5M",
505 - "-XX:+PrintGCDetails",
506 - "-XX:+UnlockExperimentalVMOptions",
507 - "-XX:G1LogLevel=finest",
508 - GCTestWithToSpaceExhaustion.class.getName());
509 + output = new OutputAnalyzer(pb.start());
510 + checkMessagesAtLevel(output, allLogMessages, Level.FINEST);
511 + output.shouldHaveExitValue(0);
512 + }
513
514 - output = new OutputAnalyzer(pb.start());
515 - output.shouldContain("[Evacuation Failure");
516 - output.shouldContain("[Recalculate Used");
517 - output.shouldContain("[Remove Self Forwards");
518 - output.shouldContain("[Restore RemSet");
519 - output.shouldHaveExitValue(0);
520 - }
521 + LogMessageWithLevel exhFailureMessages[] = new LogMessageWithLevel[] {
522 + new LogMessageWithLevel("Evacuation Failure", Level.FINER),
523 + new LogMessageWithLevel("Recalculate Used", Level.FINEST),
524 + new LogMessageWithLevel("Remove Self Forwards", Level.FINEST),
525 + new LogMessageWithLevel("Restore RemSet", Level.FINEST),
526 + };
527
528 - static class GCTest {
529 - private static byte[] garbage;
530 - public static void main(String [] args) {
531 - System.out.println("Creating garbage");
532 - // create 128MB of garbage. This should result in at least one GC
533 - for (int i = 0; i < 1024; i++) {
534 - garbage = new byte[128 * 1024];
535 - }
536 - System.out.println("Done");
537 + private void testWithToSpaceExhaustionLogs() throws Exception {
538 + ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
539 + "-Xmx32M",
540 + "-Xmn16M",
541 + "-XX:+PrintGCDetails",
542 + GCTestWithToSpaceExhaustion.class.getName());
543 +
544 + OutputAnalyzer output = new OutputAnalyzer(pb.start());
545 + checkMessagesAtLevel(output, exhFailureMessages, Level.FINER);
546 + output.shouldHaveExitValue(0);
547 +
548 + pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
549 + "-Xmx32M",
550 + "-Xmn16M",
551 + "-XX:+PrintGCDetails",
552 + "-XX:+UnlockExperimentalVMOptions",
553 + "-XX:G1LogLevel=finest",
554 + GCTestWithToSpaceExhaustion.class.getName());
555 +
556 + output = new OutputAnalyzer(pb.start());
557 + checkMessagesAtLevel(output, exhFailureMessages, Level.FINEST);
558 + output.shouldHaveExitValue(0);
559 }
560 - }
561
562 - static class GCTestWithToSpaceExhaustion {
563 - private static byte[] garbage;
564 - private static byte[] largeObject;
565 - public static void main(String [] args) {
566 - largeObject = new byte[5*1024*1024];
567 - System.out.println("Creating garbage");
568 - // create 128MB of garbage. This should result in at least one GC,
569 - // some of them with to-space exhaustion.
570 - for (int i = 0; i < 1024; i++) {
571 - garbage = new byte[128 * 1024];
572 - }
573 - System.out.println("Done");
574 + static class GCTest {
575 + private static byte[] garbage;
576 + public static void main(String [] args) {
577 + System.out.println("Creating garbage");
578 + // create 128MB of garbage. This should result in at least one GC
579 + for (int i = 0; i < 1024; i++) {
580 + garbage = new byte[128 * 1024];
581 + }
582 + System.out.println("Done");
583 + }
584 }
585 - }
586 +
587 + static class GCTestWithToSpaceExhaustion {
588 + private static byte[] garbage;
589 + private static byte[] largeObject;
590 + public static void main(String [] args) {
591 + largeObject = new byte[16*1024*1024];
592 + System.out.println("Creating garbage");
593 + // create 128MB of garbage. This should result in at least one GC,
594 + // some of them with to-space exhaustion.
595 + for (int i = 0; i < 1024; i++) {
596 + garbage = new byte[128 * 1024];
597 + }
598 + System.out.println("Done");
599 + }
600 + }
601 }
602 +