From fcd00551d6eb0c0af263823b34e07de74a483b01 Mon Sep 17 00:00:00 2001
From: Dawid Wysakowicz <dwysakowicz@apache.org>
Date: Tue, 14 Jan 2020 09:38:16 +0100
Subject: [PATCH] [FLINK-15519][configuration]Preserve logs from BashJavaUtils
 and make them part of TM logs

We build a separate jar for BashJavaUtils with bundled log4j classes and
a configuration that logs to the stdout. Using this jar we run the
utility to capture the output. Out of the last line we extract jvm
parameters. The rest we pass as an environment variable (INHERITED_LOGS)
to the TaskManager process.

As part of the EnvironmentInformation printing we log whatever was
passed through the INHERITED_LOGS in the TM/JM process.

This closes #10850
---
 flink-dist/pom.xml                            | 57 ++++++++++++++++++-
 flink-dist/src/main/assemblies/bin.xml        |  7 +++
 flink-dist/src/main/flink-bin/bin/config.sh   | 56 ++++++++++--------
 .../src/main/flink-bin/bin/taskmanager.sh     | 17 +++++-
 .../resources/log4j-bash-utils.properties     | 24 ++++++++
 .../src/test/bin/runBashJavaUtilsCmd.sh       |  6 +-
 .../runtime/util/EnvironmentInformation.java  | 16 ++++--
 7 files changed, 150 insertions(+), 33 deletions(-)
 create mode 100644 flink-dist/src/main/resources/log4j-bash-utils.properties

diff --git a/flink-dist/pom.xml b/flink-dist/pom.xml
index 6783187d54d..04266a55e28 100644
--- a/flink-dist/pom.xml
+++ b/flink-dist/pom.xml
@@ -642,7 +642,7 @@ under the License.
 				</executions>
 			</plugin>
 
-			<!--Build uber jar-->
+			<!-- Build uber jar -->
 			<plugin>
 				<groupId>org.apache.maven.plugins</groupId>
 				<artifactId>maven-shade-plugin</artifactId>
@@ -666,6 +666,7 @@ under the License.
 										<exclude>META-INF/*.SF</exclude>
 										<exclude>META-INF/*.DSA</exclude>
 										<exclude>META-INF/*.RSA</exclude>
+										<exclude>org/apache/flink/runtime/util/BashJavaUtils.class</exclude>
 									</excludes>
 								</filter>
 							</filters>
@@ -697,6 +698,60 @@ under the License.
 						<id>shade-flink</id>
 						<phase>none</phase>
 					</execution>
+					<!-- Build BashJavaUtils jar -->
+					<execution>
+						<id>bash-utils</id>
+						<phase>package</phase>
+						<goals>
+							<goal>shade</goal>
+						</goals>
+						<configuration combine.self="override">
+							<createDependencyReducedPom>false</createDependencyReducedPom>
+							<shadedArtifactAttached>false</shadedArtifactAttached>
+							<finalName>bash-java-utils</finalName>
+							<filters>
+								<!-- Globally exclude log4j.properties from our JAR files. -->
+								<filter>
+									<artifact>*</artifact>
+									<excludes>
+										<exclude>log4j.properties</exclude>
+										<exclude>log4j-test.properties</exclude>
+										<exclude>META-INF/*.SF</exclude>
+										<exclude>META-INF/*.DSA</exclude>
+										<exclude>META-INF/*.RSA</exclude>
+									</excludes>
+								</filter>
+								<!-- Include only the BashJavaUtils, other required classes should come from the flink-dist-->
+								<filter>
+									<artifact>org.apache.flink:*</artifact>
+									<includes>
+										<include>org/apache/flink/runtime/util/BashJavaUtils.class</include>
+									</includes>
+								</filter>
+							</filters>
+							<artifactSet>
+								<includes>
+									<include>org.slf4j:slf4j-log4j12</include>
+									<include>log4j:log4j</include>
+									<include>org.apache.flink:*</include>
+								</includes>
+							</artifactSet>
+							<transformers>
+								<!-- Include a log4j configuration that always prints to stdout -->
+								<transformer implementation="org.apache.maven.plugins.shade.resource.IncludeResourceTransformer">
+									<resource>log4j.properties</resource>
+									<file>src/main/resources/log4j-bash-utils.properties</file>
+								</transformer>
+								<transformer implementation="org.apache.maven.plugins.shade.resource.AppendingTransformer">
+									<resource>reference.conf</resource>
+								</transformer>
+								<transformer implementation="org.apache.maven.plugins.shade.resource.ApacheNoticeResourceTransformer">
+									<projectName>Apache Flink</projectName>
+									<encoding>UTF-8</encoding>
+								</transformer>
+							</transformers>
+						</configuration>
+					</execution>
 				</executions>
 			</plugin>
 
diff --git a/flink-dist/src/main/assemblies/bin.xml b/flink-dist/src/main/assemblies/bin.xml
index f4461ddf463..c81d9378ea4 100644
--- a/flink-dist/src/main/assemblies/bin.xml
+++ b/flink-dist/src/main/assemblies/bin.xml
@@ -52,6 +52,13 @@ under the License.
 			<fileMode>0644</fileMode>
 		</file>
 
+		<!-- copy bash utils -->
+		<file>
+			<source>target/bash-java-utils.jar</source>
+			<outputDirectory>bin/</outputDirectory>
+			<fileMode>0644</fileMode>
+		</file>
+
 		<!-- Table/SQL Uber JAR -->
 		<file>
 			<source>../flink-table/flink-table-uber/target/flink-table-uber_${scala.binary.version}-${project.version}.jar</source>
diff --git a/flink-dist/src/main/flink-bin/bin/config.sh b/flink-dist/src/main/flink-bin/bin/config.sh
index 10bb8ac4db3..b2f3d00dcdf 100755
--- a/flink-dist/src/main/flink-bin/bin/config.sh
+++ b/flink-dist/src/main/flink-bin/bin/config.sh
@@ -22,7 +22,7 @@ constructFlinkClassPath() {
     local FLINK_CLASSPATH
 
     while read -d '' -r jarfile ; do
-        if [[ "$jarfile" =~ .*flink-dist.*.jar ]]; then
+        if [[ "$jarfile" =~ .*/flink-dist[^/]*.jar$ ]]; then
             FLINK_DIST="$FLINK_DIST":"$jarfile"
         elif [[ "$FLINK_CLASSPATH" == "" ]]; then
             FLINK_CLASSPATH="$jarfile";
@@ -42,6 +42,20 @@ constructFlinkClassPath() {
     echo "$FLINK_CLASSPATH""$FLINK_DIST"
 }
 
+findFlinkDistJar() {
+    local FLINK_DIST="`find "$FLINK_LIB_DIR" -name 'flink-dist*.jar'`"
+
+    if [[ "$FLINK_DIST" == "" ]]; then
+        # write error message to stderr since stdout is stored as the classpath
+        (>&2 echo "[ERROR] Flink distribution jar not found in $FLINK_LIB_DIR.")
+
+        # exit function with empty classpath to force process failure
+        exit 1
+    fi
+
+    echo "$FLINK_DIST"
+}
+
 # These are used to mangle paths that are passed to java when using
 # cygwin. Cygwin paths are like linux paths, i.e. /path/to/somewhere
 # but the windows java version expects them in Windows Format, i.e. C:\bla\blub.
@@ -603,38 +617,32 @@ TMSlaves() {
 
 runBashJavaUtilsCmd() {
     local cmd=$1
-    local class_path=$2
-    local conf_dir=$3
-    local EXECUTION_PREFIX="BASH_JAVA_UTILS_EXEC_RESULT:"
+    local conf_dir=$2
+    local class_path="${3:-$FLINK_BIN_DIR/bash-java-utils.jar:`findFlinkDistJar`}"
+    class_path=`manglePathList ${class_path}`
 
-    local output=`${JAVA_RUN} -classpath ${class_path} org.apache.flink.runtime.util.BashJavaUtils ${cmd} --configDir ${conf_dir} | tail -n 1`
+    local output=`${JAVA_RUN} -classpath ${class_path} org.apache.flink.runtime.util.BashJavaUtils ${cmd} --configDir ${conf_dir} 2>&1 | tail -n 1000`
     if [[ $? -ne 0 ]]; then
         echo "[ERROR] Cannot run BashJavaUtils to execute command ${cmd}." 1>&2
         # Print the output in case the user redirect the log to console.
-        echo $output 1>&2
+        echo "$output" 1>&2
         exit 1
     fi
 
-    if ! [[ $output =~ ^${EXECUTION_PREFIX}.* ]]; then
-        echo "[ERROR] Unexpected result: $output" 1>&2
-        echo "[ERROR] The last line of the BashJavaUtils outputs is expected to be the execution result, following the prefix '${EXECUTION_PREFIX}'" 1>&2
-        echo $output 1>&2
-        exit 1
-    fi
-
-    echo ${output} | sed "s/$EXECUTION_PREFIX//g"
+    echo "$output"
 }
 
-getTmResourceJvmParams() {
-    local class_path=`constructFlinkClassPath`
-    class_path=`manglePathList ${class_path}`
-
-    runBashJavaUtilsCmd GET_TM_RESOURCE_JVM_PARAMS ${class_path} ${FLINK_CONF_DIR}
-}
+extractExecutionParams() {
+    local output=$1
+    local EXECUTION_PREFIX="BASH_JAVA_UTILS_EXEC_RESULT:"
 
-getTmResourceDynamicConfigs() {
-    local class_path=`constructFlinkClassPath`
-    class_path=`manglePathList ${class_path}`
+    local execution_config=`echo "$output" | tail -n 1`
+    if ! [[ $execution_config =~ ^${EXECUTION_PREFIX}.* ]]; then
+        echo "[ERROR] Unexpected result: $execution_config" 1>&2
+        echo "[ERROR] The last line of the BashJavaUtils outputs is expected to be the execution result, following the prefix '${EXECUTION_PREFIX}'" 1>&2
+        echo "$output" 1>&2
+        exit 1
+    fi
 
-    runBashJavaUtilsCmd GET_TM_RESOURCE_DYNAMIC_CONFIGS ${class_path} ${FLINK_CONF_DIR}
+    echo ${execution_config} | sed "s/$EXECUTION_PREFIX//"
 }
diff --git a/flink-dist/src/main/flink-bin/bin/taskmanager.sh b/flink-dist/src/main/flink-bin/bin/taskmanager.sh
index 1871b736be7..7f8bdc01644 100755
--- a/flink-dist/src/main/flink-bin/bin/taskmanager.sh
+++ b/flink-dist/src/main/flink-bin/bin/taskmanager.sh
@@ -49,7 +49,8 @@ if [[ $STARTSTOP == "start" ]] || [[ $STARTSTOP == "start-foreground" ]]; then
 
     # Startup parameters
 
-    jvm_params=$(getTmResourceJvmParams)
+    jvm_params_output=`runBashJavaUtilsCmd GET_TM_RESOURCE_JVM_PARAMS ${FLINK_CONF_DIR}`
+    jvm_params=`extractExecutionParams "$jvm_params_output"`
     if [[ $? -ne 0 ]]; then
         echo "[ERROR] Could not get JVM parameters properly."
         exit 1
@@ -57,12 +58,24 @@ if [[ $STARTSTOP == "start" ]] || [[ $STARTSTOP == "start-foreground" ]]; then
     export JVM_ARGS="${JVM_ARGS} ${jvm_params}"
 
     IFS=$" "
-    dynamic_configs=($(getTmResourceDynamicConfigs))
+
+    dynamic_configs_output=`runBashJavaUtilsCmd GET_TM_RESOURCE_DYNAMIC_CONFIGS ${FLINK_CONF_DIR}`
+    dynamic_configs=`extractExecutionParams "$dynamic_configs_output"`
     if [[ $? -ne 0 ]]; then
         echo "[ERROR] Could not get dynamic configurations properly."
         exit 1
     fi
     ARGS+=("--configDir" "${FLINK_CONF_DIR}" ${dynamic_configs[@]})
+
+    export FLINK_INHERITED_LOGS="
+$FLINK_INHERITED_LOGS
+
+TM_RESOURCES_JVM_PARAMS extraction logs:
+$jvm_params_output
+
+TM_RESOURCES_DYNAMIC_CONFIGS extraction logs:
+$dynamic_configs_output
+"
 fi
 
 if [[ $STARTSTOP == "start-foreground" ]]; then
diff --git a/flink-dist/src/main/resources/log4j-bash-utils.properties b/flink-dist/src/main/resources/log4j-bash-utils.properties
new file mode 100644
index 00000000000..c4a44401d1e
--- /dev/null
+++ b/flink-dist/src/main/resources/log4j-bash-utils.properties
@@ -0,0 +1,24 @@
+################################################################################
+#  Licensed to the Apache Software Foundation (ASF) under one
+#  or more contributor license agreements.  See the NOTICE file
+#  distributed with this work for additional information
+#  regarding copyright ownership.  The ASF licenses this file
+#  to you under the Apache License, Version 2.0 (the
+#  "License"); you may not use this file except in compliance
+#  with the License.  You may obtain a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+#  Unless required by applicable law or agreed to in writing, software
+#  distributed under the License is distributed on an "AS IS" BASIS,
+#  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+#  See the License for the specific language governing permissions and
+# limitations under the License.
+################################################################################
+
+
+# Logging configuration for BashJavaUtils utility
+log4j.rootLogger=INFO, console
+log4j.appender.console=org.apache.log4j.ConsoleAppender
+log4j.appender.console.layout=org.apache.log4j.PatternLayout
+log4j.appender.console.layout.ConversionPattern=%x - %m%n
diff --git a/flink-dist/src/test/bin/runBashJavaUtilsCmd.sh b/flink-dist/src/test/bin/runBashJavaUtilsCmd.sh
index e6237608611..745d129657f 100755
--- a/flink-dist/src/test/bin/runBashJavaUtilsCmd.sh
+++ b/flink-dist/src/test/bin/runBashJavaUtilsCmd.sh
@@ -30,9 +30,11 @@ fi
 bin=`dirname "$0"`
 bin=`cd "$bin"; pwd`
 
-FLINK_CLASSPATH=`find . -name 'flink-dist*.jar' | grep lib`
 FLINK_CONF_DIR=${bin}/../../main/resources
+FLINK_TARGET_DIR=${bin}/../../../target
+FLINK_DIST_JAR=`find $FLINK_TARGET_DIR -name 'flink-dist*.jar'`
 
 . ${bin}/../../main/flink-bin/bin/config.sh > /dev/null
 
-runBashJavaUtilsCmd ${COMMAND} ${FLINK_CLASSPATH} ${FLINK_CONF_DIR}
+output=`runBashJavaUtilsCmd ${COMMAND} ${FLINK_CONF_DIR} "$FLINK_TARGET_DIR/bash-java-utils.jar:$FLINK_DIST_JAR}"`
+extractExecutionParams "$output"
diff --git a/flink-runtime/src/main/java/org/apache/flink/runtime/util/EnvironmentInformation.java b/flink-runtime/src/main/java/org/apache/flink/runtime/util/EnvironmentInformation.java
index e7002567db5..1a3269be8e9 100644
--- a/flink-runtime/src/main/java/org/apache/flink/runtime/util/EnvironmentInformation.java
+++ b/flink-runtime/src/main/java/org/apache/flink/runtime/util/EnvironmentInformation.java
@@ -270,14 +270,22 @@ public class EnvironmentInformation {
 		if (log.isInfoEnabled()) {
 			RevisionInformation rev = getRevisionInformation();
 			String version = getVersion();
-			
+
 			String jvmVersion = getJvmVersion();
 			String[] options = getJvmStartupOptionsArray();
-			
+
 			String javaHome = System.getenv("JAVA_HOME");
-			
+
+			String inheritedLogs = System.getenv("FLINK_INHERITED_LOGS");
+
 			long maxHeapMegabytes = getMaxJvmHeapMemory() >>> 20;
-			
+
+			if (inheritedLogs != null) {
+				log.info("--------------------------------------------------------------------------------");
+				log.info(" Preconfiguration: ");
+				log.info(inheritedLogs);
+			}
+
 			log.info("--------------------------------------------------------------------------------");
 			log.info(" Starting " + componentName + " (Version: " + version + ", "
 					+ "Rev:" + rev.commitId + ", " + "Date:" + rev.commitDate + ")");
-- 
GitLab