DIG-1137, DIG-1618, DIG-1851: misc post-build script fixes (#880)

* redo counting of containers

* consolidate logs

* put LOGFILE into env.sh

* only print messages if there are errors/warnings

* print error in test

* save off progress.txt

* container names with candigv2_*_1

* don't print container lists

.github/workflows/candig-testing.yml

@@ -76,6 +76,6 @@ jobs:
         with:
           name: Post-build error log
           path: |
-                tmp/error.txt
+                tmp/progress.txt
                 tmp/container_logs.txt
                 tmp/vault_audit.log

Makefile

@@ -17,7 +17,6 @@ SHELL = bash
 CONDA = $(CONDA_INSTALL)/bin/conda
 CONDA_ENV_SETTINGS = $(CONDA_INSTALL)/etc/profile.d/conda.sh
 
-LOGFILE = tmp/progress.txt
 
 .PHONY: all
 all:
@@ -56,7 +55,7 @@ ifndef CONDA_INSTALL
 	echo "ERROR: Conda install location not specified. Do you have a .env?"
 	exit 1
 endif
-	echo "    started bin-conda" >> $(LOGFILE)
+	@printf "\nOutput of bin-conda:\n" | tee -a $(LOGFILE)
 ifeq ($(VENV_OS), linux)
 	curl -Lo bin/miniconda_install.sh \
 		https://repo.anaconda.com/miniconda/Miniconda3-latest-Linux-x86_64.sh
@@ -84,7 +83,6 @@ endif
 	$(CONDA) config --remove channels defaults
 	$(CONDA) config --add channels conda-forge
 	$(CONDA) config --set channel_priority strict
-	echo "    finished bin-conda" >> $(LOGFILE)
 
 
 #>>>
@@ -93,7 +91,7 @@ endif
 #<<<
 .PHONY: build-all
 build-all: mkdir
-	printf "Build started at `date '+%D %T'`.\n\n" >> $(ERRORLOG)
+	@printf "Build started at `date '+%D %T'`.\n\n" >> $(LOGFILE)
 	./pre-build-check.sh $(ARGS)
 
 # Setup the entire stack
@@ -132,15 +130,14 @@ build-images: #toil-docker
 
 #<<<
 build-%:
-	printf "\nOutput of build-$*: \n" >> $(ERRORLOG)
-	echo "    started build-$*" >> $(LOGFILE)
+	@printf "\nOutput of build-$*: \n" | tee -a $(LOGFILE)
 	source setup_hosts.sh
 	if [ -f lib/$*/$*_preflight.sh ]; then \
-	source lib/$*/$*_preflight.sh 2>&1 | tee -a $(ERRORLOG); \
+	source lib/$*/$*_preflight.sh 2>&1 | tee -a $(LOGFILE); \
 	fi
 	export SERVICE_NAME=$*; \
 	DOCKER_BUILDKIT=1 COMPOSE_DOCKER_CLI_BUILD=1 \
-	docker compose -f lib/candigv2/docker-compose.yml -f lib/$*/docker-compose.yml build $(BUILD_OPTS) 2>&1 | tee -a $(ERRORLOG)
+	docker compose -f lib/candigv2/docker-compose.yml -f lib/$*/docker-compose.yml build $(BUILD_OPTS) 2>&1 | tee -a $(LOGFILE)
 	echo "    finished build-$*" >> $(LOGFILE)
 
 
@@ -188,7 +185,6 @@ clean-authx:
 # Empties error and progress logs
 .PHONY: clean-logs
 clean-logs:
-	> $(ERRORLOG)
 	> $(LOGFILE)
 
 #>>>
@@ -289,20 +285,18 @@ containers=$(shell cat lib/$*/docker-compose.yml | yq -ojson '.services' | jq  '
 found=$(shell grep -ch $(containers) tmp/containers.txt)
 #<<<
 compose-%:
-	printf "\nOutput of compose-$*: \n" >> $(ERRORLOG)
-	echo "    started compose-$*" >> $(LOGFILE)
+	@printf "\nOutput of compose-$*: \n" | tee -a $(LOGFILE)
 	source setup_hosts.sh; \
 	python settings.py; source env.sh; \
 	export SERVICE_NAME=$*; \
-	docker compose -f lib/candigv2/docker-compose.yml -f lib/$*/docker-compose.yml --compatibility up -d 2>&1 | tee -a $(ERRORLOG)
+	docker compose -f lib/candigv2/docker-compose.yml -f lib/$*/docker-compose.yml --compatibility up -d 2>&1 | tee -a $(LOGFILE)
 	cat tmp/containers.txt
 	if [ $(found) -eq 0 ]; then \
 	echo $(containers) >> tmp/containers.txt; \
 	fi
 	if [ -f lib/$*/$*_setup.sh ]; then \
-	source lib/$*/$*_setup.sh 2>&1 | tee -a $(ERRORLOG); \
+	source lib/$*/$*_setup.sh 2>&1 | tee -a $(LOGFILE); \
 	fi
-	echo "    finished compose-$*" >> $(LOGFILE)
 
 
 #>>>
@@ -324,8 +318,7 @@ recompose-%:
 
 #<<<
 down-%:
-	printf "\nOutput of down-$*: \n" >> $(ERRORLOG)
-	echo "    started down-$*" >> $(LOGFILE)
+	@printf "\nOutput of down-$*: \n" | tee -a $(LOGFILE)
 	source setup_hosts.sh; \
 	export SERVICE_NAME=$*; \
 	docker compose -f lib/candigv2/docker-compose.yml -f lib/$*/docker-compose.yml --compatibility down 2>&1
@@ -432,7 +425,7 @@ init-authx: mkdir
 init-minio: minio-secrets
 	docker volume create minio-config
 	docker volume create minio-data $(MINIO_VOLUME_OPT)
-	docker compose -f lib/candigv2/docker-compose.yml -f lib/minio/docker-compose.yml --compatibility up -d 2>&1 | tee -a $(ERRORLOG)
+	docker compose -f lib/candigv2/docker-compose.yml -f lib/minio/docker-compose.yml --compatibility up -d 2>&1 | tee -a $(LOGFILE)
 
 
 #>>>
@@ -442,7 +435,7 @@ init-minio: minio-secrets
 #<<<
 .PHONY: init-conda
 init-conda:
-	echo "    started init-conda" >> $(LOGFILE)
+	@printf "\nOutput of init-conda: \n" | tee -a $(LOGFILE)
 	# source conda's script to be safe, so the conda command is found
 	source $(CONDA_ENV_SETTINGS) \
 		&& $(CONDA) create -y -n $(VENV_NAME) python=$(VENV_PYTHON) pip=$(VENV_PIP)
@@ -455,7 +448,6 @@ init-conda:
 #@echo "Load local conda: source bin/miniconda3/etc/profile.d/conda.sh"
 #@echo "Activate conda env: conda activate $(VENV_NAME)"
 #@echo "Install requirements: pip install -U -r etc/venv/requirements.txt"
-	echo "    finished init-conda" >> $(LOGFILE)
 
 
 #>>>
@@ -504,7 +496,7 @@ secret-%:
 #<<<
 .PHONY: toil-docker
 toil-docker:
-	echo "    started toil-docker" >> $(LOGFILE)
+	@printf "\nOutput of toil-docker: \n" | tee -a $(LOGFILE)
 	VIRTUAL_ENV=1 DOCKER_BUILDKIT=1 COMPOSE_DOCKER_CLI_BUILD=1 TOIL_DOCKER_REGISTRY=$(DOCKER_REGISTRY) \
 	$(MAKE) -C lib/toil/toil-docker docker
 	$(foreach MODULE,$(TOIL_MODULES), \
@@ -514,7 +506,6 @@ toil-docker:
 		docker tag $(DOCKER_REGISTRY)/$(MODULE):$(TOIL_VERSION) \
 		$(DOCKER_REGISTRY)/$(MODULE):latest;)
 	$(foreach MODULE, $(TOIL_MODULES), docker push $(DOCKER_REGISTRY)/$(MODULE):latest;)
-	echo "    finished toil-docker" >> $(LOGFILE)
 
 
 #>>>

etc/env/example.env

@@ -301,7 +301,9 @@ CANDIG_DATA_PORTAL_PRIVATE_URL=http://candig-data-portal:3000
 TOKEN_PATH = ${PWD}/Vault-Helper-Tool/token.txt
 PROGRESS_FILE = ${PWD}/tmp/progress.txt
 
-# error logging
-ERRORLOG=tmp/error.txt
+# install logging
+LOGFILE = tmp/progress.txt
 
 CONDA_INSTALL=bin/miniconda3
+
+COMPOSE_IGNORE_ORPHANS=True

etc/tests/test_integration.py

@@ -443,6 +443,7 @@ def test_ingest_not_admin_katsu():
     while response.status_code == 200 and "status" in response.json():
         time.sleep(2)
         response = requests.get(f"{ENV['CANDIG_URL']}/ingest/status/{queue_id}", headers=headers)
+    print(response.text)
     assert len(response.json()[f"{ENV['CANDIG_ENV']['CANDIG_SITE_LOCATION']}-SYNTH_01"]["errors"]) == 0
     assert len(response.json()[f"{ENV['CANDIG_ENV']['CANDIG_SITE_LOCATION']}-SYNTH_01"]["results"]) == 13
     katsu_response = requests.get(f"{ENV['CANDIG_ENV']['KATSU_INGEST_URL']}/v3/discovery/programs/")

post_build.sh

@@ -6,7 +6,8 @@
 # Also prints out all relevant logs from the error logging file (i.e., all lines
 # that contain the phrases 'error' or 'warn').
 
-source <(grep --color=never "ERRORLOG" .env)
+python settings.py
+source env.sh
 
 RED='\033[0;31m'
 YELLOW='\033[1;33m'
@@ -16,63 +17,77 @@ DEFAULT='\033[0m'
 
 function print_module_logs() {
 	MODULE=$1
-	BUILD_LINE=$(grep -n build-${MODULE} ${ERRORLOG} | tail -1 | cut -d ':' -f 1)
+	output=""
+	BUILD_LINE=$(grep -n build-${MODULE} ${LOGFILE} | tail -1 | cut -d ':' -f 1)
 	if [[ $BUILD_LINE != "" ]]; then
 		LNO=$BUILD_LINE
 		while read -r LINE; do
 			if [[ $LINE == "Output of build-"* || $LINE == "Output of compose-"* ]]; then
 				break
 			else
 				if [[ ${LINE} =~ .*([Ee]rror|[Ww]arn).* ]]; then
-					printf "${GREEN}${LNO}${DEFAULT}	${LINE}\n"
+					output="${output}${GREEN}${LNO}${DEFAULT}	${LINE}\n"
 				fi
 			fi
 			LNO=$((LNO+1))
-		done < <(tail -n "+$((BUILD_LINE + 1))" $ERRORLOG)
+		done < <(tail -n "+$((BUILD_LINE + 1))" $LOGFILE)
 	fi
-	COMPOSE_LINE=$(grep -n compose-${MODULE} ${ERRORLOG} | tail -1 | cut -d ':' -f 1)
+	COMPOSE_LINE=$(grep -n compose-${MODULE} ${LOGFILE} | tail -1 | cut -d ':' -f 1)
 	if [[ $COMPOSE_LINE != "" ]]; then
 		LNO=$COMPOSE_LINE
 		while read -r LINE; do
 			if [[ $LINE == "Output of build-"* || $LINE == "Output of compose-"* ]]; then
 				break
 			else
 				if [[ ${LINE} =~ .*([Ee]rror|[Ww]arn).* ]]; then
-					printf "${GREEN}${LNO}${DEFAULT}	${LINE}\n"
+					output="${output}${GREEN}${LNO}${DEFAULT}	${LINE}\n"
 				fi
 			fi
 			LNO=$((LNO+1))
-		done < <(tail -n "+$((COMPOSE_LINE+1))" $ERRORLOG)
+		done < <(tail -n "+$((COMPOSE_LINE+1))" $LOGFILE)
+	fi
+	if [[ $output != "" ]]; then
+		printf "\n\n${RED}Error logs for ${MODULE}:\n--------------------\n${DEFAULT}"
+		printf "${output}"
+		printf "${RED}--------------------\n${DEFAULT}\n"
 	fi
 }
 
 MODULES=$(cat .env | grep CANDIG_MODULES | cut -c 16- | cut -d '#' -f 1)
 ALL_MODULES="${MODULES}"
 
-SERVICE_COUNT=0
+EXPECTED_CONTAINERS=""
 for MODULE in $ALL_MODULES; do
+  services=$(cat lib/$MODULE/docker-compose.yml | yq -ojson '.services' | jq  'keys' | jq -r @sh | sed s/^\'/candigv2_/g | sed s/\'$/_1/g | sed "s/\'\ \'/_1\\ candigv2_/g" | sed "s/'\\s'/_1\\ candigv2_/g")
+  EXPECTED_CONTAINERS=$(echo $EXPECTED_CONTAINERS $services)
   sc=$(cat lib/$MODULE/docker-compose.yml | yq -ojson '.services' | jq  'keys' | jq -r @sh | wc -w | tr -d ' ')
-  SERVICE_COUNT=`expr $SERVICE_COUNT + $sc`
 done
 
-RUNNING_MODULES=$(docker ps --format "{{.Names}}")
+EXPECTED_COUNT=$(echo $EXPECTED_CONTAINERS | wc -w)
+
+RUNNING_CONTAINERS=$(docker ps --format "{{.Names}}")
+RUNNING_COUNT=$(echo $RUNNING_CONTAINERS | wc -w)
 
-if [ $(docker ps -q | wc -l) == $SERVICE_COUNT ]
+# figure out any containers that should've been there but aren't
+for i in $EXPECTED_CONTAINERS
+do
+	[[ ! $RUNNING_CONTAINERS =~ $i  ]] && MISSING_CONTAINERS="${MISSING_CONTAINERS:+${MISSING_CONTAINERS} }$i"
+done
+# echo expected: $EXPECTED_CONTAINERS
+# echo running: $RUNNING_CONTAINERS
+# echo missing: $MISSING_CONTAINERS
+if [[ $(echo $MISSING_CONTAINERS | wc -w | tr -d ' ') == "0"  ]]
 then
 	for MODULE in $ALL_MODULES; do
-		printf "\n\n${BLUE}Error logs for ${MODULE}:\n--------------------\n${DEFAULT}"
-		print_module_logs $MODULE
-		printf "${BLUE}--------------------\n${DEFAULT}"
+		print_module_logs $MODULE $COLOR
 	done
-	echo -e "${GREEN}Number of expected CanDIG services matches number of containers running!${DEFAULT} Potentially useful error log segments listed above for debugging."
+	echo -e "${GREEN}Number of expected CanDIG services matches number of containers running!${DEFAULT} Lines above are in ${LOGFILE} and may be helpful for debugging."
  	exit 0
 else
 	for MODULE in $ALL_MODULES; do
-		printf "\n\n${RED}Error logs for ${MODULE}:\n--------------------\n${DEFAULT}"
 		print_module_logs $MODULE
-		printf "${RED}--------------------\n${DEFAULT}"
 	done
-	echo -e "${RED}WARNING: ${YELLOW}The number of CanDIG containers running does not match the number of expected services.\nRunning: ${BLUE}$(docker ps -q | wc -l) ${YELLOW}Expected: ${BLUE}${SERVICE_COUNT}
-${DEFAULT}Check your build/docker logs. Potentially offending service logs shown above. View ${ERRORLOG} for more information."
+	echo -e "${RED}WARNING: ${YELLOW}Some containers that are expected to be running are missing:\n${MISSING_CONTAINERS}
+${DEFAULT}Lines above are in ${LOGFILE} and may be helpful for debugging."
 	exit 1
 fi

settings.py

@@ -41,6 +41,7 @@ def get_env_value(key):
 
 def get_env():
     vars = {}
+    vars["LOGFILE"] = get_env_value("LOGFILE")
     vars["CANDIG_URL"] = get_env_value("TYK_LOGIN_TARGET_URL")
     vars["CANDIG_CLIENT_ID"] = get_env_value("KEYCLOAK_CLIENT_ID")
     vars["KEYCLOAK_PUBLIC_URL"] = get_env_value("KEYCLOAK_PUBLIC_URL")