Fri, 13 Apr 2012 01:59:38 +0200
7160728: Introduce an extra logging level for G1 logging
Summary: Added log levels "fine", "finer" and "finest". Let PrintGC map to "fine" and PrintGCDetails map to "finer". Separated out the per worker information in the G1 logging to the "finest" level.
Reviewed-by: stefank, jwilhelm, tonyp, johnc
1 /*
2 * Copyright (c) 2001, 2012, Oracle and/or its affiliates. All rights reserved.
3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4 *
5 * This code is free software; you can redistribute it and/or modify it
6 * under the terms of the GNU General Public License version 2 only, as
7 * published by the Free Software Foundation.
8 *
9 * This code is distributed in the hope that it will be useful, but WITHOUT
10 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
12 * version 2 for more details (a copy is included in the LICENSE file that
13 * accompanied this code).
14 *
15 * You should have received a copy of the GNU General Public License version
16 * 2 along with this work; if not, write to the Free Software Foundation,
17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18 *
19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20 * or visit www.oracle.com if you need additional information or have any
21 * questions.
22 *
23 */
25 #include "precompiled.hpp"
26 #include "gc_implementation/g1/concurrentMarkThread.inline.hpp"
27 #include "gc_implementation/g1/g1CollectedHeap.inline.hpp"
28 #include "gc_implementation/g1/g1CollectorPolicy.hpp"
29 #include "gc_implementation/g1/g1Log.hpp"
30 #include "gc_implementation/g1/vm_operations_g1.hpp"
31 #include "gc_implementation/shared/isGCActiveMark.hpp"
32 #include "gc_implementation/g1/vm_operations_g1.hpp"
33 #include "runtime/interfaceSupport.hpp"
35 VM_G1CollectForAllocation::VM_G1CollectForAllocation(
36 unsigned int gc_count_before,
37 size_t word_size)
38 : VM_G1OperationWithAllocRequest(gc_count_before, word_size,
39 GCCause::_allocation_failure) {
40 guarantee(word_size > 0, "an allocation should always be requested");
41 }
43 void VM_G1CollectForAllocation::doit() {
44 G1CollectedHeap* g1h = G1CollectedHeap::heap();
45 _result = g1h->satisfy_failed_allocation(_word_size, &_pause_succeeded);
46 assert(_result == NULL || _pause_succeeded,
47 "if we get back a result, the pause should have succeeded");
48 }
50 void VM_G1CollectFull::doit() {
51 G1CollectedHeap* g1h = G1CollectedHeap::heap();
52 GCCauseSetter x(g1h, _gc_cause);
53 g1h->do_full_collection(false /* clear_all_soft_refs */);
54 }
56 VM_G1IncCollectionPause::VM_G1IncCollectionPause(
57 unsigned int gc_count_before,
58 size_t word_size,
59 bool should_initiate_conc_mark,
60 double target_pause_time_ms,
61 GCCause::Cause gc_cause)
62 : VM_G1OperationWithAllocRequest(gc_count_before, word_size, gc_cause),
63 _should_initiate_conc_mark(should_initiate_conc_mark),
64 _target_pause_time_ms(target_pause_time_ms),
65 _should_retry_gc(false),
66 _full_collections_completed_before(0) {
67 guarantee(target_pause_time_ms > 0.0,
68 err_msg("target_pause_time_ms = %1.6lf should be positive",
69 target_pause_time_ms));
70 guarantee(word_size == 0 || gc_cause == GCCause::_g1_inc_collection_pause,
71 "we can only request an allocation if the GC cause is for "
72 "an incremental GC pause");
73 _gc_cause = gc_cause;
74 }
76 bool VM_G1IncCollectionPause::doit_prologue() {
77 bool res = VM_GC_Operation::doit_prologue();
78 if (!res) {
79 if (_should_initiate_conc_mark) {
80 // The prologue can fail for a couple of reasons. The first is that another GC
81 // got scheduled and prevented the scheduling of the initial mark GC. The
82 // second is that the GC locker may be active and the heap can't be expanded.
83 // In both cases we want to retry the GC so that the initial mark pause is
84 // actually scheduled. In the second case, however, we should stall until
85 // until the GC locker is no longer active and then retry the initial mark GC.
86 _should_retry_gc = true;
87 }
88 }
89 return res;
90 }
92 void VM_G1IncCollectionPause::doit() {
93 G1CollectedHeap* g1h = G1CollectedHeap::heap();
94 assert(!_should_initiate_conc_mark ||
95 ((_gc_cause == GCCause::_gc_locker && GCLockerInvokesConcurrent) ||
96 (_gc_cause == GCCause::_java_lang_system_gc && ExplicitGCInvokesConcurrent) ||
97 _gc_cause == GCCause::_g1_humongous_allocation),
98 "only a GC locker, a System.gc() or a hum allocation induced GC should start a cycle");
100 if (_word_size > 0) {
101 // An allocation has been requested. So, try to do that first.
102 _result = g1h->attempt_allocation_at_safepoint(_word_size,
103 false /* expect_null_cur_alloc_region */);
104 if (_result != NULL) {
105 // If we can successfully allocate before we actually do the
106 // pause then we will consider this pause successful.
107 _pause_succeeded = true;
108 return;
109 }
110 }
112 GCCauseSetter x(g1h, _gc_cause);
113 if (_should_initiate_conc_mark) {
114 // It's safer to read full_collections_completed() here, given
115 // that noone else will be updating it concurrently. Since we'll
116 // only need it if we're initiating a marking cycle, no point in
117 // setting it earlier.
118 _full_collections_completed_before = g1h->full_collections_completed();
120 // At this point we are supposed to start a concurrent cycle. We
121 // will do so if one is not already in progress.
122 bool res = g1h->g1_policy()->force_initial_mark_if_outside_cycle(_gc_cause);
124 // The above routine returns true if we were able to force the
125 // next GC pause to be an initial mark; it returns false if a
126 // marking cycle is already in progress.
127 //
128 // If a marking cycle is already in progress just return and skip the
129 // pause below - if the reason for requesting this initial mark pause
130 // was due to a System.gc() then the requesting thread should block in
131 // doit_epilogue() until the marking cycle is complete.
132 //
133 // If this initial mark pause was requested as part of a humongous
134 // allocation then we know that the marking cycle must just have
135 // been started by another thread (possibly also allocating a humongous
136 // object) as there was no active marking cycle when the requesting
137 // thread checked before calling collect() in
138 // attempt_allocation_humongous(). Retrying the GC, in this case,
139 // will cause the requesting thread to spin inside collect() until the
140 // just started marking cycle is complete - which may be a while. So
141 // we do NOT retry the GC.
142 if (!res) {
143 assert(_word_size == 0, "Concurrent Full GC/Humongous Object IM shouldn't be allocating");
144 if (_gc_cause != GCCause::_g1_humongous_allocation) {
145 _should_retry_gc = true;
146 }
147 return;
148 }
149 }
151 _pause_succeeded =
152 g1h->do_collection_pause_at_safepoint(_target_pause_time_ms);
153 if (_pause_succeeded && _word_size > 0) {
154 // An allocation had been requested.
155 _result = g1h->attempt_allocation_at_safepoint(_word_size,
156 true /* expect_null_cur_alloc_region */);
157 } else {
158 assert(_result == NULL, "invariant");
159 if (!_pause_succeeded) {
160 // Another possible reason reason for the pause to not be successful
161 // is that, again, the GC locker is active (and has become active
162 // since the prologue was executed). In this case we should retry
163 // the pause after waiting for the GC locker to become inactive.
164 _should_retry_gc = true;
165 }
166 }
167 }
169 void VM_G1IncCollectionPause::doit_epilogue() {
170 VM_GC_Operation::doit_epilogue();
172 // If the pause was initiated by a System.gc() and
173 // +ExplicitGCInvokesConcurrent, we have to wait here for the cycle
174 // that just started (or maybe one that was already in progress) to
175 // finish.
176 if (_gc_cause == GCCause::_java_lang_system_gc &&
177 _should_initiate_conc_mark) {
178 assert(ExplicitGCInvokesConcurrent,
179 "the only way to be here is if ExplicitGCInvokesConcurrent is set");
181 G1CollectedHeap* g1h = G1CollectedHeap::heap();
183 // In the doit() method we saved g1h->full_collections_completed()
184 // in the _full_collections_completed_before field. We have to
185 // wait until we observe that g1h->full_collections_completed()
186 // has increased by at least one. This can happen if a) we started
187 // a cycle and it completes, b) a cycle already in progress
188 // completes, or c) a Full GC happens.
190 // If the condition has already been reached, there's no point in
191 // actually taking the lock and doing the wait.
192 if (g1h->full_collections_completed() <=
193 _full_collections_completed_before) {
194 // The following is largely copied from CMS
196 Thread* thr = Thread::current();
197 assert(thr->is_Java_thread(), "invariant");
198 JavaThread* jt = (JavaThread*)thr;
199 ThreadToNativeFromVM native(jt);
201 MutexLockerEx x(FullGCCount_lock, Mutex::_no_safepoint_check_flag);
202 while (g1h->full_collections_completed() <=
203 _full_collections_completed_before) {
204 FullGCCount_lock->wait(Mutex::_no_safepoint_check_flag);
205 }
206 }
207 }
208 }
210 void VM_CGC_Operation::acquire_pending_list_lock() {
211 assert(_needs_pll, "don't call this otherwise");
212 // The caller may block while communicating
213 // with the SLT thread in order to acquire/release the PLL.
214 ConcurrentMarkThread::slt()->
215 manipulatePLL(SurrogateLockerThread::acquirePLL);
216 }
218 void VM_CGC_Operation::release_and_notify_pending_list_lock() {
219 assert(_needs_pll, "don't call this otherwise");
220 // The caller may block while communicating
221 // with the SLT thread in order to acquire/release the PLL.
222 ConcurrentMarkThread::slt()->
223 manipulatePLL(SurrogateLockerThread::releaseAndNotifyPLL);
224 }
226 void VM_CGC_Operation::doit() {
227 gclog_or_tty->date_stamp(G1Log::fine() && PrintGCDateStamps);
228 TraceCPUTime tcpu(G1Log::finer(), true, gclog_or_tty);
229 TraceTime t(_printGCMessage, G1Log::fine(), true, gclog_or_tty);
230 SharedHeap* sh = SharedHeap::heap();
231 // This could go away if CollectedHeap gave access to _gc_is_active...
232 if (sh != NULL) {
233 IsGCActiveMark x;
234 _cl->do_void();
235 } else {
236 _cl->do_void();
237 }
238 }
240 bool VM_CGC_Operation::doit_prologue() {
241 // Note the relative order of the locks must match that in
242 // VM_GC_Operation::doit_prologue() or deadlocks can occur
243 if (_needs_pll) {
244 acquire_pending_list_lock();
245 }
247 Heap_lock->lock();
248 SharedHeap::heap()->_thread_holds_heap_lock_for_gc = true;
249 return true;
250 }
252 void VM_CGC_Operation::doit_epilogue() {
253 // Note the relative order of the unlocks must match that in
254 // VM_GC_Operation::doit_epilogue()
255 SharedHeap::heap()->_thread_holds_heap_lock_for_gc = false;
256 Heap_lock->unlock();
257 if (_needs_pll) {
258 release_and_notify_pending_list_lock();
259 }
260 }