FIX: prevent GIL/mutex deadlock when logging under concurrent multithreaded use - #678
Open
Gaurav Sharma (bewithgaurav) wants to merge 7 commits into
Open
FIX: prevent GIL/mutex deadlock when logging under concurrent multithreaded use#678Gaurav Sharma (bewithgaurav) wants to merge 7 commits into
Gaurav Sharma (bewithgaurav) wants to merge 7 commits into
Conversation
…readed use native LOG() routes records through Python's logging, so it acquires the GIL from C++. several sites did that while holding a native mutex (the connection-pool mutexes, the per-connection child-handles mutex, the logger's own mutex) or the getEnvHandle static-init guard. under concurrent use with DEBUG logging on, that inverts lock order against a thread that holds the GIL and is waiting on the same native lock, so the process deadlocks at 0% cpu. this makes native logging never hold a native lock across a GIL acquisition: build the log values under the lock, release the lock, then log; construct the Connection and close pools outside the pool mutexes; release the GIL around the env-handle init. verified no deadlock at 1/2/4/8/12/16 threads with logging on (was 100% deadlock at 4 threads). logging output and the pooling/logging/stress test suites are unchanged. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
paths the close-pooling path has the same lock/GIL shape but a different trigger (close running concurrently with active connects) and it interacts with a separate, pre-existing pool-accounting concern in the return path. reverting that hunk here keeps this PR limited to the connect / normal-use deadlock the issue reports. closePools() returns to its original behavior; the five fixed sites (logger bridge, pool acquire, acquireConnection, getEnvHandle, child handle logging) are unchanged. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
📊 Code Coverage Report
Diff CoverageDiff: main...HEAD, staged and unstaged changes
Summary
mssql_python/pybind/connection/connection.cppLines 138-146 138 // SAFETY ASSERTION: Only STMT handles should be in this vector
139 // This is guaranteed by allocStatementHandle() which only creates STMT handles
140 // If this assertion fails, it indicates a serious bug in handle tracking
141 if (handle->type() != SQL_HANDLE_STMT) {
! 142 ++badHandleCount;
143 continue; // Skip marking to prevent leak
144 }
145 handle->markImplicitlyFreed();
146 }Lines 155-164 155 if (hasGil) {
156 LOG("Compacted child handles: %zu -> %zu (removed %zu expired)",
157 originalSize, afterCompactSize, originalSize - afterCompactSize);
158 LOG("Marking %zu child statement handles as implicitly freed", afterCompactSize);
! 159 if (badHandleCount > 0) {
! 160 LOG_ERROR("CRITICAL: %zu non-STMT handle(s) found in _childStatementHandles. "
161 "This will cause a handle leak!", badHandleCount);
162 }
163 }📋 Files Needing Attention📉 Files with overall lowest coverage (click to expand)mssql_python.pybind.logger_bridge.cpp: 58.9%
mssql_python.pybind.ddbc_bindings.h: 61.5%
mssql_python.pybind.logger_bridge.hpp: 70.8%
mssql_python.pybind.ddbc_bindings.cpp: 75.5%
mssql_python.__init__.py: 77.6%
mssql_python.row.py: 77.6%
mssql_python.ddbc_bindings.py: 79.6%
mssql_python.pybind.connection.connection_pool.cpp: 81.6%
mssql_python.pybind.connection.connection.cpp: 84.5%
mssql_python.logging.py: 85.5%🔗 Quick Links
|
adds a functional test (default suite) and a stress test (@pytest.mark.stress) that run DEBUG logging + concurrent connect/execute and assert the process does not deadlock. the workload runs in a child process with a wall-clock timeout so a real GIL/native-mutex deadlock (which freezes the interpreter and can't be interrupted in-process) is turned into a clean failure, and each run gets a fresh logging singleton so it can't leak into the rest of the suite. verified the functional test fails (times out) against the pre-fix build and passes in ~5s against the fixed build. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
…ault run removes the standalone tests/_issue671_deadlock_workload.py script (an odd non-test file in tests/) and moves the workload into a __main__ block in test_025, which the tests invoke as the child process. one self-contained file, matching the layout of the other test modules. also drops the default (non-stress) test to 2 threads to match the repo's lightest concurrency baseline (test_020's (2, 50)); 2 threads is issue #671's stated minimum and still deadlocks the pre-fix build 3/3 runs, so the guard stays reliable without loading PR validation. the heavy 16-thread variant stays under @pytest.mark.stress. log file now uses pytest's tmp_path (auto-cleaned). Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Resolve conflict in connection_pool.cpp: keep the #671 hardening (construct Connection and emit LOG() outside the native mutex on top of main's new token-factory / expiry-aware pool checkout and lazy pool eviction. - ConnectionPool::acquire: reserve the slot under _mutex, construct the Connection once in Phase 3 (outside the lock) for both the normal and the rotated-token reopen paths. - ConnectionPoolManager::acquireConnection: keep both the deferred Creating new connection pool LOG (created flag) and main's evicted-pool close loop, both after releasing _manager_mutex. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> EOF )
Gaurav Sharma (bewithgaurav)
marked this pull request as ready for review
August 18, 2026 07:20
Copilot started reviewing on behalf of
Gaurav Sharma (bewithgaurav)
August 18, 2026 07:20
View session
Contributor
There was a problem hiding this comment.
Pull request overview
Fixes a native/Python lock-order inversion that could deadlock multithreaded workloads when DEBUG logging is enabled, by ensuring native logging never holds critical C++ mutexes (or static-init guards) across GIL acquisition and by restructuring pooled-connection creation to avoid constructing/logging under pool locks.
Changes:
- Removed the logger bridge’s native mutex from the hot logging path and relied on the GIL for Python logging serialization.
- Refactored connection, pooling, and child-handle tracking paths to avoid calling
LOG()while holding native mutexes; released the GIL around env-handle static initialization. - Added an out-of-process regression test that asserts the concurrent DEBUG-logged workload completes (no deadlock).
Reviewed changes
Copilot reviewed 4 out of 4 changed files in this pull request and generated 2 comments.
| File | Description |
|---|---|
| tests/test_025_logging_concurrency_deadlock.py | Adds a subprocess-based regression test for the DEBUG-logging + concurrency deadlock. |
| mssql_python/pybind/logger_bridge.cpp | Removes native mutex acquisition before GIL acquisition in the C++→Python logging bridge. |
| mssql_python/pybind/connection/connection.cpp | Avoids logging while holding connection child-handle mutex; releases GIL around env-handle static init. |
| mssql_python/pybind/connection/connection_pool.cpp | Avoids constructing/logging under pool/manager mutexes by reserving slots then constructing/logging outside locks. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
Copilot started reviewing on behalf of
Gaurav Sharma (bewithgaurav)
August 18, 2026 07:40
View session
…est spawn Two follow-ups from the PR review on the #671 deadlock fix. connection.cpp: Connection::disconnect() emitted LOG()/LOG_ERROR() unconditionally, but the same function already refuses to log on the GIL-less destructor/shutdown path (LOG() acquires the GIL internally, which can hang or std::terminate during interpreter shutdown). Gate every log site in disconnect() on hasGil, computed once up front, and make hasGil robust after Py_Finalize() by short-circuiting on Py_IsInitialized() before PyGILState_Check(). tests/test_025: forward the parent sys.path to the child subprocess verbatim (os.pathsep.join(sys.path)) instead of dropping empty entries. An empty entry means the current working directory; filtering it can leave a script-launched child unable to import the same local mssql_python. Matches test_023. Regression tests: - test_child_pythonpath_forwards_cwd_entry: asserts the empty (cwd) sys.path entry survives forwarding; fails if the old filtering is reintroduced. - test_debug_logging_pooled_connection_shutdown_exits_cleanly: DEBUG-logged pooled-connection teardown at interpreter shutdown exits cleanly (a teardown smoke guard; the pooling atexit handler drains the pool before finalization, so the pure GIL-less static-destructor branch is not deterministically reachable from Python). Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Work Item / Issue Reference
Summary
This pull request addresses a critical deadlock issue (#671) that could occur when DEBUG logging is enabled and multiple threads interact concurrently with the connection pool and logging system. The main changes ensure that any logging (which acquires Python's GIL) is never performed while holding native mutexes, thus preventing lock-order inversions and deadlocks. It also adds regression tests to guarantee that this deadlock does not return.
Deadlock Prevention and Logging Safety:
connection.cppandconnection_pool.cppso that logging calls (LOG,LOG_ERROR) are made only after releasing any native mutexes, preventing GIL/native-mutex lock-order inversions that caused deadlocks under concurrent DEBUG logging. Comments were added to explain the rationale and reference issue Deadlock under concurrent multithreaded use when DEBUG logging is enabled via setup_logging() #671. [1] [2] [3] [4] [5]logger_bridge.cpp, removed the use of a native mutex in the logging bridge, relying solely on the GIL for thread safety, which avoids deadlocks when logging from multiple threads.Connection Pooling and Handle Management:
Connectionobjects and perform ODBC handle allocation outside of pool mutexes, ensuring that any logging or GIL acquisition happens only after releasing native locks. [1] [2] [3] [4]Connection::disconnect()andallocStatementHandle()by collecting compacted handle statistics while holding the mutex, but deferring logging until after the mutex is released. [1] [2]Testing and Regression Coverage:
test_025_logging_concurrency_deadlock.pythat launches multi-threaded workloads under DEBUG logging in a subprocess, verifying that no deadlocks occur. The test is robust, runs out-of-process, and will fail if the deadlock regresses.These changes collectively ensure that the driver is robust against concurrency-related deadlocks when logging is enabled, and that future regressions will be caught by automated tests.