Merge pull request #186 from ochaloup/JBEAP-18946-cannot-query-openshift-api

luck3y · web-flow · commit 9cfaae8fad71 · 2020-07-06T16:51:03.000-05:00
[CLOUD-3517] correct processing of command exit status when OpenShift API is not available
diff --git a/os-eap-migration/added/launch/openshift-migrate-common.sh b/os-eap-migration/added/launch/openshift-migrate-common.sh
@@ -20,7 +20,7 @@ function runMigration() {
 
   echo "Running $JBOSS_IMAGE_NAME image, version $JBOSS_IMAGE_VERSION"
 
-  local txOptions="-Dcom.arjuna.ats.arjuna.common.RecoveryEnvironmentBean.recoveryBackoffPeriod=1 -Dcom.arjuna.ats.arjuna.common.RecoveryEnvironmentBean.periodicRecoveryPeriod=1 -Dcom.arjuna.ats.jta.common.JTAEnvironmentBean.orphanSafetyInterval=1"
+  local txOptions="-Djboss.node.name=${NODE_NAME} -Dcom.arjuna.ats.arjuna.common.RecoveryEnvironmentBean.recoveryBackoffPeriod=1 -Dcom.arjuna.ats.arjuna.common.RecoveryEnvironmentBean.periodicRecoveryPeriod=1 -Dcom.arjuna.ats.jta.common.JTAEnvironmentBean.orphanSafetyInterval=1"
   local terminatingFile="${JBOSS_HOME}/terminatingMigration"
 
   (runMigrationServer "$instanceDir" "${txOptions}") &
@@ -54,8 +54,11 @@ function runMigration() {
 
       if [ "${recoveryPort}" != "undefined" ] ; then
         local recoveryClass="com.arjuna.ats.arjuna.tools.RecoveryMonitor"
-        # we may have > 1 jar, if that is the case we use the most recent one
+        # for runtime image the modules jar files are under $JBOSS_HOME/modules
         recoveryJars=$(find "${JBOSS_HOME}" -name \*.jar | xargs grep -l "${recoveryClass}")
+        # for builder image the modules jar files are under galleon maven repository
+        [ -z "${recoveryJars}" ] && recoveryJars=$(find "${GALLEON_LOCAL_MAVEN_REPO}" -name \*.jar | xargs grep -l "${recoveryClass}")
+        # we may have > 1 jar, if that is the case we use the most recent one
         recoveryJar=$(ls -Art $recoveryJars | tail -n 1)
         if [ -n "${recoveryJar}" ] ; then
           echo "$(date): Executing synchronous recovery scan for a first time"
@@ -73,11 +76,11 @@ function runMigration() {
     fi
   done
 
-  # -- checking if the pod log is clean from errors (only if function of the particular name exists, provided by the os-partition module)
+  # -- checking if the migration pod log is clean from errors (only if the function exists, provided by the os-eap-txnrecovery module)
   if [ $probeStatus -eq 0 ] && [ "$(type -t probePodLogForRecoveryErrors)" = 'function' ]; then
-    probePodLogForRecoveryErrors
+    probePodLogForRecoveryErrors "${MIGRATION_POD_NAME}" "${MIGRATION_POD_TIMESTAMP}"
     probeStatus=$?
-    [ $probeStatus -ne 0 ] && echo "The migration container log contains periodic recovery errors, check it for details."
+    [ $probeStatus -ne 0 ] && echo "The migration container log contains periodic recovery errors or cannot query API, check for details above."
   fi
 
   if [ $probeStatus -eq 0 ] ; then
diff --git a/os-eap-txnrecovery/bash/added/partitionPV.sh b/os-eap-txnrecovery/bash/added/partitionPV.sh
@@ -124,7 +124,7 @@ function startApplicationServer() {
         mkdir -p "${SERVER_DATA_DIR}"
 
         if [ ! -f "${SERVER_DATA_DIR}/../data_initialized" ]; then
-           init_data_dir ${SERVER_DATA_DIR}
+            init_data_dir ${SERVER_DATA_DIR}
             touch "${SERVER_DATA_DIR}/../data_initialized"
         fi
     fi
@@ -209,7 +209,9 @@ function migratePV() {
 
         (
           # 1.a.ii) run recovery until empty (including orphan checks and empty object store hierarchy deletion)
+          MIGRATION_POD_NAME=${recoveryPodName}
           MIGRATION_POD_TIMESTAMP=$(getPodLogTimestamp)  # investigating on current pod timestamp
+          [ $? -ne 0 ] && log_warning "[`date`] Can't get log from the transaction migration pod '${MIGRATION_POD_NAME}', skipping cleanup for ${applicationPodName}" && continue
           SERVER_DATA_DIR="${applicationPodDir}/serverData"
           NODE_NAME=$(truncate_jboss_node_name "${applicationPodName}") runMigration "${SERVER_DATA_DIR}" &
 
@@ -336,7 +338,8 @@ function removeRecoveryMarker() {
 # parameters:
 # - place where pod data directories are saved (podsDir)
 function recoveryPodsGarbageCollection() {
-  local livingPods=($($(dirname ${BASH_SOURCE[0]})/queryosapi.py -q pods_living -f list_space ${DEBUG_QUERY_API_PARAM}))
+  local livingPods
+  livingPods=($($(dirname ${BASH_SOURCE[0]})/queryosapi.py -q pods_living -f list_space ${DEBUG_QUERY_API_PARAM}))
   if [ $? -ne 0 ]; then # fail to connect to openshift api
     log_warning "[`date`] Can't get list of living pods. Can't do recovery marker garbage collection."
     return 1
@@ -371,7 +374,14 @@ function getPodLogTimestamp() {
   init_pod_name
   local podNameToProbe=${1:-$POD_NAME}
 
-  local logOutput=$($(dirname ${BASH_SOURCE[0]})/queryosapi.py -q log --pod ${podNameToProbe} --tailline 1 ${DEBUG_QUERY_API_PARAM})
+  local logOutput
+  logOutput=$($(dirname ${BASH_SOURCE[0]})/queryosapi.py -q log --pod ${podNameToProbe} --tailline 1 ${DEBUG_QUERY_API_PARAM})
+
+  if [ $? -ne 0 ]; then
+    log_warning "[`date`] Cannot contact OpenShift API to get log for pod ${podNameToProbe} while searching for the log timestamp"
+    return 1
+  fi
+
   # only one, last line of the log, is returned, taking the start which is timestamp
   echo $logOutput | sed 's/ .*$//'
 }
@@ -381,13 +391,17 @@ function getPodLogTimestamp() {
 # - pod name (optional)
 function probePodLogForRecoveryErrors() {
   init_pod_name
+  local podNameToProbe=${1:-$POD_NAME}
   local sinceTimestampParam=''
-  local sinceTimestamp=${1:-$MIGRATION_POD_TIMESTAMP}
+  local sinceTimestamp=${2:-$MIGRATION_POD_TIMESTAMP}
   [ "x$sinceTimestamp" != "x" ] && sinceTimestampParam="--sincetime ${sinceTimestamp}"
-  local podNameToProbe=${2:-$POD_NAME}
 
-  local logOutput=$($(dirname ${BASH_SOURCE[0]})/queryosapi.py -q log --pod ${podNameToProbe} ${sinceTimestampParam} ${DEBUG_QUERY_API_PARAM})
+  local logOutput
+  # even for debug it's too verbose to print the listing of the log
+  [ "x${SCRIPT_DEBUG}" = "xtrue" ] && set +x
+  logOutput=$($(dirname ${BASH_SOURCE[0]})/queryosapi.py -q log --pod ${podNameToProbe} ${sinceTimestampParam} ${DEBUG_QUERY_API_PARAM})
   local probeStatus=$?
+  [ "x${SCRIPT_DEBUG}" = "xtrue" ] && set -x
 
   if [ $probeStatus -ne 0 ]; then
     log_warning "[`date`] Cannot contact OpenShift API to get log for pod ${podNameToProbe}"
diff --git a/os-eap-txnrecovery/bash/added/queryosapi.py b/os-eap-txnrecovery/bash/added/queryosapi.py
@@ -19,6 +19,7 @@
 import json
 import logging
 import osquery
+import sys, traceback
 
 from enum import Enum
 
@@ -106,20 +107,26 @@ def getLog(podName, sinceTime, tailLine):
 
     logger.debug("Starting query openshift api with args: %s", args)
 
-    if args.query == QueryType.PODS:
-        queryResult = getPods()
-    elif args.query == QueryType.PODS_LIVING:
-        queryResult = getLivingPods()
-    elif args.query == QueryType.LOG:
-        if args.pod is None:
-            logger.critical('query of type "--query log" requires one argument to be an existing pod name')
+    try:
+        if args.query == QueryType.PODS:
+            queryResult = getPods()
+        elif args.query == QueryType.PODS_LIVING:
+            queryResult = getLivingPods()
+        elif args.query == QueryType.LOG:
+            if args.pod is None:
+                logger.critical('query of type "--query log" requires one argument to be an existing pod name')
+                exit(1)
+            podName = args.pod
+            sinceTime = args.sincetime
+            tailLine = args.tailline
+            queryResult = getLog(podName, sinceTime, tailLine)
+        else:
+            logger.critical('No handler for query type %s', args.query)
             exit(1)
-        podName = args.pod
-        sinceTime = args.sincetime
-        tailLine = args.tailline
-        queryResult = getLog(podName, sinceTime, tailLine)
-    else:
-        logger.critical('No handler for query type %s', args.query)
+    except:
+        etype, value, tb = sys.exc_info()
+        logger.critical("Error while request was processed: %s : %s", etype, value)
+        logger.debug('Exception stacktrace:\n%s', ''.join(traceback.format_exception(etype, value, tb, None)))
         exit(1)
 
     if args.format == OutputFormat.LIST_SPACE:
diff --git a/os-eap-txnrecovery/bash/test/common.bash b/os-eap-txnrecovery/bash/test/common.bash
@@ -0,0 +1,38 @@
+export JBOSS_HOME="${BATS_TMPDIR}/jboss_home"
+# Prepare the directories and scripts to the right places
+mkdir -p "${JBOSS_HOME}/bin/launch"
+cp "${BATS_TEST_DIRNAME}/../added/partitionPV.sh" "${JBOSS_HOME}/bin/launch/"
+cp "${BATS_TEST_DIRNAME}/../../../test-common/launch-common.sh" "${JBOSS_HOME}/bin/launch/"
+cp "${BATS_TEST_DIRNAME}/../../../test-common/logging.sh" "${JBOSS_HOME}/bin/launch/"
+# test files
+cp "${BATS_TEST_DIRNAME}/test_queryosapi.py" "${JBOSS_HOME}/bin/launch/queryosapi.py"
+chmod ugo+x "${JBOSS_HOME}/bin/launch/queryosapi.py"
+
+# Set up the environment variables and load dependencies
+source "${JBOSS_HOME}/bin/launch/launch-common.sh"
+source "${JBOSS_HOME}/bin/launch/logging.sh"
+# Sourcing the script for testing
+source "${JBOSS_HOME}/bin/launch/partitionPV.sh"
+
+# places to store the files needed for testing
+export SERVER_TEMP_DIR="${BATS_TMPDIR}/server_temp_dir"
+export SERVER_RUNNING_MARKER_FILENAME="server.was.started"
+
+setup() {
+  rm -rf "${SERVER_TEMP_DIR}"
+}
+
+# simulating the startup of the server; normally run by 'openshift-launch.sh' script
+function runServer() {
+  # expecting the first parameter to be set
+  [ "x$1" = "x" ] && echo "The first parameter of meaning instanceDir has to be defined" && return 1
+  touch "${1}/${SERVER_RUNNING_MARKER_FILENAME}"
+  (
+    echo "${I}: Running server with PID $$"
+  )&
+}
+
+# function definition for testing purposes
+function init_data_dir() {
+  echo "init_data_dir executed"
+}
diff --git a/os-eap-txnrecovery/bash/test/partitionPV.bats b/os-eap-txnrecovery/bash/test/partitionPV.bats
@@ -0,0 +1,138 @@
+#!/usr/bin/env bats
+
+load common
+
+@test "arrContains: find existing item" {
+    ARRAY_TO_TEST=( itemone itemtwo itemthree )
+    run arrContains itemtwo "${ARRAY_TO_TEST[@]}"
+    [ "$status" -eq 0 ]
+}
+
+@test "arrContains: fail with non existing item" {
+    ARRAY_TO_TEST=( itemone itemtwo itemthree )
+    run arrContains itemfour "${ARRAY_TO_TEST[@]}"
+    [ "$status" -eq 1 ]
+}
+
+@test "init_pod_name: NODE_NAME specified" {
+    NODE_NAME="nodename"
+    init_pod_name
+    [ "$?" -eq 0 ]
+    [ "$POD_NAME" = "$NODE_NAME" ]
+}
+
+@test "init_pod_name: JBOSS_NODE_NAME overrides the pod name value" {
+    NODE_NAME="nodename"
+    JBOSS_NODE_NAME="jbossnodename"
+    init_pod_name
+    [ "$?" -eq 0 ]
+    [ "$POD_NAME" = "$JBOSS_NODE_NAME" ]
+}
+
+@test "init_pod_name: uses the host name or docker container uuid" {
+    init_pod_name
+    [ "$?" -eq 0 ]
+    [ "$POD_NAME" = "$HOSTNAME" ] || [ "$POD_NAME" = "${container_uuid}" ]
+}
+
+@test "truncate_jboss_node_name: long name has to be truncated up to 23 characters not started with -" {
+    CHARACTERS_22_LONG="ABCDEFGHIJKLMNOPQRSTUV"
+    run truncate_jboss_node_name "moreCharatersHere#-${CHARACTERS_22_LONG}"
+    [ "$status" -eq 0 ]
+    [ "$output" = "${CHARACTERS_22_LONG}" ]
+}
+
+# Server is started with data directory which is passed to the function in parameter
+@test "startApplicationServer: simple start, no split data dir" {
+    export IS_TX_SQL_BACKEND=false
+    export IS_SPLIT_DATA_DEFINED=false
+
+    SERVER_DATA_DIR="$SERVER_TEMP_DIR"
+    mkdir -p "$SERVER_DATA_DIR"
+
+    POD_NAME="node-name-1"
+    run startApplicationServer
+    [ "$status" -eq 0 ]
+    [ -f "${SERVER_DATA_DIR}/${SERVER_RUNNING_MARKER_FILENAME}" ]
+}
+
+# Definition of the split data expects that multiple servers share the same directory for their runtime data
+# The startup script has to create separate place for each server
+@test "startApplicationServer: split data dir defined, no recovery" {
+    IS_TX_SQL_BACKEND=false
+    IS_SPLIT_DATA_DEFINED=true
+    POD_NAME="node-name-split-data"
+
+    run startApplicationServer "${SERVER_TEMP_DIR}"
+    [ "$status" -eq 0 ]
+    [ -f "${SERVER_TEMP_DIR}/${POD_NAME}/serverData/${SERVER_RUNNING_MARKER_FILENAME}" ]
+    [ -f "${SERVER_TEMP_DIR}/${POD_NAME}/data_initialized" ]
+}
+
+# The test simulates the recovery in progress
+# the recovery processing creates a marker file with the name
+# the test creates the marker file with the name of the pod which is about to be started
+# the application server is started only after the recovery marker is removed
+@test "startApplicationServer: split data dir defined, recovery in progress" {
+    IS_TX_SQL_BACKEND=false
+    IS_SPLIT_DATA_DEFINED=true
+    POD_NAME="node-name-with-recovery"
+    mkdir -p "${SERVER_TEMP_DIR}"
+    local recoveryMarkerFileName="${SERVER_TEMP_DIR}/${POD_NAME}-RECOVERY-bats.testing"
+
+    touch "$recoveryMarkerFileName"
+
+    startApplicationServer "${SERVER_TEMP_DIR}" &
+    local startApplicationServerPid=$!
+    sleep "0.01"
+
+    [ ! -f "${SERVER_TEMP_DIR}/${POD_NAME}/serverData/${SERVER_RUNNING_MARKER_FILENAME}" ]
+    rm -f "$recoveryMarkerFileName"
+
+    wait $startApplicationServerPid
+    echo ":: $(kill -0 $testPid)"
+
+    [ -f "${SERVER_TEMP_DIR}/${POD_NAME}/serverData/${SERVER_RUNNING_MARKER_FILENAME}" ]
+    [ -f "${SERVER_TEMP_DIR}/${POD_NAME}/data_initialized" ]
+}
+
+@test "recovery marker creation and deletion" {
+    IS_TX_SQL_BACKEND=false
+    IS_SPLIT_DATA_DEFINED=true
+    POD_NAME="recovery-in-progress"
+    mkdir -p "${SERVER_TEMP_DIR}"
+    podsDir="${SERVER_TEMP_DIR}"
+
+    if isRecoveryInProgress "${SERVER_TEMP_DIR}"; then
+        # recovery in progress expected to fail
+        return 1
+    fi
+
+    createRecoveryMarker "${SERVER_TEMP_DIR}" "${POD_NAME}" "recovery-name"
+    isRecoveryInProgress "${SERVER_TEMP_DIR}"
+    removeRecoveryMarker "${SERVER_TEMP_DIR}" "${POD_NAME}" "recovery-name"
+
+    if isRecoveryInProgress "${SERVER_TEMP_DIR}"; then
+        # recovery in progress #2 expected to fail
+        return 1
+    fi
+}
+
+@test "recovery garbage collection cleanup" {
+    IS_TX_SQL_BACKEND=false
+    IS_SPLIT_DATA_DEFINED=true
+    POD_NAME="recovery-garbage-collection"
+    local recoveryMarkerName="recovery-name"
+    mkdir -p "${SERVER_TEMP_DIR}"
+    podsDir="${SERVER_TEMP_DIR}"
+
+    run recoveryPodsGarbageCollection "${SERVER_TEMP_DIR}"
+    [ "$status" -eq 0 ]
+
+    createRecoveryMarker "${SERVER_TEMP_DIR}" "${POD_NAME}" $recoveryMarkerName
+    [ -f "${SERVER_TEMP_DIR}/${POD_NAME}-RECOVERY-${recoveryMarkerName}" ]
+
+    run recoveryPodsGarbageCollection "${SERVER_TEMP_DIR}"
+    [ "$status" -eq 0 ]
+    [ ! -f "${SERVER_TEMP_DIR}/${POD_NAME}-RECOVERY-${recoveryMarkerName}" ]
+}
diff --git a/os-eap-txnrecovery/bash/test/test_queryosapi.py b/os-eap-txnrecovery/bash/test/test_queryosapi.py
@@ -0,0 +1 @@
+#!/bin/python
diff --git a/os-eap-txnrecovery/run/python3/osquery.py b/os-eap-txnrecovery/run/python3/osquery.py
@@ -52,7 +52,13 @@ def queryApi(urlSuffix, isPretty = False):
             headers = {'Authorization': 'Bearer ' + OpenShiftQuery.getToken(), 'Accept': 'application/json'})
         logger.debug('query for: "%s"', request.get_full_url())
         try:
-            return urllib.request.urlopen(request, cafile = OpenShiftQuery.CERT_FILE_PATH).read()
+            resource = urllib.request.urlopen(request, cafile = OpenShiftQuery.CERT_FILE_PATH)
+            charset = 'utf-8'
+            if resource.headers.get_content_charset() != None:
+                charset = resource.headers.get_content_charset()
+            elif resource.info().get_content_charset() != None:
+                charset = resource.info().get_content_charset()
+            return resource.read().decode(charset)
         except:
             logger.critical('Cannot query OpenShift API for "%s"', request.get_full_url())
             raise
