Skip to content

Commit

Permalink
patch caplog level reset failing tests sporadically
Browse files Browse the repository at this point in the history
  • Loading branch information
fmigneault committed Jun 13, 2022
1 parent a2ca4e7 commit 2f04613
Showing 1 changed file with 29 additions and 15 deletions.
44 changes: 29 additions & 15 deletions tests/processes/test_wps_package.py
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
"""
import contextlib
import io
import logging
import os
import re
import shutil
Expand Down Expand Up @@ -142,10 +143,13 @@ def __init__(self, shell_command, arguments=None, with_message_input=True):
super(MockProcess, self).__init__(body)


def test_stdout_stderr_logging_for_commandline_tool_success():
def test_stdout_stderr_logging_for_commandline_tool_success(caplog):
"""
Execute a process and assert that stdout is correctly logged to log file upon successful process execution.
"""
caplog.set_level(logging.INFO, logger="cwltool")
caplog.set_level(logging.INFO, logger="weaver")

with contextlib.ExitStack() as stack:
xml_file = stack.enter_context(tempfile.NamedTemporaryFile(suffix=".xml")) # noqa
workdir = stack.enter_context(tempfile.TemporaryDirectory())
Expand All @@ -155,16 +159,20 @@ def test_stdout_stderr_logging_for_commandline_tool_success():
wps_package_instance.settings = {}
wps_package_instance.mock_status_location = xml_file.name
wps_package_instance.set_workdir(workdir)
expect_log = os.path.splitext(wps_package_instance.mock_status_location)[0] + ".log"

# ExecuteResponse mock
wps_request = MockWpsRequest(process_id=process.id)
wps_response = type("", (object,), {"_update_status": lambda *_, **__: 1})()
wps_package_instance._handler(wps_request, wps_response)

# log assertions
expect_log = os.path.splitext(wps_package_instance.mock_status_location)[0] + ".log"
# depending on debug/command-line & pytest config, captured logs can be 'hijacked' or not, use any active one
stdout = io.StringIO()
with contextlib.redirect_stdout(stdout):
wps_package_instance._handler(wps_request, wps_response)
with open(expect_log, mode="r", encoding="utf-8") as file:
log_data = file.read()
job_log = file.read()
log_data = stdout.getvalue() + "\n" + caplog.text + "\n" + job_log

# captured log portion added by the injected stdout/stderr logs
assert re.match(
r".*"
Expand All @@ -176,22 +184,24 @@ def test_stdout_stderr_logging_for_commandline_tool_success():
re.MULTILINE | re.DOTALL
)
# cwltool call with reference to the command and stdout/stderr redirects
log_cwltool = f"[cwltool] [job {process.id}]"
assert re.match(
r".*"
rf"{log_cwltool}.*\$ echo \\\n"
rf"cwltool.*job {process.id}.*\$ echo \\\n"
r"\s+'Dummy message' \> [\w\-/\.]+/stdout\.log 2\> [\w\-/\.]+/stderr\.log\n"
r".*",
log_data,
re.MULTILINE | re.DOTALL
)
assert f"{log_cwltool} completed success" in log_data
), f"Information expected in:\n{log_data}"
assert f"[cwltool] [job {process.id}] completed success" in log_data


def test_stdout_stderr_logging_for_commandline_tool_failure(caplog):
"""
Execute a process and assert that stderr is correctly logged to log file upon failing process execution.
"""
caplog.set_level(logging.INFO, logger="cwltool")
caplog.set_level(logging.INFO, logger="weaver")

with contextlib.ExitStack() as stack:
xml_file = stack.enter_context(tempfile.NamedTemporaryFile(suffix=".xml")) # noqa
workdir = stack.enter_context(tempfile.TemporaryDirectory())
Expand All @@ -213,9 +223,8 @@ def test_stdout_stderr_logging_for_commandline_tool_failure(caplog):
except PackageExecutionError as exception:
assert "Failed package execution" in exception.args[0]
assert "Missing required input parameter 'message'" in exception.args[0]
# depending on debug/command-line & pytest test order, the captured logs by be 'hijacked' or not
# use whichever one is active (stderr empty if captured by pytest)
log_err = stderr.getvalue() or caplog.text
# depending on debug/command-line & pytest config, captured logs can be 'hijacked' or not, use any active one
log_err = stderr.getvalue() + "\n" + caplog.text
assert "Could not retrieve any internal application log." not in log_err, (
"Since tool did not reach execution, not captured logged is expected."
)
Expand All @@ -230,6 +239,9 @@ def test_stdout_stderr_logging_for_commandline_tool_exception(caplog):
"""
Execute a process and assert that traceback is correctly logged to log file upon failing process execution.
"""
caplog.set_level(logging.INFO, logger="cwltool")
caplog.set_level(logging.INFO, logger="weaver")

with contextlib.ExitStack() as stack:
xml_file = stack.enter_context(tempfile.NamedTemporaryFile(suffix=".xml")) # noqa
workdir = stack.enter_context(tempfile.TemporaryDirectory())
Expand All @@ -239,6 +251,7 @@ def test_stdout_stderr_logging_for_commandline_tool_exception(caplog):
wps_package_instance.settings = {}
wps_package_instance.mock_status_location = xml_file.name
wps_package_instance.set_workdir(workdir)
expect_log = os.path.splitext(wps_package_instance.mock_status_location)[0] + ".log"

# ExecuteResponse mock
wps_request = MockWpsRequest(process_id=process["id"])
Expand All @@ -250,9 +263,10 @@ def test_stdout_stderr_logging_for_commandline_tool_exception(caplog):
wps_package_instance._handler(wps_request, wps_response)
except PackageExecutionError as exception:
assert "Completed permanentFail" in exception.args[0]
# depending on debug/command-line & pytest test order, the captured logs by be 'hijacked' or not
# use whichever one is active (stderr empty if captured by pytest)
log_err = stderr.getvalue() or caplog.text
# depending on debug/command-line & pytest config, captured logs can be 'hijacked' or not, use any active one
with open(expect_log, mode="r", encoding="utf-8") as file:
job_err = file.read()
log_err = stderr.getvalue() + "\n" + caplog.text + "\n" + job_err
assert "Could not retrieve any internal application log." in log_err, (
"Since command did not run, nothing captured is expected"
)
Expand Down

0 comments on commit 2f04613

Please sign in to comment.