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 16 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
124 changes: 123 additions & 1 deletion tests/test_utils.py
Original file line number Diff line number Diff line change
@@ -1,14 +1,19 @@
# Copyright (c) Facebook, Inc. and its affiliates. All Rights Reserved
import io
import os
from pathlib import Path
from textwrap import dedent
from typing import Any
from unittest.mock import patch

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

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


def test_get_original_cwd(hydra_restore_singletons: Any) -> None:
Expand Down Expand Up @@ -60,3 +65,120 @@ def test_to_absolute_path_without_hydra(
path = str(Path(path))
expected = str(Path(expected).absolute())
assert utils.to_absolute_path(path) == expected


class TestRunAndReport:
class DemoFunctions:
"""Demo inputs for `run_and_report`"""
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you explain the testing logic?
The test is surprisingly large.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The test is surprisingly large.

Sorry about that.
This is not just testing the new functionality. It is also testing the pre-existing run_and_report behavior.

The run_and_report function has the following signature:

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

There are three test methods:

  • test_success tests when run_and_report runs func successfully.
  • test_failure tests when func raises an exception and run_and_report is able to print a nicely-formatted error message.
  • test_simplified_traceback_failure tests when func raises an exception and run_and_report is not able to print a nicely-formatted error message -- this is the case where the original exception gets re-raised.

There are four @staticmethod definitions. These are passed in to run_and_report as the func argument. They are designed to trigger different logic code paths inside of run_and_report:

  • success_func raises no exception
  • simple_error raises an AssertionError
  • run_job_wrapper triggers the special logic in run_and_report that looks for a function called "run_job" in the stack, and strips away the leading stack frames
  • omegaconf_job_wrapper triggers the special logic in run_and_report that looks for the omegaconf module in the stack, and strips away the bottom stack frames

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Gotcha.
Thanks for adding this. Can you add a comment describing this in the test class?
(does not need to be as detailed).


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

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

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

nested_error()

run_job()

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

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)