Skip to content

Commit

Permalink
per #2377, added LOG_TO_TERMINAL_ONLY variable to force logging to sc…
Browse files Browse the repository at this point in the history
…reen instead of log files. Fixed bug where incorrect log file path is logged when a MET tool fails and LOG_MET_OUTPUT_TO_METPLUS is true
  • Loading branch information
georgemccabe committed Oct 27, 2023
1 parent e28e84d commit 7d51daf
Show file tree
Hide file tree
Showing 7 changed files with 73 additions and 73 deletions.
1 change: 1 addition & 0 deletions internal/tests/pytests/util/run_util/test_run_util.py
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@
'CONFIG_INPUT',
'RUN_ID',
'LOG_TIMESTAMP',
'LOG_TO_TERMINAL_ONLY',
'METPLUS_BASE',
'PARM_BASE',
'METPLUS_VERSION',
Expand Down
26 changes: 15 additions & 11 deletions metplus/util/config_metplus.py
Original file line number Diff line number Diff line change
Expand Up @@ -291,19 +291,23 @@ def _set_logvars(config):
# add LOG_TIMESTAMP to the final configuration file
config.set('config', 'LOG_TIMESTAMP', log_filenametimestamp)

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)
if config.getbool('config', 'LOG_TO_TERMINAL_ONLY'):
metplus_log = ''
else:
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 and os.path.basename(metplus_log) == metplus_log:
metplus_log = os.path.join(config.getdir('LOG_DIR'), metplus_log)

if not metplus_log:
print('Logging to terminal only')
else:
print('Logging to %s' % metplus_log)

# set LOG_METPLUS with timestamp substituted
config.set('config', 'LOG_METPLUS', metplus_log)
Expand Down
7 changes: 2 additions & 5 deletions metplus/util/run_util.py
Original file line number Diff line number Diff line change
@@ -1,18 +1,16 @@
import sys
import os
import shutil
import logging
from datetime import datetime

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
from .config_validate import validate_config_variables
from .. import get_metplus_version
from .config_metplus import setup
from . import camel_to_underscore, get_wrapper_instance
from . import get_wrapper_instance


def pre_run_setup(config_inputs):
Expand Down Expand Up @@ -63,8 +61,7 @@ def pre_run_setup(config_inputs):
f"generated in {sed_file}")

logger.error("Correct configuration variables and rerun. Exiting.")
logger.info("Check the log file for more information: "
f"{get_logfile_info(config)}")
logger.info(f"Check the log file for more information: {log_file}")
sys.exit(1)

if not config.getdir('MET_INSTALL_DIR', must_exist=True):
Expand Down
29 changes: 29 additions & 0 deletions metplus/util/string_manip.py
Original file line number Diff line number Diff line change
Expand Up @@ -570,13 +570,42 @@ def find_indices_in_config_section(regex, config, sec='config',
return indices


def get_log_path(config, logfile=None):
"""!Returns the location of where the command output will be sent.
The METplus log, the MET log, or tty.
@param config METplusConfig object to read
@param logfile 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 = config.getstr('config', 'LOG_METPLUS', '')
if not metplus_log:
return None

# return METplus log file if logging all output there
if config.getbool('config', 'LOG_MET_OUTPUT_TO_METPLUS') or logfile is None:
return metplus_log

log_path = os.path.join(config.getdir('LOG_DIR'), logfile)

# add log timestamp to log filename if set
log_timestamp = config.getstr('config', 'LOG_TIMESTAMP', '')
if log_timestamp:
log_path = f'{log_path}.{log_timestamp}'

return log_path


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
"""
if config.getbool('config', 'LOG_TO_TERMINAL_ONLY'):
return 'Set LOG_TO_TERMINAL_ONLY=False to write logs to a file'
log_file = config.getstr('config', 'LOG_METPLUS', '')
return log_file if log_file else 'Set LOG_METPLUS to write logs to a file'

Expand Down
19 changes: 9 additions & 10 deletions metplus/wrappers/command_builder.py
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,6 @@
"""

import os
import sys
import glob
from datetime import datetime
from abc import ABCMeta
Expand All @@ -31,7 +30,7 @@
from ..util import get_field_info, format_field_info
from ..util import get_wrapper_name, is_python_script
from ..util.met_config import add_met_config_dict, handle_climo_dict
from ..util import mkdir_p, get_skip_times
from ..util import mkdir_p, get_skip_times, get_log_path

# pylint:disable=pointless-string-statement
'''!@namespace CommandBuilder
Expand Down Expand Up @@ -1275,25 +1274,25 @@ def run_command(self, cmd, cmd_name=None):
if self.instance:
log_name = f"{log_name}.{self.instance}"

log_name = log_name if log_name else os.path.basename(cmd.split()[0])

# Determine where to send the output from the MET command.
log_path = get_log_path(self.config, logfile=log_name+'.log')

ret, out_cmd = self.cmdrunner.run_cmd(cmd,
env=self.env,
log_name=log_name,
log_path=log_path,
copyable_env=self.get_env_copy())
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:
if log_path is None:
return False

# 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}")
f"it failed: {log_path}")
return False

def run_all_times(self, custom=None):
Expand Down
63 changes: 16 additions & 47 deletions metplus/wrappers/command_runner.py
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@
import os
from produtil.run import exe, run
import shlex
from datetime import datetime, timezone
from datetime import datetime


class CommandRunner(object):
Expand All @@ -53,8 +53,7 @@ def __init__(self, config, logger=None, verbose=2, skip_run=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):
def run_cmd(self, cmd, env=None, log_path=None, copyable_env=None, **kwargs):
"""!The command cmd is a string which is converted to a produtil
exe Runner object and than run. Output of the command may also
be redirected to either METplus log, MET log, or TTY.
Expand All @@ -63,13 +62,13 @@ def run_cmd(self, cmd, env=None, log_name=None,
non MET commands ie. convert, in addition to MET binary commands,
ie. regrid_data_plane.
Args:
@param cmd: A string, Command used in the produtil exe Runner object.
@param env: Default None, environment for run to pass in, uses
os.environ if not set.
@param log_name: Used only when ismetcmd=True, The name of the exectable
being run.
@param kwargs Other options sent to the produtil Run constructor
@param cmd: A string, Command used in the produtil exe Runner object.
@param env: Default None, environment for run to pass in, uses
os.environ if not set.
@param log_path: Path to log file or None if logging to terminal
@param copyable_env string of commands that set environment variables
that can be copy/pasted by the user or None
@param kwargs Other options sent to the produtil Run constructor
"""
if cmd is None:
return cmd
Expand All @@ -84,11 +83,6 @@ def run_cmd(self, cmd, env=None, log_name=None,
self.logger.info("Not running command (DO_NOT_RUN_EXE = True)")
return 0, cmd

log_name = log_name if log_name else os.path.basename(cmd.split()[0])

# Determine where to send the output from the MET command.
log_dest = self.get_log_path(log_filename=log_name+'.log')

# determine if command must be run in a shell
run_inshell = '*' in cmd or ';' in cmd or '<' in cmd or '>' in cmd

Expand All @@ -105,14 +99,14 @@ def run_cmd(self, cmd, env=None, log_name=None,
# Split the command in to a sequence using shell syntax.
the_exe = shlex.split(cmd)[0]
the_args = shlex.split(cmd)[1:]
if log_dest:
self.logger.debug("Logging command output to: %s" % log_dest)
self.log_header_info(log_dest, copyable_env, cmd)
if log_path:
self.logger.debug("Logging command output to: %s" % log_path)
self.log_header_info(log_path, copyable_env, cmd)

if run_inshell:
cmd_exe = exe('sh')['-c', cmd].env(**env).err2out() >> log_dest
cmd_exe = exe('sh')['-c', cmd].env(**env).err2out() >> log_path
else:
cmd_exe = exe(the_exe)[the_args].env(**env).err2out() >> log_dest
cmd_exe = exe(the_exe)[the_args].env(**env).err2out() >> log_path
else:
if run_inshell:
cmd_exe = exe('sh')['-c', cmd].env(**env)
Expand All @@ -136,8 +130,8 @@ def run_cmd(self, cmd, env=None, log_name=None,

return ret, cmd

def log_header_info(self, log_dest, copyable_env, cmd):
with open(log_dest, 'a+') as log_file_handle:
def log_header_info(self, log_path, copyable_env, cmd):
with open(log_path, 'a+') as log_file_handle:
# if logging MET command to its own log file,
# add command that was run to that log
if not self.log_met_to_metplus:
Expand All @@ -154,28 +148,3 @@ 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")

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.
@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

# return METplus log file if logging all output there
if self.log_met_to_metplus:
return metplus_log

log_path = os.path.join(self.config.getdir('LOG_DIR'), log_filename)

# 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 log_path
1 change: 1 addition & 0 deletions parm/metplus_config/defaults.conf
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,7 @@ SCRUB_STAGING_DIR = True
# Log File Information (Where to write logs files) #
###############################################################################

LOG_TO_TERMINAL_ONLY = False

LOG_METPLUS = {LOG_DIR}/metplus.log.{LOG_TIMESTAMP}

Expand Down

0 comments on commit 7d51daf

Please sign in to comment.