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 */
24
25 #include "precompiled.hpp"
26 #include "gc/g1/g1CollectedHeap.inline.hpp"
27 #include "gc/g1/g1GCPhaseTimes.hpp"
28 #include "gc/g1/g1HotCardCache.hpp"
29 #include "gc/g1/g1StringDedup.hpp"
30 #include "gc/g1/workerDataArray.inline.hpp"
31 #include "memory/resourceArea.hpp"
32 #include "logging/log.hpp"
33 #include "runtime/timer.hpp"
34 #include "runtime/os.hpp"
35
36 static const char* Indents[5] = {"", " ", " ", " ", " "};
37
38 G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
39 _max_gc_threads(max_gc_threads),
40 _gc_start_counter(0),
41 _gc_pause_time_ms(0.0)
42 {
43 assert(max_gc_threads > 0, "Must have some GC threads");
44
45 _gc_par_phases[GCWorkerStart] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Start (ms):");
46 _gc_par_phases[ExtRootScan] = new WorkerDataArray<double>(max_gc_threads, "Ext Root Scanning (ms):");
47
48 // Root scanning phases
49 _gc_par_phases[ThreadRoots] = new WorkerDataArray<double>(max_gc_threads, "Thread Roots (ms):");
50 _gc_par_phases[StringTableRoots] = new WorkerDataArray<double>(max_gc_threads, "StringTable Roots (ms):");
51 _gc_par_phases[UniverseRoots] = new WorkerDataArray<double>(max_gc_threads, "Universe Roots (ms):");
52 _gc_par_phases[JNIRoots] = new WorkerDataArray<double>(max_gc_threads, "JNI Handles Roots (ms):");
209 void G1GCPhaseTimes::add_time_secs(GCParPhases phase, uint worker_i, double secs) {
210 _gc_par_phases[phase]->add(worker_i, secs);
211 }
212
213 void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_i, size_t count) {
214 _gc_par_phases[phase]->set_thread_work_item(worker_i, count);
215 }
216
217 // return the average time for a phase in milliseconds
218 double G1GCPhaseTimes::average_time_ms(GCParPhases phase) {
219 return _gc_par_phases[phase]->average() * 1000.0;
220 }
221
222 size_t G1GCPhaseTimes::sum_thread_work_items(GCParPhases phase) {
223 assert(_gc_par_phases[phase]->thread_work_items() != NULL, "No sub count");
224 return _gc_par_phases[phase]->thread_work_items()->sum();
225 }
226
227 template <class T>
228 void G1GCPhaseTimes::details(T* phase, const char* indent) const {
229 Log(gc, phases, task) log;
230 if (log.is_level(LogLevel::Trace)) {
231 outputStream* trace_out = log.trace_stream();
232 trace_out->print("%s", indent);
233 phase->print_details_on(trace_out);
234 }
235 }
236
237 void G1GCPhaseTimes::log_phase(WorkerDataArray<double>* phase, uint indent, outputStream* out, bool print_sum) const {
238 out->print("%s", Indents[indent]);
239 phase->print_summary_on(out, print_sum);
240 details(phase, Indents[indent]);
241
242 WorkerDataArray<size_t>* work_items = phase->thread_work_items();
243 if (work_items != NULL) {
244 out->print("%s", Indents[indent + 1]);
245 work_items->print_summary_on(out, true);
246 details(work_items, Indents[indent + 1]);
247 }
248 }
249
250 void G1GCPhaseTimes::debug_phase(WorkerDataArray<double>* phase) const {
251 Log(gc, phases) log;
252 if (log.is_level(LogLevel::Debug)) {
253 ResourceMark rm;
254 log_phase(phase, 2, log.debug_stream(), true);
255 }
256 }
257
258 void G1GCPhaseTimes::trace_phase(WorkerDataArray<double>* phase, bool print_sum) const {
259 Log(gc, phases) log;
260 if (log.is_level(LogLevel::Trace)) {
261 ResourceMark rm;
262 log_phase(phase, 3, log.trace_stream(), print_sum);
263 }
264 }
265
266 #define TIME_FORMAT "%.1lfms"
267
268 void G1GCPhaseTimes::info_time(const char* name, double value) const {
269 log_info(gc, phases)("%s%s: " TIME_FORMAT, Indents[1], name, value);
270 }
271
272 void G1GCPhaseTimes::debug_time(const char* name, double value) const {
273 log_debug(gc, phases)("%s%s: " TIME_FORMAT, Indents[2], name, value);
274 }
275
276 void G1GCPhaseTimes::trace_time(const char* name, double value) const {
277 log_trace(gc, phases)("%s%s: " TIME_FORMAT, Indents[3], name, value);
278 }
279
280 void G1GCPhaseTimes::trace_count(const char* name, size_t value) const {
281 log_trace(gc, phases)("%s%s: " SIZE_FORMAT, Indents[3], name, value);
282 }
|
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 */
24
25 #include "precompiled.hpp"
26 #include "gc/g1/g1CollectedHeap.inline.hpp"
27 #include "gc/g1/g1GCPhaseTimes.hpp"
28 #include "gc/g1/g1HotCardCache.hpp"
29 #include "gc/g1/g1StringDedup.hpp"
30 #include "gc/g1/workerDataArray.inline.hpp"
31 #include "memory/resourceArea.hpp"
32 #include "logging/log.hpp"
33 #include "logging/logStream.hpp"
34 #include "runtime/timer.hpp"
35 #include "runtime/os.hpp"
36
37 static const char* Indents[5] = {"", " ", " ", " ", " "};
38
39 G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
40 _max_gc_threads(max_gc_threads),
41 _gc_start_counter(0),
42 _gc_pause_time_ms(0.0)
43 {
44 assert(max_gc_threads > 0, "Must have some GC threads");
45
46 _gc_par_phases[GCWorkerStart] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Start (ms):");
47 _gc_par_phases[ExtRootScan] = new WorkerDataArray<double>(max_gc_threads, "Ext Root Scanning (ms):");
48
49 // Root scanning phases
50 _gc_par_phases[ThreadRoots] = new WorkerDataArray<double>(max_gc_threads, "Thread Roots (ms):");
51 _gc_par_phases[StringTableRoots] = new WorkerDataArray<double>(max_gc_threads, "StringTable Roots (ms):");
52 _gc_par_phases[UniverseRoots] = new WorkerDataArray<double>(max_gc_threads, "Universe Roots (ms):");
53 _gc_par_phases[JNIRoots] = new WorkerDataArray<double>(max_gc_threads, "JNI Handles Roots (ms):");
210 void G1GCPhaseTimes::add_time_secs(GCParPhases phase, uint worker_i, double secs) {
211 _gc_par_phases[phase]->add(worker_i, secs);
212 }
213
214 void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_i, size_t count) {
215 _gc_par_phases[phase]->set_thread_work_item(worker_i, count);
216 }
217
218 // return the average time for a phase in milliseconds
219 double G1GCPhaseTimes::average_time_ms(GCParPhases phase) {
220 return _gc_par_phases[phase]->average() * 1000.0;
221 }
222
223 size_t G1GCPhaseTimes::sum_thread_work_items(GCParPhases phase) {
224 assert(_gc_par_phases[phase]->thread_work_items() != NULL, "No sub count");
225 return _gc_par_phases[phase]->thread_work_items()->sum();
226 }
227
228 template <class T>
229 void G1GCPhaseTimes::details(T* phase, const char* indent) const {
230 LogTarget(Trace, gc, phases, task) lt;
231 if (lt.is_enabled()) {
232 LogStream ls(lt);
233 ls.print("%s", indent);
234 phase->print_details_on(&ls);
235 }
236 }
237
238 void G1GCPhaseTimes::log_phase(WorkerDataArray<double>* phase, uint indent, outputStream* out, bool print_sum) const {
239 out->print("%s", Indents[indent]);
240 phase->print_summary_on(out, print_sum);
241 details(phase, Indents[indent]);
242
243 WorkerDataArray<size_t>* work_items = phase->thread_work_items();
244 if (work_items != NULL) {
245 out->print("%s", Indents[indent + 1]);
246 work_items->print_summary_on(out, true);
247 details(work_items, Indents[indent + 1]);
248 }
249 }
250
251 void G1GCPhaseTimes::debug_phase(WorkerDataArray<double>* phase) const {
252 Log(gc, phases) log;
253 if (log.is_level(LogLevel::Debug)) {
254 ResourceMark rm;
255 LogStream ls(log.debug());
256 log_phase(phase, 2, &ls, true);
257 }
258 }
259
260 void G1GCPhaseTimes::trace_phase(WorkerDataArray<double>* phase, bool print_sum) const {
261 LogTarget(Trace, gc, phases) lt;
262 if (lt.is_enabled()) {
263 LogStream ls(lt);
264 log_phase(phase, 3, &ls, print_sum);
265 }
266 }
267
268 #define TIME_FORMAT "%.1lfms"
269
270 void G1GCPhaseTimes::info_time(const char* name, double value) const {
271 log_info(gc, phases)("%s%s: " TIME_FORMAT, Indents[1], name, value);
272 }
273
274 void G1GCPhaseTimes::debug_time(const char* name, double value) const {
275 log_debug(gc, phases)("%s%s: " TIME_FORMAT, Indents[2], name, value);
276 }
277
278 void G1GCPhaseTimes::trace_time(const char* name, double value) const {
279 log_trace(gc, phases)("%s%s: " TIME_FORMAT, Indents[3], name, value);
280 }
281
282 void G1GCPhaseTimes::trace_count(const char* name, size_t value) const {
283 log_trace(gc, phases)("%s%s: " SIZE_FORMAT, Indents[3], name, value);
284 }
|