Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

handle frame in stack trace that doesn't have a module #1741

Merged
merged 19 commits into from
Aug 6, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
150 changes: 80 additions & 70 deletions hydra/_internal/utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@
from dataclasses import dataclass
from os.path import dirname, join, normpath, realpath
from traceback import print_exc, print_exception
from types import FrameType
from types import FrameType, TracebackType
from typing import Any, Callable, List, Optional, Sequence, Tuple, Union

from omegaconf.errors import OmegaConfBaseException
Expand Down Expand Up @@ -213,75 +213,85 @@ def run_and_report(func: Any) -> Any:
if _is_env_set("HYDRA_FULL_ERROR") or is_under_debugger():
raise ex
else:
if isinstance(ex, CompactHydraException):
sys.stderr.write(str(ex) + os.linesep)
if isinstance(ex.__cause__, OmegaConfBaseException):
sys.stderr.write(str(ex.__cause__) + os.linesep)
else:
# Custom printing that strips the Hydra related stack frames from the top
# And any omegaconf frames from the bottom.
# It is possible to add additional libraries to sanitize from the bottom later,
# maybe even make it configurable.

tb: Any = ex.__traceback__
search_max = 10
# strip Hydra frames from start of stack
# will strip until it hits run_job()
while search_max > 0:
if tb is None:
break
frame = tb.tb_frame
tb = tb.tb_next
search_max = search_max - 1
if inspect.getframeinfo(frame).function == "run_job":
break

if search_max == 0 or tb is None:
# could not detect run_job, probably a runtime exception before we got there.
# do not sanitize the stack trace.
print_exc()
sys.exit(1)

# strip OmegaConf frames from bottom of stack
end = tb
num_frames = 0
while end is not None:
frame = end.tb_frame
mdl = inspect.getmodule(frame)
assert mdl is not None
name = mdl.__name__
if name.startswith("omegaconf."):
break
end = end.tb_next
num_frames = num_frames + 1

@dataclass
class FakeTracebackType:
tb_next: Any = None # Optional["FakeTracebackType"]
tb_frame: Optional[FrameType] = None
tb_lasti: Optional[int] = None
tb_lineno: Optional[int] = None

iter_tb = tb
final_tb = FakeTracebackType()
cur = final_tb
added = 0
while True:
cur.tb_lasti = iter_tb.tb_lasti
cur.tb_lineno = iter_tb.tb_lineno
cur.tb_frame = iter_tb.tb_frame

if added == num_frames - 1:
break
added = added + 1
cur.tb_next = FakeTracebackType()
cur = cur.tb_next
iter_tb = iter_tb.tb_next

print_exception(etype=None, value=ex, tb=final_tb) # type: ignore
sys.stderr.write(
"\nSet the environment variable HYDRA_FULL_ERROR=1 for a complete stack trace.\n"
)
try:
if isinstance(ex, CompactHydraException):
sys.stderr.write(str(ex) + os.linesep)
if isinstance(ex.__cause__, OmegaConfBaseException):
sys.stderr.write(str(ex.__cause__) + os.linesep)
else:
# Custom printing that strips the Hydra related stack frames from the top
# And any omegaconf frames from the bottom.
# It is possible to add additional libraries to sanitize from the bottom later,
# maybe even make it configurable.

tb = ex.__traceback__
search_max = 10
# strip Hydra frames from start of stack
# will strip until it hits run_job()
while search_max > 0:
if tb is None:
break
frame = tb.tb_frame
tb = tb.tb_next
search_max = search_max - 1
if inspect.getframeinfo(frame).function == "run_job":
break

if search_max == 0 or tb is None:
# could not detect run_job, probably a runtime exception before we got there.
# do not sanitize the stack trace.
print_exc()
sys.exit(1)

# strip OmegaConf frames from bottom of stack
end: Optional[TracebackType] = tb
num_frames = 0
while end is not None:
frame = end.tb_frame
mdl = inspect.getmodule(frame)
assert mdl is not None
name = mdl.__name__
if name.startswith("omegaconf."):
break
end = end.tb_next
num_frames = num_frames + 1

@dataclass
class FakeTracebackType:
tb_next: Any = None # Optional["FakeTracebackType"]
tb_frame: Optional[FrameType] = None
tb_lasti: Optional[int] = None
tb_lineno: Optional[int] = None

iter_tb = tb
final_tb = FakeTracebackType()
cur = final_tb
added = 0
while True:
cur.tb_lasti = iter_tb.tb_lasti
cur.tb_lineno = iter_tb.tb_lineno
cur.tb_frame = iter_tb.tb_frame

if added == num_frames - 1:
break
added = added + 1
cur.tb_next = FakeTracebackType()
cur = cur.tb_next
assert iter_tb.tb_next is not None
iter_tb = iter_tb.tb_next

print_exception(etype=None, value=ex, tb=final_tb) # type: ignore
sys.stderr.write(
"\nSet the environment variable HYDRA_FULL_ERROR=1 for a complete stack trace.\n"
)
except Exception as ex2:
sys.stderr.write(
"An error occurred during Hydra's exception formatting:"
+ os.linesep
+ repr(ex2)
+ os.linesep
)
raise ex
sys.exit(1)


Expand Down
1 change: 1 addition & 0 deletions news/1739.bugfix
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Fix failure when sanitizing stack traces resulting from job exceptions
154 changes: 154 additions & 0 deletions tests/test_utils.py
Original file line number Diff line number Diff line change
@@ -1,17 +1,22 @@
# Copyright (c) Facebook, Inc. and its affiliates. All Rights Reserved
import io
import os
import re
from pathlib import Path
from textwrap import dedent
from typing import Any, Optional
from unittest.mock import patch

from omegaconf import DictConfig, OmegaConf
from pytest import mark, param, raises, warns

from hydra import utils
from hydra._internal.deprecation_warning import deprecation_warning
from hydra._internal.utils import run_and_report
from hydra.conf import HydraConf, RuntimeConf
from hydra.core.hydra_config import HydraConfig
from hydra.errors import HydraDeprecationError
from hydra.test_utils.test_utils import assert_regex_match


def test_get_original_cwd(hydra_restore_singletons: Any) -> None:
Expand Down Expand Up @@ -85,3 +90,152 @@ def test_deprecation_warning(
else:
with warns(UserWarning, match=re.escape(msg)):
deprecation_warning(msg)


class TestRunAndReport:
"""
Test the `hydra._internal.utils.run_and_report` function.

def run_and_report(func: Any) -> Any: ...

This class defines several test methods:
test_success:
a simple test case where `run_and_report(func)` succeeds.
test_failure:
test when `func` raises an exception, and `run_and_report(func)`
prints a nicely-formatted error message
test_simplified_traceback_failure:
test when printing a nicely-formatted error message fails, so
`run_and_report` falls back to re-raising the exception from `func`.
"""

class DemoFunctions:
"""
The methods of this `DemoFunctions` class are passed to
`run_and_report` as the func argument.
"""

@staticmethod
def success_func() -> Any:
return 123

@staticmethod
def simple_error() -> None:
assert False, "simple_err_msg"

@staticmethod
def run_job_wrapper() -> None:
"""
Trigger special logic in `run_and_report` that looks for a function
called "run_job" in the stack and strips away the leading stack
frames.
"""

def run_job() -> None:
def nested_error() -> None:
assert False, "nested_err"

nested_error()

run_job()

@staticmethod
def omegaconf_job_wrapper() -> None:
"""
Trigger special logic in `run_and_report` that looks for the
`omegaconf` module in the stack and strips away the bottom stack
frames.
"""

def run_job() -> None:
def job_calling_omconf() -> None:
from omegaconf import OmegaConf

# The below causes an exception:
OmegaConf.resolve(123) # type: ignore

job_calling_omconf()

run_job()

def test_success(self) -> None:
assert run_and_report(self.DemoFunctions.success_func) == 123

@mark.parametrize(
"demo_func, expected_traceback_regex",
[
param(
DemoFunctions.simple_error,
dedent(
r"""
Traceback \(most recent call last\):$
File "[^"]+", line \d+, in run_and_report$
return func\(\)$
File "[^"]+", line \d+, in simple_error$
assert False, "simple_err_msg"$
AssertionError: simple_err_msg$
assert False$
"""
),
id="simple_failure_full_traceback",
),
param(
DemoFunctions.run_job_wrapper,
dedent(
r"""
Traceback \(most recent call last\):$
File "[^"]+", line \d+, in nested_error$
assert False, "nested_err"$
AssertionError: nested_err$
assert False$
Set the environment variable HYDRA_FULL_ERROR=1 for a complete stack trace\.$
"""
),
id="strip_run_job_from_top_of_stack",
),
param(
DemoFunctions.omegaconf_job_wrapper,
dedent(
r"""
Traceback \(most recent call last\):$
File "[^"]+", line \d+, in job_calling_omconf$
OmegaConf.resolve\(123\) # type: ignore$
ValueError: Invalid config type \(int\), expected an OmegaConf Container$
Set the environment variable HYDRA_FULL_ERROR=1 for a complete stack trace\.$
"""
),
id="strip_omegaconf_from_bottom_of_stack",
),
],
)
def test_failure(self, demo_func: Any, expected_traceback_regex: str) -> None:
mock_stderr = io.StringIO()
with raises(SystemExit, match="1"), patch("sys.stderr", new=mock_stderr):
run_and_report(demo_func)
mock_stderr.seek(0)
stderr_output = mock_stderr.read()
assert_regex_match(expected_traceback_regex, stderr_output)

def test_simplified_traceback_failure(self) -> None:
"""
Test that a warning is printed and the original exception is re-raised
when an exception occurs during the simplified traceback logic.
"""
demo_func = self.DemoFunctions.run_job_wrapper
expected_traceback_regex = dedent(
r"""
An error occurred during Hydra's exception formatting:$
AssertionError\(.*\)$
"""
)
mock_stderr = io.StringIO()
with raises(AssertionError, match="nested_err"), patch(
"sys.stderr", new=mock_stderr
):
# patch `inspect.getmodule` so that an exception will occur in the
# simplified traceback logic:
with patch("inspect.getmodule", new=lambda *args: None):
run_and_report(demo_func)
mock_stderr.seek(0)
stderr_output = mock_stderr.read()
assert_regex_match(expected_traceback_regex, stderr_output)