Skip to content
Permalink
Browse files
Added CLI submit config toggle for verbose GC logging (#3663)
  • Loading branch information
nicknezis committed Jan 21, 2021
1 parent fdf3430 commit f11ebc378044baad91738fa7cd77291a1859eef6
Show file tree
Hide file tree
Showing 11 changed files with 92 additions and 170 deletions.
@@ -102,6 +102,7 @@
@click.option("--topology-defn-file", required=True)
@click.option("--topology-id", required=True)
@click.option("--topology-name", required=True)
@click.option("--verbose-gc", is_flag=True)
@click.option("--jvm-remote-debugger-ports",
help="comma separated list of ports to be used"
" by a remote debugger for JVM instances")
@@ -342,6 +343,7 @@ def init_from_parsed_args(self, parsed_args):
self.health_manager_mode = parsed_args.health_manager_mode
self.health_manager_classpath = '%s:%s'\
% (self.scheduler_classpath, parsed_args.health_manager_classpath)
self.verbose_gc = parsed_args.verbose_gc
self.jvm_remote_debugger_ports = \
parsed_args.jvm_remote_debugger_ports.split(",") \
if parsed_args.jvm_remote_debugger_ports else None
@@ -574,36 +576,17 @@ def _get_java_major_version(self):
return int(self._get_jvm_version().split(".")[0])

def _get_java_gc_instance_cmd(self, cmd, gc_name):
gc_cmd = ['-verbosegc']
if self._get_java_major_version() >= 9:
gc_cmd += [
'-XX:+UseG1GC',
'-XX:+ParallelRefProcEnabled',
'-XX:+UseStringDeduplication',
'-XX:MaxGCPauseMillis=100',
'-XX:InitiatingHeapOccupancyPercent=30',
'-XX:+HeapDumpOnOutOfMemoryError',
'-XX:ParallelGCThreads=4',
'-Xlog:gc*,safepoint=info:file=' + self.log_dir + '/gc.' + gc_name +
'.log:tags,time,uptime,level:filecount=5,filesize=100M']
else:
gc_cmd += [
'-XX:+UseConcMarkSweepGC',
'-XX:+CMSScavengeBeforeRemark',
'-XX:TargetSurvivorRatio=90',
'-XX:+PrintGCDetails',
'-XX:+PrintGCTimeStamps',
'-XX:+PrintGCDateStamps',
'-XX:+PrintGCCause',
'-XX:+UseGCLogFileRotation',
'-XX:NumberOfGCLogFiles=5',
'-XX:GCLogFileSize=100M',
'-XX:+PrintPromotionFailure',
'-XX:+PrintTenuringDistribution',
'-XX:+PrintHeapAtGC',
'-XX:+HeapDumpOnOutOfMemoryError',
'-XX:ParallelGCThreads=4',
'-Xloggc:' + self.log_dir + '/gc.' + gc_name + '.log']
gc_cmd = [
'-XX:+UseG1GC',
'-XX:+ParallelRefProcEnabled',
'-XX:+UseStringDeduplication',
'-XX:MaxGCPauseMillis=100',
'-XX:InitiatingHeapOccupancyPercent=30',
'-XX:+HeapDumpOnOutOfMemoryError',
'-XX:ParallelGCThreads=4']
if self.verbose_gc:
gc_cmd += ['-Xlog:gc*,safepoint=info:file=' + self.log_dir + '/gc.' + gc_name +
'.log:tags,time,uptime,level:filecount=5,filesize=100M']
try:
cp_index = cmd.index('-cp')
return list(itertools.chain(*[cmd[0:cp_index], gc_cmd, cmd[cp_index:]]))
@@ -82,7 +82,7 @@ def _run_process(self, name, cmd, env=None):
return popen

def _get_jvm_version(self):
return "1.8.y.x"
return "11.0.6"


class HeronExecutorTest(unittest.TestCase):
@@ -105,50 +105,41 @@ def build_packing_plan(self, instance_distribution):
instance_plan.component_index = int(component_index)
return packing_plan

# pylint: disable=no-self-argument
# pylint: disable=no-self-argument
def get_expected_metricsmgr_command(container_id):
return "heron_java_home/bin/java -Xmx1024M -XX:+PrintCommandLineFlags " \
"-Djava.net.preferIPv4Stack=true -verbosegc " \
"-XX:+UseConcMarkSweepGC -XX:+CMSScavengeBeforeRemark -XX:TargetSurvivorRatio=90 " \
"-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps " \
"-XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 " \
"-XX:GCLogFileSize=100M -XX:+PrintPromotionFailure -XX:+PrintTenuringDistribution " \
"-XX:+PrintHeapAtGC -XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-Xloggc:log-files/gc.metricsmgr-%d.log " \
"-Djava.net.preferIPv4Stack=true " \
"-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:+UseStringDeduplication " \
"-XX:MaxGCPauseMillis=100 -XX:InitiatingHeapOccupancyPercent=30 " \
"-XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-cp metricsmgr_classpath org.apache.heron.metricsmgr.MetricsManager " \
"--id=metricsmgr-%d --port=metricsmgr_port " \
"--topology=topname --cluster=cluster --role=role --environment=environ " \
"--topology-id=topid " \
"--system-config-file=%s --override-config-file=%s " \
"--sink-config-file=metrics_sinks_config_file" %\
(container_id, container_id, INTERNAL_CONF_PATH, OVERRIDE_PATH)
"--sink-config-file=metrics_sinks_config_file" % \
(container_id, INTERNAL_CONF_PATH, OVERRIDE_PATH)

def get_expected_metricscachemgr_command():
return "heron_java_home/bin/java -Xmx1024M -XX:+PrintCommandLineFlags " \
"-Djava.net.preferIPv4Stack=true -verbosegc " \
"-XX:+UseConcMarkSweepGC -XX:+CMSScavengeBeforeRemark -XX:TargetSurvivorRatio=90 " \
"-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps " \
"-XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 " \
"-XX:GCLogFileSize=100M -XX:+PrintPromotionFailure -XX:+PrintTenuringDistribution " \
"-XX:+PrintHeapAtGC -XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-Xloggc:log-files/gc.metricscache.log " \
"-Djava.net.preferIPv4Stack=true " \
"-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:+UseStringDeduplication " \
"-XX:MaxGCPauseMillis=100 -XX:InitiatingHeapOccupancyPercent=30 " \
"-XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-cp metricscachemgr_classpath org.apache.heron.metricscachemgr.MetricsCacheManager " \
"--metricscache_id metricscache-0 --server_port metricscachemgr_serverport " \
"--stats_port metricscachemgr_statsport --topology_name topname --topology_id topid " \
"--system_config_file %s --override_config_file %s " \
"--sink_config_file metrics_sinks_config_file " \
"--cluster cluster --role role --environment environ" %\
(INTERNAL_CONF_PATH, OVERRIDE_PATH)
"--cluster cluster --role role --environment environ" \
% (INTERNAL_CONF_PATH, OVERRIDE_PATH)

def get_expected_healthmgr_command():
return "heron_java_home/bin/java -Xmx1024M -XX:+PrintCommandLineFlags " \
"-Djava.net.preferIPv4Stack=true -verbosegc " \
"-XX:+UseConcMarkSweepGC -XX:+CMSScavengeBeforeRemark -XX:TargetSurvivorRatio=90 " \
"-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps " \
"-XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 " \
"-XX:GCLogFileSize=100M -XX:+PrintPromotionFailure -XX:+PrintTenuringDistribution " \
"-XX:+PrintHeapAtGC -XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-Xloggc:log-files/gc.healthmgr.log " \
"-Djava.net.preferIPv4Stack=true " \
"-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:+UseStringDeduplication " \
"-XX:MaxGCPauseMillis=100 -XX:InitiatingHeapOccupancyPercent=30 " \
"-XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-cp scheduler_classpath:healthmgr_classpath " \
"org.apache.heron.healthmgr.HealthManager --cluster cluster --role role " \
"--environment environ --topology_name topname --metricsmgr_port metricsmgr_port"
@@ -157,19 +148,16 @@ def get_expected_instance_command(component_name, instance_id, container_id):
instance_name = "container_%d_%s_%d" % (container_id, component_name, instance_id)
return "heron_java_home/bin/java -Xmx320M -Xms320M -Xmn160M -XX:MaxMetaspaceSize=128M " \
"-XX:MetaspaceSize=128M -XX:ReservedCodeCacheSize=64M -XX:+PrintCommandLineFlags " \
"-Djava.net.preferIPv4Stack=true -verbosegc " \
"-XX:+UseConcMarkSweepGC -XX:+CMSScavengeBeforeRemark -XX:TargetSurvivorRatio=90 " \
"-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps " \
"-XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 " \
"-XX:GCLogFileSize=100M -XX:+PrintPromotionFailure -XX:+PrintTenuringDistribution " \
"-XX:+PrintHeapAtGC -XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-Xloggc:log-files/gc.%s.log " \
"-Djava.net.preferIPv4Stack=true " \
"-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:+UseStringDeduplication " \
"-XX:MaxGCPauseMillis=100 -XX:InitiatingHeapOccupancyPercent=30 " \
"-XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-cp instance_classpath:classpath -XX:+HeapDumpOnOutOfMemoryError " \
"org.apache.heron.instance.HeronInstance -topology_name topname -topology_id topid " \
"-instance_id %s -component_name %s -task_id %d -component_index 0 -stmgr_id stmgr-%d " \
"-stmgr_port tmanager_controller_port -metricsmgr_port metricsmgr_port " \
"-system_config_file %s -override_config_file %s" \
% (instance_name, instance_name, component_name, instance_id,
% (instance_name, component_name, instance_id,
container_id, INTERNAL_CONF_PATH, OVERRIDE_PATH)

MockPOpen.set_next_pid(37)
@@ -391,103 +379,3 @@ def assert_process(self, expected_process, found_processes):
self.assertEqual(expected_process.command, found_processes[pid].command_str)
self.assertEqual(1, found_processes[pid].attempts)


class MockExecutorJDK11(HeronExecutor):
"""
mock executor that overrides methods that don't apply to unit tests, like running processes
"""
def __init__(self, args):
self.processes = []
super(MockExecutorJDK11, self).__init__(args, None)

# pylint: disable=no-self-use
def _load_logging_dir(self, heron_internals_config_file):
return "log-files"

def _run_process(self, name, cmd, env=None):
popen = MockPOpen()
self.processes.append(ProcessInfo(popen, name, cmd))
return popen

def _get_jvm_version(self):
return "11.0.6"


class HeronExecutorJDK11Test(unittest.TestCase):
"""Unittest for Heron Executor"""

def __init__(self, args):
super(HeronExecutorJDK11Test, self).__init__(args, None)

# pylint: disable=no-self-argument
def get_expected_metricsmgr_command(container_id):
return "heron_java_home/bin/java -Xmx1024M -XX:+PrintCommandLineFlags " \
"-Djava.net.preferIPv4Stack=true -verbosegc " \
"-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:+UseStringDeduplication " \
"-XX:MaxGCPauseMillis=100 -XX:InitiatingHeapOccupancyPercent=30 " \
"-XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-Xlog:gc*,safepoint=info:file=log-files/gc.metricsmgr-%d.log:tags,time,uptime," \
"level:filecount=5,filesize=100M " \
"-cp metricsmgr_classpath org.apache.heron.metricsmgr.MetricsManager " \
"--id=metricsmgr-%d --port=metricsmgr_port " \
"--topology=topname --cluster=cluster --role=role --environment=environ " \
"--topology-id=topid " \
"--system-config-file=%s --override-config-file=%s " \
"--sink-config-file=metrics_sinks_config_file" % \
(container_id, container_id, INTERNAL_CONF_PATH, OVERRIDE_PATH)

def get_expected_metricscachemgr_command():
return "heron_java_home/bin/java -Xmx1024M -XX:+PrintCommandLineFlags " \
"-Djava.net.preferIPv4Stack=true -verbosegc " \
"-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:+UseStringDeduplication " \
"-XX:MaxGCPauseMillis=100 -XX:InitiatingHeapOccupancyPercent=30 " \
"-XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
" -Xlog:gc*,safepoint=info:file=log-files/gc.metricscache.log:tags,time,uptime," \
"level:filecount=5,filesize=100M " \
"-cp metricscachemgr_classpath org.apache.heron.metricscachemgr.MetricsCacheManager " \
"--metricscache_id metricscache-0 --server_port metricscachemgr_serverport " \
"--stats_port metricscachemgr_statsport --topology_name topname --topology_id topid " \
"--system_config_file %s --override_config_file %s " \
"--sink_config_file metrics_sinks_config_file " \
"--cluster cluster --role role --environment environ" % \
(INTERNAL_CONF_PATH, OVERRIDE_PATH)

def get_expected_healthmgr_command():
return "heron_java_home/bin/java -Xmx1024M -XX:+PrintCommandLineFlags " \
"-Djava.net.preferIPv4Stack=true -verbosegc " \
"-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:+UseStringDeduplication " \
"-XX:MaxGCPauseMillis=100 -XX:InitiatingHeapOccupancyPercent=30 " \
"-XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
" -Xlog:gc*,safepoint=info:file=log-files/gc.healthmgr.log:tags,time,uptime," \
"level:filecount=5,filesize=100M " \
"-cp scheduler_classpath:healthmgr_classpath " \
"org.apache.heron.healthmgr.HealthManager --cluster cluster --role role " \
"--environment environ --topology_name topname --metricsmgr_port metricsmgr_port"

def get_expected_instance_command(component_name, instance_id, container_id):
instance_name = "container_%d_%s_%d" % (container_id, component_name, instance_id)
return "heron_java_home/bin/java -Xmx320M -Xms320M -Xmn160M -XX:MaxMetaspaceSize=128M " \
"-XX:MetaspaceSize=128M -XX:ReservedCodeCacheSize=64M -XX:+PrintCommandLineFlags " \
"-Djava.net.preferIPv4Stack=true -verbosegc " \
"-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:+UseStringDeduplication " \
"-XX:MaxGCPauseMillis=100 -XX:InitiatingHeapOccupancyPercent=30 " \
"-XX:+HeapDumpOnOutOfMemoryError -XX:ParallelGCThreads=4 " \
"-Xloggc:log-files/gc.%s.log " \
"-cp instance_classpath:classpath -XX:+HeapDumpOnOutOfMemoryError " \
"org.apache.heron.instance.HeronInstance -topology_name topname -topology_id topid " \
"-instance_id %s -component_name %s -task_id %d -component_index 0 -stmgr_id stmgr-%d " \
"-stmgr_port tmanager_controller_port -metricsmgr_port metricsmgr_port " \
"-system_config_file %s -override_config_file %s" \
% (instance_name, instance_name, component_name, instance_id,
container_id, INTERNAL_CONF_PATH, OVERRIDE_PATH)

def setUp(self):
MockPOpen.set_next_pid(37)
self.maxDiff = None
self.executor_0 = MockExecutorJDK11(self.get_args(0))
self.executor_1 = MockExecutorJDK11(self.get_args(1))
self.executor_7 = MockExecutorJDK11(self.get_args(7))
self.packing_plan_expected = self.build_packing_plan({
1:[('word', '3', '0'), ('exclaim1', '2', '0'), ('exclaim1', '1', '0')],
7:[('word', '11', '0'), ('exclaim1', '210', '0')],
})
@@ -66,6 +66,7 @@ public enum ExecutorFlag {
StatefulConfigFile("stateful-config-file"),
HealthManagerMode("health-manager-mode"),
HealthManagerClasspath("health-manager-classpath"),
EnableVerboseGCLog("verbose-gc"),
JvmRemoteDebuggerPorts("jvm-remote-debugger-ports");

private final String name;
@@ -73,6 +73,7 @@ public class SubmitterMain {
* @param dryRun run as dry run
* @param dryRunFormat the dry run format
* @param verbose enable verbose logging
* @param verboseGC enable verbose JVM GC logging
* @return config the command line config
*/
protected static Config commandLineConfigs(String cluster,
@@ -81,7 +82,8 @@ protected static Config commandLineConfigs(String cluster,
String submitUser,
Boolean dryRun,
DryRunFormatType dryRunFormat,
Boolean verbose) {
Boolean verbose,
Boolean verboseGC) {
return Config.newBuilder()
.put(Key.CLUSTER, cluster)
.put(Key.ROLE, role)
@@ -90,6 +92,7 @@ protected static Config commandLineConfigs(String cluster,
.put(Key.DRY_RUN, dryRun)
.put(Key.DRY_RUN_FORMAT_TYPE, dryRunFormat)
.put(Key.VERBOSE, verbose)
.put(Key.VERBOSE_GC, verboseGC)
.build();
}

@@ -207,6 +210,11 @@ private static Options constructOptions() {
.longOpt("verbose")
.build();

Option verboseGC = Option.builder("vgc")
.desc("Enable verbose JVM GC logs")
.longOpt("verbose_gc")
.build();

options.addOption(cluster);
options.addOption(role);
options.addOption(environment);
@@ -221,6 +229,7 @@ private static Options constructOptions() {
options.addOption(dryRun);
options.addOption(dryRunFormat);
options.addOption(verbose);
options.addOption(verboseGC);

return options;
}
@@ -241,6 +250,10 @@ private static boolean isVerbose(CommandLine cmd) {
return cmd.hasOption("v");
}

private static boolean isVerboseGC(CommandLine cmd) {
return cmd.hasOption("vgc");
}

@SuppressWarnings("JavadocMethod")
@VisibleForTesting
public static Config loadConfig(CommandLine cmd, TopologyAPI.Topology topology) {
@@ -277,7 +290,7 @@ public static Config loadConfig(CommandLine cmd, TopologyAPI.Topology topology)
return Config.toLocalMode(Config.newBuilder()
.putAll(ConfigLoader.loadConfig(heronHome, configPath, releaseFile, overrideConfigFile))
.putAll(commandLineConfigs(cluster, role, environ, submitUser, dryRun,
dryRunFormat, isVerbose(cmd)))
dryRunFormat, isVerbose(cmd), isVerboseGC(cmd)))
.putAll(SubmitterUtils.topologyConfigs(topologyPackage, topologyBinaryFile,
topologyDefnFile, topology))
.build());
@@ -279,6 +279,9 @@ public static void addExecutorTopologyArgs(List<String> args, Config config, Con
args.add(createCommandArg(ExecutorFlag.TopologyBinaryFile,
Context.topologyBinaryFile(config)));
args.add(createCommandArg(ExecutorFlag.HeronJavaHome, Context.clusterJavaHome(config)));
if (Context.verboseGC(config)) {
args.add(ExecutorFlag.EnableVerboseGCLog.getFlag());
}
args.add(createCommandArg(ExecutorFlag.HeronShellBinary, Context.shellBinary(config)));
args.add(createCommandArg(ExecutorFlag.Cluster, Context.cluster(config)));
args.add(createCommandArg(ExecutorFlag.Role, Context.role(config)));
@@ -58,6 +58,10 @@ public static Boolean verbose(Config cfg) {
return cfg.getBooleanValue(Key.VERBOSE);
}

public static Boolean verboseGC(Config cfg) {
return cfg.getBooleanValue(Key.VERBOSE_GC);
}

public static String buildVersion(Config cfg) {
return cfg.getStringValue(Key.BUILD_VERSION);
}
@@ -62,6 +62,9 @@ public enum Key {
DRY_RUN ("heron.config.dry_run", Boolean.FALSE),
DRY_RUN_FORMAT_TYPE ("heron.config.dry_run_format_type", Type.DRY_RUN_FORMAT_TYPE),
VERBOSE ("heron.config.verbose", Boolean.FALSE),
// Used to enable verbose JVM GC logging
VERBOSE_GC ("heron.config.verbose_gc", Boolean.FALSE),

CONFIG_PROPERTY ("heron.config.property", Type.STRING),

//keys for release/build information
@@ -106,6 +106,10 @@ public void testConfig() throws Exception {
"heron.config.verbose",
Key.VERBOSE
);
assertEquals(
"heron.config.verbose_gc",
Key.VERBOSE_GC
);
assertEquals(
"heron.config.property",
Key.CONFIG_PROPERTY

0 comments on commit f11ebc3

Please sign in to comment.