def main_runner(argv, parser, exe_runner_func,
level=logging.DEBUG, str_formatter=_LOG_FORMAT):
"""
Fundamental interface to commandline applications
"""
dep_msg = "The `pbservice` commandline is deprecated and will be removed " \
"in a future version. Please using the scala implementation in smrtflow " \
"at https://github.com/PacificBiosciences/smrtflow"
started_at = time.time()
args = parser.parse_args(argv)
level = get_parsed_args_log_level(args, default_level=level)
console_or_file = args.log_file
setup_logger(console_or_file, level, formatter=str_formatter)
warnings.warn(dep_msg, DeprecationWarning)
log.warn(dep_msg)
log.debug(args)
log.info("Starting tool version {v}".format(v=parser.version))
rcode = exe_runner_func(args)
run_time = time.time() - started_at
_d = dict(r=rcode, s=run_time)
log.info("exiting with return code {r} in {s:.2f} sec.".format(**_d))
return rcode
def main_runner(argv, parser, exe_runner_func,
level=logging.DEBUG, str_formatter=_LOG_FORMAT):
"""
Fundamental interface to commandline applications
"""
dep_msg = "The `pbservice` commandline is deprecated and will be removed " \
"in a future version. Please using the scala implementation in smrtflow " \
"at https://github.com/PacificBiosciences/smrtflow"
started_at = time.time()
args = parser.parse_args(argv)
level = get_parsed_args_log_level(args, default_level=level)
console_or_file = args.log_file
setup_logger(console_or_file, level, formatter=str_formatter)
log.warn(dep_msg)
log.debug(args)
log.info("Starting tool version {v}".format(v=parser.version))
rcode = exe_runner_func(args)
run_time = time.time() - started_at
_d = dict(r=rcode, s=run_time)
log.info("exiting with return code {r} in {s:.2f} sec.".format(**_d))
return rcode
def pacbio_args_or_contract_runner(argv, parser, args_runner_func,
contract_tool_runner_func, alog,
setup_log_func):
"""
For tools that understand resolved_tool_contracts, but can't emit
tool contracts (they may have been written by hand)
:param parser: argparse Parser
:type parser: ArgumentParser
:param args_runner_func: func(args) => int signature
:param contract_tool_runner_func: func(tool_contract_instance) should be the signature
:param alog: a python log instance
:param setup_log_func: func(log_instance) => void signature
:return: int return code
:rtype: int
"""
def _log_not_none(msg):
if alog is not None:
alog.info(msg)
# circumvent the argparse parsing by inspecting the raw argv, then create
# a temporary parser with limited arguments to process the special case of
# --resolved-cool-contract (while still respecting verbosity flags).
if any(a.startswith(RESOLVED_TOOL_CONTRACT_OPTION) for a in argv):
p_tmp = get_default_argparser(version=parser.version,
description=parser.description)
add_resolved_tool_contract_option(
add_base_options(p_tmp, default_level="NOTSET"))
args_tmp = p_tmp.parse_args(argv)
resolved_tool_contract = load_resolved_tool_contract_from(
args_tmp.resolved_tool_contract)
_log_not_none(
"Successfully loaded resolved tool contract from {a}".format(
a=argv))
# XXX if one of the logging flags was specified, that takes precedence,
# otherwise use the log level in the resolved tool contract. note that
# this takes advantage of the fact that argparse allows us to use
# NOTSET as the default level even though it's not one of the choices.
log_level = get_parsed_args_log_level(args_tmp,
default_level=logging.NOTSET)
if log_level == logging.NOTSET:
log_level = resolved_tool_contract.task.log_level
with TemporaryResourcesManager(resolved_tool_contract) as tmp_mgr:
r = _pacbio_main_runner(alog,
setup_log_func,
contract_tool_runner_func,
resolved_tool_contract,
level=log_level)
_log_not_none("Completed running resolved contract. {c}".format(
c=resolved_tool_contract))
return r
else:
# tool was called with the standard commandline invocation
return pacbio_args_runner(argv, parser, args_runner_func, alog,
setup_log_func)
def test_get_parsed_args_log_level(self):
# XXX more of an integration test, sorry - we need to ensure that
# these functions work in combination with get_parsed_args_log_level
from pbcommand.common_options import (
add_log_debug_option, add_log_quiet_option, add_log_verbose_option,
add_log_level_option)
def _get_argparser(level="INFO"):
p = argparse.ArgumentParser()
p.add_argument("--version", action="store_true")
add_log_level_option(add_log_debug_option(add_log_quiet_option(
add_log_verbose_option(p))), default_level=level)
return p
p = _get_argparser().parse_args([])
l = get_parsed_args_log_level(p)
assert l == logging.INFO
p = _get_argparser().parse_args(["--quiet"])
l = get_parsed_args_log_level(p)
assert l == logging.ERROR
p = _get_argparser().parse_args(["--debug"])
l = get_parsed_args_log_level(p)
assert l == logging.DEBUG
p = _get_argparser("ERROR").parse_args(["--verbose"])
l = get_parsed_args_log_level(p)
assert l == logging.INFO
p = _get_argparser("DEBUG").parse_args(["--log-level=WARNING"])
l = get_parsed_args_log_level(p)
assert l == logging.WARNING
p = _get_argparser("NOTSET").parse_args([])
l = get_parsed_args_log_level(p)
assert l == logging.NOTSET
p = _get_argparser(logging.NOTSET).parse_args([])
l = get_parsed_args_log_level(p)
assert l == logging.NOTSET
def test_get_parsed_args_log_level(self):
# XXX more of an integration test, sorry - we need to ensure that
# these functions work in combination with get_parsed_args_log_level
from pbcommand.common_options import (
add_log_debug_option, add_log_quiet_option, add_log_verbose_option,
add_log_level_option)
def _get_argparser(level="INFO"):
p = argparse.ArgumentParser()
p.add_argument("--version", action="store_true")
add_log_level_option(add_log_debug_option(add_log_quiet_option(
add_log_verbose_option(p))), default_level=level)
return p
p = _get_argparser().parse_args([])
l = get_parsed_args_log_level(p)
self.assertEqual(l, logging.INFO)
p = _get_argparser().parse_args(["--quiet"])
l = get_parsed_args_log_level(p)
self.assertEqual(l, logging.ERROR)
p = _get_argparser().parse_args(["--debug"])
l = get_parsed_args_log_level(p)
self.assertEqual(l, logging.DEBUG)
p = _get_argparser("ERROR").parse_args(["--verbose"])
l = get_parsed_args_log_level(p)
self.assertEqual(l, logging.INFO)
p = _get_argparser("DEBUG").parse_args(["--log-level=WARNING"])
l = get_parsed_args_log_level(p)
self.assertEqual(l, logging.WARNING)
p = _get_argparser("NOTSET").parse_args([])
l = get_parsed_args_log_level(p)
self.assertEqual(l, logging.NOTSET)
p = _get_argparser(logging.NOTSET).parse_args([])
l = get_parsed_args_log_level(p)
self.assertEqual(l, logging.NOTSET)
def pacbio_args_or_contract_runner(argv,
parser,
args_runner_func,
contract_tool_runner_func,
alog, setup_log_func):
"""
For tools that understand resolved_tool_contracts, but can't emit
tool contracts (they may have been written by hand)
:param parser: argparse Parser
:type parser: ArgumentParser
:param args_runner_func: func(args) => int signature
:param contract_tool_runner_func: func(tool_contract_instance) should be
the signature
:param alog: a python log instance
:param setup_log_func: func(log_instance) => void signature
:return: int return code
:rtype: int
"""
def _log_not_none(msg):
if alog is not None:
alog.info(msg)
# circumvent the argparse parsing by inspecting the raw argv, then create
# a temporary parser with limited arguments to process the special case of
# --resolved-cool-contract (while still respecting verbosity flags).
if any(a.startswith(RESOLVED_TOOL_CONTRACT_OPTION) for a in argv):
p_tmp = get_default_argparser(version=parser.version,
description=parser.description)
add_resolved_tool_contract_option(add_base_options(p_tmp,
default_level="NOTSET"))
args_tmp = p_tmp.parse_args(argv)
resolved_tool_contract = load_resolved_tool_contract_from(
args_tmp.resolved_tool_contract)
_log_not_none("Successfully loaded resolved tool contract from {a}".format(a=argv))
# XXX if one of the logging flags was specified, that takes precedence,
# otherwise use the log level in the resolved tool contract. note that
# this takes advantage of the fact that argparse allows us to use
# NOTSET as the default level even though it's not one of the choices.
log_level = get_parsed_args_log_level(args_tmp,
default_level=logging.NOTSET)
if log_level == logging.NOTSET:
log_level = resolved_tool_contract.task.log_level
with TemporaryResourcesManager(resolved_tool_contract) as tmp_mgr:
r = _pacbio_main_runner(alog, setup_log_func, contract_tool_runner_func, resolved_tool_contract, level=log_level)
_log_not_none("Completed running resolved contract. {c}".format(c=resolved_tool_contract))
return r
else:
# tool was called with the standard commandline invocation
return pacbio_args_runner(argv, parser, args_runner_func, alog,
setup_log_func)
def _w(args):
started_at = time.time()
def run_time():
return time.time() - started_at
def exit_msg(rcode_):
return "Completed running {r} exitcode {e} in {t:.2f} sec.".format(
r=rtc, e=rcode_, t=run_time())
level = get_parsed_args_log_level(args)
setup_logger(None, level=level)
log.info("Loading pbcommand {v}".format(v=pbcommand.get_version()))
log.info("Registry {r}".format(r=registry))
log.info("Setting log-level to {d}".format(d=level))
log.debug("args {a}".format(a=args))
log.info("loading RTC from {i}".format(i=args.rtc_path))
rtc = load_resolved_tool_contract_from(args.rtc_path)
id_funcs = {
t.task.task_id: func
for t, func in registry.rtc_runners.iteritems()
}
func = id_funcs.get(rtc.task.task_id, None)
if func is None:
rcode = 1
log.error(
"Unknown tool contract id '{x}' Registered TC ids {i}".format(
x=rtc.task.task_id, i=id_funcs.keys()))
log.error(exit_msg(rcode))
return rcode
else:
log.info("Running id:{i} Resolved Tool Contract {r}".format(
r=rtc, i=rtc.task.task_id))
log.info("Runner func {f}".format(f=func))
exit_code = func(rtc)
if exit_code == 0:
log.info(exit_msg(exit_code))
else:
log.error(exit_msg(exit_code))
return exit_code
def main_runner(argv, parser, exe_runner_func,
level=logging.DEBUG, str_formatter=_LOG_FORMAT):
"""
Fundamental interface to commandline applications
"""
started_at = time.time()
args = parser.parse_args(argv)
level = get_parsed_args_log_level(args, default_level=level)
console_or_file = args.log_file
setup_logger(console_or_file, level, formatter=str_formatter)
log.debug(args)
log.info("Starting tool version {v}".format(v=parser.version))
rcode = exe_runner_func(args)
run_time = time.time() - started_at
_d = dict(r=rcode, s=run_time)
log.info("exiting with return code {r} in {s:.2f} sec.".format(**_d))
return rcode
def _w(args):
started_at = time.time()
def run_time():
return time.time() - started_at
def exit_msg(rcode_):
return "Completed running {r} exitcode {e} in {t:.2f} sec.".format(r=rtc, e=rcode_, t=run_time())
level = get_parsed_args_log_level(args)
setup_logger(None, level=level)
log.info("Loading pbcommand {v}".format(v=pbcommand.get_version()))
log.info("Registry {r}".format(r=registry))
log.info("Setting log-level to {d}".format(d=level))
log.debug("args {a}".format(a=args))
log.info("loading RTC from {i}".format(i=args.rtc_path))
rtc = load_resolved_tool_contract_from(args.rtc_path)
id_funcs = {t.task.task_id: func for t, func in registry.rtc_runners.iteritems()}
func = id_funcs.get(rtc.task.task_id, None)
if func is None:
rcode = 1
log.error("Unknown tool contract id '{x}' Registered TC ids {i}".format(x=rtc.task.task_id, i=id_funcs.keys()))
log.error(exit_msg(rcode))
return rcode
else:
log.info("Running id:{i} Resolved Tool Contract {r}".format(r=rtc, i=rtc.task.task_id))
log.info("Runner func {f}".format(f=func))
exit_code = func(rtc)
if exit_code == 0:
log.info(exit_msg(exit_code))
else:
log.error(exit_msg(exit_code))
return exit_code
def main_runner(argv,
parser,
exe_runner_func,
level=logging.DEBUG,
str_formatter=_LOG_FORMAT):
"""
Fundamental interface to commandline applications
"""
started_at = time.time()
args = parser.parse_args(argv)
level = get_parsed_args_log_level(args, default_level=level)
console_or_file = args.log_file
setup_logger(console_or_file, level, formatter=str_formatter)
log.debug(args)
log.info("Starting tool version {v}".format(v=parser.version))
rcode = exe_runner_func(args)
run_time = time.time() - started_at
_d = dict(r=rcode, s=run_time)
log.info("exiting with return code {r} in {s:.2f} sec.".format(**_d))
return rcode
def _pacbio_main_runner(alog, setup_log_func, exe_main_func, *args, **kwargs):
"""
Runs a general func and logs results. The return type is expected to be an (int) return code.
:param alog: a log instance
:param func: a cli exe func, must return an int exit code. func(args) => Int, where args is parsed from p.parse_args()
:param args: parsed args from parser
:param setup_log_func: F(alog, level=value, file_name=value, formatter=value) or None
:return: Exit code of callable func
:rtype: int
"""
started_at = time.time()
pargs = args[0]
# default logging level
level = logging.INFO
if 'level' in kwargs:
level = kwargs.pop('level')
else:
level = get_parsed_args_log_level(pargs)
# None will default to stdout
log_file = getattr(pargs, 'log_file', None)
# Currently, only support to stdout. More customization would require
# more required commandline options in base parser (e.g., --log-file, --log-formatter)
log_options = dict(level=level, file_name=log_file)
# The Setup log func must adhere to the pbcommand.utils.setup_log func
# signature
# FIXME. This should use the more concrete F(file_name_or_name, level, formatter)
# signature of setup_logger
if setup_log_func is not None and alog is not None:
setup_log_func(alog, **log_options)
alog.info("Using pbcommand v{v}".format(v=pbcommand.get_version()))
alog.info(
"completed setting up logger with {f}".format(f=setup_log_func))
alog.info("log opts {d}".format(d=log_options))
try:
# the code in func should catch any exceptions. The try/catch
# here is a fail safe to make sure the program doesn't fail
# and the makes sure the exit code is logged.
return_code = exe_main_func(*args, **kwargs)
run_time = time.time() - started_at
except Exception as e:
run_time = time.time() - started_at
if alog is not None:
alog.error(e, exc_info=True)
else:
traceback.print_exc(sys.stderr)
# We should have a standard map of exit codes to Int
if isinstance(e, IOError):
return_code = 1
else:
return_code = 2
_d = dict(r=return_code, s=run_time)
if alog is not None:
alog.info("exiting with return code {r} in {s:.2f} sec.".format(**_d))
return return_code
def _pacbio_main_runner(alog, setup_log_func, exe_main_func, *args, **kwargs):
"""
Runs a general func and logs results. The return type is expected to be an (int) return code.
:param alog: a log instance
:param func: a cli exe func, must return an int exit code. func(args) => Int, where args is parsed from p.parse_args()
:param args: parsed args from parser
:param setup_log_func: F(alog, level=value, file_name=value, formatter=value) or None
:return: Exit code of callable func
:rtype: int
"""
started_at = time.time()
pargs = args[0]
# default logging level
level = logging.INFO
if 'level' in kwargs:
level = kwargs.pop('level')
else:
level = get_parsed_args_log_level(pargs)
# None will default to stdout
log_file = getattr(pargs, 'log_file', None)
# Currently, only support to stdout. More customization would require
# more required commandline options in base parser (e.g., --log-file, --log-formatter)
log_options = dict(level=level, file_name=log_file)
# The Setup log func must adhere to the pbcommand.utils.setup_log func
# signature
# FIXME. This should use the more concrete F(file_name_or_name, level, formatter)
# signature of setup_logger
if setup_log_func is not None and alog is not None:
setup_log_func(alog, **log_options)
alog.info("Using pbcommand v{v}".format(v=pbcommand.get_version()))
alog.info("completed setting up logger with {f}".format(f=setup_log_func))
alog.info("log opts {d}".format(d=log_options))
try:
# the code in func should catch any exceptions. The try/catch
# here is a fail safe to make sure the program doesn't fail
# and the makes sure the exit code is logged.
return_code = exe_main_func(*args, **kwargs)
run_time = time.time() - started_at
except Exception as e:
run_time = time.time() - started_at
if alog is not None:
alog.error(e, exc_info=True)
else:
traceback.print_exc(sys.stderr)
# We should have a standard map of exit codes to Int
if isinstance(e, IOError):
return_code = 1
else:
return_code = 2
_d = dict(r=return_code, s=run_time)
if alog is not None:
alog.info("exiting with return code {r} in {s:.2f} sec.".format(**_d))
return return_code
def _pacbio_main_runner(alog, setup_log_func, exe_main_func, *args, **kwargs):
"""
Runs a general func and logs results. The return type is expected to be an (int) return code.
:param alog: a log instance
:param func: a cli exe func, must return an int exit code. func(args) => Int, where args is parsed from p.parse_args()
:param args: parsed args from parser
:param setup_log_func: F(alog, level=value, file_name=value, formatter=value) or None
:return: Exit code of callable func
:rtype: int
"""
started_at = time.time()
pargs = args[0]
# default logging level
level = logging.INFO
if 'level' in kwargs:
level = kwargs.pop('level')
else:
level = get_parsed_args_log_level(pargs)
# None will default to stdout
log_file = getattr(pargs, 'log_file', None)
# Currently, only support to stdout. More customization would require
# more required commandline options in base parser (e.g., --log-file,
# --log-formatter)
log_options = dict(level=level, file_name=log_file)
base_dir = os.getcwd()
dump_alarm_on_error = False
if "dump_alarm_on_error" in kwargs:
dump_alarm_on_error = kwargs.pop("dump_alarm_on_error")
is_cromwell_environment = bool(
os.environ.get("SMRT_PIPELINE_BUNDLE_DIR",
None)) and "cromwell-executions" in base_dir
dump_alarm_on_error = dump_alarm_on_error and is_cromwell_environment
# The Setup log func must adhere to the pbcommand.utils.setup_log func
# signature
# FIXME. This should use the more concrete F(file_name_or_name, level, formatter)
# signature of setup_logger
if setup_log_func is not None and alog is not None:
setup_log_func(alog, **log_options)
alog.info("Using pbcommand v{v}".format(v=pbcommand.get_version()))
alog.info(
"completed setting up logger with {f}".format(f=setup_log_func))
alog.info("log opts {d}".format(d=log_options))
if dump_alarm_on_error:
alog.info(
"This command appears to be running as part of a Cromwell workflow"
)
alog.info("Additional output files may be generated")
try:
# the code in func should catch any exceptions. The try/catch
# here is a fail safe to make sure the program doesn't fail
# and the makes sure the exit code is logged.
return_code = exe_main_func(*args, **kwargs)
run_time = time.time() - started_at
except Exception as e:
run_time = time.time() - started_at
if alog is not None:
alog.error(e, exc_info=True)
else:
traceback.print_exc(sys.stderr)
if dump_alarm_on_error:
PacBioAlarm.dump_error(file_name=os.path.join(
base_dir, "alarms.json"),
exception=e,
info="".join(traceback.format_exc()),
message=str(e),
name=e.__class__.__name__,
severity=logging.ERROR)
# We should have a standard map of exit codes to Int
if isinstance(e, IOError):
return_code = 1
else:
return_code = 2
_d = dict(r=return_code, s=run_time)
if is_cromwell_environment:
alog.info("Writing task report to task-report.json")
write_task_report(run_time, getattr(pargs, "nproc", 1), return_code)
if alog is not None:
alog.info("exiting with return code {r} in {s:.2f} sec.".format(**_d))
return return_code