logginglog4jheron

Without log output in Heron cluster using AuroraScheduler


I submitted a topology to Heron cluster using CustomAuroraScheduler that modified based on the default AuroraScheduler. For this scheduler, I just added one line code in this CustomAuroraScheduler as following: enter image description here And I have successfully deployed this custom scheduler to Heron and submitted topology succeed. But I cannot find the output contents of this LOG.Info when submitted topology using --verbose parameter. Then, I tried to write this log contents to a specified .txt file, but also cannot create the .txt file.
The output when submitted topology as following:

yitian@heron01:~$ heron submit aurora/yitian/devel --config-path ~/.heron/conf ~/aurora-topolgoies/heron-java-streamlet-api-example-latest-jar-with-dependencies.jar zyt.custom.topology.aurora.AuroraMonitorSentenceWordCountTopology AuroraMonitorSentenceWordCountTopology --deploy-deactivated --verbose
[2018-07-01 20:26:05 +0000] [DEBUG]: Input Command Line Args: {'config_property': [], 'dry_run_format': 'colored_table', 'topology-file-name': '/home/yitian/aurora-topolgoies/heron-java-streamlet-api-example-latest-jar-with-dependencies.jar', 'cluster/[role]/[env]': 'aurora/yitian/devel', 'dry_run': False, 'config_path': '/home/yitian/.heron/conf', 'subcommand': 'submit', 'deploy_deactivated': 'True', 'topology_main_jvm_property': [], 'extra_launch_classpath': '', 'service_url': '', 'topology-class-name': 'zyt.custom.topology.aurora.AuroraMonitorSentenceWordCountTopology', 'verbose': 'True'}
[2018-07-01 20:26:05 +0000] [INFO]: Using cluster definition in /home/yitian/.heron/conf/aurora
[2018-07-01 20:26:05 +0000] [DEBUG]: Processed Command Line Args: {'config_property': [], 'topology-file-name': '/home/yitian/aurora-topolgoies/heron-java-streamlet-api-example-latest-jar-with-dependencies.jar', 'verbose': 'True', 'subcommand': 'submit', 'deploy_deactivated': 'True', 'submit_user': 'yitian', 'cluster': 'aurora', 'extra_launch_classpath': '', 'deploy_mode': 'direct', 'role': 'yitian', 'dry_run_format': 'colored_table', 'override_config_file': '/tmp/tmp8GPfB9/override.yaml', 'dry_run': False, 'config_path': '/home/yitian/.heron/conf/aurora', 'topology_main_jvm_property': [], 'environ': 'devel', 'service_url': '', 'topology-class-name': 'zyt.custom.topology.aurora.AuroraMonitorSentenceWordCountTopology'}
[2018-07-01 20:26:05 +0000] [DEBUG]: Submit Args {'config_property': [], 'topology-file-name': '/home/yitian/aurora-topolgoies/heron-java-streamlet-api-example-latest-jar-with-dependencies.jar', 'verbose': 'True', 'subcommand': 'submit', 'deploy_deactivated': 'True', 'submit_user': 'yitian', 'cluster': 'aurora', 'extra_launch_classpath': '', 'deploy_mode': 'direct', 'role': 'yitian', 'dry_run_format': 'colored_table', 'override_config_file': '/tmp/tmp8GPfB9/override.yaml', 'dry_run': False, 'config_path': '/home/yitian/.heron/conf/aurora', 'topology_main_jvm_property': [], 'environ': 'devel', 'service_url': '', 'topology-class-name': 'zyt.custom.topology.aurora.AuroraMonitorSentenceWordCountTopology'}
[2018-07-01 20:26:05 +0000] [DEBUG]: Invoking class using command: ``/usr/java/jdk1.8.0_151/bin/java -client -Xmx1g -cp /home/yitian/aurora-topolgoies/heron-java-streamlet-api-example-latest-jar-with-dependencies.jar:/home/yitian/.heron/lib/third_party/* zyt.custom.topology.aurora.AuroraMonitorSentenceWordCountTopology AuroraMonitorSentenceWordCountTopology''
[2018-07-01 20:26:05 +0000] [DEBUG]: Heron options: {cmdline.topologydefn.tmpdirectory=/tmp/tmpmyAYVf,cmdline.topology.initial.state=PAUSED}
[2018-07-01 20:26:06 +0000] [INFO]: Launching topology: 'AuroraMonitorSentenceWordCountTopology'
[2018-07-01 20:26:06 +0000] [DEBUG]: Invoking class using command: ``/usr/java/jdk1.8.0_151/bin/java -client -Xmx1g -cp :/home/yitian/.heron/lib/scheduler/*:/home/yitian/.heron/lib/uploader/*:/home/yitian/.heron/lib/statemgr/*:/home/yitian/.heron/lib/packing/* com.twitter.heron.scheduler.SubmitterMain --cluster aurora --role yitian --environment devel --submit_user yitian --heron_home /home/yitian/.heron --config_path /home/yitian/.heron/conf/aurora --override_config_file /tmp/tmp8GPfB9/override.yaml --release_file /home/yitian/.heron/release.yaml --topology_package /tmp/tmpmyAYVf/topology.tar.gz --topology_defn /tmp/tmpmyAYVf/AuroraMonitorSentenceWordCountTopology.defn --topology_bin heron-java-streamlet-api-example-latest-jar-with-dependencies.jar --verbose''
[2018-07-01 20:26:06 +0000] [DEBUG]: Heron options: {cmdline.topologydefn.tmpdirectory=/tmp/tmpmyAYVf,cmdline.topology.initial.state=PAUSED}
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Config file /home/yitian/.heron/conf/aurora/cluster.yaml does not exist  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Reading config file /home/yitian/.heron/conf/aurora/client.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Successfully read config file /home/yitian/.heron/conf/aurora/client.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Config file /home/yitian/.heron/conf/aurora/healthmgr.yaml does not exist  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Reading config file /home/yitian/.heron/conf/aurora/packing.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Successfully read config file /home/yitian/.heron/conf/aurora/packing.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Reading config file /home/yitian/.heron/conf/aurora/scheduler.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Successfully read config file /home/yitian/.heron/conf/aurora/scheduler.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Reading config file /home/yitian/.heron/conf/aurora/statemgr.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Successfully read config file /home/yitian/.heron/conf/aurora/statemgr.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Reading config file /home/yitian/.heron/conf/aurora/uploader.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Successfully read config file /home/yitian/.heron/conf/aurora/uploader.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Reading config file /home/yitian/.heron/conf/aurora/stateful.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Successfully read config file /home/yitian/.heron/conf/aurora/stateful.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Reading config file /home/yitian/.heron/release.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Successfully read config file /home/yitian/.heron/release.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Reading config file /tmp/tmp8GPfB9/override.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.common.config.ConfigReader: Successfully read config file /tmp/tmp8GPfB9/override.yaml  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.scheduler.SubmitterMain: Static config loaded successfully  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.scheduler.SubmitterMain: ("heron.binaries.cpp.instance", /home/yitian/.heron/bin/heron-cpp-instance)
("heron.binaries.downloader", /home/yitian/.heron/bin/heron-downloader)
("heron.binaries.executor", /home/yitian/.heron/bin/heron-executor)
("heron.binaries.python.instance", /home/yitian/.heron/bin/heron-python-instance)
("heron.binaries.shell", /home/yitian/.heron/bin/heron-shell)
("heron.binaries.stmgr", /home/yitian/.heron/bin/heron-stmgr)
("heron.binaries.tmaster", /home/yitian/.heron/bin/heron-tmaster)
("heron.build.git.revision", 874feb31b1ad9df6ea4a51d58b573750468ad28d)
("heron.build.git.status", Clean)
("heron.build.host", ci-server-01)
("heron.build.time", Sat Nov 18 01:07:07 UTC 2017)
("heron.build.timestamp", 1510967227000)
("heron.build.user", release-agent1)
("heron.build.version", 0.17.1)
("heron.ckptmgr.network.options.maximum.packetsize.bytes", 10485760)
("heron.ckptmgr.network.options.socket.receive.buffer.size.bytes", 655360)
("heron.ckptmgr.network.options.socket.send.buffer.size.bytes", 655360)
("heron.ckptmgr.network.read.batch.size.bytes", 32768)
("heron.ckptmgr.network.read.batch.time.ms", 16)
("heron.ckptmgr.network.write.batch.size.bytes", 32768)
("heron.ckptmgr.network.write.batch.time.ms", 16)
("heron.class.launcher", com.twitter.heron.scheduler.aurora.AuroraLauncher)
("heron.class.packing.algorithm", com.twitter.heron.packing.roundrobin.RoundRobinPacking)
("heron.class.scheduler", zyt.custom.my.scheduler.aurora.AuroraHotEdgeSchedulerWithTxtLog)
("heron.class.scheduler.aurora.controller.cli", true)
("heron.class.state.manager", com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager)
("heron.class.uploader", com.twitter.heron.uploader.hdfs.HdfsUploader)
("heron.classpath.ckptmgr", /home/yitian/.heron/lib/ckptmgr/*)
("heron.classpath.healthmgr", /home/yitian/.heron/lib/healthmgr/*)
("heron.classpath.instance", /home/yitian/.heron/lib/instance/*)
("heron.classpath.metrics.manager", /home/yitian/.heron/lib/metricsmgr/*)
("heron.classpath.metricscache.manager", /home/yitian/.heron/lib/metricscachemgr/*)
("heron.classpath.packing", /home/yitian/.heron/lib/packing/*)
("heron.classpath.scheduler", /home/yitian/.heron/lib/scheduler/*)
("heron.classpath.statefulstorage", /home/yitian/.heron/lib/statefulstorage/*)
("heron.classpath.statemgr", /home/yitian/.heron/lib/statemgr/*)
("heron.classpath.uploader", /home/yitian/.heron/lib/uploader/*)
("heron.config.cluster", aurora)
("heron.config.dry_run", false)
("heron.config.dry_run_format_type", TABLE)
("heron.config.environ", devel)
("heron.config.file.client.yaml", /home/yitian/.heron/conf/aurora/client.yaml)
("heron.config.file.cluster.yaml", /home/yitian/.heron/conf/aurora/cluster.yaml)
("heron.config.file.healthmgr.yaml", /home/yitian/.heron/conf/aurora/healthmgr.yaml)
("heron.config.file.metrics.yaml", /home/yitian/.heron/conf/aurora/metrics_sinks.yaml)
("heron.config.file.override.yaml", /home/yitian/.heron/conf/aurora/override.yaml)
("heron.config.file.packing.yaml", /home/yitian/.heron/conf/aurora/packing.yaml)
("heron.config.file.scheduler.yaml", /home/yitian/.heron/conf/aurora/scheduler.yaml)
("heron.config.file.stateful.yaml", /home/yitian/.heron/conf/aurora/stateful.yaml)
("heron.config.file.statemgr.yaml", /home/yitian/.heron/conf/aurora/statemgr.yaml)
("heron.config.file.system.yaml", /home/yitian/.heron/conf/aurora/heron_internals.yaml)
("heron.config.file.uploader.yaml", /home/yitian/.heron/conf/aurora/uploader.yaml)
("heron.config.is.env.required", true)
("heron.config.is.role.required", true)
("heron.config.role", yitian)
("heron.config.submit_user", yitian)
("heron.config.verbose", true)
("heron.directory.bin", /home/yitian/.heron/bin)
("heron.directory.cluster.conf", ./heron-conf)
("heron.directory.cluster.home", ./heron-core)
("heron.directory.conf", /home/yitian/.heron/conf/aurora)
("heron.directory.dist", /home/yitian/.heron/dist)
("heron.directory.etc", /home/yitian/.heron/etc)
("heron.directory.home", /home/yitian/.heron)
("heron.directory.java.home", /usr/java/jdk1.8.0_151)
("heron.directory.lib", /home/yitian/.heron/lib)
("heron.directory.sandbox.java.home", /usr/lib/jvm/java-1.8.0-openjdk-amd64)
("heron.jars.scheduler", /home/yitian/.heron/lib/scheduler/heron-scheduler.jar)
("heron.package.core.uri", /heron/dist/heron-core.tar.gz)
("heron.resources.instance.cpu", 1.0)
("heron.resources.instance.disk", ByteAmount{1 GB (1073741824 bytes)})
("heron.resources.instance.ram", ByteAmount{1 GB (1073741824 bytes)})
("heron.resources.stmgr.ram", ByteAmount{1 GB (1073741824 bytes)})
("heron.scheduler.is.service", false)
("heron.scheduler.is.tunnel.needed", false)
("heron.scheduler.job.kill.retry.interval.ms", 2000)
("heron.scheduler.job.max.kill.attempts", 5)
("heron.scheduler.tunnel.connection.retry.count", 2)
("heron.scheduler.tunnel.connection.timeout.ms", 1000)
("heron.scheduler.tunnel.host", my.tunnel.host)
("heron.scheduler.tunnel.retry.interval.ms", 1000)
("heron.scheduler.tunnel.verify.count", 10)
("heron.statefulstorage.classname", com.twitter.heron.statefulstorage.hdfs.HDFSStorage)
("heron.statefulstorage.config", {heron.statefulstorage.classpath=$(hadoop --config /path/to/configs classpath), heron.statefulstorage.hdfs.root.path=/user/heron/checkpoints})
("heron.statemgr.connection.string", heron01:2181)
("heron.statemgr.is.tunnel.needed", false)
("heron.statemgr.root.path", /heron)
("heron.statemgr.tunnel.connection.retry.count", 2)
("heron.statemgr.tunnel.connection.timeout.ms", 30000)
("heron.statemgr.tunnel.host", my.tunnel.host)
("heron.statemgr.tunnel.retry.interval.ms", 1000)
("heron.statemgr.tunnel.verify.count", 10)
("heron.statemgr.zookeeper.is.initialize.tree", true)
("heron.topology.binary.file", heron-java-streamlet-api-example-latest-jar-with-dependencies.jar)
("heron.topology.definition.file", /tmp/tmpmyAYVf/AuroraMonitorSentenceWordCountTopology.defn)
("heron.topology.id", AuroraMonitorSentenceWordCountTopology3c4b6a81-5289-4fa0-b2d6-e6b48d1d9ab8)
("heron.topology.name", AuroraMonitorSentenceWordCountTopology)
("heron.topology.package.file", /tmp/tmpmyAYVf/topology.tar.gz)
("heron.topology.package.type", JAR)
("heron.uploader.hdfs.config.directory", /home/yitian/hadoop/hadoop-2.7.4/etc/hadoop)
("heron.uploader.hdfs.topologies.directory.uri", /heron/topologies/aurora)

[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.FileSystemStateManager: File system state manager root address: /heron  
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/home/yitian/.heron/lib/uploader/heron-dlog-uploader.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/yitian/.heron/lib/statemgr/heron-zookeeper-statemgr.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.JDK14LoggerFactory]
[2018-07-01 20:26:06 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Starting Curator client connecting to: heron01:2181  
[2018-07-01 20:26:06 +0800] [INFO] org.apache.curator.framework.imps.CuratorFrameworkImpl: Starting  
[2018-07-01 20:26:06 +0800] [FINE] org.apache.curator.CuratorZookeeperClient: Starting  
[2018-07-01 20:26:06 +0800] [FINE] org.apache.curator.ConnectionState: Starting  
[2018-07-01 20:26:06 +0800] [FINE] org.apache.curator.ConnectionState: reset  
[2018-07-01 20:26:06 +0800] [INFO] org.apache.curator.framework.state.ConnectionStateManager: State change: CONNECTED  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: connection-state-parent-process - 2 ms  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: TMaster location directory: /heron/tmasters  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: MetricsCache location directory: /heron/metricscaches  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Topologies directory: /heron/topologies  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Packing plan directory: /heron/packingplans  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Physical plan directory: /heron/pplans  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Execution state directory: /heron/executionstate  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Scheduler location directory: /heron/schedulers  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Stateful checkpoints directory: /heron/statefulcheckpoints  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Distributed locks directory: /heron/locks  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 6 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 1 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground-CreateParents - 0 ms  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 0 ms  
[2018-07-01 20:26:06 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Directory tree initialized.  
[2018-07-01 20:26:06 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Checking existence of path: /heron/topologies/AuroraMonitorSentenceWordCountTopology  
[2018-07-01 20:26:06 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: ExistsBuilderImpl-Foreground - 1 ms  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.scheduler.SubmitterMain: Topology AuroraMonitorSentenceWordCountTopology to be submitted  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.spi.utils.ShellUtils: Running synced process: ``hadoop --config /home/yitian/hadoop/hadoop-2.7.4/etc/hadoop fs -test -e /heron/topologies/aurora''  
[2018-07-01 20:26:06 +0800] [FINE] com.twitter.heron.spi.utils.ShellUtils: Process output (stdout+stderr):  
[2018-07-01 20:26:08 +0800] [INFO] com.twitter.heron.uploader.hdfs.HdfsUploader: Target topology file already exists at '/heron/topologies/aurora/AuroraMonitorSentenceWordCountTopology-yitian-tag-0-4968969921041261350.tar.gz'. Overwriting it now  
[2018-07-01 20:26:08 +0800] [INFO] com.twitter.heron.uploader.hdfs.HdfsUploader: Uploading topology package at '/tmp/tmpmyAYVf/topology.tar.gz' to target HDFS at '/heron/topologies/aurora/AuroraMonitorSentenceWordCountTopology-yitian-tag-0-4968969921041261350.tar.gz'  
[2018-07-01 20:26:08 +0800] [FINE] com.twitter.heron.spi.utils.ShellUtils: Running synced process: ``hadoop --config /home/yitian/hadoop/hadoop-2.7.4/etc/hadoop fs -copyFromLocal -f /tmp/tmpmyAYVf/topology.tar.gz /heron/topologies/aurora/AuroraMonitorSentenceWordCountTopology-yitian-tag-0-4968969921041261350.tar.gz''  
[2018-07-01 20:26:08 +0800] [FINE] com.twitter.heron.spi.utils.ShellUtils: Process output (stdout+stderr):  
[2018-07-01 20:26:11 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: CreateBuilderImpl-Foreground - 5 ms  
[2018-07-01 20:26:11 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Created node for path: /heron/topologies/AuroraMonitorSentenceWordCountTopology  
[2018-07-01 20:26:11 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: CreateBuilderImpl-Foreground - 1 ms  
[2018-07-01 20:26:11 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Created node for path: /heron/packingplans/AuroraMonitorSentenceWordCountTopology  
[2018-07-01 20:26:11 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: CreateBuilderImpl-Foreground - 11 ms  
[2018-07-01 20:26:11 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Created node for path: /heron/executionstate/AuroraMonitorSentenceWordCountTopology  
[2018-07-01 20:26:11 +0800] [INFO] com.twitter.heron.scheduler.aurora.AuroraLauncher: Launching topology in aurora  
[2018-07-01 20:26:11 +0800] [INFO] com.twitter.heron.scheduler.utils.SchedulerUtils: Updating scheduled-resource in packing plan: AuroraMonitorSentenceWordCountTopology  
[2018-07-01 20:26:11 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: GetDataBuilderImpl-Background - 2 ms  
[2018-07-01 20:26:11 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: DeleteBuilderImpl-Foreground - 1 ms  
[2018-07-01 20:26:11 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Deleted node for path: /heron/packingplans/AuroraMonitorSentenceWordCountTopology  
[2018-07-01 20:26:11 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: CreateBuilderImpl-Foreground - 8 ms  
[2018-07-01 20:26:11 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Created node for path: /heron/packingplans/AuroraMonitorSentenceWordCountTopology  
[2018-07-01 20:26:11 +0800] [FINE] com.twitter.heron.spi.utils.ShellUtils: Running synced process: ...
DEBUG] Getting tier configurations
DEBUG] Using auth module: <apache.aurora.common.auth.auth_module.InsecureAuthModule object at 0x7f9fb8c704d0>
 INFO] Creating job AuroraMonitorSentenceWordCountTopology
DEBUG] Full configuration: ...
DEBUG] Querying instance statuses: None
DEBUG] Response from scheduler: OK (message: )
DEBUG] Querying instance statuses: None
DEBUG] Response from scheduler: OK (message: )
DEBUG] Querying instance statuses: None
DEBUG] Response from scheduler: OK (message: )
 INFO] Checking status of aurora/yitian/devel/AuroraMonitorSentenceWordCountTopology
DEBUG] Command terminated successfully
Job create succeeded: job url=http://218.195.228.24:8081/scheduler/yitian/devel/AuroraMonitorSentenceWordCountTopology
[2018-07-01 20:26:19 +0800] [INFO] com.twitter.heron.scheduler.utils.SchedulerUtils: Setting Scheduler locations: topology_name: "AuroraMonitorSentenceWordCountTopology"
http_endpoint: "scheduler_as_lib_no_endpoint"

[2018-07-01 20:26:20 +0800] [FINEST] org.apache.curator.utils.DefaultTracerDriver: Trace: CreateBuilderImpl-Foreground - 1 ms  
[2018-07-01 20:26:20 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Created node for path: /heron/schedulers/AuroraMonitorSentenceWordCountTopology  
[2018-07-01 20:26:20 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Closing the CuratorClient to: heron01:2181  
[2018-07-01 20:26:20 +0800] [FINE] org.apache.curator.framework.imps.CuratorFrameworkImpl: Closing  
[2018-07-01 20:26:20 +0800] [FINE] org.apache.curator.CuratorZookeeperClient: Closing  
[2018-07-01 20:26:20 +0800] [FINE] org.apache.curator.ConnectionState: Closing  
[2018-07-01 20:26:20 +0800] [INFO] com.twitter.heron.statemgr.zookeeper.curator.CuratorStateManager: Closing the tunnel processes  
[2018-07-01 20:26:20 +0800] [FINE] com.twitter.heron.scheduler.SubmitterMain: Topology AuroraMonitorSentenceWordCountTopology submitted successfully  
[2018-07-01 20:26:20 +0000] [INFO]: Successfully launched topology 'AuroraMonitorSentenceWordCountTopology' 
[2018-07-01 20:26:20 +0000] [DEBUG]: Elapsed time: 14.217s.

I don't know what reason caused this problem that this log output cannot display, and how can I fix it?


Solution

  • Based on the log you posted, the onSchedule method is not executed at all. One suggestion is to figure out which method is actually being invoked.