FIX: prevent GIL/mutex deadlock when logging under concurrent multithreaded use#678
Draft
bewithgaurav wants to merge 2 commits into
Draft
FIX: prevent GIL/mutex deadlock when logging under concurrent multithreaded use#678bewithgaurav wants to merge 2 commits into
bewithgaurav wants to merge 2 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 131-139 131 // SAFETY ASSERTION: Only STMT handles should be in this vector
132 // This is guaranteed by allocStatementHandle() which only creates STMT handles
133 // If this assertion fails, it indicates a serious bug in handle tracking
134 if (handle->type() != SQL_HANDLE_STMT) {
! 135 ++badHandleCount;
136 continue; // Skip marking to prevent leak
137 }
138 handle->markImplicitlyFreed();
139 }Lines 146-155 146 // the GIL and must not run while a native mutex is held.
147 LOG("Compacted child handles: %zu -> %zu (removed %zu expired)",
148 originalSize, afterCompactSize, originalSize - afterCompactSize);
149 LOG("Marking %zu child statement handles as implicitly freed", afterCompactSize);
! 150 if (badHandleCount > 0) {
! 151 LOG_ERROR("CRITICAL: %zu non-STMT handle(s) found in _childStatementHandles. "
152 "This will cause a handle leak!", badHandleCount);
153 }
154
155 SQLRETURN ret;📋 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: 59.9%
mssql_python.pybind.logger_bridge.hpp: 70.8%
mssql_python.pybind.ddbc_bindings.cpp: 76.2%
mssql_python.pybind.connection.connection.cpp: 76.5%
mssql_python.__init__.py: 77.3%
mssql_python.row.py: 77.6%
mssql_python.ddbc_bindings.py: 79.6%
mssql_python.pybind.connection.connection_pool.cpp: 80.4%
mssql_python.connection.py: 83.6%🔗 Quick Links
|
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
1 participant
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
native LOG() from C++ routes records through Python's logging, so it acquires
the GIL. several sites did that while holding a native lock (the connection-pool
mutexes, the per-connection child-handles mutex, the logger's own mutex) or the
getEnvHandle static-init guard. with DEBUG logging on and 2+ threads connecting
or executing, 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. logging
off, or single-threaded, never deadlocks.
fix makes native logging never hold a native lock across a GIL acquisition:
build the log values under the lock and log after releasing it, construct the
pooled Connection outside the pool mutex, release the GIL around the env-handle
init, and drop the mutex the logger took before the GIL.
reproduced the report locally and confirmed the fix: no deadlock at
1/2/4/8/12/16 threads with logging on (was a permanent hang at 4). logging
output is unchanged (native + python records still written), and the
logging / pooling / connection / lifecycle / multithreaded-stress suites pass.