Skip to content

[BUG] --report ndjson writes only the Initialize event since 4.27.3 — writer thread dies on _DeadlockError from the lazy import requests added in #4792 (silent data loss, exit 0) #4807

Description

@PeterObeden

Checklist

  • I checked the FAQ section of the documentation
  • I looked for similar issues in the issue tracker
  • I am using the latest version of Schemathesis

Describe the bug

Severity: urgent — silent data loss with exit code 0. Since 4.27.3, st run … --report ndjson writes a file containing a single Initialize line and nothing else: no LoadingStarted, PhaseStarted, ScenarioStarted, ScenarioFinished, SuiteFinished or EngineFinished. The console summary is complete and correct, the CLI exits 0, and the Reports section lists the NDJSON path as if it had been written. Nothing in the output indicates a problem. The other five report formats (JUnit, VCR, HAR, JSON, Allure) are intact.

The documented contract for the flag is that it "exports all engine events as newline-delimited JSON, useful for analysis and tooling integration" (https://schemathesis.readthedocs.io/en/stable/reference/cli/#-report-ndjson-path-filename). Anything consuming that stream now sees an empty run with no error anywhere, and the CLI's exit code says the run was fine.

Cause. #4792 ("perf: st starts about 2.5x faster", commit 5c2b5ae, merged 2026-09-16, shipped in 4.27.3 on 2026-09-17) moved import requests in src/schemathesis/reporting/ndjson.py from module level (old line 13, removed) into serialize() (new line 114:

). It is the only change to that file between v4.27.2 and v4.27.3 (diff -u of the two installed packages):

@@ -10,8 +10,6 @@
 from types import TracebackType
 from typing import IO, TYPE_CHECKING, Any

-import requests
-
 from schemathesis.core import NOT_SET
@@ -112,6 +110,9 @@ def serialize(obj: Any, *, sanitization: SanitizationConfig | None = None) -> Any:
         if obj.is_truncated:
             data["content_size"] = obj.content_size
         return data
+    # Imported late so the CLI does not load `requests` before a command needs it.
+    import requests
+
     if isinstance(obj, requests.PreparedRequest):

serialize() runs on the SchemathesisNdjsonWriter thread (cli/commands/run/handlers/ndjson.py::NdjsonHandler.start spawns it; _run() loops queue.get()writer.write_event()serialize()). That thread starts on Initialize, before the schema is loaded. The first event after Initialize makes it execute import requests while the main thread is loading the schema and, via the lazy from schemathesis.specs.openapi.schemas import OpenApiSchema in openapi/loaders.py::from_dict (line 241), executing specs/openapi/schemas.py:11 from requests.structures import CaseInsensitiveDict. The two threads take the requests and requests.structures import locks in opposite order and importlib's cycle detector raises _DeadlockError in the writer.

_run() has no exception handling, so the thread ends, NdjsonWriter.__exit__ closes the file, every later queue.put goes to a dead consumer, and shutdown()'s bounded worker.join(WRITER_WORKER_JOIN_TIMEOUT) lets the CLI finish normally. The traceback reaches stderr through threading.excepthook only; the exit code and summary are unchanged.

Before #4792 the module-level import meant requests was fully loaded on the main thread at CLI import time, before any thread existed, so the imports could never coincide. reporting/ndjson.py on master still has the in-function import at line 114 as of 2026-09-18, so 4.27.4 will ship it unless fixed.

To Reproduce

  1. Start any HTTP server (below: a stdlib ThreadingHTTPServer on 127.0.0.1:PORT answering 200 {"ok": true} to every GET).
  2. Save the minimal schema below as spec.json.
  3. Run:
st run spec.json --url http://127.0.0.1:PORT --max-examples 2 --phases fuzzing \
   --checks not_a_server_error --report ndjson --report-ndjson-path out.ndjson --workers 1 --seed 1
  1. wc -l out.ndjson1 on 4.27.3; 23 on 4.27.1 and 4.27.2. head -c 20 out.ndjson{"Initialize": {…. The console shows Tested: 2, 4 generated, 4 passed, exit code 0, and lists out.ndjson under Reports.

Minimal schema:

{
  "openapi": "3.0.3",
  "info": {"title": "stub", "version": "1.0.0"},
  "paths": {
    "/health": {
      "get": {
        "operationId": "health",
        "responses": {"200": {"description": "ok", "content": {"application/json": {"schema": {"type": "object"}}}}}
      }
    },
    "/items/{id}": {
      "get": {
        "operationId": "getItem",
        "parameters": [{"name": "id", "in": "path", "required": true, "schema": {"type": "string"}}],
        "responses": {"200": {"description": "ok", "content": {"application/json": {"schema": {"type": "object"}}}}}
      }
    }
  }
}

Reproduction rate — 3 versions × 2 worker counts × 20 runs (120 runs). Each run is a fresh subprocess of the venv's interpreter invoking the CLI the way the console script does (python -c "import sys; from schemathesis.cli import schemathesis; sys.argv=['schemathesis']+sys.argv[1:]; schemathesis()" run …), same stub, same schema, same seed. "complete" = EngineFinished present AND ScenarioFinished count == console Tested.

version workers complete / runs NDJSON lines ScenarioFinished console Tested exit wall-clock min / median / max
4.27.1 1 20/20 23 2 2 0 0.45 / 0.48 / 1.16 s
4.27.1 12 20/20 23 2 2 0 0.48 / 0.50 / 1.16 s
4.27.2 1 20/20 23 2 2 0 0.46 / 0.48 / 1.15 s
4.27.2 12 20/20 23 2 2 0 0.49 / 0.50 / 1.10 s
4.27.3 1 0/20 1 0 2 0 0.46 / 0.47 / 1.16 s
4.27.3 12 0/20 1 0 2 0 0.47 / 0.49 / 1.14 s

Event mix of a complete file (4.27.1/4.27.2): Initialize 1, LoadingStarted 1, LoadingFinished 1, EngineStarted 1, PhaseStarted 6, PhaseFinished 6, SuiteStarted 1, ScenarioStarted 2, ScenarioFinished 2, SuiteFinished 1, EngineFinished 1. On 4.27.3, every run: Initialize 1. Deterministic, not intermittent: 40 of 40 runs on 4.27.3 lost the file; 80 of 80 on the two prior versions were complete.

Causation, two independent ways (20 runs each, workers 1 and 12, same stub/schema/seed):

variant on 4.27.3 workers 1 workers 12
(a) import requests executed on the main thread before from schemathesis.cli import schemathesis 20/20 20/20
(b) the #4792 hunk reverted in the installed package (module-level import requests restored in reporting/ndjson.py, nothing else changed) 20/20 20/20

Untouched 4.27.3: 0/40. (a) and (b): 40/40 each.

Expected behavior

out.ndjson contains every engine event of the run (23 lines for this schema), ending with EngineFinished, as on 4.27.2 and as documented. If the writer thread ever fails, the run should say so — in the summary and ideally in the exit code — rather than exit 0 with the path listed under Reports.

Environment

- OS: macOS (arm64)
- Python version: 3.14.6
- Schemathesis version: 4.27.3 (bug); 4.27.1 and 4.27.2 (not affected)
- Spec version: Open API 3.0.3
- hypothesis 6.168.0, jsonschema_rs 0.56.0, requests 2.34.2, click 8.5.0 (identical across the three venvs)

Additional context

Both parties of the lock cycle, captured in-process on 4.27.3 with importlib._bootstrap._ModuleLock.acquire wrapped to log every requests* module lock, and threading.excepthook set:

t (s) thread event where
0.1165 SchemathesisNdjsonWriter acquires lock requests (starts running requests/__init__.py) handlers/ndjson.py:73 _runreporting/ndjson.py:201 write_eventreporting/ndjson.py:114 serialize
0.1261 MainThread acquires lock requests.structures cli/loaders.py:127 _try_load_schemacli/loaders.py:161 _load_schemaopenapi/loaders.py:163 from_pathopenapi/loaders.py:241 from_dict → import schemathesis.specs.openapi.schemasspecs/openapi/schemas.py:11
0.1530 SchemathesisNdjsonWriter asks for requests.structures (owner = MainThread) while still holding requests requests/__init__.py:158requests/utils.py:69
0.1530 SchemathesisNdjsonWriter _frozen_importlib._DeadlockError: deadlock detected by _ModuleLock('requests.structures') importlib's cycle detector
0.1532 SchemathesisNdjsonWriter thread exits; file closed by NdjsonWriter.__exit__

Writer-thread traceback (stderr, via threading.excepthook):

Exception in thread SchemathesisNdjsonWriter:
  threading.py:1082 _bootstrap_inner
  threading.py:1024 run
  schemathesis/cli/commands/run/handlers/ndjson.py:73 _run
  schemathesis/reporting/ndjson.py:201 write_event
  schemathesis/reporting/ndjson.py:114 serialize
  requests/__init__.py:158 <module>
  requests/utils.py:69 <module>
  <frozen importlib._bootstrap>:1368 _find_and_load
  <frozen importlib._bootstrap>:421 __enter__
  <frozen importlib._bootstrap>:346 acquire
_frozen_importlib._DeadlockError: deadlock detected by _ModuleLock('requests.structures') at 0x...

The same in-process script with import requests executed on the main thread before main() writes 23 lines.

Startup cost of the fix (st --help, 20 runs each, same -c bootstrap):

cell median p90 min
4.27.2 267 ms 273 ms 257 ms
4.27.3 as released 161 ms 173 ms 154 ms
4.27.3 + main-thread pre-import of requests 195 ms 201 ms 190 ms
4.27.3 with the module-level import restored (variant b) 198 ms 210 ms 192 ms

Restoring the import costs ~35 ms of the ~106 ms that #4792 saved.

Suggested fix. Either import requests at module level in reporting/ndjson.py again, or import it once on the main thread before NdjsonHandler.start() spawns the writer. Independently, _run() in cli/commands/run/handlers/ndjson.py should not let a writer-thread exception pass silently — surface it in the summary and/or exit code — otherwise any future failure inside serialize() reproduces this class of silent data loss.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions