8165292: The gc+task logging is repeated a lot, decreasing the usefulness of -Xlog:gc*=info

Separate number of workers used debugging information from adaptive worker sizing log messages.

Reviewed-by: ehelin, sjohanss, jmasa
This commit is contained in:
Thomas Schatzl 2016-09-07 09:20:10 +02:00
parent 180c089047
commit c271d83599
6 changed files with 111 additions and 1 deletions

View File

@ -3511,6 +3511,7 @@ bool CMSCollector::do_marking_mt() {
conc_workers()->active_workers(),
Threads::number_of_non_daemon_threads());
num_workers = conc_workers()->update_active_workers(num_workers);
log_info(gc,task)("Using %u workers of %u for marking", num_workers, conc_workers()->total_workers());
CompactibleFreeListSpace* cms_space = _cmsGen->cmsSpace();

View File

@ -899,6 +899,8 @@ void ParNewGeneration::collect(bool full,
workers->active_workers(),
Threads::number_of_non_daemon_threads());
active_workers = workers->update_active_workers(active_workers);
log_info(gc,task)("Using %u workers of %u for evacuation", active_workers, workers->total_workers());
_old_gen = gch->old_gen();
// If the next generation is too full to accommodate worst-case promotion

View File

@ -1332,6 +1332,7 @@ bool G1CollectedHeap::do_full_collection(bool explicit_gc,
workers()->active_workers(),
Threads::number_of_non_daemon_threads());
workers()->update_active_workers(n_workers);
log_info(gc,task)("Using %u workers of %u to rebuild remembered set", n_workers, workers()->total_workers());
ParRebuildRSTask rebuild_rs_task(this);
workers()->run_task(&rebuild_rs_task);
@ -3068,6 +3069,7 @@ G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) {
workers()->active_workers(),
Threads::number_of_non_daemon_threads());
workers()->update_active_workers(active_workers);
log_info(gc,task)("Using %u workers of %u for evacuation", active_workers, workers()->total_workers());
TraceCollectorStats tcs(g1mm()->incremental_collection_counters());
TraceMemoryManagerStats tms(false /* fullGC */, gc_cause());

View File

@ -1035,6 +1035,8 @@ void G1ConcurrentMark::mark_from_roots() {
// worker threads may currently exist and more may not be
// available.
active_workers = _parallel_workers->update_active_workers(active_workers);
log_info(gc, task)("Using %u workers of %u for marking", active_workers, _parallel_workers->total_workers());
// Parallel task terminator is set in "set_concurrency_and_phase()"
set_concurrency_and_phase(active_workers, true /* concurrent */);

View File

@ -162,7 +162,7 @@ class AbstractWorkGang : public CHeapObj<mtInternal> {
_active_workers = MIN2(v, _total_workers);
add_workers(false /* exit_on_failure */);
assert(v != 0, "Trying to set active workers to 0");
log_info(gc, task)("GC Workers: using %d out of %d", _active_workers, _total_workers);
log_trace(gc, task)("%s: using %d out of %d workers", name(), _active_workers, _total_workers);
return _active_workers;
}

View File

@ -0,0 +1,103 @@
/*
* Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
* under the terms of the GNU General Public License version 2 only, as
* published by the Free Software Foundation.
*
* This code is distributed in the hope that it will be useful, but WITHOUT
* ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
* FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
* version 2 for more details (a copy is included in the LICENSE file that
* accompanied this code).
*
* You should have received a copy of the GNU General Public License version
* 2 along with this work; if not, write to the Free Software Foundation,
* Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
*
* Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
* or visit www.oracle.com if you need additional information or have any
* questions.
*/
/*
* @test TestNumWorkerOutput
* @bug 8165292
* @summary Check that when PrintGCDetails is enabled, gc,task output is printed only once per collection.
* @key gc
* @requires vm.gc=="null"
* @modules java.base/jdk.internal.misc
* @library /test/lib
* @build sun.hotspot.WhiteBox
* @run main ClassFileInstaller sun.hotspot.WhiteBox
* @run main/othervm -XX:+UseConcMarkSweepGC TestNumWorkerOutput UseConcMarkSweepGC
* @run main/othervm -XX:+UseG1GC TestNumWorkerOutput UseG1GC
*/
import sun.hotspot.WhiteBox;
import java.util.regex.Matcher;
import java.util.regex.Pattern;
import jdk.test.lib.Platform;
import jdk.test.lib.process.OutputAnalyzer;
import jdk.test.lib.process.ProcessTools;
import static jdk.test.lib.Asserts.*;
public class TestNumWorkerOutput {
public static void checkPatternOnce(String pattern, String what) throws Exception {
Pattern r = Pattern.compile(pattern);
Matcher m = r.matcher(what);
if (!m.find()) {
throw new RuntimeException("Could not find pattern " + pattern + " in output");
}
if (m.find()) {
throw new RuntimeException("Could find pattern " + pattern + " in output more than once");
}
}
public static void runTest(String gcArg) throws Exception {
final String[] arguments = {
"-Xbootclasspath/a:.",
"-XX:+UnlockExperimentalVMOptions",
"-XX:+UnlockDiagnosticVMOptions",
"-XX:+WhiteBoxAPI",
"-XX:+" + gcArg,
"-Xmx10M",
"-XX:+PrintGCDetails",
GCTest.class.getName()
};
ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(arguments);
OutputAnalyzer output = new OutputAnalyzer(pb.start());
output.shouldHaveExitValue(0);
System.out.println(output.getStdout());
String stdout = output.getStdout();
checkPatternOnce(".*[info.*].*[gc,task.*].*GC\\(0\\) .*Using \\d+ workers of \\d+ for evacuation.*", stdout);
}
public static void main(String[] args) throws Exception {
runTest(args[0]);
}
static class GCTest {
private static final WhiteBox WB = WhiteBox.getWhiteBox();
public static Object holder;
public static void main(String [] args) {
holder = new byte[100];
WB.youngGC();
System.out.println(holder);
}
}
}