Skip to content

PERF: Guard disabled debug logging in fetchval only - #823

Open
Jahnvi Thakkar (jahnvi480) wants to merge 2 commits into
mainfrom
jahnvi/scalar-fetch-logging-guard
Open

Jahnvi Thakkar (jahnvi480) wants to merge 2 commits into
mainfrom
jahnvi/scalar-fetch-logging-guard

Conversation

@jahnvi480

@jahnvi480 Jahnvi Thakkar (jahnvi480) commented Sep 28, 2026 •

Copy link
Copy Markdown
Contributor

Work Item / Issue Reference

AB#48364


Summary

This fix applies only to Cursor.fetchval(). It is not a general fix for fetch performance.

Add the existing logger.is_debug_enabled guard at each of the four fetchval debug call sites, avoiding logger.debug dispatch when debug logging is disabled. Check the flag separately at each call site so a logging-level change during self.fetchone() is observed by the success/EOF message.

Preserve existing messages, exception order, self.fetchone() dispatch, scalar return values, row consumption, and EOF behavior. fetchone, fetchmany, iteration, Row, converters, UUID handling, the logger implementation, and native code are unchanged. The production change is four added guard lines.

Strengthen the existing test_fetchval_basic_functionality test with a local mocked module logger: disabled dispatch, exact enabled messages for success/EOF/non-result statements, and both directions of logging-flag changes during the real fetchone() call. No new test functions, fixtures, or dependencies.

Performance scope and limitations

Bounded local measurements showed a fetchval benefit, and separate profiles confirmed that its disabled-debug debug/_log calls were eliminated while public fetch, Python-visible native-entry, and Row operation counts stayed unchanged. Profiling is attribution evidence, not a prediction of latency savings.

Unchanged fetchone controls remained slower in the candidate arms. Same-code A/A measurements also varied, but that does not explain away or justify subtracting the adverse control results. Broader performance qualification and the control cause remain unresolved. The evidence does not establish universal no-regression or merge/performance clearance.

Guard each fetchval debug call with the current cached debug flag and strengthen the existing fetchval basic-functionality test. Leave other fetch APIs and Row/native code unchanged.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot AI lite review requested due to automatic review settings September 28, 2026 10:31
@github-actions github-actions Bot added the pr-size: small Minimal code update label Sep 28, 2026
@github-actions

github-actions Bot commented Sep 28, 2026 •

Copy link
Copy Markdown

PR Performance Report

✅ No regression detected

No consistent slowdowns detected across all 2 environments.

0 IMPROVEMENTS 0 SLOWDOWNS 2/2 ENVIRONMENTS

Coverage: 2 of 2 environments completed. Advisory result; does not block merging.

Performance diagnostics

Phase times are inclusive diagnostics and must not be added together. They identify where measured time changed, not why it changed.

No affected phases or call-count changes were recorded.

All database tasks and timings

Unix / SQL Server 2022

Database task Before After Paired change Result
Connection opening 10.652 ms 10.363 ms -2.7% no signal
SELECT queries 1.791 ms 1.108 ms -38.1% no signal
Row insertion 35.036 ms 34.627 ms -1.9% no signal
Executemany inserts 157.377 ms 153.507 ms -1.8% no signal
Fetch-all queries 119.660 ms 119.123 ms -0.9% no signal
Row-by-row fetching 14.372 ms 14.058 ms -2.4% no signal
Batched row fetching 115.393 ms 117.110 ms +1.7% no signal
Transaction commit and rollback 114.290 ms 121.553 ms +6.4% no signal
Arrow row fetching 92.795 ms 95.501 ms +3.1% no signal
100,000-row insertion 441.316 ms 435.688 ms -1.2% no signal
Row fetching in batches of 100 123.009 ms 120.402 ms -0.9% no signal
Row fetching in batches of 10,000 127.417 ms 138.267 ms +1.1% no signal
Repeated positional queries 33.833 ms 33.817 ms +0.5% no signal
Repeated named-parameter queries 35.936 ms 35.926 ms -0.0% no signal
Legacy 100,000-row insertion 346.249 ms 353.022 ms +1.7% no signal
Insertion with explicit input sizes 486.541 ms 486.687 ms -1.0% no signal
Joined aggregation queries 176.529 ms 177.749 ms +0.8% no signal
Large joined-result fetching 180.399 ms 184.586 ms +3.2% no signal
1.2-million-row fetching 3502.621 ms 3434.709 ms -2.5% no signal
Common table expression queries 5.424 ms 5.426 ms +1.9% no signal
256 KiB VARCHAR(MAX) / fetchall() 1.340 ms 1.298 ms -2.2% no signal
10,000 scalar values / fetchval() (debug disabled) 117.806 ms 107.124 ms -9.1% no signal

Unix / SQL Server 2025

Database task Before After Paired change Result
Connection opening 97.486 ms 97.412 ms -0.5% no signal
SELECT queries 1.143 ms 1.112 ms -0.8% no signal
Row insertion 34.726 ms 34.836 ms -0.8% no signal
Executemany inserts 152.508 ms 153.730 ms -1.5% no signal
Fetch-all queries 141.362 ms 124.197 ms -8.4% no signal
Row-by-row fetching 14.415 ms 14.513 ms -0.7% no signal
Batched row fetching 121.305 ms 119.707 ms +0.9% no signal
Transaction commit and rollback 115.283 ms 115.741 ms +0.4% no signal
Arrow row fetching 94.394 ms 96.714 ms +2.3% no signal
100,000-row insertion 451.461 ms 458.013 ms +3.9% no signal
Row fetching in batches of 100 123.208 ms 123.502 ms +0.0% no signal
Row fetching in batches of 10,000 128.425 ms 132.826 ms +1.3% no signal
Repeated positional queries 33.546 ms 33.661 ms +0.7% no signal
Repeated named-parameter queries 35.979 ms 36.191 ms -0.8% no signal
Legacy 100,000-row insertion 381.039 ms 365.992 ms -1.9% no signal
Insertion with explicit input sizes 489.158 ms 505.018 ms +1.7% no signal
Joined aggregation queries 161.247 ms 160.287 ms -0.5% no signal
Large joined-result fetching 188.147 ms 189.133 ms -5.9% no signal
1.2-million-row fetching 3573.811 ms 3547.494 ms -1.4% no signal
Common table expression queries 5.152 ms 5.268 ms +3.2% no signal
256 KiB VARCHAR(MAX) / fetchall() 1.526 ms 1.487 ms +0.8% no signal
10,000 scalar values / fetchval() (debug disabled) 119.874 ms 108.140 ms -7.6% no signal
Build and measurement details

ADO build 178795

PR head: 0830faf539990a7478b4553411341ff378258508
Base: fead15c30e49172bab643bc9cc5504936e86459e
Measured merge: 149b6879fa11b3a5aefc37736f451457debe956d

  • Unix / SQL Server 2022: Python 3.12.3, x86_64, SQL 16.0.4295.3; 5 paired comparisons and 1 warmup.
  • Unix / SQL Server 2025: Python 3.12.3, x86_64, SQL 17.0.5005.3; 5 paired comparisons and 1 warmup.

A consistent change requires more than 20% median paired movement, at least 1 ms between the median runtimes, and at least 80% of pairs exceeding the relative threshold in the same direction. A slowdown without enough pair agreement is reported as inconsistent.

The displayed change is the median of paired before-and-after ratios. It is not recalculated from the two displayed median runtimes.

Both revisions use profiling-enabled builds on the same agent and database, with alternating order and discarded warmups. Results are diagnostic and do not represent production-wheel latency.

Raw samples and logs are attached to the ADO run as profiler-* artifacts.

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copilot review overview

🔵 Needs a closer look

Broader performance qualification and unresolved control results remain.

Review effort: Lite
Findings: None

What changed in this PR

This PR guards disabled debug logging in Cursor.fetchval() and strengthens related regression tests.

Changes:

  • Adds four per-call debug guards.
  • Expands tests for logging states, messages, and flag transitions.
  • Preserves fetch, result, EOF, and non-result behavior.
File Description
tests/​test_004_cursor.py Verifies fetchval logging and behavior.
mssql_python/​cursor.py Guards each fetchval debug call.

💡 Configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

@jahnvi480 Jahnvi Thakkar (jahnvi480) changed the title FIX: Guard disabled debug logging in fetchval only PERF: Guard disabled debug logging in fetchval only Sep 28, 2026
@github-actions

github-actions Bot commented Sep 28, 2026 •

Copy link
Copy Markdown

📊 Code Coverage Report

🔥 Diff Coverage

100%


🎯 Overall Coverage

84%


📈 Total Lines Covered: 9406 out of 11089
📁 Project: mssql-python


Diff Coverage

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

  • mssql_python/cursor.py (100%)

Summary

  • Total: 4 lines
  • Missing: 0 lines
  • Coverage: 100%

📋 Files Needing Attention

📉 Files with overall lowest coverage (click to expand)
mssql_python.pybind.performance_counter.hpp: 0.7%
mssql_python.pybind.logger_bridge.cpp: 57.9%
mssql_python.pybind.ddbc_bindings.h: 62.6%
mssql_python.pybind.logger_bridge.hpp: 70.8%
mssql_python.pybind.ddbc_bindings.cpp: 79.3%
mssql_python.pybind.connection.connection_pool.cpp: 82.3%
mssql_python.pybind.connection.connection.cpp: 83.1%
mssql_python.logging.py: 86.2%
mssql_python.pooling.py: 90.1%
mssql_python.pybind.fetch_temporal.hpp: 92.1%

🔗 Quick Links

⚙️ Build Summary 📋 Coverage Details

View Azure DevOps Build

Browse Full Coverage Report

Measure 10000 scalar fetches and EOF with debug logging disabled. Register one report workload, validate its timing and result contract, and keep existing production code and comparison thresholds unchanged.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot AI review requested due to automatic review settings September 28, 2026 12:12
@github-actions github-actions Bot added pr-size: medium Moderate update size and removed pr-size: small Minimal code update labels Sep 28, 2026

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copilot review overview

🔵 Needs a closer look

Unresolved performance qualification and control results warrant final human review.

Review effort: Lite
Findings: None

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

Labels

pr-size: medium Moderate update size

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants