FIX: prevent GIL/mutex deadlock when logging under concurrent multithreaded use

[bewithgaurav]

Work Item / Issue Reference

GitHub Issue: #671

---

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.

[github-actions]

📊 Code Coverage Report

🔥 Diff Coverage 90%

🎯 Overall Coverage 80%

📈 Total Lines Covered: 6759 out of 8361 📁 Project: mssql-python

---

Diff Coverage

Diff: main...HEAD, staged and unstaged changes

• mssql_python/pybind/connection/connection.cpp (88.5%): Missing lines 135,150-151
• mssql_python/pybind/connection/connection_pool.cpp (100%)

Summary

• Total: 32 lines
• Missing: 3 lines
• Coverage: 90%

mssql_python/pybind/connection/connection.cpp

Lines 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

⚙️ Build Summary	📋 Coverage Details
View Azure DevOps Build	Browse Full Coverage Report