FEAT: mssql-python driver changes to support bulk copy logging.#430
FEAT: mssql-python driver changes to support bulk copy logging.#430subrata-ms wants to merge 9 commits intomainfrom
Conversation
📊 Code Coverage Report
Diff CoverageDiff: main...HEAD, staged and unstaged changes
Summary
mssql_python/logging.pyLines 161-170 161 class CSVFormatter(logging.Formatter):
162 def format(self, record):
163 # Check if this is from py-core (via py_core_log method)
164 if hasattr(record, "funcName") and record.funcName == "py-core":
! 165 source = "py-core"
! 166 message = record.getMessage()
167 else:
168 # Extract source from message (e.g., [Python] or [DDBC])
169 msg = record.getMessage()
170 if msg.startswith("[") and "]" in msg:Lines 171-180 171 end_bracket = msg.index("]")
172 source = msg[1:end_bracket]
173 message = msg[end_bracket + 2 :].strip() # Skip '] '
174 else:
! 175 source = "Unknown"
! 176 message = msg
177
178 # Format timestamp with milliseconds using period separator
179 timestamp = self.formatTime(record, "%Y-%m-%d %H:%M:%S")
180 timestamp_with_ms = f"{timestamp}.{int(record.msecs):03d}"Lines 355-370 355 msg: Message string (already formatted)
356 filename: Source filename (e.g., 'cursor.rs')
357 lineno: Line number in source file
358 """
! 359 try:
! 360 # Fast level check using cached level (same optimization as _log method)
! 361 # Exception: Always allow WARNING and ERROR messages through
362 if level < self._cached_level and level < logging.WARNING:
363 return
! 364
365 # Create a custom LogRecord with Rust source location
! 366 import logging as log_module
367
368 record = log_module.LogRecord(
369 name=self._logger.name,
370 level=level,Lines 373-387 373 msg=msg,
374 args=(),
375 exc_info=None,
376 func="py-core",
! 377 sinfo=None,
! 378 )
379 self._logger.handle(record)
! 380 except Exception:
! 381 # Fallback - use regular logging
! 382 try:
! 383 self._logger.log(level, msg)
384 except:
385 pass
386
387 def _log(self, level: int, msg: str, add_prefix: bool = True, *args, **kwargs):📋 Files Needing Attention📉 Files with overall lowest coverage (click to expand)mssql_python.pybind.logger_bridge.hpp: 58.8%
mssql_python.pybind.logger_bridge.cpp: 59.2%
mssql_python.row.py: 66.2%
mssql_python.pybind.ddbc_bindings.cpp: 69.3%
mssql_python.pybind.ddbc_bindings.h: 69.7%
mssql_python.pybind.connection.connection.cpp: 75.3%
mssql_python.ddbc_bindings.py: 79.6%
mssql_python.pybind.connection.connection_pool.cpp: 79.6%
mssql_python.logging.py: 81.7%
mssql_python.cursor.py: 84.7%🔗 Quick Links
|
subrata-ms
changed the title
subrata-ms
requested review from
Theekshna,
bewithgaurav,
gargsaumya,
jahnvi480,
saurabh500 and
sumitmsft
There was a problem hiding this comment.
Pull request overview
This pull request enhances the bulk copy operation in mssql_python with comprehensive logging infrastructure to improve troubleshooting and observability. The changes introduce performance-optimized logging with cached level checks, a new method for Rust core integration, and extensive debug logging throughout the bulk copy workflow.
Changes:
- Added cached logging level (_cached_level and _is_debug_enabled) to avoid repeated isEnabledFor() calls in performance-critical paths
- Implemented py_core_log() method to support structured logging from Rust/TDS core with custom source location tracking
- Enhanced _bulkcopy method with detailed debug and info logging at all major stages (validation, connection setup, execution, cleanup), all gated by is_debug_enabled checks for minimal performance impact when disabled
Reviewed changes
Copilot reviewed 2 out of 2 changed files in this pull request and generated 3 comments.
| File | Description |
|---|---|
| mssql_python/logging.py | Adds cached logging level for fast checks, implements py_core_log for Rust integration, updates _log to use cached level and proper stacklevel, and updates CSVFormatter to handle py-core records |
| mssql_python/cursor.py | Adds comprehensive logging throughout _bulkcopy method including parameter validation, connection setup, column mappings, execution, results, and cleanup - all conditionally gated by is_debug_enabled |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
|
@subrata-ms - I think there are some tests which need to be fixed, let me know once done, will review it |
| python_logger=logger if is_logging else None, # Only pass logger if enabled | ||
| ) | ||
|
|
||
| if is_logging: |
There was a problem hiding this comment.
What would happen if we dont have the is_logging check?
The note about is_logging says that its the fast path check.
But could we simply not do this check before logger.info and just call logger info? I am trying to understand the applicability of this check for bulk copy before calling logger.info. If its applicable here, then is there a plan to have this path everywhere else as well?
It would nice to see this code align with other parts of the mssql-python
| # Create the underlying Python logger | ||
| self._logger = logging.getLogger("mssql_python") | ||
| self._logger.setLevel(logging.CRITICAL) # Disabled by default | ||
| self._logger.setLevel(logging.WARNING) # Allow WARNING and ERROR by default |
There was a problem hiding this comment.
Why is this change in behavior needed for a bulk copy logger integration? Should this change not be a part of a separate improvement to change the default level?
|
|
||
| @property | ||
| def is_debug_enabled(self) -> bool: | ||
| """Fast check if debug logging is enabled (cached for performance)""" |
There was a problem hiding this comment.
Is the performance hit noticeable ? I am wondering the gains that you saw? In logging the overhead due to I/O seems large enough that this optimization may or may not make sense. I will let this be a team call though, however I am interested in knowing any impactful perf improvements. Else I would err on the side of a simpler code.
3 participants
Work Item / Issue Reference
Summary
This pull request introduces significant improvements to the logging system in the
mssql_pythonpackage, focusing on performance optimization, better integration with Rust (py-core), and enhanced test coverage. The changes optimize how logging levels are checked, ensure that logging from Rust code is handled correctly, and add thorough tests for these new features.Key changes:
Logging Performance and Behavior Improvements
CRITICALtoWARNING, ensuring that warnings and errors are visible by default without explicit configuration. Also, a default stderr handler is now added for warnings and errors. [1] [2]_cached_leveland_is_debug_enabled) for fast, low-overhead decision-making in logging calls, with a newis_debug_enabledproperty for quick checks. [1] [2] [3]_bulkcopy(incursor.py) to use the new fast check for debug logging, and to avoid unnecessary logger passing to Rust unless logging is enabled. [1] [2] [3]Rust (
py-core) Logging Integrationpy_core_logmethod to the logger, allowing Rust-side code to emit logs with custom source locations and levels, and ensuring these logs are formatted and filtered consistently with Python logs.py-coredistinctly.Robustness and Error Handling
WARNINGandERRORmessages, even when the logger is otherwise disabled, both in Python and Rust-originated logs. [1] [2]_bulkcopyfor various failure cases, such as missing dependencies or invalid parameters. [1] [2] [3]Test Suite Enhancements
is_debug_enabledproperty and forpy_core_log, covering level filtering, custom source locations, CSV formatting, error fallback, and integration with different Rust files.These changes collectively improve logging performance, reliability, and cross-language integration, while ensuring robust test coverage for the new features.
High Level Design
Success Test Log
Failure Test Log
