Feature 685 log updates (#1992)

.github/jobs/bash_functions.sh

@@ -1,16 +1,20 @@
 #! /bin/bash
 
 # utility function to run command get log the time it took to run
+# ::group:: and ::endgroup:: create collapsible log groups in GitHub Actions
 function time_command {
   local start_seconds=$SECONDS
-  echo "RUNNING: $*"
+  echo "::group::RUNNING: $*"
   "$@"
   local error=$?
 
   local duration=$(( SECONDS - start_seconds ))
   echo "TIMING: Command took `printf '%02d' $(($duration / 60))`:`printf '%02d' $(($duration % 60))` (MM:SS): '$*'"
+  echo "::endgroup::"
+
   if [ ${error} -ne 0 ]; then
     echo "ERROR: '$*' exited with status = ${error}"
   fi
+
   return $error
 }

.github/jobs/docker_utils.py

@@ -1,5 +1,8 @@
 import os
 import re
+import subprocess
+import shlex
+import time
 
 # Utilities used by various CI jobs. Functionality includes:
 #  - Check if Docker data volumes need to be updated.
@@ -15,6 +18,7 @@
 # extension to add to conda environments
 VERSION_EXT = '.v5'
 
+
 def get_data_repo(branch_name):
     """! Branch names that start with main_v or contain only
        digits and dots with out without a prefix 'v' will return
@@ -26,10 +30,12 @@ def get_data_repo(branch_name):
         return DOCKERHUB_METPLUS_DATA
     return DOCKERHUB_METPLUS_DATA_DEV
 
+
 def get_dockerhub_url(branch_name):
     data_repo = get_data_repo(branch_name)
     return f'https://hub.docker.com/v2/repositories/{data_repo}/tags'
 
+
 def docker_get_volumes_last_updated(current_branch):
     import requests
     dockerhub_url = get_dockerhub_url(current_branch)
@@ -60,6 +66,7 @@ def docker_get_volumes_last_updated(current_branch):
 
     return volumes_last_updated
 
+
 def get_branch_name():
     # get branch name from env var BRANCH_NAME
     branch_name = os.environ.get('BRANCH_NAME')
@@ -82,3 +89,56 @@ def get_branch_name():
         return None
 
     return github_ref.replace('refs/heads/', '').replace('/', '_')
+
+
+def run_commands(commands):
+    """!Run a list of commands via subprocess. Print the command and the length
+    of time it took to run. Includes ::group:: and ::endgroup:: syntax which
+    creates log groups in GitHub Actions log output.
+
+    @param commands list of commands to run or a single command string
+    @returns True if all commands ran successfully, False if any commands fail
+    """
+    # handle a single command string or list of command strings
+    if isinstance(commands, str):
+        command_list = [commands]
+    else:
+        command_list = commands
+
+    is_ok = True
+    for command in command_list:
+        error_message = None
+        print(f"::group::RUNNING {command}")
+        start_time = time.time()
+        try:
+            process = subprocess.Popen(shlex.split(command),
+                                       shell=False,
+                                       encoding='utf-8',
+                                       stdout=subprocess.PIPE,
+                                       stderr=subprocess.STDOUT)
+            # Poll process.stdout to show stdout live
+            while True:
+                output = process.stdout.readline()
+                if process.poll() is not None:
+                    break
+                if output:
+                    print(output.strip())
+            rc = process.poll()
+            if rc:
+                raise subprocess.CalledProcessError(rc, command)
+
+        except subprocess.CalledProcessError as err:
+            error_message = f"ERROR: Command failed -- {err}"
+            is_ok = False
+
+        end_time = time.time()
+        print("TIMING: Command took "
+              f"{time.strftime('%M:%S', time.gmtime(end_time - start_time))}"
+              f" (MM:SS): '{command}')")
+
+        print("::endgroup::")
+
+        if error_message:
+            print(error_message)
+
+    return is_ok

.github/jobs/get_data_volumes.py

@@ -12,6 +12,8 @@
 
 from docker_utils import docker_get_volumes_last_updated, get_branch_name
 from docker_utils import get_data_repo, DOCKERHUB_METPLUS_DATA_DEV
+from docker_utils import run_commands
+
 
 def main(args):
     # get METplus version
@@ -94,9 +96,7 @@ def main(args):
         print(f"CREATING DATA VOLUME FROM: {full_volume_name}")
         cmd = (f'docker create --name {model_app_name} '
                f'{full_volume_name}')
-        ret = subprocess.run(shlex.split(cmd))
-
-        if ret.returncode:
+        if not run_commands(cmd):
             continue
 
         # add name to volumes from list to pass to docker build

.github/jobs/get_use_case_commands.py

@@ -60,13 +60,14 @@ def handle_automation_env(host_name, reqs, work_dir):
     conda_env_w_ext = f'{conda_env}{VERSION_EXT}'
 
     # start building commands to run before run_metplus.py in Docker
-    setup_env = 'source /etc/bashrc;'
+    setup_env = []
+    setup_env.append(_add_to_bashrc('# BELOW WAS ADDED BY TEST SCRIPT'))
 
     # add conda bin to beginning of PATH
     python_dir = os.path.join('/usr', 'local', 'envs',
                               conda_env_w_ext, 'bin')
     python_path = os.path.join(python_dir, 'python3')
-    setup_env += f' export PATH={python_dir}:$PATH;'
+    setup_env.append(_add_to_bashrc(f'export PATH={python_dir}:$PATH'))
 
     # if py_embed listed in requirements and using a Python
     # environment that differs from the MET env, set MET_PYTHON_EXE
@@ -86,45 +87,53 @@ def handle_automation_env(host_name, reqs, work_dir):
     if any([item for item in PLOTCALC_KEYWORDS if item in str(reqs).lower()]):
         ce_file = os.path.join(work_dir, '.github', 'parm',
                                f'Externals_metplotcalcpy{externals_ext}')
-        setup_env += (
-            f'cd {METPLUS_DOCKER_LOC};'
-            f'{work_dir}/manage_externals/checkout_externals -e {ce_file};'
-            f'{python_path} -m pip install {METPLUS_DOCKER_LOC}/../METplotpy;'
-            f'{python_path} -m pip install {METPLUS_DOCKER_LOC}/../METcalcpy;'
-            'cd -;'
-        )
+        setup_env.extend((
+            f'cd {METPLUS_DOCKER_LOC}',
+            f'{work_dir}/manage_externals/checkout_externals -e {ce_file}',
+            f'{python_path} -m pip install {METPLUS_DOCKER_LOC}/../METplotpy',
+            f'{python_path} -m pip install {METPLUS_DOCKER_LOC}/../METcalcpy',
+            'cd -',
+        ))
 
     # if metdataio is in requirements list, add command to obtain METdataio
     if 'metdataio' in str(reqs).lower():
         ce_file = os.path.join(work_dir, '.github', 'parm',
                                f'Externals_metdataio{externals_ext}')
-        setup_env += (
-            f'cd {METPLUS_DOCKER_LOC};'
-            f'{work_dir}/manage_externals/checkout_externals -e {ce_file};'
-            f'{python_path} -m pip install {METPLUS_DOCKER_LOC}/../METdataio;'
-            'cd -;'
-        )
+        setup_env.extend((
+            f'cd {METPLUS_DOCKER_LOC}',
+            f'{work_dir}/manage_externals/checkout_externals -e {ce_file}',
+            f'{python_path} -m pip install {METPLUS_DOCKER_LOC}/../METdataio',
+            'cd -',
+        ))
 
     # if gempak is in requirements list, add JRE bin to path for java
     if 'gempak' in str(reqs).lower():
-        setup_env += 'export PATH=$PATH:/usr/lib/jvm/jre/bin;'
+        setup_env.append(_add_to_bashrc(
+            'export PATH=$PATH:/usr/lib/jvm/jre/bin'
+        ))
 
     # if metplus is in requirements list,
     # add top of METplus repo to PYTHONPATH so metplus can be imported
     if 'metplus' in str(reqs).lower():
-        setup_env += f'export PYTHONPATH={METPLUS_DOCKER_LOC}:$PYTHONPATH;'
+        setup_env.append(_add_to_bashrc(
+            f'export PYTHONPATH={METPLUS_DOCKER_LOC}:$PYTHONPATH'
+        ))
 
     # list packages in python environment that will be used
     if conda_env not in NOT_PYTHON_ENVS:
-        setup_env += (
-            f'echo Using environment: dtcenter/metplus-envs:{conda_env_w_ext};'
-            f'echo cat /usr/local/envs/{conda_env_w_ext}/environments.yml;'
-            f'echo ----------------------------------------;'
-            f'cat /usr/local/envs/{conda_env_w_ext}/environments.yml;'
-            'echo ----------------------------------------;'
-        )
+        setup_env.extend((
+            f'echo Using environment: dtcenter/metplus-envs:{conda_env_w_ext}',
+            f'echo cat /usr/local/envs/{conda_env_w_ext}/environments.yml',
+            f'echo ----------------------------------------',
+            f'cat /usr/local/envs/{conda_env_w_ext}/environments.yml',
+            'echo ----------------------------------------',
+        ))
 
-    return setup_env, py_embed_arg
+    return ';'.join(setup_env), py_embed_arg
+
+
+def _add_to_bashrc(command):
+    return f"echo '{command};' >> /etc/bashrc"
 
 
 def main(categories, subset_list, work_dir=None,
@@ -151,10 +160,13 @@ def main(categories, subset_list, work_dir=None,
         for use_case_by_requirement in use_cases_by_req:
             reqs = use_case_by_requirement.requirements
 
-            setup_env, py_embed_arg = handle_automation_env(host_name, reqs, work_dir)
+            setup_env, py_embed_arg = handle_automation_env(host_name, reqs,
+                                                            work_dir)
 
             # use status variable to track if any use cases failed
-            use_case_cmds = ['status=0']
+            use_case_cmds = []
+            if host_name != 'docker':
+                use_case_cmds.append('status=0')
             for use_case in use_case_by_requirement.use_cases:
                 # add parm/use_cases path to config args if they are conf files
                 config_args = []
@@ -174,13 +186,14 @@ def main(categories, subset_list, work_dir=None,
                 use_case_cmds.append(use_case_cmd)
                 # check exit code from use case command and
                 # set status to non-zero value on error
-                use_case_cmds.append("if [ $? != 0 ]; then status=1; fi")
+                if host_name != 'docker':
+                    use_case_cmds.append("if [ $? != 0 ]; then status=1; fi")
 
             # if any use cases failed, force non-zero exit code with false
-            use_case_cmds.append("if [ $status != 0 ]; then false; fi")
+            if host_name != 'docker':
+                use_case_cmds.append("if [ $status != 0 ]; then false; fi")
             # add commands to set up environment before use case commands
-            group_commands = f"{setup_env}{';'.join(use_case_cmds)}"
-            all_commands.append((group_commands, reqs))
+            all_commands.append((setup_env, use_case_cmds, reqs))
 
     return all_commands
 
@@ -203,7 +216,6 @@ def handle_command_line_args():
     else:
         subset_list = None
 
-
     # check if comparison flag should be set
     if len(sys.argv) > 3:
         do_comparison = True
@@ -216,7 +228,10 @@ def handle_command_line_args():
 if __name__ == '__main__':
     categories, subset_list, _ = handle_command_line_args()
     all_commands = main(categories, subset_list)
-    for command, requirements in all_commands:
+    for setup_commands, use_case_commands, requirements in all_commands:
         print(f"REQUIREMENTS: {','.join(requirements)}")
-        command_format = ';\\\n'.join(command.split(';'))
-        print(f"COMMAND:\n{command_format}\n")
+        if setup_commands:
+            command_format = ';\\\n'.join(setup_commands.split(';'))
+            print(f"SETUP COMMANDS:\n{command_format}\n")
+        command_format = ';\\\n'.join(use_case_commands)
+        print(f"USE CASE COMMANDS:\n{command_format}\n")

.github/jobs/setup_and_run_diff.py

@@ -11,6 +11,7 @@
 sys.path.insert(0, ci_dir)
 
 from jobs import get_data_volumes
+from jobs.docker_utils import run_commands
 
 CI_JOBS_DIR = '.github/jobs'
 
@@ -39,22 +40,32 @@
 
 print(f"Output Volumes: {VOLUMES_FROM}")
 
-volume_mounts = [
+VOLUME_MOUNTS = [
     f'-v {WS_PATH}:{GITHUB_WORKSPACE}',
     f'-v {RUNNER_WORKSPACE}/output:/data/output',
     f'-v {RUNNER_WORKSPACE}/diff:/data/diff',
 ]
 
-mount_args = ' '.join(volume_mounts)
+MOUNT_ARGS = ' '.join(VOLUME_MOUNTS)
 
 # command to run inside Docker
-cmd = (f'/usr/local/envs/diff{VERSION_EXT}/bin/python3 '
-       f'{GITHUB_WORKSPACE}/{CI_JOBS_DIR}/run_diff_docker.py')
+diff_command = (f'/usr/local/envs/diff{VERSION_EXT}/bin/python3 '
+                f'{GITHUB_WORKSPACE}/{CI_JOBS_DIR}/run_diff_docker.py')
+
+# start detached interactive diff env container
+# mount METplus code and output dir, volumes from output volumes
+docker_cmd = (
+    f'docker run -d --rm -it --name diff -e GITHUB_WORKSPACE {VOLUMES_FROM}'
+    f' {MOUNT_ARGS} dtcenter/metplus-envs:diff{VERSION_EXT} bash'
+)
+if not run_commands(docker_cmd):
+    sys.exit(1)
 
-# run inside diff env: mount METplus code and output dir, volumes from output volumes
-docker_cmd = (f'docker run -e GITHUB_WORKSPACE {VOLUMES_FROM} '
-              f'{mount_args} dtcenter/metplus-envs:diff{VERSION_EXT} '
-              f'bash -c "{cmd}"')
+# execute command to run difference tests in Docker container
+# do not run using run_commands function so GitHub Actions log grouping
+# can be used to put full diff output into a group so it is easier to
+# view the diff summary
+docker_cmd = f'docker exec -e GITHUB_WORKSPACE diff bash -cl "{diff_command}"'
 print(f'RUNNING: {docker_cmd}')
 try:
     process = subprocess.Popen(shlex.split(docker_cmd),
@@ -76,3 +87,7 @@
 except subprocess.CalledProcessError as err:
     print(f"ERROR: Command failed -- {err}")
     sys.exit(1)
+
+# force remove container to stop and remove it
+if not run_commands('docker rm -f diff'):
+    sys.exit(1)