diff --git a/docs/source/pcapkit/utilities/exceptions.rst b/docs/source/pcapkit/utilities/exceptions.rst index 9b21dedbc6..9907498451 100644 --- a/docs/source/pcapkit/utilities/exceptions.rst +++ b/docs/source/pcapkit/utilities/exceptions.rst @@ -13,9 +13,12 @@ Loud and Quiet Errors Raising a :class:`~pcapkit.utilities.exceptions.BaseError` is, by default, a **loud** act: the error is logged once at :data:`logging.CRITICAL` on the :data:`~pcapkit.utilities.logging.logger` logger, and outside development mode -:data:`sys.tracebacklimit` is set to ``0``, which suppresses the traceback frames -entirely so the user sees the exception line rather than a walk through -:mod:`pcapkit`'s internals. +an exception hook is installed on :data:`sys.excepthook` and +:data:`threading.excepthook`, the first time a loud error needs it, so the user +sees the exception line rather than a walk through :mod:`pcapkit`'s internals. +That hook only shortens the printing of a +:class:`~pcapkit.utilities.exceptions.BaseError` itself; every other exception +is handed on to whichever hook was previously installed, unchanged. ``quiet=True`` marks an error that :mod:`pcapkit` raises as **internal control flow** and expects to catch itself -- the @@ -42,8 +45,8 @@ It is still an ordinary exception carrying its message, so ``except`` clauses an :show-inheritance: :param quiet: If :data:`True`, the error is neither logged nor allowed to - alter :data:`sys.tracebacklimit`; it is raised silently, as internal - control flow. + install the exception hook; it is raised silently, as internal control + flow. :param \*args: Arbitrary positional arguments. :param \*\*kwargs: Arbitrary keyword arguments. diff --git a/pcapkit/utilities/exceptions.py b/pcapkit/utilities/exceptions.py index 7c55b35bdf..78f796b194 100644 --- a/pcapkit/utilities/exceptions.py +++ b/pcapkit/utilities/exceptions.py @@ -19,13 +19,17 @@ import os import struct import sys +import threading +import traceback from typing import TYPE_CHECKING from pcapkit.utilities.compat import ModuleNotFoundError # pylint: disable=redefined-builtin from pcapkit.utilities.logging import DEVMODE, VERBOSE, get_logger if TYPE_CHECKING: - from typing import Any + from threading import ExceptHookArgs + from types import TracebackType + from typing import Any, Callable, Optional, Type __all__ = [ 'stacklevel', @@ -100,14 +104,18 @@ def stacklevel() -> 'int': the :mod:`sys` module. The walk goes through :func:`inspect.currentframe` and ``f_back`` rather than - :func:`traceback.extract_stack`, which cannot be used here: - :meth:`traceback.StackSummary.extract` honours :data:`sys.tracebacklimit`, and - :class:`BaseError` sets that to ``0`` for every loud error outside development - mode. One such error therefore made ``extract_stack()`` return an *empty* list - for the rest of the process, which is where the old ``-1`` came from -- so in - ordinary use the first error silently broke the attribution of every warning - after it. Walking frames also skips building the :class:`~traceback.FrameSummary` - objects and the :mod:`linecache` lookups behind them, which is worth having on + :func:`traceback.extract_stack`, which *used to* be unusable here for a sharper + reason than cost: :meth:`traceback.StackSummary.extract` honours + :data:`sys.tracebacklimit`, and :class:`BaseError` used to set that to ``0`` for + every loud error outside development mode. One such error therefore made + ``extract_stack()`` return an *empty* list for the rest of the process, which is + where the old ``-1`` came from -- so in ordinary use the first error silently + broke the attribution of every warning after it. :class:`BaseError` no longer + touches :data:`sys.tracebacklimit` at all (it prints its terse line through an + exception hook instead), which removes that failure mode -- but the frame walk + remains the right approach regardless of it: it skips building the + :class:`~traceback.FrameSummary` objects and the :mod:`linecache` lookups + :func:`traceback.extract_stack` does for every frame, which is worth avoiding on a function called once per warning. Important: @@ -160,23 +168,42 @@ class BaseError(Exception): A loud error -- the default -- is reported once, at :data:`logging.CRITICAL` level, on the :data:`~pcapkit.utilities.logging.logger` logger. Outside development mode it - also sets :data:`sys.tracebacklimit` to ``0``, which suppresses the traceback - frames entirely, so a user sees the exception line rather than a walk through - :mod:`pcapkit`'s internals. + also installs :func:`_excepthook` as :data:`sys.excepthook` and + :func:`_threading_excepthook` as :data:`threading.excepthook`, the first time + a loud error needs them, so that error -- and every loud error reaching the + top level after it, on the main thread or any other -- prints its one-line + exception message rather than a walk through :mod:`pcapkit`'s internals. A **quiet** error (``quiet=True``) is one :mod:`pcapkit` raises as internal control flow and expects to catch itself, such as the :exc:`~pcapkit.utilities.exceptions.MissingKeyError` behind :meth:`MultiDict.get `. It is - therefore silent and free of side effects: nothing is logged, and - :data:`sys.tracebacklimit` is left alone. It is still a perfectly ordinary - exception, carrying its message for whoever catches it. + therefore silent and free of side effects: nothing is logged, and neither + :data:`sys.excepthook` nor :data:`threading.excepthook` is touched. It is + still a perfectly ordinary exception, carrying its message for whoever + catches it. Important: - * :data:`sys.tracebacklimit` is process-global, so it is only set for a - loud error -- a quiet one used as control flow must not truncate the - tracebacks of unrelated exceptions for the rest of the process. + * This terseness used to come from setting :data:`sys.tracebacklimit` to + ``0``, which is process-global: one loud error truncated the tracebacks + of every *other*, unrelated exception for the rest of the process, + including ones that had nothing to do with :mod:`pcapkit`. It also, + incidentally, was what kept a loud error raised on a worker thread + terse, since the interpreter's default :data:`threading.excepthook` + itself consults :data:`sys.tracebacklimit`. The two hooks here replace + that mechanism precisely because neither has that reach -- each + shortens the printing of a :class:`BaseError` only, and hands every + other exception, unchanged, to whatever hook :mod:`pcapkit` found + installed before it first needed its own. + * Both hooks are installed lazily, from here, rather than at import + time, so a program that imports :mod:`pcapkit` but never raises one of + its errors never has :data:`sys.excepthook` or + :data:`threading.excepthook` touched. + * The two hooks still do not cover *every* path an exception can take. + A traceback a caller formats itself with :mod:`traceback` -- rather + than letting it reach the top level uncaught -- passes through + neither. See GitHub issue #719. * The ``stacklevel`` of the log record is the relative level :func:`stacklevel` computes, so the record is attributed to the caller whose operation failed rather than to this module. It used to be @@ -198,10 +225,214 @@ def __init__(self, *args: 'Any', quiet: 'bool' = False, **kwargs: 'Any') -> 'Non stack_info=VERBOSE, stacklevel=stacklevel()) else: logger.critical('%s: %s', type(self).__name__, str(self)) - sys.tracebacklimit = 0 + _install_excepthook() super().__init__(*args, **kwargs) +#: Callable[[Type[BaseException], BaseException, Optional[TracebackType]], None]: +#: Whatever :data:`sys.excepthook` was installed immediately before +#: :func:`_install_excepthook` last replaced it -- :data:`None` until that +#: happens. This is what a non-:class:`BaseError` is delegated to from +#: :func:`_excepthook`. +#: +#: Not a durable, one-time capture: an in-place :func:`importlib.reload` of +#: *this exact module* re-executes the line below, resetting this back to +#: :data:`None` in the very globals the already-installed :func:`_excepthook` +#: still reads from on every call (a global lookup, not a value closed over at +#: definition time). The old hook -- still installed, since a reload does not +#: retroactively change what :data:`sys.excepthook` points at -- then falls +#: back to :data:`sys.__excepthook__` for a non-:class:`BaseError`, silently +#: losing whatever had been captured before the reload (a host application's +#: own hook, or ``tbtrim``'s). Measured: a delegate trimmed to one frame before +#: such a reload, the bare default's full walk after it. Harmless for +#: :class:`BaseError` printing, which does not consult this at all, and for +#: the far more common case this module exercises -- a *fresh* module object +#: per load, as :func:`tests._support.load_module` and a plain re-``import`` +#: both are -- where the old instance's own globals, including this one, are +#: simply left alone. +_previous_excepthook = None # type: Optional[Callable[..., None]] + +#: bool: Set for the duration of :func:`_excepthook`, so a re-entrant call -- the +#: delegate somehow routing back through :data:`sys.excepthook` -- falls back to +#: the interpreter's own hook rather than recursing or printing twice. A single +#: shared flag is correct here, unlike the threading analogue below: nothing +#: but the main thread's own unwind ever calls :data:`sys.excepthook`, so there +#: is no concurrent, unrelated invocation for one flag to be confused with. +_excepthook_running = False + + +def _excepthook(etype: 'Type[BaseException]', value: 'BaseException', + tb: 'Optional[TracebackType]') -> 'None': + """Print a loud :class:`BaseError` tersely; chain through everything else. + + Installed by :func:`_install_excepthook`, which is also what records + ``_previous_excepthook``. A :class:`BaseError` reaching here is printed with + ``limit=0`` against its *real* traceback -- not a bare one-liner built by + discarding the traceback outright, which is close but not the same thing. + :func:`traceback.print_exception` is also what formats a chained exception + (``raise ... from err``, or a bare ``raise`` inside an ``except`` block), + and it does so by walking from the outermost cause or context *inward*, + applying ``limit`` to each link's own frames as it goes. Passing ``tb=None`` + only ever hands it the top exception's own traceback -- the chain's inner + links keep their *real* ``__cause__``/``__context__`` traceback attributes + regardless, untouched by this call, and get printed in full. ``limit=0`` + against the real ``tb`` is what reaches every link, matching exactly what + :data:`sys.tracebacklimit` set to ``0`` used to produce for the same + exception -- the one-line answer for a plain :class:`BaseError` and the + *same* chain-without-frames answer this used to get wrong. + + Anything else is handed to ``_previous_excepthook`` exactly as received, so + a program with its own hook installed before :mod:`pcapkit` needed one -- + or none, in which case that is :data:`sys.__excepthook__` -- keeps seeing + exactly what it would have seen without :mod:`pcapkit` in the process at + all. + + """ + global _excepthook_running # pylint: disable=global-statement + + if _excepthook_running: + sys.__excepthook__(etype, value, tb) + return + + _excepthook_running = True + try: + if isinstance(value, BaseError): + traceback.print_exception(etype, value, tb, 0) + else: + delegate = _previous_excepthook or sys.__excepthook__ + delegate(etype, value, tb) + finally: + _excepthook_running = False + + +# A generic, external marker -- "some pcapkit instance's hook is active" -- for +# a caller that only has :data:`sys.excepthook` and no reference to a particular +# loaded copy of this module. Diagnostic only: :func:`_install_excepthook`'s own +# guard below does *not* use this, and must not go back to doing so. The marker +# is a plain :obj:`True`, identical on every reloaded copy of this function, so +# it cannot tell "my own instance's hook" from "some *other* instance's" -- +# which is exactly the distinction the guard needs and a shared value cannot +# give it. +_excepthook.installed_by_pcapkit = True # type: ignore[attr-defined] + + +#: Callable[[ExceptHookArgs], object]: The thread analogue of +#: ``_previous_excepthook`` -- whatever :data:`threading.excepthook` was +#: installed immediately before :func:`_install_excepthook` last replaced it. +#: Subject to the same reload caveat documented on ``_previous_excepthook``. +#: Typed to return :class:`object` rather than :data:`None`, matching +#: :data:`threading.excepthook` itself in typeshed -- unlike +#: :data:`sys.excepthook`, which is typed as returning :data:`None`. +_previous_threading_excepthook = None # type: Optional[Callable[..., object]] + +#: threading.local: Per-thread re-entrancy guard for +#: :func:`_threading_excepthook`, kept separate from ``_excepthook_running`` +#: rather than shared with it. Unlike :data:`sys.excepthook`, which only ever +#: fires once, on the main thread's own unwind, :data:`threading.excepthook` +#: can genuinely be running in *two different threads at once* -- each with its +#: own uncaught exception, entirely unrelated to the other. A single shared +#: flag would make one thread's hook see the other's unrelated, concurrent +#: call and mistake it for its own re-entrancy, falling back when it should +#: not. Scoping the flag per thread is what keeps the guard meaningful only +#: against a thread routing back through its *own* call. +_threading_hook_state = threading.local() + + +def _threading_excepthook(args: 'ExceptHookArgs') -> 'None': + """Thread analogue of :func:`_excepthook`; same contract, one argument. + + :data:`threading.excepthook` is called with a single + :class:`threading.ExceptHookArgs`, carrying ``exc_type``, ``exc_value``, + ``exc_traceback`` and ``thread`` -- not the three positional parameters + :data:`sys.excepthook` takes. Everything else here mirrors :func:`_excepthook` + as closely as the default thread hook's own output allows: a loud + :class:`BaseError` prints the ``"Exception in thread ...:"`` header the + default hook always prints first -- the one piece of that output + :data:`sys.tracebacklimit` never touched, since it only ever bounded the + traceback -- then its own message tersely, with ``limit=0`` against the real + traceback so a chained exception still comes out right. Anything else is + handed to ``_previous_threading_excepthook`` -- or + :data:`threading.__excepthook__`, the interpreter's own default, if nothing + was previously installed -- unchanged, header included, since that path + does not touch the default hook's own printing at all. + + Replacing this hook is the other half of why :data:`sys.tracebacklimit` + cannot simply be dropped without a replacement: the interpreter's *default* + :data:`threading.excepthook` itself consults :data:`sys.tracebacklimit` when + printing an uncaught exception from a worker thread, which is what made a + loud :class:`BaseError` there terse before this hook existed, incidentally + rather than by any thread-aware design on this module's part. Without this, + removing the global would have *regressed* that path from one line to a + full default traceback, even though the defect it was fixing is itself + thread-independent. + + """ + if getattr(_threading_hook_state, 'running', False): + threading.__excepthook__(args) + return + + _threading_hook_state.running = True + try: + if isinstance(args.exc_value, BaseError): + # The thread identity the default hook would have named, replicated + # rather than borrowed: there is no way to ask the default hook for + # *only* its header line, and ``args.thread`` is documented as + # possibly ``None`` -- in which case the default hook names the + # current thread's bare identifier instead, which is exactly what + # calling it from here, on that same thread, reproduces. + name = args.thread.name if args.thread is not None else str(threading.get_ident()) + print(f'Exception in thread {name}:', file=sys.stderr) + traceback.print_exception(args.exc_type, args.exc_value, args.exc_traceback, 0) + else: + delegate = _previous_threading_excepthook or threading.__excepthook__ + delegate(args) + finally: + _threading_hook_state.running = False + + +_threading_excepthook.installed_by_pcapkit = True # type: ignore[attr-defined] + + +def _install_excepthook() -> 'None': + """Install :func:`_excepthook` and :func:`_threading_excepthook`, once each. + + Called from :class:`BaseError`'s constructor rather than at import time, so + that a program that never raises a :mod:`pcapkit` error never has + :data:`sys.excepthook` or :data:`threading.excepthook` touched merely for + having imported the package. + + Idempotent for *this* module instance, independently for each of the two + hooks: if a given hook slot already holds this instance's own function -- + checked by identity, ``is``, not by the ``installed_by_pcapkit`` marker -- + installing it again does nothing, so a loud error later in the same run + never wraps either hook in another copy of itself. That distinction matters + because the identical check is wrong one level up: a hook slot already + holding *some* function of the same name from an *earlier* loaded copy of + this module -- a genuine :func:`importlib.reload`, or a test harness + re-executing the file fresh -- is not this instance's own hook, and must + not be skipped over. A fresh instance installs over it exactly as it would + over a host application's own hook, capturing it as the matching + ``_previous_*`` and delegating to it for whatever that older instance's own + hook does not claim as one of its own :class:`BaseError` instances -- + which, correctly, includes a :class:`BaseError` raised by that *older* + instance, since ``isinstance`` does not hold across the reload and + delegating down the chain is what lets the older instance's own hook + recognise it instead. + + """ + global _previous_excepthook, _previous_threading_excepthook # pylint: disable=global-statement + + current = sys.excepthook + if current is not _excepthook: + _previous_excepthook = current + sys.excepthook = _excepthook + + current_threading = threading.excepthook + if current_threading is not _threading_excepthook: + _previous_threading_excepthook = current_threading + threading.excepthook = _threading_excepthook + + ############################################################################## # TypeError session. ############################################################################## diff --git a/tests/utilities/test_decorators.py b/tests/utilities/test_decorators.py index a49ff86178..f4819e19b2 100644 --- a/tests/utilities/test_decorators.py +++ b/tests/utilities/test_decorators.py @@ -1,6 +1,7 @@ from __future__ import annotations import io +import sys import unittest from tests._support import (bootstrap_core_modules, install_fake_payload_protocols, @@ -13,10 +14,41 @@ def setUp(self) -> None: # binds partially-initialised real modules under ``pcapkit.*`` names, and # ``_payload_stand_ins`` binds outright stand-ins. See #660. isolate_modules(self) + self._protect_global_exception_state() modules = bootstrap_core_modules() self.decorators = modules['decorators'] self.exceptions = modules['exceptions'] + def _protect_global_exception_state(self) -> None: + """Restore ``sys.excepthook`` (and, defensively, ``sys.tracebacklimit``). + + Several tests below construct a loud ``BaseError`` directly -- + :meth:`test_beholder_wraps_struct_eof_with_no_payload`'s + ``StructError('unexpected eof', eof=True)`` does not pass ``quiet=True``, + for one -- and a loud error outside development mode installs + :mod:`pcapkit.utilities.exceptions`'s own exception hook on first use + (GitHub issue #719). This file had no ``tearDown`` before that issue and + never needed one: the equivalent side effect at the time, + ``sys.tracebacklimit = 0``, was already left unrestored, corrupting + every test that ran afterwards in the same process -- the #981 shape, + just not previously visible as a failure here. Addressed the way + ``isolate_modules`` addresses its own restore: via ``addCleanup``, so it + still runs if the rest of ``setUp`` raises partway through. + + """ + saved_hook = sys.excepthook + had_limit = hasattr(sys, 'tracebacklimit') + saved_limit = getattr(sys, 'tracebacklimit', None) + + def _restore() -> None: + sys.excepthook = saved_hook + if had_limit: + sys.tracebacklimit = saved_limit + elif hasattr(sys, 'tracebacklimit'): + del sys.tracebacklimit + + self.addCleanup(_restore) + def test_seekset_restores_original_offset(self) -> None: class DemoProtocol: def __init__(self) -> None: diff --git a/tests/utilities/test_exceptions_excepthook.py b/tests/utilities/test_exceptions_excepthook.py new file mode 100644 index 0000000000..6d6dd6582d --- /dev/null +++ b/tests/utilities/test_exceptions_excepthook.py @@ -0,0 +1,793 @@ +"""Regression tests for the ``sys.tracebacklimit`` leak in a loud ``BaseError``. + +GitHub issue #719: :class:`~pcapkit.utilities.exceptions.BaseError` set +:data:`sys.tracebacklimit` to ``0`` for every loud error outside development +mode, and nothing ever restored it. The attribute is process-global, so after +one pcapkit error every subsequent traceback in the *process* was truncated -- +including exceptions that have nothing to do with :mod:`pcapkit`. Measured +against the tree before this fix:: + + DEVMODE: False + before hasattr(sys, 'tracebacklimit') = False + after one loud IntError hasattr = True, value = 0 + then, unrelated: [][5] -> IndexError + traceback.extract_tb(...) -> 0 frames + +The fix removes the assignment outright and produces the same terse, one-line +output for a loud error through an exception hook instead -- +:func:`pcapkit.utilities.exceptions._excepthook`, installed lazily by +:func:`pcapkit.utilities.exceptions._install_excepthook` the first time a loud +error actually needs it. A hook only shortens the printing of the exception it +recognises as its own; it does not reach into how :mod:`traceback`, or any other +code, formats a *different* exception, which is what let the old mechanism leak +in the first place. + +A hook is awkward to probe from inside the very process that installs it -- +:data:`sys.excepthook` only fires for an exception that reaches the real +interpreter uncaught, which a ``self.assertRaises`` block never lets happen. Most +of what follows therefore drives a fresh interpreter with :mod:`subprocess` and +reads its ``stderr``, exercising the actual printing path rather than a +simulation of it. The tests that only check *state* -- whether +``sys.tracebacklimit`` or ``sys.excepthook`` were touched at all -- stay +in-process, via the same ``bootstrap``/``capture`` harness the rest of this +directory uses. + +""" +from __future__ import annotations + +import os +import subprocess +import sys +import textwrap +import threading +import unittest + +from tests._support import purge_modules +from tests.utilities._harness import bootstrap, capture + +#: Repository root -- three directories up from this file +#: (``tests/utilities/test_exceptions_excepthook.py``). Passed to the child +#: interpreter as ``PYTHONPATH`` explicitly, rather than relied on via the +#: current working directory: ``PYTHONSAFEPATH=1`` strips the cwd from +#: ``sys.path``, so a bare ``PYTHONPATH``-less invocation would silently import +#: whatever ``pcapkit`` happens to be installed, not this checkout. +REPO_ROOT = os.path.dirname(os.path.dirname(os.path.dirname(os.path.abspath(__file__)))) + + +def run_in_subprocess(code: 'str', devmode: 'bool' = False) -> 'subprocess.CompletedProcess[str]': + """Run ``code`` in a fresh interpreter against *this* checkout of :mod:`pcapkit`. + + Prepends an assertion that the ``pcapkit`` the child imports lives under + :data:`REPO_ROOT` -- not some other copy on the path -- so a green test here + actually proves something about the tree under review rather than about + whatever happens to be on ``sys.path`` by default. + + """ + preamble = textwrap.dedent(f''' + import pcapkit + assert pcapkit.__file__.startswith({REPO_ROOT!r}), ( + 'wrong tree', pcapkit.__file__, {REPO_ROOT!r}) + ''') + env = dict(os.environ) + env['PCAPKIT_DEVMODE'] = '1' if devmode else '0' + env['PYTHONSAFEPATH'] = '1' + env['PYTHONPATH'] = REPO_ROOT + return subprocess.run([sys.executable, '-c', preamble + textwrap.dedent(code)], + capture_output=True, text=True, env=env, timeout=30) + + +class UnrelatedTracebackSurvivesALoudErrorTests(unittest.TestCase): + """The regression itself, live and reproducible against the pre-fix tree.""" + + def test_unrelated_exception_keeps_its_frames_after_a_loud_error(self) -> None: + code = ''' + import traceback + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + try: + raise exc.IntError('boom') + except exc.IntError: + pass + + def inner(): + raise ValueError('an exception with nothing to do with pcapkit') + def middle(): + inner() + + try: + middle() + except ValueError: + import sys as _sys + etype, value, tb = _sys.exc_info() + print(len(traceback.extract_tb(tb))) + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + frame_count = int(proc.stdout.strip()) + self.assertGreater(frame_count, 0, + 'traceback.extract_tb returned 0 frames for an exception ' + 'that has nothing to do with pcapkit, raised after a loud ' + 'pcapkit error -- the #719 tracebacklimit leak is back') + + +class TracebacklimitNeverSetTests(unittest.TestCase): + """No path -- loud or quiet, in development mode or out of it -- sets the limit. + + Folded in with the same matrix: *which* paths install the replacement + hooks -- both of them, :data:`sys.excepthook` and + :data:`threading.excepthook`. Only one of the four combinations should -- a + loud error outside development mode -- and the other three must leave both + exactly as they found them. + + """ + + def setUp(self) -> None: + self._saved_devmode = os.environ.get('PCAPKIT_DEVMODE') + self._had_tracebacklimit = hasattr(sys, 'tracebacklimit') + self._saved_tracebacklimit = getattr(sys, 'tracebacklimit', None) + self._saved_excepthook = sys.excepthook + self._saved_threading_excepthook = threading.excepthook + + def tearDown(self) -> None: + if self._had_tracebacklimit: + sys.tracebacklimit = self._saved_tracebacklimit + elif hasattr(sys, 'tracebacklimit'): + del sys.tracebacklimit + sys.excepthook = self._saved_excepthook + threading.excepthook = self._saved_threading_excepthook + if self._saved_devmode is None: + os.environ.pop('PCAPKIT_DEVMODE', None) + else: + os.environ['PCAPKIT_DEVMODE'] = self._saved_devmode + purge_modules(['pcapkit']) + + def test_no_combination_of_quiet_and_devmode_sets_tracebacklimit(self) -> None: + for devmode in (False, True): + for quiet in (False, True): + with self.subTest(devmode=devmode, quiet=quiet): + if hasattr(sys, 'tracebacklimit'): + del sys.tracebacklimit + # Clean slate each iteration, so one subTest installing the + # hook cannot make a later one's "did it install?" check + # ambiguous via the already-marked guard in + # ``_install_excepthook``. + sys.excepthook = self._saved_excepthook + threading.excepthook = self._saved_threading_excepthook + + modules = bootstrap(devmode=devmode) + exceptions = modules['exceptions'] + logger = modules['logging'].logger + + with capture(logger): + exceptions.BaseError('boom', quiet=quiet) + + self.assertFalse(hasattr(sys, 'tracebacklimit')) + + if quiet or devmode: + self.assertIsNone( + exceptions._previous_excepthook, + 'a quiet error, or one in development mode, must not ' + 'install the exception hook') + self.assertIsNone( + exceptions._previous_threading_excepthook, + 'a quiet error, or one in development mode, must not ' + 'install the threading hook either') + self.assertIs(sys.excepthook, self._saved_excepthook) + self.assertIs(threading.excepthook, self._saved_threading_excepthook) + else: + self.assertIs(exceptions._previous_excepthook, self._saved_excepthook) + self.assertIs(exceptions._previous_threading_excepthook, + self._saved_threading_excepthook) + self.assertTrue(getattr(sys.excepthook, 'installed_by_pcapkit', False)) + self.assertTrue(getattr(threading.excepthook, 'installed_by_pcapkit', False)) + + +class LoudErrorPrintsOneLineTests(unittest.TestCase): + def test_a_loud_base_error_reaching_the_hook_prints_one_line(self) -> None: + code = ''' + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + raise exc.IntError('boom') + ''' + proc = run_in_subprocess(code) + self.assertNotEqual(proc.returncode, 0) + lines = [line for line in proc.stderr.splitlines() if line.strip()] + self.assertEqual(len(lines), 1, proc.stderr) + self.assertIn('IntError: boom', lines[0]) + self.assertNotIn('Traceback', proc.stderr) + + def test_development_mode_keeps_the_full_traceback(self) -> None: + """The terse form is the outside-DEVMODE behaviour only.""" + code = ''' + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + raise exc.IntError('boom') + ''' + proc = run_in_subprocess(code, devmode=True) + self.assertNotEqual(proc.returncode, 0) + self.assertIn('Traceback (most recent call last):', proc.stderr) + self.assertIn('IntError: boom', proc.stderr) + + +class ChainingTests(unittest.TestCase): + def test_a_non_base_error_is_delegated_to_the_previously_installed_hook(self) -> None: + code = ''' + import sys + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + def previous_hook(etype, value, tb): + print('PREVIOUS_HOOK_RAN', file=sys.stderr) + sys.__excepthook__(etype, value, tb) + sys.excepthook = previous_hook + + try: + raise exc.IntError('boom') + except exc.IntError: + pass + + # Confirm pcapkit's own hook is now what is actually installed, + # before raising the exception the assertions below are about. + # Without this, the assertions would also pass on code with no + # hook mechanism at all: previous_hook would simply still *be* + # sys.excepthook, unmoved, and would answer the raise directly -- + # nothing would have delegated to it, the marker would appear for + # free, and the test would prove nothing about chaining. + print('INSTALLED:', getattr(sys.excepthook, 'installed_by_pcapkit', False), + file=sys.stderr) + print('IS_PCAPKIT_HOOK:', sys.excepthook is exc._excepthook, file=sys.stderr) + print('PREVIOUS_IS_PREVIOUS_HOOK:', exc._previous_excepthook is previous_hook, + file=sys.stderr) + + raise ValueError('route through previous_hook') + ''' + proc = run_in_subprocess(code) + self.assertIn('INSTALLED: True', proc.stderr) + self.assertIn('IS_PCAPKIT_HOOK: True', proc.stderr) + self.assertIn('PREVIOUS_IS_PREVIOUS_HOOK: True', proc.stderr) + self.assertIn('PREVIOUS_HOOK_RAN', proc.stderr) + self.assertIn('ValueError: route through previous_hook', proc.stderr) + # The thing actually being delegated to is the previous hook, not just + # something that happens to print the same traceback regardless. + self.assertNotIn('IntError', proc.stderr.split('PREVIOUS_HOOK_RAN')[-1]) + + +class ChainedExceptionTests(unittest.TestCase): + """A chained exception must come out in the *shape* ``tracebacklimit = 0`` + produced, not just "one line". + + ``traceback.print_exception(etype, value, None)`` -- the hook's first + draft -- discards only the *top* exception's own traceback by handing in + ``tb=None``; it never touches ``value.__cause__`` or ``value.__context__``, + each of which carries its *own*, real ``__traceback__`` that + :func:`traceback.print_exception` walks and prints in full regardless, + since no ``limit`` was given for it to apply there either. The old + ``sys.tracebacklimit = 0`` applied to the whole chain, because + :func:`traceback.StackSummary.extract` -- which every link's formatting + goes through -- consults the global itself, independently, at every link. + ``limit=0`` against the *real* traceback (not ``None``) is what reaches + every link the same way, and is what the two tests below compare against: + not a one-line assertion, but the exact text ``sys.tracebacklimit = 0`` + would have produced for the same exception, chain included. + + """ + + def test_an_explicit_from_chain_matches_the_old_shape(self) -> None: + code = ''' + import contextlib + import io + import sys + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + def build(): + try: + 1 / 0 + except ZeroDivisionError as err: + raise exc.IntError('wrapped explicitly') from err + + def old_mechanism_output(): + try: + build() + except exc.IntError: + etype, value, tb = sys.exc_info() + sys.tracebacklimit = 0 + buf = io.StringIO() + with contextlib.redirect_stderr(buf): + sys.__excepthook__(etype, value, tb) + del sys.tracebacklimit + return buf.getvalue() + + def new_mechanism_output(): + try: + build() + except exc.IntError: + etype, value, tb = sys.exc_info() + buf = io.StringIO() + with contextlib.redirect_stderr(buf): + exc._excepthook(etype, value, tb) + return buf.getvalue() + + old = old_mechanism_output() + new = new_mechanism_output() + if old == new: + print('MATCH') + else: + print('MISMATCH') + print('old:', repr(old)) + print('new:', repr(new)) + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertEqual(proc.stdout.strip(), 'MATCH', proc.stdout) + + def test_an_implicit_context_chain_matches_the_old_shape(self) -> None: + code = ''' + import contextlib + import io + import sys + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + def build(): + try: + 1 / 0 + except ZeroDivisionError: + raise exc.IntError('wrapped implicitly') # no `from` -- implicit context + + def old_mechanism_output(): + try: + build() + except exc.IntError: + etype, value, tb = sys.exc_info() + sys.tracebacklimit = 0 + buf = io.StringIO() + with contextlib.redirect_stderr(buf): + sys.__excepthook__(etype, value, tb) + del sys.tracebacklimit + return buf.getvalue() + + def new_mechanism_output(): + try: + build() + except exc.IntError: + etype, value, tb = sys.exc_info() + buf = io.StringIO() + with contextlib.redirect_stderr(buf): + exc._excepthook(etype, value, tb) + return buf.getvalue() + + old = old_mechanism_output() + new = new_mechanism_output() + if old == new: + print('MATCH') + else: + print('MISMATCH') + print('old:', repr(old)) + print('new:', repr(new)) + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertEqual(proc.stdout.strip(), 'MATCH', proc.stdout) + + +class DoubleInstallTests(unittest.TestCase): + def test_installing_twice_does_not_double_print(self) -> None: + code = ''' + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + exc._install_excepthook() + exc._install_excepthook() + + raise exc.IntError('boom') + ''' + proc = run_in_subprocess(code) + lines = [line for line in proc.stderr.splitlines() if line.strip()] + self.assertEqual(len(lines), 1, proc.stderr) + + def test_installing_twice_does_not_wrap_itself(self) -> None: + code = ''' + import sys + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + def previous_hook(etype, value, tb): + print('PREVIOUS_HOOK_RAN', file=sys.stderr) + sys.__excepthook__(etype, value, tb) + sys.excepthook = previous_hook + + exc._install_excepthook() + first = sys.excepthook + exc._install_excepthook() + second = sys.excepthook + print('SAME_HOOK' if first is second else 'DIFFERENT_HOOK') + print('PREVIOUS_IS_MY_HOOK' if exc._previous_excepthook is previous_hook + else 'PREVIOUS_IS_SOMETHING_ELSE') + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertIn('SAME_HOOK', proc.stdout) + self.assertIn('PREVIOUS_IS_MY_HOOK', proc.stdout) + + def test_a_reentrant_delegate_falls_back_instead_of_recursing(self) -> None: + """A delegate that routes back through the hook must not loop forever.""" + code = ''' + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + exc._install_excepthook() + + calls = [] + def exploding_delegate(etype, value, tb): + calls.append(1) + if len(calls) > 3: + raise RecursionError('would spin forever without the guard') + exc._excepthook(etype, value, tb) + exc._previous_excepthook = exploding_delegate + + exc._excepthook(ValueError, ValueError('boom'), None) + print(len(calls)) + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertEqual(int(proc.stdout.strip()), 1) + + +class CrossInstanceReinstallTests(unittest.TestCase): + """A fresh module instance must install *over* a stale instance's hook. + + GitHub issue #983: CI caught this one. ``_install_excepthook``'s guard used + to skip installing whenever :data:`sys.excepthook` already carried the + ``installed_by_pcapkit`` marker -- a plain ``True``, identical on *every* + reloaded copy of :func:`~pcapkit.utilities.exceptions._excepthook`, so it + could not tell "my own instance already installed" from "some *other*, + possibly long-gone instance did". A worker that had already run some other + test touching a loud :class:`~pcapkit.utilities.exceptions.BaseError` left + exactly that: a marked hook with no live module behind it any more. The + next instance's own :func:`~pcapkit.utilities.exceptions._install_excepthook` + then saw the marker, concluded there was nothing to do, and left + ``_previous_excepthook`` at :data:`None` -- never actually installing + *its own* hook at all. + + This reproduces that directly: install a first instance's hook, drop that + instance (:func:`tests._support.purge_modules`, same as a reload would), + then bootstrap a second instance and require it to install over the first + one's still-active hook rather than mistaking it for its own. + + """ + + def setUp(self) -> None: + self._saved_devmode = os.environ.get('PCAPKIT_DEVMODE') + self._saved_excepthook = sys.excepthook + self._saved_threading_excepthook = threading.excepthook + + def tearDown(self) -> None: + sys.excepthook = self._saved_excepthook + threading.excepthook = self._saved_threading_excepthook + if self._saved_devmode is None: + os.environ.pop('PCAPKIT_DEVMODE', None) + else: + os.environ['PCAPKIT_DEVMODE'] = self._saved_devmode + purge_modules(['pcapkit']) + + def test_a_fresh_instance_installs_over_a_stale_instance_hook(self) -> None: + # ``capture()`` alone is enough to keep this quiet -- it swaps the + # logger's handlers out and restores them in a ``finally``. Setting + # ``logger.disabled`` directly instead, as an earlier revision of this + # test did, would not be: ``logging.getLogger(name)`` hands back the + # *same* cached singleton regardless of how many times this module is + # reloaded, so disabling it here without restoring it would silence + # every other test in the process sharing that name afterwards -- + # exactly the class of leak this file exists to catch, just aimed at a + # different piece of global state. + first = bootstrap(devmode=False)['exceptions'] + with capture(first.logger): + first.BaseError('boom') + + self.assertIs(sys.excepthook, first._excepthook, + 'precondition: the first instance must have installed') + self.assertIs(threading.excepthook, first._threading_excepthook, + 'precondition: the first instance must have installed the ' + 'threading hook too') + + # Drop the first instance the way a reload would -- its hook is still + # the live sys.excepthook, but nothing in sys.modules points at the + # module that installed it any more. + purge_modules(['pcapkit']) + + second = bootstrap(devmode=False)['exceptions'] + with capture(second.logger): + second.BaseError('boom') + + self.assertIs(sys.excepthook, second._excepthook, + 'the second instance must install its own hook rather than ' + 'mistaking the stale first one for its own') + self.assertIs(second._previous_excepthook, first._excepthook, + 'the stale hook must be captured and chained through, not ' + 'silently dropped') + self.assertIs(threading.excepthook, second._threading_excepthook, + 'the second instance must install its own threading hook too') + self.assertIs(second._previous_threading_excepthook, first._threading_excepthook, + 'the stale threading hook must be captured and chained ' + 'through as well') + + +class ThreadingExcepthookTests(unittest.TestCase): + """The thread analogue of :class:`LoudErrorPrintsOneLineTests` and friends. + + :data:`threading.excepthook` needed its own hook for a reason distinct from + "symmetry with :data:`sys.excepthook`": the interpreter's *default* + :data:`threading.excepthook` itself consults :data:`sys.tracebacklimit` + when printing, so removing the global without replacing it on this side too + would have *regressed* a loud :class:`~pcapkit.utilities.exceptions.BaseError` + on a worker thread from one line to a full default traceback -- the + opposite of this change's purpose. Measured: 2 lines with + ``sys.tracebacklimit = 0`` in place, 12 without it and without this hook. + + """ + + def test_a_loud_base_error_on_a_thread_matches_the_old_two_line_shape(self) -> None: + code = ''' + import io + import sys + import threading + import contextlib + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + error = exc.IntError('boom on a thread', quiet=True) + + def old_mechanism_output(name): + def boom(): + raise error + captured = io.StringIO() + saved_hook = threading.excepthook + threading.excepthook = threading.__excepthook__ + sys.tracebacklimit = 0 + try: + t = threading.Thread(target=boom, name=name) + with contextlib.redirect_stderr(captured): + t.start() + t.join() + finally: + del sys.tracebacklimit + threading.excepthook = saved_hook + return captured.getvalue() + + def new_mechanism_output(name): + exc._install_excepthook() + def boom(): + raise error + captured = io.StringIO() + t = threading.Thread(target=boom, name=name) + with contextlib.redirect_stderr(captured): + t.start() + t.join() + return captured.getvalue() + + old = old_mechanism_output('CompareWorker') + new = new_mechanism_output('CompareWorker') + if old == new: + print('MATCH') + else: + print('MISMATCH') + print('old:', repr(old)) + print('new:', repr(new)) + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertEqual(proc.stdout.strip(), 'MATCH', proc.stdout) + + def test_a_chained_error_on_a_thread_also_matches_the_old_shape(self) -> None: + code = ''' + import io + import sys + import threading + import contextlib + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + def build_chained_error(): + try: + 1 / 0 + except ZeroDivisionError as err: + error = exc.IntError('wrapped on a thread', quiet=True) + error.__cause__ = err + return error + + error = build_chained_error() + + def old_mechanism_output(name): + def boom(): + raise error + captured = io.StringIO() + saved_hook = threading.excepthook + threading.excepthook = threading.__excepthook__ + sys.tracebacklimit = 0 + try: + t = threading.Thread(target=boom, name=name) + with contextlib.redirect_stderr(captured): + t.start() + t.join() + finally: + del sys.tracebacklimit + threading.excepthook = saved_hook + return captured.getvalue() + + def new_mechanism_output(name): + exc._install_excepthook() + def boom(): + raise error + captured = io.StringIO() + t = threading.Thread(target=boom, name=name) + with contextlib.redirect_stderr(captured): + t.start() + t.join() + return captured.getvalue() + + old = old_mechanism_output('ChainedWorker') + new = new_mechanism_output('ChainedWorker') + if old == new: + print('MATCH') + else: + print('MISMATCH') + print('old:', repr(old)) + print('new:', repr(new)) + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertEqual(proc.stdout.strip(), 'MATCH', proc.stdout) + + def test_a_non_base_error_on_a_thread_is_delegated_to_the_previous_hook(self) -> None: + code = ''' + import sys + import threading + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + def previous_hook(args): + print('PREVIOUS_THREADING_HOOK_RAN', file=sys.stderr) + threading.__excepthook__(args) + threading.excepthook = previous_hook + + try: + raise exc.IntError('boom') + except exc.IntError: + pass + + print('INSTALLED:', getattr(threading.excepthook, 'installed_by_pcapkit', False), + file=sys.stderr) + print('IS_PCAPKIT_HOOK:', threading.excepthook is exc._threading_excepthook, + file=sys.stderr) + + def unrelated(): + raise ValueError('route through previous_hook') + + t = threading.Thread(target=unrelated) + t.start() + t.join() + ''' + proc = run_in_subprocess(code) + self.assertIn('INSTALLED: True', proc.stderr) + self.assertIn('IS_PCAPKIT_HOOK: True', proc.stderr) + self.assertIn('PREVIOUS_THREADING_HOOK_RAN', proc.stderr) + self.assertIn('ValueError: route through previous_hook', proc.stderr) + self.assertNotIn('IntError', proc.stderr.split('PREVIOUS_THREADING_HOOK_RAN')[-1]) + + def test_installing_twice_does_not_wrap_the_threading_hook_either(self) -> None: + code = ''' + import sys + import threading + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + + def previous_hook(args): + print('PREVIOUS_THREADING_HOOK_RAN', file=sys.stderr) + threading.__excepthook__(args) + threading.excepthook = previous_hook + + exc._install_excepthook() + first = threading.excepthook + exc._install_excepthook() + second = threading.excepthook + print('SAME_HOOK' if first is second else 'DIFFERENT_HOOK') + print('PREVIOUS_IS_MY_HOOK' if exc._previous_threading_excepthook is previous_hook + else 'PREVIOUS_IS_SOMETHING_ELSE') + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertIn('SAME_HOOK', proc.stdout) + self.assertIn('PREVIOUS_IS_MY_HOOK', proc.stdout) + + def test_a_reentrant_threading_delegate_falls_back_instead_of_recursing(self) -> None: + """The per-thread guard, not the main-thread one, protects this path.""" + code = ''' + import sys + import threading + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + exc._install_excepthook() + + calls = [] + def exploding_delegate(args): + calls.append(1) + if len(calls) > 3: + raise RecursionError('would spin forever without the guard') + exc._threading_excepthook(args) + exc._previous_threading_excepthook = exploding_delegate + + try: + raise ValueError('boom') + except ValueError: + etype, value, tb = sys.exc_info() + args = threading.ExceptHookArgs([etype, value, tb, threading.current_thread()]) + exc._threading_excepthook(args) + print(len(calls)) + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertEqual(int(proc.stdout.strip()), 1) + + def test_two_threads_raising_concurrently_do_not_confuse_each_others_guard(self) -> None: + """The per-thread (not shared) re-entrancy flag, under real concurrency. + + A shared ``_excepthook_running``-style flag would make one thread's + hook see the *other* thread's unrelated, concurrent call as if it were + its own re-entrancy, and wrongly fall back instead of printing tersely. + Both threads block on the same barrier immediately after entering the + hook (via a slow delegate that waits on it), so neither can finish + before the other has also entered -- forcing the overlap this guards + against, rather than hoping for it. + + """ + code = ''' + import sys + import threading + import pcapkit.utilities.exceptions as exc + exc.logger.disabled = True + exc._install_excepthook() + + barrier = threading.Barrier(2) + results = {} + + def slow_delegate(args): + # Hold this thread inside the hook until the other thread has + # also entered it, so the two calls genuinely overlap. + barrier.wait(timeout=5) + exc._previous_threading_excepthook = slow_delegate + + def worker(name): + try: + raise exc.IntError(f'boom from {name}') + except exc.IntError: + etype, value, tb = sys.exc_info() + args = threading.ExceptHookArgs([etype, value, tb, threading.current_thread()]) + # A BaseError does not reach slow_delegate at all -- it is + # printed directly -- so route a *non*-BaseError through this + # thread's own call to actually exercise the shared guard + # object instead, which is the thing under test. + non_base_args = threading.ExceptHookArgs( + [ValueError, ValueError(f'from {name}'), None, threading.current_thread()]) + exc._threading_excepthook(non_base_args) + results[name] = 'completed without raising' + + threads = [threading.Thread(target=worker, args=(f'T{i}',)) for i in range(2)] + for t in threads: + t.start() + for t in threads: + t.join(timeout=10) + + print(len(results), 'threads completed') + for name, outcome in sorted(results.items()): + print(name, outcome) + ''' + proc = run_in_subprocess(code) + self.assertEqual(proc.returncode, 0, proc.stderr) + self.assertIn('2 threads completed', proc.stdout) + self.assertIn('T0 completed without raising', proc.stdout) + self.assertIn('T1 completed without raising', proc.stdout) + + +if __name__ == '__main__': + unittest.main() diff --git a/tests/utilities/test_exceptions_warnings.py b/tests/utilities/test_exceptions_warnings.py index f5ea6cd2fb..2585d7b54d 100644 --- a/tests/utilities/test_exceptions_warnings.py +++ b/tests/utilities/test_exceptions_warnings.py @@ -24,22 +24,33 @@ def test_struct_error_records_eof_flag(self) -> None: self.assertTrue(error.eof) self.assertEqual(str(error), 'truncated') - def test_base_error_limits_traceback_in_non_dev_mode(self) -> None: - # Only a *loud* error does this: `sys.tracebacklimit` is process-global, - # and a quiet error is internal control flow that must not truncate - # unrelated tracebacks. See tests/utilities/test_quiet_exceptions.py. - original = getattr(sys, 'tracebacklimit', None) + def test_base_error_installs_an_excepthook_in_non_dev_mode(self) -> None: + # Only a *loud* error does this: the mechanism is process-global, and a + # quiet error is internal control flow that must not disturb it. See + # tests/utilities/test_quiet_exceptions.py. It used to be + # `sys.tracebacklimit = 0`, which is the #719 defect -- a loud error's + # own terseness truncated every *other* exception in the process too. + # It now installs an exception hook instead, which only shortens the + # printing of a BaseError; see + # tests/utilities/test_exceptions_excepthook.py for that hook's actual + # printing behaviour, end to end. + original_limit = getattr(sys, 'tracebacklimit', None) + original_hook = sys.excepthook try: + if hasattr(sys, 'tracebacklimit'): + del sys.tracebacklimit with mock.patch.object(self.exceptions, 'DEVMODE', False): with mock.patch.object(self.exceptions.logger, 'critical'): self.exceptions.BaseError('boom') - self.assertEqual(sys.tracebacklimit, 0) + self.assertFalse(hasattr(sys, 'tracebacklimit')) + self.assertTrue(getattr(sys.excepthook, 'installed_by_pcapkit', False)) finally: - if original is None: + if original_limit is None: if hasattr(sys, 'tracebacklimit'): del sys.tracebacklimit else: - sys.tracebacklimit = original + sys.tracebacklimit = original_limit + sys.excepthook = original_hook def test_base_error_devmode_logs_with_verbose_metadata(self) -> None: with mock.patch.object(self.exceptions, 'DEVMODE', True): diff --git a/tests/utilities/test_quiet_exceptions.py b/tests/utilities/test_quiet_exceptions.py index 66b91aa0d8..f199a6e8a2 100644 --- a/tests/utilities/test_quiet_exceptions.py +++ b/tests/utilities/test_quiet_exceptions.py @@ -52,6 +52,7 @@ class QuietExceptionTests(unittest.TestCase): def setUp(self) -> None: self._saved_devmode = os.environ.get('PCAPKIT_DEVMODE') self._saved_tracebacklimit = getattr(sys, 'tracebacklimit', None) + self._saved_excepthook = sys.excepthook # The defect, and the traceback truncation, only reproduce outside # development mode. modules = bootstrap(devmode=False) @@ -66,6 +67,10 @@ def tearDown(self) -> None: del sys.tracebacklimit else: sys.tracebacklimit = self._saved_tracebacklimit + # A loud error constructed by any test below now installs an exception + # hook (see tests/utilities/test_exceptions_excepthook.py) rather than + # setting sys.tracebacklimit -- so this has to be restored too. + sys.excepthook = self._saved_excepthook if self._saved_devmode is None: os.environ.pop('PCAPKIT_DEVMODE', None) else: @@ -125,6 +130,7 @@ def test_absent_key_subscript_still_raises(self) -> None: def test_quiet_error_leaves_tracebacklimit_alone(self) -> None: if hasattr(sys, 'tracebacklimit'): del sys.tracebacklimit + before_hook = sys.excepthook before = _unrelated_failure() with capture(self.logger): @@ -132,6 +138,11 @@ def test_quiet_error_leaves_tracebacklimit_alone(self) -> None: self.exceptions.BaseError('boom', quiet=True) self.assertFalse(hasattr(sys, 'tracebacklimit')) + # Also no side effect on the replacement mechanism: a quiet error must + # not install the exception hook either (see + # tests/utilities/test_exceptions_excepthook.py). + self.assertIs(sys.excepthook, before_hook) + self.assertIsNone(self.exceptions._previous_excepthook) self.assertEqual(_unrelated_failure(), before) self.assertGreater(before, 1) @@ -191,15 +202,26 @@ def test_loud_stream_eof_error_still_logs(self) -> None: self.assertEqual(recorder.messages, [('CRITICAL', 'StreamEOFError: boom')]) - def test_loud_error_still_limits_the_traceback(self) -> None: - """The feature a loud error provides is unchanged.""" + def test_loud_error_leaves_tracebacklimit_unset_and_installs_a_hook(self) -> None: + """The feature a loud error provides is unchanged; the mechanism is not. + + A loud error used to shorten its own printing by setting + ``sys.tracebacklimit = 0`` -- process-wide, for every exception, for the + rest of the process, which is the #719 defect. It now installs an + exception hook instead, which only shortens the printing of a + :class:`~pcapkit.utilities.exceptions.BaseError` itself; see + ``tests/utilities/test_exceptions_excepthook.py`` for what that hook + actually prints, end to end. + + """ if hasattr(sys, 'tracebacklimit'): del sys.tracebacklimit with capture(self.logger): self.exceptions.BaseError('boom') - self.assertEqual(sys.tracebacklimit, 0) + self.assertFalse(hasattr(sys, 'tracebacklimit')) + self.assertTrue(getattr(sys.excepthook, 'installed_by_pcapkit', False)) if __name__ == '__main__': diff --git a/tests/utilities/test_stacklevel.py b/tests/utilities/test_stacklevel.py index b5ae5a1320..d7fca2a91e 100644 --- a/tests/utilities/test_stacklevel.py +++ b/tests/utilities/test_stacklevel.py @@ -13,10 +13,12 @@ It also returned ``-1``, and not only in theory: :func:`traceback.extract_stack` honours :data:`sys.tracebacklimit`, which :class:`BaseError -` sets to ``0`` for every loud error -outside development mode. After the first such error the extracted stack was -*empty*, the ``for``/``else`` branch ran, and every subsequent warning in the -process got ``-1``. +` *used to* set to ``0`` for every loud +error outside development mode (GitHub issue #719 removed that -- it prints its +terse line through an exception hook instead, and no longer touches the global +at all). After the first such error the extracted stack was *empty*, the +``for``/``else`` branch ran, and every subsequent warning in the process got +``-1``. Three groups of tests here, because they fail for different reasons: @@ -363,13 +365,17 @@ def test_warning_is_not_attributed_to_pcapkit_itself(self) -> None: def test_a_truncated_traceback_limit_does_not_blind_the_walk(self) -> None: """``sys.tracebacklimit = 0`` must not change the answer. - :class:`~pcapkit.utilities.exceptions.BaseError` sets it for every loud - error outside development mode, and :func:`traceback.extract_stack` honours - it -- returning an *empty* list, on which the old implementation fell - through to its ``for``/``else`` and returned ``-1``. So in ordinary use the - first error silently broke the attribution of every warning after it, for - the life of the process. It is also why this only ever reproduced in a - full-suite run: alone, this module never raises a loud error first. + :class:`~pcapkit.utilities.exceptions.BaseError` *used to* set it for + every loud error outside development mode (GitHub issue #719 removed + that), and :func:`traceback.extract_stack` honours it -- returning an + *empty* list, on which the old implementation fell through to its + ``for``/``else`` and returned ``-1``. So in ordinary use the first error + silently broke the attribution of every warning after it, for the life + of the process. It is also why this only ever reproduced in a + full-suite run: alone, this module never raised a loud error first. + Nothing in :mod:`pcapkit` sets the global any more, but the frame walk + this guards is correct regardless of who does, which is exactly the + point of setting it by hand below rather than provoking it indirectly. """ saved = getattr(sys, 'tracebacklimit', None) @@ -428,9 +434,9 @@ def noisy(cls: 'type[Info]') -> 'type[Info]': def error_site(self) -> 'logging.LogRecord': """Provoke one :exc:`~pcapkit.utilities.exceptions.UnsupportedCall`. - Development mode is forced on because that is the branch which logs; the - other one sets :data:`sys.tracebacklimit` and reports no attribution to - read back. + Development mode is forced on because that is the branch which logs with + a ``stacklevel`` to read back at all; the other one logs with none, + installs pcapkit's own exception hook, and reports no attribution. """ recorder = Recorder()