diff --git a/.github/jobs/bash_functions.sh b/.github/jobs/bash_functions.sh index c018add863..e909ea4930 100755 --- a/.github/jobs/bash_functions.sh +++ b/.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 } diff --git a/.github/jobs/docker_utils.py b/.github/jobs/docker_utils.py index 4df2384b44..0e5c365f3f 100644 --- a/.github/jobs/docker_utils.py +++ b/.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 diff --git a/.github/jobs/get_data_volumes.py b/.github/jobs/get_data_volumes.py index b544609e52..5c568577a1 100755 --- a/.github/jobs/get_data_volumes.py +++ b/.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 diff --git a/.github/jobs/get_use_case_commands.py b/.github/jobs/get_use_case_commands.py index 1e28e2e8f6..f1cb2046fb 100755 --- a/.github/jobs/get_use_case_commands.py +++ b/.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") diff --git a/.github/jobs/setup_and_run_diff.py b/.github/jobs/setup_and_run_diff.py index 9b3725c901..b1318bcd5f 100755 --- a/.github/jobs/setup_and_run_diff.py +++ b/.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) diff --git a/.github/jobs/setup_and_run_use_cases.py b/.github/jobs/setup_and_run_use_cases.py index 00aa682092..4330a6a653 100755 --- a/.github/jobs/setup_and_run_use_cases.py +++ b/.github/jobs/setup_and_run_use_cases.py @@ -10,23 +10,31 @@ import os import sys -import subprocess -import shlex -import time import get_use_case_commands import get_data_volumes -from docker_utils import get_branch_name, VERSION_EXT +from docker_utils import get_branch_name, VERSION_EXT, run_commands -runner_workspace = os.environ.get('RUNNER_WORKSPACE') -github_workspace = os.environ.get('GITHUB_WORKSPACE') +RUNNER_WORKSPACE = os.environ.get('RUNNER_WORKSPACE') +GITHUB_WORKSPACE = os.environ.get('GITHUB_WORKSPACE') -repo_name =os.path.basename(runner_workspace) -ws_path = os.path.join(runner_workspace, repo_name) +REPO_NAME = os.path.basename(RUNNER_WORKSPACE) +WS_PATH = os.path.join(RUNNER_WORKSPACE, REPO_NAME) + +DOCKER_DATA_DIR = '/data' +DOCKER_OUTPUT_DIR = os.path.join(DOCKER_DATA_DIR, 'output') +GHA_OUTPUT_DIR = os.path.join(RUNNER_WORKSPACE, 'output') + +RUN_TAG = 'metplus-run-env' + +VOLUME_MOUNTS = [ + f"-v {RUNNER_WORKSPACE}/output/mysql:/var/lib/mysql", + f"-v {GHA_OUTPUT_DIR}:{DOCKER_OUTPUT_DIR}", + f"-v {WS_PATH}:{GITHUB_WORKSPACE}", +] + +DOCKERFILE_DIR = os.path.join('.github', 'actions', 'run_tests') -docker_data_dir = '/data' -docker_output_dir = os.path.join(docker_data_dir, 'output') -gha_output_dir = os.path.join(runner_workspace, 'output') def main(): categories, subset_list, _ = ( @@ -48,105 +56,133 @@ def main(): if os.environ.get('GITHUB_EVENT_NAME') == 'pull_request': branch_name = f"{branch_name}-pull_request" - run_tag = 'metplus-run-env' - dockerfile_dir = os.path.join('.github', 'actions', 'run_tests') - # use BuildKit to build image os.environ['DOCKER_BUILDKIT'] = '1' - volume_mounts = [ - f"-v {runner_workspace}/output/mysql:/var/lib/mysql", - f"-v {gha_output_dir}:{docker_output_dir}", - f"-v {ws_path}:{github_workspace}", - ] - isOK = True - for cmd, requirements in all_commands: - + failed_use_cases = [] + for setup_commands, use_case_commands, requirements in all_commands: # get environment image tag - use_env = [item for item in requirements if item.endswith('_env')] - if use_env: - env_tag = use_env[0].replace('_env', '') - else: - env_tag = 'metplus_base' - - env_tag = f'{env_tag}{VERSION_EXT}' + env_tag = _get_metplus_env_tag(requirements) # get Dockerfile to use - dockerfile_name = 'Dockerfile.run' - if 'gempak' in str(requirements).lower(): - dockerfile_name = f'{dockerfile_name}_gempak' - elif 'gfdl' in str(requirements).lower(): - dockerfile_name = f'{dockerfile_name}_gfdl' - elif 'cartopy' in str(requirements).lower(): - dockerfile_name = f'{dockerfile_name}_cartopy' + dockerfile_name = _get_dockerfile_name(requirements) docker_build_cmd = ( - f"docker build -t {run_tag} " + f"docker build -t {RUN_TAG} " f"--build-arg METPLUS_IMG_TAG={branch_name} " f"--build-arg METPLUS_ENV_TAG={env_tag} " - f"-f {dockerfile_dir}/{dockerfile_name} ." + f"-f {DOCKERFILE_DIR}/{dockerfile_name} ." ) - print(f"Building Docker environment/branch image...\n" - f"Running: {docker_build_cmd}") - start_time = time.time() - try: - subprocess.run(shlex.split(docker_build_cmd), check=True) - except subprocess.CalledProcessError as err: - print(f"ERROR: Docker Build failed: {docker_build_cmd} -- {err}") + + print(f'Building Docker environment/branch image...') + if not run_commands(docker_build_cmd): isOK = False continue - end_time = time.time() - print("TIMING: Command took " - f"{time.strftime('%M:%S', time.gmtime(end_time - start_time))}" - f" (MM:SS): '{docker_build_cmd}')") - - cmd_args = {'check': True, - 'encoding': 'utf-8', - 'capture_output': True, - } - output = subprocess.run(shlex.split('docker ps -a'), - **cmd_args).stdout.strip() - print(f"docker ps -a\n{output}") - - full_cmd = ( - f"docker run -e GITHUB_WORKSPACE " + commands = [] + + # print list of existing docker images + commands.append('docker images') + + # start interactive container in the background + commands.append( + f"docker run -d --rm -it -e GITHUB_WORKSPACE " + f"--name {RUN_TAG} " f"{os.environ.get('NETWORK_ARG', '')} " - f"{' '.join(volume_mounts)} " - f"{volumes_from} --workdir {github_workspace} " - f'{run_tag} bash -c "{cmd}"') - print(f"RUNNING: {full_cmd}") - start_time = time.time() - try: - process = subprocess.Popen(shlex.split(full_cmd), - 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, full_cmd) - - except subprocess.CalledProcessError as err: - print(f"ERROR: Command failed -- {err}") + f"{' '.join(VOLUME_MOUNTS)} " + f"{volumes_from} --workdir {GITHUB_WORKSPACE} " + f'{RUN_TAG} bash' + ) + + # list running containers + commands.append('docker ps -a') + + # execute setup commands in running docker container + commands.append(_format_docker_exec_command(setup_commands)) + + # run docker commands and skip running cases if something went wrong + if not run_commands(commands): + isOK = False + + # force remove container if setup step fails + run_commands(f'docker rm -f {RUN_TAG}') + + # add all use cases that couldn't run to list of failed cases + failed_use_cases.extend(use_case_commands) + + continue + + # execute use cases in running docker container + # save list of use cases that failed + for use_case_command in use_case_commands: + if not run_commands(_format_docker_exec_command(use_case_command)): + failed_use_cases.append(use_case_command) + isOK = False + + # print bashrc file to see what was added by setup commands + # then force remove container to stop and remove it + if not run_commands([ + _format_docker_exec_command('cat /etc/bashrc'), + f'docker rm -f {RUN_TAG}', + ]): isOK = False - end_time = time.time() - print("TIMING: Command took " - f"{time.strftime('%M:%S', time.gmtime(end_time - start_time))}" - f" (MM:SS): '{full_cmd}')") + # print summary of use cases that failed + for failed_use_case in failed_use_cases: + print(f'ERROR: Use case failed: {failed_use_case}') if not isOK: print("ERROR: Some commands failed.") sys.exit(1) + +def _format_docker_exec_command(command): + """! Get docker exec command to call given command in a bash login shell + + @param command string of command to run in docker + @returns string of docker exec command to run command + """ + return f'docker exec -e GITHUB_WORKSPACE {RUN_TAG} bash -cl "{command}"' + + +def _get_metplus_env_tag(requirements): + """!Parse use case requirements to get Docker tag to obtain conda + environment to use in tests. Append version extension e.g. .v5 + + @param requirements list of use case requirements + @returns string of Docker tag + """ + use_env = [item for item in requirements if item.endswith('_env')] + if use_env: + env_tag = use_env[0].replace('_env', '') + else: + env_tag = 'metplus_base' + + return f'{env_tag}{VERSION_EXT}' + + +def _get_dockerfile_name(requirements): + """!Parse use case requirements to get name of Dockerfile to use to build + environment to use in tests. Dockerfile.run copies conda directories into + test image. Other Dockerfiles copy additional files needed to run certain + use cases. For example, cartopy uses shape files that occasionally cannot + be downloaded on the fly, so they are downloaded in advance and copied + into the test image. GEMPAK requires JavaRE. GFDL Tracker requires + NetCDF libraries and tracker executable. + + @param requirements list of use case requirements + @returns string of Dockerfile to use to create test environment + """ + dockerfile_name = 'Dockerfile.run' + if 'gempak' in str(requirements).lower(): + return f'{dockerfile_name}_gempak' + if 'gfdl' in str(requirements).lower(): + return f'{dockerfile_name}_gfdl' + if 'cartopy' in str(requirements).lower(): + return f'{dockerfile_name}_cartopy' + return dockerfile_name + + if __name__ == '__main__': main() diff --git a/.github/parm/test_settings.conf b/.github/parm/test_settings.conf index 9927f8f7e1..5e211e806f 100644 --- a/.github/parm/test_settings.conf +++ b/.github/parm/test_settings.conf @@ -1,5 +1,6 @@ [config] LOG_LEVEL = DEBUG +LOG_LEVEL_TERMINAL = INFO LOG_MET_OUTPUT_TO_METPLUS = no LOG_LINE_FORMAT = (%(filename)s) %(levelname)s: %(message)s LOG_ERR_LINE_FORMAT = {LOG_LINE_FORMAT} diff --git a/docs/Users_Guide/configuration.rst b/docs/Users_Guide/configuration.rst index 507f67b7b4..071292ad7e 100644 --- a/docs/Users_Guide/configuration.rst +++ b/docs/Users_Guide/configuration.rst @@ -266,6 +266,8 @@ Log File Information Where to write logs files +.. _log_metplus: + LOG_METPLUS """"""""""" @@ -348,9 +350,10 @@ How much information to log LOG_LEVEL """"""""" -This controls the level of logging output from the METplus wrappers. It does -not control the logging level of the actual MET applications. The possible -values to: +This controls the level of logging output from the METplus wrappers that is +written to the log file defined by :ref:`log_metplus`. +It does not control the logging level of the actual MET applications. +The possible values to: * CRITICAL * ERROR @@ -371,6 +374,14 @@ If a use case is producing errors, then setting:: will produce additional logging output that is helpful to discover the cause of the error. +.. _log_level_terminal: + +LOG_LEVEL_TERMINAL +"""""""""""""""""" + +This controls the level of logging that is output to the screen. +The valid values are the same as :ref:`log_level`. + LOG_MET_VERBOSITY """"""""""""""""" diff --git a/docs/Users_Guide/glossary.rst b/docs/Users_Guide/glossary.rst index 58a81365c1..d4ebf18ae6 100644 --- a/docs/Users_Guide/glossary.rst +++ b/docs/Users_Guide/glossary.rst @@ -2361,15 +2361,20 @@ METplus Configuration Glossary | *Used by:* All LOG_LEVEL - Specify the level of logging. Everything above this level is sent to standard output. To quiet the output to a comfortable level, set this to "ERROR" - - Options (ordered MOST verbose to LEAST verbose): - | NOTSET - | DEBUG - | INFO - | WARNING - | ERROR - | CRITICAL + Specify the level of logging for the METplus wrapper output to the + :term:`LOG_METPLUS` log file. Log level of the applications that are + called by the wrappers are controlled with :term:`LOG_MET_VERBOSITY`. + Default log level is INFO. Set to DEBUG to see additional log output. + Log level for screen output can be set with :term:`LOG_LEVEL_TERMINAL`. + + Options (ordered LEAST verbose to MOST verbose): + CRITICAL, ERROR, WARNING, INFO, DEBUG, NOTSET + + | *Used by:* All + + LOG_LEVEL_TERMINAL + Specify the level of logging for terminal screen output. + See :term:`LOG_LEVEL` for more information. | *Used by:* All diff --git a/internal/tests/pytests/minimum_pytest.conf b/internal/tests/pytests/minimum_pytest.conf index 9982acc1a4..ae6183fe5e 100644 --- a/internal/tests/pytests/minimum_pytest.conf +++ b/internal/tests/pytests/minimum_pytest.conf @@ -5,6 +5,7 @@ MET_INSTALL_DIR = {ENV[METPLUS_TEST_MET_INSTALL_DIR]} TMP_DIR = {ENV[METPLUS_TEST_TMP_DIR]} LOG_LEVEL = DEBUG +LOG_LEVEL_TERMINAL = WARNING LOG_MET_OUTPUT_TO_METPLUS = no LOG_LINE_FORMAT = (%(filename)s) %(levelname)s: %(message)s LOG_ERR_LINE_FORMAT = {LOG_LINE_FORMAT} diff --git a/metplus/util/config_metplus.py b/metplus/util/config_metplus.py index b1f8431c28..e3a2dd7ead 100644 --- a/metplus/util/config_metplus.py +++ b/metplus/util/config_metplus.py @@ -85,30 +85,25 @@ logging.Formatter.converter = time.gmtime -def setup(args, logger=None, base_confs=None): - """!The METplus setup function. - @param args list of configuration files or configuration - variable overrides. Reads all configuration inputs and returns - a configuration object. +def setup(args, base_confs=None): + """!Setup the METplusConfig by reading in default configurations and any + arguments from the command line. + + @param args list of configuration files or configuration + variable overrides. Reads all configuration inputs and returns + a configuration object + @param base_confs optional config files to read first + @returns METplusConfig object """ if base_confs is None: base_confs = _get_default_config_list() - # Setup Task logger, Until a Conf object is created, Task logger is - # only logging to tty, not a file. - if logger is None: - logger = logging.getLogger('metplus') - - logger.info('Starting METplus configuration setup.') - - override_list = _parse_launch_args(args, logger) + override_list = _parse_launch_args(args) # add default config files to override list override_list = base_confs + override_list config = launch(override_list) - logger.debug('Completed METplus configuration setup.') - return config @@ -142,7 +137,7 @@ def _get_default_config_list(parm_base=None): return default_config_list -def _parse_launch_args(args, logger): +def _parse_launch_args(args): """! Parsed arguments to scripts that launch the METplus wrappers. Options: @@ -150,7 +145,6 @@ def _parse_launch_args(args, logger): * /path/to/file.conf --- read this conf file after the default conf files @param args the script arguments, after script-specific ones are removed - @param logger a logging.Logger for log messages @returns tuple containing path to parm directory, list of config files and collections.defaultdict of explicit config overrides """ @@ -180,7 +174,7 @@ def _parse_launch_args(args, logger): filepath = arg # check if argument is a path to a file that exists if not os.path.exists(filepath): - logger.error(f'Invalid argument: {filepath}') + print(f'ERROR: Invalid argument: {filepath}') bad = True continue @@ -189,13 +183,13 @@ def _parse_launch_args(args, logger): # path exists but is not a file if not os.path.isfile(filepath): - logger.error(f'Conf is not a file: {filepath}') + print(f'ERROR: Conf is not a file: {filepath}') bad = True continue # warn and skip if file is empty if os.stat(filepath).st_size == 0: - logger.warning(f'Conf file is empty: {filepath}. Skipping') + print(f'WARNING: Conf file is empty: {filepath}. Skipping') continue # add file path to override list @@ -217,7 +211,6 @@ def launch(config_list): @param config_list list of configuration files to process """ config = METplusConfig() - logger = config.log() # set config variable for current time config.set('config', 'CLOCK_TIME', @@ -227,7 +220,7 @@ def launch(config_list): # Read in and parse all the conf files and overrides for config_item in config_list: if isinstance(config_item, str): - logger.info(f"Parsing config file: {config_item}") + print(f"Parsing config file: {config_item}") config.read(config_item) config_format_list.append(config_item) else: @@ -236,7 +229,7 @@ def launch(config_list): if not config.has_section(section): config.add_section(section) - logger.info(f"Parsing override: [{section}] {key} = {value}") + print(f"Parsing override: [{section}] {key} = {value}") config.set(section, key, value) config_format_list.append(f'{section}.{key}={value}') @@ -274,20 +267,15 @@ def launch(config_list): return config -def _set_logvars(config, logger=None): +def _set_logvars(config): """!Sets and adds the LOG_METPLUS and LOG_TIMESTAMP to the config object. If LOG_METPLUS was already defined by the user in their conf file. It expands and rewrites it in the conf object and the final file. conf file. - Args: + @param config: the config instance - @param logger: the logger, optional """ - - if logger is None: - logger = config.log() - log_timestamp_template = config.getstr('config', 'LOG_TIMESTAMP_TEMPLATE', '') if config.getbool('config', 'LOG_TIMESTAMP_USE_DATATIME', False): @@ -300,95 +288,69 @@ def _set_logvars(config, logger=None): log_filenametimestamp = date_t.strftime(log_timestamp_template) - # Adding LOG_TIMESTAMP to the final configuration file. - logger.info('Adding LOG_TIMESTAMP=%s' % repr(log_filenametimestamp)) + # add LOG_TIMESTAMP to the final configuration file config.set('config', 'LOG_TIMESTAMP', log_filenametimestamp) - log_dir = config.getdir('LOG_DIR') - - # NOTE: LOG_METPLUS or metpluslog is meant to include the absolute path - # and the metpluslog_filename, - # so metpluslog = /path/to/metpluslog_filename - - # if LOG_METPLUS = unset in the conf file, means NO logging. - # Also, assUmes the user has included the intended path in LOG_METPLUS. - user_defined_log_file = None - metpluslog = '' - if config.has_option('config', 'LOG_METPLUS'): - user_defined_log_file = True - # strinterp will set metpluslog to '' if LOG_METPLUS = is unset. - metpluslog = config.strinterp( - 'config', - '{LOG_METPLUS}', - LOG_TIMESTAMP_TEMPLATE=log_filenametimestamp - ) - - # test if there is any path information, if there is, - # assume it is as intended, if there is not, than add log_dir. - if metpluslog: - if os.path.basename(metpluslog) == metpluslog: - metpluslog = os.path.join(log_dir, metpluslog) - - # Setting LOG_METPLUS in the configuration object - # At this point LOG_METPLUS will have a value or '' the empty string. - if user_defined_log_file: - logger.info('Replace LOG_METPLUS with %s' % repr(metpluslog)) + metplus_log = config.strinterp( + 'config', + '{LOG_METPLUS}', + LOG_TIMESTAMP_TEMPLATE=log_filenametimestamp + ) + + # add log directory to log file path if only filename was provided + if metplus_log: + if os.path.basename(metplus_log) == metplus_log: + metplus_log = os.path.join(config.getdir('LOG_DIR'), metplus_log) + print('Logging to %s' % metplus_log) else: - logger.info('Adding LOG_METPLUS=%s' % repr(metpluslog)) - # expand LOG_METPLUS to ensure it is available - config.set('config', 'LOG_METPLUS', metpluslog) + print('Logging to terminal only') + # set LOG_METPLUS with timestamp substituted + config.set('config', 'LOG_METPLUS', metplus_log) -def get_logger(config, sublog=None): + +def get_logger(config): """!This function will return a logger with a formatted file handler for writing to the LOG_METPLUS and it sets the LOG_LEVEL. If LOG_METPLUS is not defined, a logger is still returned without adding a file handler, but still setting the LOG_LEVEL. - Args: - @param config: the config instance - @param sublog the logging subdomain, or None - Returns: - logger: the logger + + @param config: the config instance + @returns logger """ _set_logvars(config) # Retrieve all logging related parameters from the param file - log_dir = config.getdir('LOG_DIR') log_level = config.getstr('config', 'LOG_LEVEL') + log_level_terminal = config.getstr('config', 'LOG_LEVEL_TERMINAL') # Create the log directory if it does not exist - mkdir_p(log_dir) + mkdir_p(config.getdir('LOG_DIR')) + + logger = config.log() - if sublog is not None: - logger = config.log(sublog) - else: - logger = config.log() - - # Setting of the logger level from the config instance. - # Check for log_level by Integer or LevelName. - # Try to convert the string log_level to an integer and use that, if - # it can't convert then we assume it is a valid LevelName, which - # is what is should be anyway, ie. DEBUG. - # Note: - # Earlier versions of python2 require setLevel(), argument - # to be an int. Passing in the LevelName, 'DEBUG' will disable - # logging output. Later versions of python2 will accept 'DEBUG', - # not sure which version that changed with, but the logic below - # should work for all version. I know python 2.6.6 must be an int, - # and python 2.7.5 accepts the LevelName. try: - int_log_level = int(log_level) - logger.setLevel(int_log_level) + log_level_val = logging.getLevelName(log_level) except ValueError: - logger.setLevel(logging.getLevelName(log_level)) + print(f'ERROR: Invalid value set for LOG_LEVEL: {log_level}') + sys.exit(1) + + try: + log_level_terminal_val = logging.getLevelName(log_level_terminal) + except ValueError: + print('ERROR: Invalid value set for LOG_LEVEL_TERMINAL:' + f' {log_level_terminal}') + sys.exit(1) metpluslog = config.getstr('config', 'LOG_METPLUS', '') + if not metpluslog: + logger.setLevel(log_level_terminal_val) + else: + # set logger level to the minimum of the two log levels because + # setting level for each handler will not work otherwise + logger.setLevel(min(log_level_val, log_level_terminal_val)) - if metpluslog: - # It is possible that more path, other than just LOG_DIR, was added - # to the metpluslog, by either a user defining more path in - # LOG_METPLUS or LOG_FILENAME_TEMPLATE definitions in their conf file. - # So lets check and make more directory if needed. + # create log directory if it does not already exist dir_name = os.path.dirname(metpluslog) if not os.path.exists(dir_name): mkdir_p(dir_name) @@ -402,14 +364,15 @@ def get_logger(config, sublog=None): # set up the file logging file_handler = logging.FileHandler(metpluslog, mode='a') file_handler.setFormatter(formatter) + file_handler.setLevel(log_level_val) logger.addHandler(file_handler) # set up console logging stream_handler = logging.StreamHandler() stream_handler.setFormatter(formatter) + stream_handler.setLevel(log_level_terminal_val) logger.addHandler(stream_handler) - # set add the logger to the config config.logger = logger return logger diff --git a/metplus/util/diff_util.py b/metplus/util/diff_util.py index 15eaeee787..611732ab9b 100644 --- a/metplus/util/diff_util.py +++ b/metplus/util/diff_util.py @@ -71,6 +71,7 @@ def get_file_type(filepath): def compare_dir(dir_a, dir_b, debug=False, save_diff=False): + print('::group::Full diff results:') # if input are files and not directories, compare them if os.path.isfile(dir_a): result = compare_files(dir_a, dir_b, debug=debug, save_diff=save_diff) @@ -136,6 +137,7 @@ def compare_dir(dir_a, dir_b, debug=False, save_diff=False): print(f"ERROR: File does not exist: {filepath_a}") diff_files.append(('', filepath_b, 'file not found (new output)', '')) + print('::endgroup::') print("\n\n**************************************************\nSummary:\n") if diff_files: print("\nERROR: Some differences were found") diff --git a/metplus/util/run_util.py b/metplus/util/run_util.py index 3298e5fdac..e201392f42 100644 --- a/metplus/util/run_util.py +++ b/metplus/util/run_util.py @@ -1,10 +1,12 @@ import sys import os import shutil +import logging from datetime import datetime from importlib import import_module from .constants import NO_COMMAND_WRAPPERS +from .string_manip import get_logfile_info, log_terminal_includes_info from .system_util import get_user_info, write_list_to_file from .config_util import get_process_list, handle_env_var_config from .config_util import handle_tmp_dir, write_final_conf, write_all_commands @@ -28,10 +30,18 @@ def pre_run_setup(config_inputs): user_string = f' as user {user_info} ' if user_info else ' ' config.set('config', 'METPLUS_VERSION', version_number) - logger.info('Running METplus v%s%swith command: %s', - version_number, user_string, ' '.join(sys.argv)) + running_log = (f"Running METplus v{version_number}{user_string}with " + f"command: {' '.join(sys.argv)}") + logger.info(running_log) - logger.info(f"Log file: {config.getstr('config', 'LOG_METPLUS')}") + # print running message if terminal log does not include INFO + if not log_terminal_includes_info(config): + print(running_log) + + # if log file is not set, log message instructing user how to set it + log_file = get_logfile_info(config) + + logger.info(f"Log file: {log_file}") logger.info(f"METplus Base: {config.getdir('METPLUS_BASE')}") logger.info(f"Final Conf: {config.getstr('config', 'METPLUS_CONF')}") config_list = config.getstr('config', 'CONFIG_INPUT').split(',') @@ -55,7 +65,7 @@ def pre_run_setup(config_inputs): logger.error("Correct configuration variables and rerun. Exiting.") logger.info("Check the log file for more information: " - f"{config.getstr('config', 'LOG_METPLUS')}") + f"{get_logfile_info(config)}") sys.exit(1) if not config.getdir('MET_INSTALL_DIR', must_exist=True): @@ -157,7 +167,7 @@ def run_metplus(config): except: logger.exception("Fatal error occurred") logger.info("Check the log file for more information: " - f"{config.getstr('config', 'LOG_METPLUS')}") + f"{get_logfile_info(config)}") return 1 @@ -174,7 +184,7 @@ def post_run_cleanup(config, app_name, total_errors): # save log file path and clock time before writing final conf file log_message = (f"Check the log file for more information: " - f"{config.getstr('config', 'LOG_METPLUS')}") + f"{get_logfile_info(config)}") start_clock_time = datetime.strptime(config.getstr('config', 'CLOCK_TIME'), '%Y%m%d%H%M%S') @@ -185,14 +195,19 @@ def post_run_cleanup(config, app_name, total_errors): # compute time it took to run end_clock_time = datetime.now() total_run_time = end_clock_time - start_clock_time - logger.debug(f"{app_name} took {total_run_time} to run.") + logger.info(f"{app_name} took {total_run_time} to run.") user_info = get_user_info() user_string = f' as user {user_info}' if user_info else '' if not total_errors: logger.info(log_message) - logger.info('%s has successfully finished running%s.', - app_name, user_string) + success_log = (f'{app_name} has successfully ' + f'finished running{user_string}.') + logger.info(success_log) + + # print success log message if terminal does not include INFO + if not log_terminal_includes_info(config): + print(success_log) return error_msg = (f'{app_name} has finished running{user_string} ' diff --git a/metplus/util/string_manip.py b/metplus/util/string_manip.py index 07f4610c81..3ddc53e02d 100644 --- a/metplus/util/string_manip.py +++ b/metplus/util/string_manip.py @@ -10,6 +10,7 @@ from csv import reader import random import string +import logging try: from .constants import VALID_COMPARISONS, LOWER_TO_WRAPPER_NAME @@ -560,3 +561,29 @@ def find_indices_in_config_section(regex, config, sec='config', indices[index].append(identifier) return indices + + +def get_logfile_info(config): + """!Get path to log file from LOG_METPLUS config variable or return a + useful message if it is not set to instruct users how to set it. + + @param config METplusConfig object to read LOG_METPLUS from + @returns path to log file or message if unset + """ + log_file = config.getstr('config', 'LOG_METPLUS', '') + return log_file if log_file else 'Set LOG_METPLUS to write logs to a file' + + +def log_terminal_includes_info(config): + """!Check LOG_LEVEL_TERMINAL to see if it is set to a logging level that + includes INFO output. Check [runtime] section if not found in [config] + because the variable is moved at the end of the run. + + @param config METplusConfig object to query + @returns True if log level is set to include INFO messages. False if not. + """ + log_terminal_level = logging.getLevelName( + config.getstr('config', 'LOG_LEVEL_TERMINAL', + config.getstr('runtime', 'LOG_LEVEL_TERMINAL')) + ) + return log_terminal_level <= logging.INFO diff --git a/metplus/wrappers/command_builder.py b/metplus/wrappers/command_builder.py index b25c0e2f77..4a9ba4131d 100755 --- a/metplus/wrappers/command_builder.py +++ b/metplus/wrappers/command_builder.py @@ -241,15 +241,8 @@ def set_environment_variables(self, time_info=None): # set user defined environment variables self.set_user_environment(time_info) - # send environment variables to logger - for msg in self.print_all_envs(print_each_item=True, - print_copyable=False): - self.logger.info(msg) - - # log environment variables that can be copied into terminal - # to rerun application if debug logging is turned on - for msg in self.print_all_envs(print_each_item=False, - print_copyable=True): + # send environment variables and copyable commands to logger + for msg in self.print_all_envs(): self.logger.debug(msg) def log_error(self, error_string): @@ -1228,6 +1221,7 @@ def run_command(self, cmd, cmd_name=None): list of all commands run. @param cmd command to run + @param cmd_name optional command name to use in the log filename @returns True on success, False otherwise """ # add command to list of all commands run @@ -1243,20 +1237,22 @@ def run_command(self, cmd, cmd_name=None): env=self.env, log_name=log_name, copyable_env=self.get_env_copy()) - if ret: - logfile_path = self.config.getstr('config', 'LOG_METPLUS') - # if MET output is written to its own logfile, get that filename - if not self.config.getbool('config', 'LOG_MET_OUTPUT_TO_METPLUS'): - logfile_path = logfile_path.replace('run_metplus', - log_name) - - self.log_error("MET command returned a non-zero return code:" - f"{cmd}") - self.logger.info("Check the logfile for more information on why " - f"it failed: {logfile_path}") + if not ret: + return True + + self.log_error(f"Command returned a non-zero return code: {cmd}") + + logfile_path = self.config.getstr('config', 'LOG_METPLUS') + if not logfile_path: return False - return True + # if MET output is written to its own logfile, get that filename + if not self.config.getbool('config', 'LOG_MET_OUTPUT_TO_METPLUS'): + logfile_path = logfile_path.replace('run_metplus', log_name) + + self.logger.info("Check the logfile for more information on why " + f"it failed: {logfile_path}") + return False def run_all_times(self, custom=None): """! Loop over time range specified in conf file and diff --git a/metplus/wrappers/command_runner.py b/metplus/wrappers/command_runner.py index e6e783a975..1332e911a4 100755 --- a/metplus/wrappers/command_runner.py +++ b/metplus/wrappers/command_runner.py @@ -49,7 +49,8 @@ def __init__(self, config, logger=None, verbose=2, skip_run=False): self.config = config self.verbose = verbose self.skip_run = skip_run - self.log_command_to_met_log = False + self.log_met_to_metplus = config.getbool('config', + 'LOG_MET_OUTPUT_TO_METPLUS') def run_cmd(self, cmd, env=None, log_name=None, copyable_env=None, **kwargs): @@ -69,7 +70,6 @@ def run_cmd(self, cmd, env=None, log_name=None, being run. @param kwargs Other options sent to the produtil Run constructor """ - if cmd is None: return cmd @@ -98,12 +98,12 @@ def run_cmd(self, cmd, env=None, log_name=None, ' contructor: %s, ' % repr(self)) # Determine where to send the output from the MET command. - log_dest = self.cmdlog_destination(cmdlog=log_name+'.log') + log_dest = self.get_log_path(log_filename=log_name+'.log') # determine if command must be run in a shell run_inshell = False if '*' in cmd or ';' in cmd or '<' in cmd or '>' in cmd: - run_inshell=True + run_inshell = True # KEEP This comment as a reference note. # Run the executable in a new process instead of through a shell. @@ -119,8 +119,7 @@ def run_cmd(self, cmd, env=None, log_name=None, the_exe = shlex.split(cmd)[0] the_args = shlex.split(cmd)[1:] if log_dest: - self.logger.debug("log_name is: %s, output sent to: %s" % (log_name, log_dest)) - + self.logger.debug("Logging command output to: %s" % log_dest) self.log_header_info(log_dest, copyable_env, cmd) if run_inshell: @@ -145,16 +144,18 @@ def run_cmd(self, cmd, env=None, log_name=None, # calculate time to run end_cmd_time = datetime.now() total_cmd_time = end_cmd_time - start_cmd_time - self.logger.debug(f'Finished running {the_exe} ' - f'in {total_cmd_time}') + self.logger.info(f'Finished running {the_exe} ' + f'- took {total_cmd_time}') return ret, cmd def log_header_info(self, log_dest, copyable_env, cmd): with open(log_dest, 'a+') as log_file_handle: - # if logging MET command to its own log file, add command that was run to that log - if self.log_command_to_met_log: - # if environment variables were set and available, write them to MET tool log + # if logging MET command to its own log file, + # add command that was run to that log + if not self.log_met_to_metplus: + # if environment variables were set and available, + # write them to MET tool log if copyable_env: log_file_handle.write( "\nCOPYABLE ENVIRONMENT FOR NEXT COMMAND:\n") @@ -167,93 +168,27 @@ def log_header_info(self, log_dest, copyable_env, cmd): # write line to designate where MET tool output starts log_file_handle.write("OUTPUT:\n") - # if cmdlog=None. The returned value is either the METplus log - # or None - def cmdlog_destination(self, cmdlog=None): + def get_log_path(self, log_filename): """!Returns the location of where the command output will be sent. The METplus log, the MET log, or tty. - Args: - @param cmdlog: The cmdlog is a filename, any path info is removed. - It is joined with LOG_DIR. If cmdlog is None, - output is sent to either the METplus log or TTY. - @returns log_dest: The destination of where to send the command output. - """ - - # Check the cmdlog argument. - # ie. if cmdlog = '', or '/', or trailing slash /path/blah.log/ etc..., - # os.path.basename returns '', and we can't write to '', - # so set cmdlog to None. - if cmdlog: - cmdlog = os.path.basename(cmdlog) - if not cmdlog: cmdlog = None - # Set the default destination to None, which will be TTY - cmdlog_dest = None - - # metpluslog is the setting used to determine if output is sent to either - # a log file or tty. - # metpluslog includes /path/filename. - metpluslog = self.config.getstr('config', 'LOG_METPLUS', '') - - self.log_command_to_met_log = False - - # This block determines where to send the command output, cmdlog_dest. - # To the METplus log, a MET log, or tty. - # If no metpluslog, cmlog_dest is None, which should be interpreted as tty. - if metpluslog: - log_met_output_to_metplus = self.config.getbool('config', - 'LOG_MET_OUTPUT_TO_METPLUS') - # If cmdlog is None send output to metpluslog. - if log_met_output_to_metplus or not cmdlog: - cmdlog_dest = metpluslog - else: - self.log_command_to_met_log = True - log_timestamp = self.config.getstr('config', 'LOG_TIMESTAMP', '') - if log_timestamp: - cmdlog_dest = os.path.join(self.config.getdir('LOG_DIR'), - cmdlog + '.' + log_timestamp) - else: - cmdlog_dest = os.path.join(self.config.getdir('LOG_DIR'),cmdlog) - - - # If cmdlog_dest None we will not redirect output to a log file - # when building the Runner object, so it will end up going to tty. - return cmdlog_dest - - # This method SHOULD ONLY BE USED by wrappers that build their cmd - # outside of the command_builder.py get_command() method - # ie. such as tc_pairs wrapper. Objects that fully use the CommandBuilder - # already have the metverbosity set in the command. - def insert_metverbosity_opt(self,cmd=None): - """!Returns the cmd with the verbosity option inserted - and set after the first space found in the cmd string or - after the cmd string if there are no spaces. - - There is NO CHECKING to see if the verbosity is already - inserted in the command. If cmd is None, None is returned. - - Args: - @param cmd: One string, The cmd string to insert the -v option. - @returns cmd: The cmd string w/ -v inserted - after the first white space or end if no - spaces. If cmd is None, None is returned. + @param log_filename file name to use if logging to a separate file + @returns Log file path or None if logging to terminal """ + # if LOG_METPLUS is unset or empty, log to terminal + metplus_log = self.config.getstr('config', 'LOG_METPLUS', '') + if not metplus_log: + return None - if cmd: + # return METplus log file if logging all output there + if self.log_met_to_metplus: + return metplus_log - verbose_opt = " -v "+str(self.verbose) + " " - # None splits on whitespace space, tab, newline, return, formfeed - cmd_split = cmd.split(None, 1) + log_path = os.path.join(self.config.getdir('LOG_DIR'), log_filename) - # Handle two cases of splitting. - # /path/to/cmd - # /path/to/cmd blah blah blah .... - if len(cmd_split) == 1: - cmd = cmd_split[0] + verbose_opt - elif len(cmd_split) == 2: - cmd = cmd_split[0] + verbose_opt + cmd_split[1] - else: - self.logger.debug('Can not Insert MET verbosity option, ' - 'command unchanged, using: %s .' % repr(cmd)) + # add log timestamp to log filename if set + log_timestamp = self.config.getstr('config', 'LOG_TIMESTAMP', '') + if log_timestamp: + log_path = f'{log_path}.{log_timestamp}' - return cmd + return log_path diff --git a/parm/metplus_config/defaults.conf b/parm/metplus_config/defaults.conf index c1e340545a..850eb68434 100644 --- a/parm/metplus_config/defaults.conf +++ b/parm/metplus_config/defaults.conf @@ -97,6 +97,8 @@ LOG_MET_OUTPUT_TO_METPLUS = yes LOG_LEVEL = INFO +LOG_LEVEL_TERMINAL = INFO + LOG_MET_VERBOSITY = 2 diff --git a/ush/run_metplus.py b/ush/run_metplus.py index 1971c2f0e9..66dbb038a2 100755 --- a/ush/run_metplus.py +++ b/ush/run_metplus.py @@ -81,10 +81,6 @@ def get_config_inputs_from_command_line(): invalid flag was provided, i.e. -a. @returns list of config inputs """ - - # output version that is run to screen - print('Running METplus %s' % metplus_version) - # if not arguments were provided, print usage and exit if len(sys.argv) < 2: usage()