-
Notifications
You must be signed in to change notification settings - Fork 1.5k
Expand file tree
/
Copy pathtest_timeout_diagnostics.py
More file actions
317 lines (276 loc) · 10.4 KB
/
Copy pathtest_timeout_diagnostics.py
File metadata and controls
317 lines (276 loc) · 10.4 KB
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
"""Regression tests for diagnostic evidence retained after an async timeout."""
import asyncio
import io
import os
import signal
import subprocess
import sys
from pathlib import Path
from types import SimpleNamespace
import pytest
from copilot._jsonrpc import JsonRpcClient
from copilot.session import CopilotSession
from e2e import timeout_diagnostics
from e2e.timeout_diagnostics import (
_dump_awaitable,
_sample_native_threads,
add_timeout_diagnostics,
)
@pytest.mark.parametrize("blocked_write", [False, True])
async def test_timeout_report_identifies_pending_rpc_without_payloads(
tmp_path, monkeypatch, blocked_write
):
rpc = JsonRpcClient(None)
rpc._loop = asyncio.get_running_loop()
sent = asyncio.Event()
release_write = asyncio.Event()
async def send_message(message):
sent.set()
if blocked_write:
await release_write.wait()
monkeypatch.setattr(rpc, "_send_message", send_message)
task = asyncio.create_task(
rpc.request(
"session.resume",
{"sessionId": "diagnostic-session", "githubToken": "secret-not-in-diagnostics"},
),
name="pending-resume",
)
try:
await sent.wait()
client = SimpleNamespace(_client=rpc, _sessions={}, _ffi_host=None)
item = SimpleNamespace(
nodeid="test_session_config_e2e.py::test_resume",
config=SimpleNamespace(rootpath=tmp_path),
funcargs={"ctx": SimpleNamespace(_client=client)},
stash=pytest.Stash(),
)
call = SimpleNamespace(
excinfo=SimpleNamespace(value=Exception("Timeout (>300.0s) from pytest-timeout."))
)
report = SimpleNamespace(failed=True, when="call", sections=[])
# Snapshotting must not try to acquire a potentially orphaned SDK lock.
with rpc._pending_lock:
add_timeout_diagnostics(item, call, report)
title, text = report.sections[0]
assert title == "Async timeout diagnostics"
assert "Phase: call" in text
assert "Task pending-resume" in text
assert "JsonRpcClient.request" in text
assert "outbound method=session.resume" in text
assert "session_id=diagnostic-session" in text
assert f"pending request_id={next(iter(rpc.pending_requests))} done=False" in text
assert "pending_locked=True" in text
if blocked_write:
assert "<locals>.send_message" in text
else:
assert "awaiting FutureIter" in text
assert "secret-not-in-diagnostics" not in text
assert "githubToken" not in text
(artifact,) = (tmp_path / ".pytest-diagnostics").glob("*.txt")
assert artifact.read_text(encoding="utf-8") == text
assert report.failed
assert not task.done()
finally:
task.cancel()
await asyncio.gather(task, return_exceptions=True)
async def test_teardown_dump_follows_async_generator_and_disconnect_lock(monkeypatch):
rpc = JsonRpcClient(None)
rpc._loop = asyncio.get_running_loop()
sent = asyncio.Event()
async def send_message(message):
sent.set()
monkeypatch.setattr(rpc, "_send_message", send_message)
session = CopilotSession("diagnostic-session", rpc)
disconnect = asyncio.create_task(session.disconnect())
teardown_started = asyncio.Event()
async def fixture():
yield
teardown_started.set()
await session.disconnect()
generator = fixture()
await anext(generator)
async def finalize():
await anext(generator)
finalizer = None
try:
await sent.wait()
finalizer = asyncio.create_task(finalize())
await teardown_started.wait()
output = io.StringIO()
_dump_awaitable(finalizer.get_coro(), output)
text = output.getvalue()
assert "async_generator_asend" in text
assert "<locals>.fixture" in text
assert "CopilotSession.disconnect" in text
assert "Lock.acquire" in text
assert not finalizer.done()
assert not disconnect.done()
finally:
tasks = [disconnect] + ([finalizer] if finalizer is not None else [])
for task in tasks:
task.cancel()
await asyncio.gather(*tasks, return_exceptions=True)
await generator.aclose()
@pytest.mark.parametrize("error", [None, AssertionError("ordinary failure")])
def test_non_timeout_does_not_collect_diagnostics(error):
item = SimpleNamespace()
call = SimpleNamespace(excinfo=None if error is None else SimpleNamespace(value=error))
report = SimpleNamespace(failed=error is not None, sections=[])
add_timeout_diagnostics(item, call, report)
assert report.sections == []
def test_native_sample_is_bounded_and_targets_this_worker(tmp_path, monkeypatch):
calls = []
def run(args, **kwargs):
calls.append((args, kwargs))
return SimpleNamespace(returncode=0)
monkeypatch.setattr(subprocess, "run", run)
path = tmp_path / "native.sample.txt"
output = io.StringIO()
_sample_native_threads(path, output)
args, options = calls[0]
assert args == ["sample", str(os.getpid()), "1", "-file", str(path)]
assert options["timeout"] == 10
assert "Native sample exit=0" in output.getvalue()
@pytest.mark.parametrize(
"error", [FileNotFoundError(), subprocess.TimeoutExpired("sample", timeout=10)]
)
def test_native_sample_failure_preserves_diagnostics(tmp_path, monkeypatch, error):
def run(*args, **kwargs):
raise error
monkeypatch.setattr(subprocess, "run", run)
output = io.StringIO()
_sample_native_threads(tmp_path / "native.sample.txt", output)
assert f"Native sample unavailable: {type(error).__name__}" in output.getvalue()
async def test_signal_snapshot_precedes_task_cleanup_and_keeps_original_failure(
tmp_path, monkeypatch
):
installed = []
failure = pytest.fail.Exception("Timeout (>300.0s) from pytest-timeout.")
def original_handler(signum, frame):
raise failure
monkeypatch.setattr(signal, "SIGALRM", 12345, raising=False)
monkeypatch.setattr(signal, "getsignal", lambda signum: original_handler)
monkeypatch.setattr(signal, "signal", lambda signum, handler: installed.append(handler))
rpc = JsonRpcClient(None)
rpc._loop = asyncio.get_running_loop()
client = SimpleNamespace(_client=rpc, _sessions={}, _ffi_host=None)
item = SimpleNamespace(
nodeid="test_teardown",
config=SimpleNamespace(rootpath=tmp_path),
funcargs={"ctx": SimpleNamespace(_client=client)},
stash=pytest.Stash(),
)
hook = timeout_diagnostics.pytest_timeout_set_timer(item, SimpleNamespace(method="signal"))
next(hook)
with pytest.raises(StopIteration):
next(hook)
started = asyncio.Event()
async def teardown_waiting_for_disconnect():
started.set()
await asyncio.Future()
task = asyncio.create_task(teardown_waiting_for_disconnect())
try:
await started.wait()
with pytest.raises(pytest.fail.Exception) as caught:
installed[0](signal.SIGALRM, None)
assert caught.value is failure
finally:
task.cancel()
await asyncio.gather(task, return_exceptions=True)
report = SimpleNamespace(failed=True, when="teardown", sections=[])
add_timeout_diagnostics(item, SimpleNamespace(excinfo=SimpleNamespace(value=failure)), report)
text = report.sections[0][1]
assert "Phase: teardown" in text
assert (
"in test_signal_snapshot_precedes_task_cleanup_and_keeps_original_failure.<locals>." in text
)
assert "teardown_waiting_for_disconnect" in text
assert not item.stash
@pytest.mark.parametrize("phase", ["call", "teardown"] if hasattr(signal, "SIGALRM") else ["call"])
def test_timeout_report_survives_xdist_without_stdout_capture(tmp_path, phase):
# Exercise the real signal timeout on POSIX. On Windows emulate its exception
# at the event-loop boundary, since the thread timeout terminates the worker.
(tmp_path / "conftest.py").write_text(
"""
import pytest
from e2e.timeout_diagnostics import add_timeout_diagnostics
from e2e.timeout_diagnostics import pytest_timeout_set_timer as pytest_timeout_set_timer
@pytest.hookimpl(hookwrapper=True)
def pytest_runtest_makereport(item, call):
outcome = yield
add_timeout_diagnostics(item, call, outcome.get_result())
""",
encoding="utf-8",
)
(tmp_path / "test_stalled.py").write_text(
"""
import asyncio
import signal
import pytest
@pytest.fixture
def runner():
with asyncio.Runner() as runner:
yield runner
def stall(runner):
loop = runner.get_loop()
if not hasattr(signal, "SIGALRM"):
run_once = loop._run_once
def interrupt_loop():
run_once()
loop._run_once = run_once
pytest.fail("Timeout (>1.0s) from pytest-timeout.")
loop._run_once = interrupt_loop
async def stalled_rpc():
await asyncio.Future()
runner.run(stalled_rpc())
@pytest.fixture
def cleanup(runner):
yield
if PHASE == "teardown":
stall(runner)
@pytest.mark.timeout(
1 if hasattr(signal, "SIGALRM") else 10,
method="signal" if hasattr(signal, "SIGALRM") else "thread",
)
def test_stalled(runner, cleanup):
if PHASE == "call":
stall(runner)
""",
encoding="utf-8",
)
with (tmp_path / "test_stalled.py").open("a", encoding="utf-8") as source:
source.write(f"\nPHASE = {phase!r}\n")
env = dict(os.environ)
env["PYTHONPATH"] = str(Path(__file__).parent.resolve())
result = subprocess.run(
[
sys.executable,
"-m",
"pytest",
"-v",
"-s",
"-n",
"1",
"--dist=loadfile",
"--basetemp",
str(tmp_path / "workers"),
"--rootdir",
str(tmp_path),
str(tmp_path / "test_stalled.py"),
],
cwd=tmp_path,
env=env,
capture_output=True,
text=True,
timeout=30,
check=False,
)
assert result.returncode == 1, result.stdout + result.stderr
assert ("1 failed" if phase == "call" else "1 error") in result.stdout
assert "Async timeout diagnostics" in result.stdout
assert f"Phase: {phase}" in result.stdout
assert "stalled_rpc" in result.stdout
assert "awaiting FutureIter" in result.stdout
(artifact,) = (tmp_path / ".pytest-diagnostics").glob("*.txt")
assert "stalled_rpc" in artifact.read_text(encoding="utf-8")