Skip to content

Commit 69ea9b3

Browse files
committed
test(protocols): bound the #1428 deadline test so a lost alarm cannot hang the worker (#1889)
- examples/generators/options.py: each raise of _deadline re-arms the alarm for one more second until the deadline is settled. roundtrip settles it as the first statement of every `except` clause, __exit__ settles it before cancelling, and it is entered after catch_warnings so it is torn down first. A raise landing in a finaliser run by the cyclic collector, or in an `except OSError`, is dropped, and the single alarm then left the case spinning until pytest-timeout ended the xdist worker. - tests/protocols/test_option_generator_deadline_scale_1428_unit.py: _Spin gives up after SPIN_LIMIT, and the hang test then fails by name instead of hanging; new tests pin the repeat, the settled no-op, a lost alarm, and SIGALRM fired on every way out of roundtrip. - The option captures regenerate byte-identical. Closes #1889
1 parent 44ed96f commit 69ea9b3

2 files changed

Lines changed: 252 additions & 13 deletions

File tree

‎examples/generators/options.py‎

Lines changed: 39 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -102,7 +102,12 @@
102102
Python and holds the GIL for the whole of an iteration, so no watchdog thread
103103
would ever get to run. The deadline is wall-clock time, so a stalled runner
104104
can trip it on a case that normally takes milliseconds (#1428):
105-
:data:`TIMEOUT_SCALE_ENV` stretches it without disarming it.
105+
:data:`TIMEOUT_SCALE_ENV` stretches it without disarming it. It also repeats
106+
every second until :func:`roundtrip` has the :exc:`TimeoutError`, because one
107+
raise can be lost: a finaliser the cyclic collector runs reports it to
108+
:func:`sys.unraisablehook` and drops it, and an ``except OSError`` drops it too,
109+
:exc:`TimeoutError` being one. A single alarm then left the case running for good
110+
(#1889).
106111
107112
"""
108113

@@ -1744,7 +1749,13 @@ def roundtrip(case: 'Case', deadline: 'int' = DEADLINE) -> 'Outcome':
17441749
octets = b''
17451750
again = b''
17461751

1747-
with _deadline(deadline), warnings.catch_warnings(record=True) as caught:
1752+
# The deadline is entered last, so it is torn down first: nothing of
1753+
# catch_warnings runs on the way out while it can still fire. And
1754+
# ``limit.settled`` is the first statement of every ``except`` clause, so a
1755+
# repeat that fires while the outcome is being built is a no-op (#1889). An
1756+
# attribute store rather than a method call, which would give a repeat
1757+
# already due one more place to land.
1758+
with warnings.catch_warnings(record=True) as caught, _deadline(deadline) as limit:
17481759
warnings.simplefilter('always')
17491760

17501761
def seen() -> 'tuple[str, ...]':
@@ -1764,8 +1775,10 @@ def seen() -> 'tuple[str, ...]':
17641775
try:
17651776
octets = bytes(family.build(case.code, case.kwargs))
17661777
except TimeoutError as exc:
1778+
limit.settled = True
17671779
return Outcome(case, 'TIMEOUT', str(exc), None, seen())
17681780
except Exception as exc: # pylint: disable=broad-except
1781+
limit.settled = True
17691782
# Broad on purpose: the point is to find out *what* a constructor
17701783
# does when it is wrong, and narrowing this to ProtocolError would
17711784
# let an AttributeError or a KeyError -- which is what most of the
@@ -1776,20 +1789,24 @@ def seen() -> 'tuple[str, ...]':
17761789
try:
17771790
parsed = family.extract(family.parse(octets))
17781791
except TimeoutError as exc:
1792+
limit.settled = True
17791793
return Outcome(case, 'TIMEOUT', str(exc), octets, seen())
17801794
except Exception as exc: # pylint: disable=broad-except
1795+
limit.settled = True
17811796
return Outcome(case, 'PARSE', f'{type(exc).__name__}: {exc}', octets, seen())
17821797

17831798
try:
17841799
again = bytes(family.rebuild(parsed))
17851800
except TimeoutError as exc:
1801+
limit.settled = True
17861802
return Outcome(case, 'TIMEOUT', str(exc), octets, seen())
17871803
except Exception as exc: # pylint: disable=broad-except
1804+
limit.settled = True
17881805
return Outcome(case, 'RECONSTRUCT', f'{type(exc).__name__}: {exc}',
17891806
octets, seen())
17901807

1791-
warned = seen()
1792-
1808+
# Read after the deadline is gone; ``caught`` outlives the ``with``.
1809+
warned = seen()
17931810
if octets != again:
17941811
return Outcome(case, 'MISMATCH', f'{octets.hex()} != {again.hex()}',
17951812
octets, warned)
@@ -1842,6 +1859,11 @@ class _deadline: # pylint: disable=invalid-name
18421859
:exc:`TimeoutError` names the stretched value -- the seconds actually
18431860
allowed.
18441861
1862+
Each raise re-arms the alarm for one more second, so the raise repeats until
1863+
the body sets :attr:`settled`, or :meth:`__exit__` does (#1889). One raise is
1864+
not enough: one that lands in a finaliser, or in an ``except OSError``, never
1865+
reaches the body, and a single alarm then left a hung case hung.
1866+
18451867
Written as a class rather than a :func:`contextlib.contextmanager` so that
18461868
it can be entered alongside :func:`warnings.catch_warnings` in one ``with``
18471869
statement without the generator machinery swallowing the alarm.
@@ -1862,6 +1884,10 @@ def __init__(self, seconds: 'int') -> 'None':
18621884
self.armed = False
18631885
#: Handler displaced by :meth:`__enter__`, restored by :meth:`__exit__`.
18641886
self.previous = None # type: Any
1887+
#: Set by the body once it has caught what ends it, and by
1888+
#: :meth:`__exit__`: a firing after that does nothing, so it cannot
1889+
#: interrupt the way out.
1890+
self.settled = False
18651891

18661892
def __enter__(self) -> '_deadline':
18671893
if self.seconds <= 0 or not hasattr(signal, 'SIGALRM'):
@@ -1870,7 +1896,12 @@ def __enter__(self) -> '_deadline':
18701896
# nothing installed that would need restoring.
18711897
self.seconds = scale_deadline(self.seconds)
18721898

1873-
def expire(signum: 'int', frame: 'Any') -> 'None':
1899+
def expire(signum: 'int', frame: 'Any') -> 'None': # pylint: disable=unused-argument
1900+
if self.settled:
1901+
return
1902+
# Re-armed before raising, so a raise that never reaches the body
1903+
# is followed by another one.
1904+
signal.alarm(1)
18741905
raise TimeoutError(f'did not finish within {self.seconds}s')
18751906

18761907
self.previous = signal.signal(signal.SIGALRM, expire)
@@ -1879,6 +1910,9 @@ def expire(signum: 'int', frame: 'Any') -> 'None':
18791910
return self
18801911

18811912
def __exit__(self, *exc_info: 'Any') -> 'None':
1913+
# Settled before anything else, on every way out: a firing before the
1914+
# cancel below must not re-arm and raise, which would skip the restore.
1915+
self.settled = True
18821916
if self.armed:
18831917
# Cancel before restoring, so an alarm firing between the two
18841918
# cannot be delivered to whatever handler was installed before.

‎tests/protocols/test_option_generator_deadline_scale_1428_unit.py‎

Lines changed: 213 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,12 @@
1010
and ``PCAPKIT_TEST_TIMEOUT_SCALE`` stretches it exactly as it stretches
1111
:func:`tests._support.time_limit`.
1212
13+
The spin that stands in for a hang is bounded (#1889). Unbounded, a deadline
14+
whose raise was lost -- one raised inside a finaliser is reported and dropped --
15+
spun until pytest-timeout's backstop ended the whole xdist worker. Now it gives up
16+
after :data:`SPIN_LIMIT` and the test fails by name, and the generator repeats
17+
the raise until :func:`roundtrip` has it.
18+
1319
This module is unit tier: it loads the generator by path and builds nothing, so
1420
it imports no :mod:`pcapkit` and reads no capture.
1521
@@ -21,8 +27,11 @@
2127
import os
2228
import signal
2329
import sys
30+
import threading
31+
import time
2432
import types
2533
import unittest
34+
import warnings
2635
from typing import TYPE_CHECKING
2736
from unittest import mock
2837

@@ -35,6 +44,11 @@
3544
#: different name fails here rather than agreeing with itself.
3645
SCALE_ENV = 'PCAPKIT_TEST_TIMEOUT_SCALE'
3746

47+
#: Seconds :class:`_Spin` runs before it gives up on being interrupted: ten times
48+
#: the one-second deadline the tests here arm, so a deadline that fires at all,
49+
#: repeats included, lands well inside it.
50+
SPIN_LIMIT = 10.0
51+
3852

3953
def _load_generator() -> 'types.ModuleType':
4054
"""Load :file:`examples/generators/options.py` by path, under a name of its own.
@@ -58,13 +72,85 @@ def _load_generator() -> 'types.ModuleType':
5872
return module
5973

6074

75+
class _SpinGaveUp(Exception):
76+
"""Raised by :class:`_Spin` once its limit passes with no deadline raised in it."""
77+
78+
6179
class _Spin: # pylint: disable=too-few-public-methods
62-
"""A family whose constructor never returns, standing in for a real hang."""
80+
"""A family whose constructor spins until the deadline interrupts it.
81+
82+
It stands in for a real hang, but a bounded one: after ``limit`` seconds it
83+
sets :attr:`gave_up` and raises :exc:`_SpinGaveUp`, so a lost deadline fails
84+
the test in seconds instead of hanging the worker.
85+
86+
Args:
87+
limit: Seconds to spin before giving up.
88+
swallow: How many :exc:`TimeoutError` to drop before letting one
89+
through, standing in for a finaliser that drops the deadline's raise.
90+
clear: Cancel the pending alarm on entry, so no deadline ever fires.
91+
92+
"""
93+
94+
def __init__(self, limit: float = SPIN_LIMIT, swallow: int = 0,
95+
clear: bool = False) -> None:
96+
self.limit = limit
97+
self.swallow = swallow
98+
self.clear = clear
99+
#: :exc:`TimeoutError` dropped so far.
100+
self.swallowed = 0
101+
#: Whether the limit passed before a deadline got through.
102+
self.gave_up = False
103+
104+
def build(self, code: 'Any', kwargs: 'Any') -> bytes: # pylint: disable=unused-argument
105+
"""Loop until the deadline interrupts it, or until :attr:`limit` passes."""
106+
if self.clear:
107+
signal.alarm(0)
108+
end = time.monotonic() + self.limit
109+
while time.monotonic() < end:
110+
try:
111+
while time.monotonic() < end:
112+
pass
113+
except TimeoutError:
114+
if self.swallowed == self.swallow:
115+
raise
116+
self.swallowed += 1
117+
self.gave_up = True
118+
raise _SpinGaveUp(f'no deadline interrupted the spin within {self.limit:g}s')
119+
120+
121+
class _Abort(BaseException):
122+
"""Leaves :func:`roundtrip` past every ``except Exception`` clause."""
123+
124+
125+
class _RaiseAt:
126+
"""A family that raises ``exc`` at ``step``, or round-trips one octet if it is :data:`None`."""
127+
128+
def __init__(self, step: 'str | None', exc: 'BaseException | None') -> None:
129+
self.step = step
130+
self.exc = exc
131+
132+
def _at(self, step: str) -> None:
133+
if step == self.step and self.exc is not None:
134+
raise self.exc
63135

64136
def build(self, code: 'Any', kwargs: 'Any') -> bytes: # pylint: disable=unused-argument
65-
"""Loop until the deadline interrupts it."""
66-
while True:
67-
pass
137+
"""One zero octet, unless this is the step to raise at."""
138+
self._at('build')
139+
return b'\x00'
140+
141+
def parse(self, octets: bytes) -> bytes:
142+
"""``octets`` as they are, unless this is the step to raise at."""
143+
self._at('parse')
144+
return octets
145+
146+
def extract(self, parsed: bytes) -> bytes:
147+
"""``parsed`` as it is."""
148+
return parsed
149+
150+
def rebuild(self, parsed: bytes) -> bytes:
151+
"""``parsed`` as it is, unless this is the step to raise at."""
152+
self._at('rebuild')
153+
return parsed
68154

69155

70156
@unittest.skipUnless(hasattr(signal, 'SIGALRM'), 'needs signal.SIGALRM')
@@ -94,6 +180,19 @@ def armed(self, seconds: int) -> int:
94180
with self.options._deadline(seconds): # pylint: disable=protected-access
95181
return signal.alarm(0)
96182

183+
def roundtrip(self, family: 'Any') -> 'Any':
184+
""":func:`roundtrip` over ``family`` under a one-second deadline (scale 0.5 x 2s)."""
185+
os.environ[SCALE_ENV] = '0.5'
186+
case = self.options.Case('spin', 0, 'Spin', {})
187+
with mock.patch.dict(self.options.FAMILY_MAP, {'spin': family}):
188+
return self.options.roundtrip(case, deadline=2)
189+
190+
def assert_interrupted(self, spin: '_Spin', outcome: 'Any') -> None:
191+
"""Fail by name, rather than on a status mismatch, if the deadline never got through."""
192+
if spin.gave_up:
193+
self.fail(f'the deadline never interrupted the spin; roundtrip recorded '
194+
f'{outcome.status}: {outcome.detail}')
195+
97196
def test_the_default_is_thirty_seconds_unscaled(self) -> None:
98197
"""Unset, the default applies as written -- and it is no longer 5."""
99198
self.assertEqual(self.options.DEADLINE, 30)
@@ -142,13 +241,119 @@ def test_a_zero_deadline_stays_disarmed_under_any_scale(self) -> None:
142241

143242
def test_a_hang_is_still_recorded_as_timeout_naming_the_scaled_deadline(self) -> None:
144243
"""The ``'TIMEOUT'`` contract holds, and its detail names the seconds allowed."""
145-
os.environ[SCALE_ENV] = '0.5'
146-
case = self.options.Case('spin', 0, 'Spin', {})
147-
with mock.patch.dict(self.options.FAMILY_MAP, {'spin': _Spin()}):
148-
outcome = self.options.roundtrip(case, deadline=2)
244+
spin = _Spin()
245+
outcome = self.roundtrip(spin)
246+
self.assert_interrupted(spin, outcome)
247+
self.assertEqual(outcome.status, 'TIMEOUT')
248+
self.assertEqual(outcome.detail, 'did not finish within 1s')
249+
self.assertIs(signal.getsignal(signal.SIGALRM), self.handler)
250+
251+
def test_a_raise_that_never_reaches_the_body_is_repeated(self) -> None:
252+
"""#1889: a dropped raise is followed by another, still recorded as ``'TIMEOUT'``."""
253+
spin = _Spin(swallow=1)
254+
outcome = self.roundtrip(spin)
255+
self.assert_interrupted(spin, outcome)
256+
self.assertEqual(spin.swallowed, 1)
149257
self.assertEqual(outcome.status, 'TIMEOUT')
150258
self.assertEqual(outcome.detail, 'did not finish within 1s')
151259
self.assertIs(signal.getsignal(signal.SIGALRM), self.handler)
260+
self.assertEqual(signal.alarm(0), 0)
261+
262+
def test_each_raise_re_arms_until_the_body_settles_it(self) -> None:
263+
"""A raise re-arms one second; once :attr:`settled` is set, a firing does nothing."""
264+
with self.options._deadline(5) as limit: # pylint: disable=protected-access
265+
expire = signal.getsignal(signal.SIGALRM)
266+
with self.assertRaisesRegex(TimeoutError, 'did not finish within 5s'):
267+
expire(signal.SIGALRM, None)
268+
self.assertEqual(signal.alarm(5), 1)
269+
limit.settled = True
270+
self.assertIsNone(expire(signal.SIGALRM, None))
271+
self.assertIn(signal.alarm(0), (4, 5))
272+
self.assertIs(signal.getsignal(signal.SIGALRM), self.handler)
273+
274+
def test_a_lost_deadline_fails_in_seconds_rather_than_hanging(self) -> None:
275+
"""#1889: with the alarm cancelled under it, the spin gives up and the test says why."""
276+
spin = _Spin(limit=0.5, clear=True)
277+
outcome = self.roundtrip(spin)
278+
self.assertTrue(spin.gave_up)
279+
self.assertEqual(outcome.status, 'CONSTRUCT')
280+
self.assertEqual(outcome.detail,
281+
'_SpinGaveUp: no deadline interrupted the spin within 0.5s')
282+
with self.assertRaisesRegex(AssertionError, 'the deadline never interrupted the spin'):
283+
self.assert_interrupted(spin, outcome)
284+
285+
@unittest.skipUnless(hasattr(signal, 'pthread_kill'), 'needs signal.pthread_kill')
286+
def test_a_firing_on_the_way_out_leaves_nothing_behind(self) -> None:
287+
"""#1889: ``SIGALRM`` on the way out of :func:`roundtrip` changes nothing.
288+
289+
Fired while the outcome is built, just before :meth:`_deadline.__exit__`
290+
cancels the alarm, and from :meth:`warnings.catch_warnings.__exit__`, on
291+
every way out: each step's ``'TIMEOUT'`` and failure, a
292+
:exc:`BaseException`, and ``'OK'``. Each time the outcome or the exception
293+
comes back as it was, no alarm is left pending, and the handler is this
294+
test's again. ``reached`` is whether the firing found the deadline's
295+
handler still installed.
296+
"""
297+
real_alarm = signal.alarm
298+
real_outcome = self.options.Outcome
299+
real_exit = warnings.catch_warnings.__exit__
300+
fired = [] # type: list[bool]
301+
302+
def fire() -> None:
303+
fired.append(signal.getsignal(signal.SIGALRM) is not self.handler)
304+
# Delivered to this thread, and its handler run before this returns.
305+
signal.pthread_kill(threading.get_ident(), signal.SIGALRM)
306+
307+
def firing_outcome(*args: 'Any') -> 'Any':
308+
if not fired:
309+
fire()
310+
return real_outcome(*args)
311+
312+
def firing_alarm(seconds: int) -> int:
313+
if not seconds and not fired:
314+
fire()
315+
return real_alarm(seconds)
316+
317+
def firing_exit(manager: 'Any', *exc_info: 'Any') -> 'Any':
318+
fire()
319+
return real_exit(manager, *exc_info)
320+
321+
where = {
322+
'outcome': lambda: mock.patch.object(self.options, 'Outcome', firing_outcome),
323+
'cancel': lambda: mock.patch.object(signal, 'alarm', firing_alarm),
324+
'catch_warnings': lambda: mock.patch.object(warnings.catch_warnings, '__exit__',
325+
firing_exit),
326+
}
327+
ways_out = (
328+
('build', TimeoutError, 'TIMEOUT'), ('build', ValueError, 'CONSTRUCT'),
329+
('parse', TimeoutError, 'TIMEOUT'), ('parse', ValueError, 'PARSE'),
330+
('rebuild', TimeoutError, 'TIMEOUT'), ('rebuild', ValueError, 'RECONSTRUCT'),
331+
('build', _Abort, '_Abort'), (None, None, 'OK'),
332+
)
333+
for point, patch in where.items():
334+
for step, error, expected in ways_out:
335+
if point == 'outcome' and expected == '_Abort':
336+
continue # no outcome is built on that way out
337+
# Only an ``'OK'`` outcome is built after the deadline is gone.
338+
reached = point == 'cancel' or (point == 'outcome' and expected != 'OK')
339+
with self.subTest(fired=point, step=step, result=expected):
340+
fired.clear()
341+
try:
342+
with patch():
343+
result = self.roundtrip(_RaiseAt(step, error and error()))
344+
except (_Abort, TimeoutError) as exc:
345+
result = exc
346+
finally:
347+
pending = real_alarm(0)
348+
handler = signal.signal(signal.SIGALRM, self.handler)
349+
# One comparison, so a failure shows the leak and the result together.
350+
self.assertEqual(
351+
{'result': (result.status if isinstance(result, real_outcome)
352+
else type(result).__name__),
353+
'reached': fired, 'pending': pending,
354+
'restored': handler is self.handler},
355+
{'result': expected, 'reached': [reached], 'pending': 0,
356+
'restored': True})
152357

153358

154359
if __name__ == '__main__':

0 commit comments

Comments
 (0)