Refactor container cleanup to improve logging

In the past, the set of logs coming from containers was not well labeled
and we were losing information about the containers when we harvested
their logs, which could have led to name collisions. By naming the
container log files the same as k8s names the containers, we have a
better guarantee of uniqueness.

Signed-off-by: Steve Kuznetsov <[email protected]>

Author: stevekuznetsov

hack/lib/cleanup.sh

@@ -14,4 +14,89 @@
 function os::cleanup::dump_etcd() {
 	os::log::info "Dumping etcd contents to ${ARTIFACT_DIR}/etcd_dump.json"
 	os::util::curl_etcd "/v2/keys/?recursive=true" > "${ARTIFACT_DIR}/etcd_dump.json"
-}
+}
+
+# os::cleanup::containers operates on k8s containers to stop the containers
+# and optionally remove the containers and any volumes they had attached.
+#
+# Globals:
+#  - SKIP_IMAGE_CLEANUP
+# Arguments:
+#  None
+# Returns:
+#  None
+function os::cleanup::containers() {
+	if ! os::util::find::system_binary docker >/dev/null 2>&1; then
+		os::log::warning "No \`docker\` binary found, skipping container cleanup."
+		return
+	fi
+
+	os::log::info "Stopping k8s docker containers"
+	for id in $( os::cleanup::internal::list_k8s_containers ); do
+		os::log::debug "Stopping ${id}"
+		docker stop "${id}" >/dev/null
+	done
+
+	if [[ -n "${SKIP_IMAGE_CLEANUP:-}" ]]; then
+		return
+	fi
+
+	os::log::info "Removing k8s docker containers"
+	for id in $( os::cleanup::internal::list_k8s_containers ); do
+		os::log::debug "Removing ${id}"
+		docker stop "${id}" >/dev/null
+	done
+}
+readonly -f os::cleanup::containers
+
+# os::cleanup::dump_container_logs operates on k8s containers to dump any logs
+# from the containers.
+#
+# Globals:
+#  None
+# Arguments:
+#  None
+# Returns:
+#  None
+function os::cleanup::dump_container_logs() {
+	if ! os::util::find::system_binary docker >/dev/null 2>&1; then
+		os::log::warning "No \`docker\` binary found, skipping container cleanup."
+		return
+	fi
+
+	local container_log_dir="${LOG_DIR}/containers"
+	mkdir -p "${container_log_dir}"
+
+	os::log::info "Dumping container logs to ${container_log_dir}"
+	for id in $( os::cleanup::internal::list_k8s_containers ); do
+		local name; name="$( docker inspect --format '{{ .Name }}' "${id}" )"
+		os::log::debug "Dumping logs for ${id} to ${name}.log"
+		docker logs "${id}" >"${container_log_dir}/${name}.log" 2>&1
+	done
+}
+readonly -f os::cleanup::dump_container_logs
+
+
+
+# os::cleanup::internal::list_k8s_containers returns a space-delimited list of
+# docker containers that belonged to k8s.
+#
+# Globals:
+#  None
+# Arguments:
+#  None
+# Returns:
+#  None
+function os::cleanup::internal::list_k8s_containers() {
+	local ids;
+	for short_id in $( docker ps -aq ); do
+		local id; id="$( docker inspect --format '{{ .Id }}' "${short_id}" )"
+		local name; name="$( docker inspect --format '{{ .Name }}' "${id}" )"
+		if [[ "${name}" =~ ^/k8s_.* ]]; then
+			ids+=( "${id}" )
+		fi
+	done
+
+	echo "${ids[*]}"
+}
+readonly -f os::cleanup::internal::list_k8s_containers

hack/test-end-to-end-docker.sh

@@ -24,11 +24,11 @@ function cleanup()
 	echo
 
 	set +e
-	dump_container_logs
+	os::cleanup::dump_container_logs
 
 	# pull information out of the server log so that we can get failure management in jenkins to highlight it and
 	# really have it smack people in their logs.  This is a severe correctness problem
-    grep -a5 "CACHE.*ALTERED" ${LOG_DIR}/container-origin.log
+    grep -ra5 "CACHE.*ALTERED" ${LOG_DIR}/containers
 
 	os::cleanup::dump_etcd
 
@@ -37,10 +37,7 @@ function cleanup()
 		docker stop origin
 		docker rm origin
 
-		os::log::info "Stopping k8s docker containers"; docker ps | awk 'index($NF,"k8s_")==1 { print $1 }' | xargs -l -r docker stop
-		if [[ -z "${SKIP_IMAGE_CLEANUP-}" ]]; then
-			os::log::info "Removing k8s docker containers"; docker ps -a | awk 'index($NF,"k8s_")==1 { print $1 }' | xargs -l -r docker rm
-		fi
+		os::cleanup::containers
 		set -u
 	fi
 

hack/util.sh

@@ -15,28 +15,6 @@ function kill_all_processes() {
 }
 readonly -f kill_all_processes
 
-# dump_container_logs writes container logs to $LOG_DIR
-function dump_container_logs() {
-	if ! docker version >/dev/null 2>&1; then
-		return
-	fi
-
-	mkdir -p ${LOG_DIR}
-
-	os::log::info "Dumping container logs to ${LOG_DIR}"
-	for container in $(docker ps -aq); do
-		container_name=$(docker inspect -f "{{.Name}}" $container)
-		# strip off leading /
-		container_name=${container_name:1}
-		if [[ "$container_name" =~ ^k8s_ ]]; then
-			pod_name=$(echo $container_name | awk 'BEGIN { FS="[_.]+" }; { print $4 }')
-			container_name=${pod_name}-$(echo $container_name | awk 'BEGIN { FS="[_.]+" }; { print $2 }')
-		fi
-		docker logs "$container" >&"${LOG_DIR}/container-${container_name}.log"
-	done
-}
-readonly -f dump_container_logs
-
 # delete_empty_logs deletes empty logs
 function delete_empty_logs() {
 	# Clean up zero byte log files
@@ -71,25 +49,18 @@ function cleanup_openshift() {
 	ETCD_PORT="${ETCD_PORT:-4001}"
 
 	set +e
-	dump_container_logs
-
 	# pull information out of the server log so that we can get failure management in jenkins to highlight it and
 	# really have it smack people in their logs.  This is a severe correctness problem
 	grep -a5 "CACHE.*ALTERED" ${LOG_DIR}/openshift.log
 
 	os::cleanup::dump_etcd
+	os::cleanup::dump_container_logs
 
 	if [[ -z "${SKIP_TEARDOWN-}" ]]; then
 		os::log::info "Tearing down test"
 		kill_all_processes
 
-		if docker version >/dev/null 2>&1; then
-			os::log::info "Stopping k8s docker containers"; docker ps | awk 'index($NF,"k8s_")==1 { print $1 }' | xargs -l -r docker stop -t 1 >/dev/null
-			if [[ -z "${SKIP_IMAGE_CLEANUP-}" ]]; then
-				os::log::info "Removing k8s docker containers"; docker ps -a | awk 'index($NF,"k8s_")==1 { print $1 }' | xargs -l -r docker rm -v >/dev/null
-			fi
-		fi
-
+		os::cleanup::containers
 		os::log::info "Pruning etcd data directory..."
 		local sudo="${USE_SUDO:+sudo}"
 		${sudo} rm -rf "${ETCD_DATA_DIR}"