--- old/src/share/vm/gc/parallel/psParallelCompact.cpp 2016-03-17 14:11:51.189576842 +0100 +++ new/src/share/vm/gc/parallel/psParallelCompact.cpp 2016-03-17 14:11:51.029571451 +0100 @@ -195,10 +195,10 @@ }; void PSParallelCompact::print_region_ranges() { - if (!log_develop_is_enabled(Trace, gc, compaction, phases)) { + if (!log_develop_is_enabled(Trace, gc, compaction)) { return; } - LogHandle(gc, compaction, phases) log; + LogHandle(gc, compaction) log; ResourceMark rm; Universe::print_on(log.trace_stream()); log.trace("space bottom top end new_top"); @@ -225,7 +225,7 @@ ParallelCompactData& sd = PSParallelCompact::summary_data(); size_t dci = c->destination() ? sd.addr_to_region_idx(c->destination()) : 0; - log_develop_trace(gc, compaction, phases)( + log_develop_trace(gc, compaction)( REGION_IDX_FORMAT " " PTR_FORMAT " " REGION_IDX_FORMAT " " PTR_FORMAT " " REGION_DATA_FORMAT " " REGION_DATA_FORMAT " " @@ -258,14 +258,14 @@ ++i; } - log_develop_trace(gc, compaction, phases)("summary_data_bytes=" SIZE_FORMAT, total_words * HeapWordSize); + log_develop_trace(gc, compaction)("summary_data_bytes=" SIZE_FORMAT, total_words * HeapWordSize); } void print_generic_summary_data(ParallelCompactData& summary_data, SpaceInfo* space_info) { - if (!log_develop_is_enabled(Trace, gc, compaction, phases)) { + if (!log_develop_is_enabled(Trace, gc, compaction)) { return; } @@ -296,7 +296,7 @@ size_t i = summary_data.addr_to_region_idx(space->bottom()); while (i < end_region && summary_data.region(i)->data_size() == region_size) { ParallelCompactData::RegionData* c = summary_data.region(i); - log_develop_trace(gc, compaction, phases)( + log_develop_trace(gc, compaction)( SIZE_FORMAT_W(5) " " PTR_FORMAT " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " %d", i, p2i(c->destination()), c->partial_obj_size(), c->live_obj_size(), @@ -330,7 +330,7 @@ } ParallelCompactData::RegionData* c = summary_data.region(i); - log_develop_trace(gc, compaction, phases)( + log_develop_trace(gc, compaction)( SIZE_FORMAT_W(5) " " PTR_FORMAT " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " %d" "%12.10f " SIZE_FORMAT_W(10) " " SIZE_FORMAT_W(10), i, p2i(c->destination()), @@ -346,21 +346,21 @@ // Any remaining regions are empty. Print one more if there is one. if (i < end_region) { ParallelCompactData::RegionData* c = summary_data.region(i); - log_develop_trace(gc, compaction, phases)( + log_develop_trace(gc, compaction)( SIZE_FORMAT_W(5) " " PTR_FORMAT " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " " SIZE_FORMAT_W(5) " %d", i, p2i(c->destination()), c->partial_obj_size(), c->live_obj_size(), c->data_size(), c->source_region(), c->destination_count()); } - log_develop_trace(gc, compaction, phases)("max: " SIZE_FORMAT_W(4) " d2r=" SIZE_FORMAT_W(10) " l2r=" SIZE_FORMAT_W(10) " max_ratio=%14.12f", - max_reclaimed_ratio_region, max_dead_to_right, max_live_to_right, max_reclaimed_ratio); + log_develop_trace(gc, compaction)("max: " SIZE_FORMAT_W(4) " d2r=" SIZE_FORMAT_W(10) " l2r=" SIZE_FORMAT_W(10) " max_ratio=%14.12f", + max_reclaimed_ratio_region, max_dead_to_right, max_live_to_right, max_reclaimed_ratio); } void print_initial_summary_data(ParallelCompactData& summary_data, SpaceInfo* space_info) { - if (!log_develop_is_enabled(Trace, gc, compaction, phases)) { + if (!log_develop_is_enabled(Trace, gc, compaction)) { return; } @@ -621,7 +621,7 @@ sr->partial_obj_size())); const size_t end_idx = addr_to_region_idx(target_end); - log_develop_trace(gc, compaction, phases)("split: clearing source_region field in [" SIZE_FORMAT ", " SIZE_FORMAT ")", beg_idx, end_idx); + log_develop_trace(gc, compaction)("split: clearing source_region field in [" SIZE_FORMAT ", " SIZE_FORMAT ")", beg_idx, end_idx); for (size_t idx = beg_idx; idx < end_idx; ++idx) { _region_data[idx].set_source_region(0); } @@ -641,22 +641,22 @@ *target_next = split_destination + partial_obj_size; HeapWord* const source_next = region_to_addr(split_region) + partial_obj_size; - if (log_develop_is_enabled(Trace, gc, compaction, phases)) { + if (log_develop_is_enabled(Trace, gc, compaction)) { const char * split_type = partial_obj_size == 0 ? "easy" : "hard"; - log_develop_trace(gc, compaction, phases)("%s split: src=" PTR_FORMAT " src_c=" SIZE_FORMAT " pos=" SIZE_FORMAT, - split_type, p2i(source_next), split_region, partial_obj_size); - log_develop_trace(gc, compaction, phases)("%s split: dst=" PTR_FORMAT " dst_c=" SIZE_FORMAT " tn=" PTR_FORMAT, - split_type, p2i(split_destination), - addr_to_region_idx(split_destination), - p2i(*target_next)); + log_develop_trace(gc, compaction)("%s split: src=" PTR_FORMAT " src_c=" SIZE_FORMAT " pos=" SIZE_FORMAT, + split_type, p2i(source_next), split_region, partial_obj_size); + log_develop_trace(gc, compaction)("%s split: dst=" PTR_FORMAT " dst_c=" SIZE_FORMAT " tn=" PTR_FORMAT, + split_type, p2i(split_destination), + addr_to_region_idx(split_destination), + p2i(*target_next)); if (partial_obj_size != 0) { HeapWord* const po_beg = split_info.destination(); HeapWord* const po_end = po_beg + split_info.partial_obj_size(); - log_develop_trace(gc, compaction, phases)("%s split: po_beg=" PTR_FORMAT " " SIZE_FORMAT " po_end=" PTR_FORMAT " " SIZE_FORMAT, - split_type, - p2i(po_beg), addr_to_region_idx(po_beg), - p2i(po_end), addr_to_region_idx(po_end)); + log_develop_trace(gc, compaction)("%s split: po_beg=" PTR_FORMAT " " SIZE_FORMAT " po_end=" PTR_FORMAT " " SIZE_FORMAT, + split_type, + p2i(po_beg), addr_to_region_idx(po_beg), + p2i(po_end), addr_to_region_idx(po_end)); } } @@ -670,7 +670,7 @@ HeapWord** target_next) { HeapWord* const source_next_val = source_next == NULL ? NULL : *source_next; - log_develop_trace(gc, compaction, phases)( + log_develop_trace(gc, compaction)( "sb=" PTR_FORMAT " se=" PTR_FORMAT " sn=" PTR_FORMAT "tb=" PTR_FORMAT " te=" PTR_FORMAT " tn=" PTR_FORMAT, p2i(source_beg), p2i(source_end), p2i(source_next_val), @@ -938,7 +938,7 @@ // at each young gen gc. Do the update unconditionally (even though a // promotion failure does not swap spaces) because an unknown number of young // collections will have swapped the spaces an unknown number of times. - GCTraceTime(Trace, gc, phases) tm("Pre Compact", &_gc_timer); + GCTraceTime(Debug, gc, phases) tm("Pre Compact", &_gc_timer); ParallelScavengeHeap* heap = ParallelScavengeHeap::heap(); _space_info[from_space_id].set_space(heap->young_gen()->from_space()); _space_info[to_space_id].set_space(heap->young_gen()->to_space()); @@ -981,7 +981,7 @@ void PSParallelCompact::post_compact() { - GCTraceTime(Trace, gc, phases) tm("Post Compact", &_gc_timer); + GCTraceTime(Info, gc, phases) tm("Post Compact", &_gc_timer); for (unsigned int id = old_space_id; id < last_space_id; ++id) { // Clear the marking bitmap, summary data and split info. @@ -1524,7 +1524,7 @@ } } - if (log_develop_is_enabled(Trace, gc, compaction, phases)) { + if (log_develop_is_enabled(Trace, gc, compaction)) { const size_t region_size = ParallelCompactData::RegionSize; HeapWord* const dense_prefix_end = _space_info[id].dense_prefix(); const size_t dp_region = _summary_data.addr_to_region_idx(dense_prefix_end); @@ -1532,7 +1532,7 @@ HeapWord* const new_top = _space_info[id].new_top(); const HeapWord* nt_aligned_up = _summary_data.region_align_up(new_top); const size_t cr_words = pointer_delta(nt_aligned_up, dense_prefix_end); - log_develop_trace(gc, compaction, phases)( + log_develop_trace(gc, compaction)( "id=%d cap=" SIZE_FORMAT " dp=" PTR_FORMAT " " "dp_region=" SIZE_FORMAT " " "dp_count=" SIZE_FORMAT " " "cr_count=" SIZE_FORMAT " " "nt=" PTR_FORMAT, @@ -1548,7 +1548,7 @@ SpaceId src_space_id, HeapWord* src_beg, HeapWord* src_end) { - log_develop_trace(gc, compaction, phases)( + log_develop_trace(gc, compaction)( "Summarizing %d [%s] into %d [%s]: " "src=" PTR_FORMAT "-" PTR_FORMAT " " SIZE_FORMAT "-" SIZE_FORMAT " " @@ -1568,7 +1568,7 @@ void PSParallelCompact::summary_phase(ParCompactionManager* cm, bool maximum_compaction) { - GCTraceTime(Trace, gc, phases) tm("Summary Phase", &_gc_timer); + GCTraceTime(Info, gc, phases) tm("Summary Phase", &_gc_timer); #ifdef ASSERT if (TraceParallelOldGCMarkingPhase) { @@ -1584,7 +1584,7 @@ // Quick summarization of each space into itself, to see how much is live. summarize_spaces_quick(); - log_develop_trace(gc, compaction, phases)("summary phase: after summarizing each space to self"); + log_develop_trace(gc, compaction)("summary phase: after summarizing each space to self"); NOT_PRODUCT(print_region_ranges()); NOT_PRODUCT(print_initial_summary_data(_summary_data, _space_info)); @@ -1660,7 +1660,7 @@ } } - log_develop_trace(gc, compaction, phases)("Summary_phase: after final summarization"); + log_develop_trace(gc, compaction)("Summary_phase: after final summarization"); NOT_PRODUCT(print_region_ranges()); NOT_PRODUCT(print_initial_summary_data(_summary_data, _space_info)); } @@ -2042,7 +2042,7 @@ bool maximum_heap_compaction, ParallelOldTracer *gc_tracer) { // Recursively traverse all live objects and mark them - GCTraceTime(Trace, gc, phases) tm("Marking Phase", &_gc_timer); + GCTraceTime(Info, gc, phases) tm("Marking Phase", &_gc_timer); ParallelScavengeHeap* heap = ParallelScavengeHeap::heap(); uint parallel_gc_threads = heap->gc_task_manager()->workers(); @@ -2057,7 +2057,7 @@ ClassLoaderDataGraph::clear_claimed_marks(); { - GCTraceTime(Trace, gc, phases) tm("Par Mark", &_gc_timer); + GCTraceTime(Debug, gc, phases) tm("Par Mark", &_gc_timer); ParallelScavengeHeap::ParStrongRootsScope psrs; @@ -2086,7 +2086,7 @@ // Process reference objects found during marking { - GCTraceTime(Trace, gc, phases) tm("Reference Processing", &_gc_timer); + GCTraceTime(Debug, gc, phases) tm("Reference Processing", &_gc_timer); ReferenceProcessorStats stats; if (ref_processor()->processing_is_mt()) { @@ -2107,7 +2107,7 @@ assert(cm->marking_stacks_empty(), "Marking should have completed"); { - GCTraceTime(Debug, gc) tm_m("Class Unloading", &_gc_timer); + GCTraceTime(Debug, gc, phases) tm_m("Class Unloading", &_gc_timer); // Follow system dictionary roots and unload classes. bool purged_class = SystemDictionary::do_unloading(is_alive_closure()); @@ -2120,13 +2120,13 @@ } { - GCTraceTime(Debug, gc) t("Scrub String Table", &_gc_timer); + GCTraceTime(Debug, gc, phases) t("Scrub String Table", &_gc_timer); // Delete entries for dead interned strings. StringTable::unlink(is_alive_closure()); } { - GCTraceTime(Debug, gc) t("Scrub Symbol Table", &_gc_timer); + GCTraceTime(Debug, gc, phases) t("Scrub Symbol Table", &_gc_timer); // Clean up unreferenced symbols in symbol table. SymbolTable::unlink(); } @@ -2136,7 +2136,7 @@ void PSParallelCompact::adjust_roots(ParCompactionManager* cm) { // Adjust the pointers to reflect the new locations - GCTraceTime(Trace, gc, phases) tm("Adjust Roots", &_gc_timer); + GCTraceTime(Info, gc, phases) tm("Adjust Roots", &_gc_timer); // Need new claim bits when tracing through and adjusting pointers. ClassLoaderDataGraph::clear_claimed_marks(); @@ -2410,7 +2410,7 @@ #endif // #ifdef ASSERT void PSParallelCompact::compact() { - GCTraceTime(Trace, gc, phases) tm("Compaction Phase", &_gc_timer); + GCTraceTime(Info, gc, phases) tm("Compaction Phase", &_gc_timer); ParallelScavengeHeap* heap = ParallelScavengeHeap::heap(); PSOldGen* old_gen = heap->old_gen();