Log stats details for long running SQL queries by apurvabhaleMS · Pull Request #5376 · microsoft/fhir-server

apurvabhaleMS · 2026-02-06T16:20:07Z

Description

This PR adds diagnostic logging for long-running SQL Server search queries by measuring execution time and (optionally) querying SQL Server Query Store for recent runtime stats matching the executed query text. The logging is runtime-configurable via dbo.Parameters, runs asynchronously (fire-and-forget), and is best-effort (never impacts the search request path).

What’s included

Runtime feature flag + threshold (dbo.Parameters)
- Added Search.LongRunningQueryDetails.IsEnabled to enable/disable Query Store stats logging at runtime (default: enabled).
- Added Search.LongRunningQueryDetails.Threshold to configure the “long-running” threshold in milliseconds (default: 5000ms).
Cached dbo.Parameters reader (generalized)
- Replaced ProcessingFlag<T> with CachedParameter<T>:
  - Reads numeric values from dbo.Parameters and caches them (10-minute TTL).
  - Supports feature flags via IsEnabled() (1 = enabled, 0 = disabled).
- Updated existing SQL datastore flags to use CachedParameter<T>.
Execution time measurement
- Added Stopwatch timing around ExecuteReaderAsync for:
  - the main SQL search execution path
  - the SQL include execution path
- If elapsed time exceeds the threshold and the feature is enabled, a Query Store lookup/log is triggered.
Query Store lookup + logging (non-blocking, best-effort)
- Added query text normalization to improve matching against Query Store stored texts:
  - strips preamble lines like SET STATISTICS ..., DECLARE ..., OPTION (RECOMPILE), and timeout comments
  - normalizes leading ;WITH to WITH
- Handles multi-statement include batches by splitting into fragments at INSERT INTO @FilteredData.
- Runs Query Store lookup on a new connection and logs top recent matches (avg/max duration, CPU, IO, rows, last execution time, query_id, plan_id).
- Lookup is fire-and-forget (Task.Run) with a short timeout (2 seconds).
- Any Query Store lookup failures are caught and logged (warning/debug) and do not affect the original request.

Related issues

Addresses AB180196

Testing

Describe how this change was tested.

FHIR Team Checklist

Update the title of the PR to be succinct and less than 65 characters
Add a milestone to the PR for the sprint that it is merged (i.e. add S47)
Tag the PR with the type of update: Bug, Build, Dependencies, Enhancement, New-Feature or Documentation
Tag the PR with Open source, Azure API for FHIR (CosmosDB or common code) or Azure Healthcare APIs (SQL or common code) to specify where this change is intended to be released.
Tag the PR with Schema Version backward compatible or Schema Version backward incompatible or Schema Version unchanged if this adds or updates Sql script which is/is not backward compatible with the code.
When changing or adding behavior, if your code modifies the system design or changes design assumptions, please create and include an ADR.
CI is green before merge
Review squash-merge requirements

Semver Change (docs)

Patch|Skip|Feature|Breaking (reason)

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

Copilot

Pull request overview

Adds best-effort logging of Query Store runtime stats for long-running SQL search queries in the SQL Server search layer, controlled via dbo.Parameters feature flag + threshold.

Changes:

Adds a runtime feature flag (Search.LongRunningQueryDetails.IsEnabled) and numeric threshold (Search.LongRunningQueryDetails.Threshold, default 60s).
Measures query execution time around ExecuteReaderAsync in both search and include-search paths.
Introduces query-text normalization and a Query Store lookup query to log recent runtime stats for matching statements.

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

Co-authored-by: Copilot <[email protected]>

Co-authored-by: Copilot Autofix powered by AI <62310815+github-advanced-security[bot]@users.noreply.github.com>

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

src/Microsoft.Health.Fhir.SqlServer/Features/Storage/CachedParameter.cs

…nfo-long-running-queries

Copilot

Pull request overview

Copilot reviewed 2 out of 2 changed files in this pull request and generated 9 comments.

Comments suppressed due to low confidence (1)

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs:570

The stopwatch starts before ExecuteReaderAsync but stops after the entire reader processing completes, so the measured "execution" time includes result materialization/decompression in addition to SQL execution. If the intent is to detect long-running SQL, consider measuring only the DB call (e.g., around ExecuteReaderAsync / DB read loop) or clearly renaming this to reflect end-to-end processing time.

                        var st = DateTime.UtcNow;
                        var executionStopwatch = Stopwatch.StartNew();

                        try
                        {
                            using (var reader = await sqlCommand.ExecuteReaderAsync(CommandBehavior.SequentialAccess, cancellationToken))
                            {

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

src/Microsoft.Health.Fhir.SqlServer/Features/Storage/CachedParameter.cs

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

Copilot

Pull request overview

Copilot reviewed 3 out of 3 changed files in this pull request and generated 10 comments.

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

src/Microsoft.Health.Fhir.SqlServer/Features/Storage/CachedParameter.cs

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

...oft.Health.Fhir.SqlServer.UnitTests/Features/Search/SqlServerSearchServiceQueryStoreTests.cs

…nfo-long-running-queries

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

apurvabhaleMS · 2026-02-14T16:49:27Z

/azp run

azure-pipelines · 2026-02-14T16:49:43Z

Azure Pipelines successfully started running 1 pipeline(s).

SergeyGaluzo · 2026-02-19T00:25:02Z

I do not see "fire and forget" mentioned in description, Is it implemented?

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

…nfo-long-running-queries

Copilot

Pull request overview

Copilot reviewed 4 out of 4 changed files in this pull request and generated 3 comments.

Comments suppressed due to low confidence (2)

src/Microsoft.Health.Fhir.SqlServer/Features/Storage/CachedParameter.cs:20

CachedParameter<TLogger> is declared public even though it appears to be an internal SQL Server implementation detail (replacing ProcessingFlag). Making it public expands the surface area of Microsoft.Health.Fhir.SqlServer and can become a supported API inadvertently. Consider making the class internal (and only exposing what’s needed via internal helpers) unless there’s a concrete cross-assembly requirement.
src/Microsoft.Health.Fhir.SqlServer/Features/Storage/CachedParameter.cs:85
ReadFromDatabase blocks on an async call via .Result. This can cause thread-pool starvation under load and wraps exceptions in AggregateException, making diagnostics harder. Prefer awaiting asynchronously (make the call path async) or, if it must be synchronous, use GetAwaiter().GetResult() and ensure the async operation doesn’t capture a context.

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

...oft.Health.Fhir.SqlServer.UnitTests/Features/Search/SqlServerSearchServiceQueryStoreTests.cs

src/Microsoft.Health.Fhir.SqlServer/Features/Storage/CachedParameter.cs

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs

src/Microsoft.Health.Fhir.SqlServer/Features/Storage/SqlServerFhirDataStore.cs

apurvabhaleMS · 2026-02-19T19:28:54Z

/azp run

azure-pipelines · 2026-02-19T19:29:14Z

Azure Pipelines successfully started running 1 pipeline(s).

Log stats details for long running sql queries

ab1e715

apurvabhaleMS added the Azure Healthcare APIs Label denotes that the issue or PR is relevant to the FHIR service in the Azure Healthcare APIs label Feb 6, 2026

apurvabhaleMS added this to the FY26\Q3\2Wk\2Wk16 milestone Feb 6, 2026

github-advanced-security bot found potential problems Feb 6, 2026

View reviewed changes

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs Fixed Show fixed Hide fixed

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs Fixed Show fixed Hide fixed

apurvabhaleMS requested a review from Copilot February 6, 2026 18:26

Copilot started reviewing on behalf of apurvabhaleMS February 6, 2026 18:27 View session

Copilot AI reviewed Feb 6, 2026

View reviewed changes

apurvabhaleMS and others added 3 commits February 6, 2026 10:40

Update finally block

a46c91f

Co-authored-by: Copilot <[email protected]>

static field written by instance method

583f46f

Co-authored-by: Copilot Autofix powered by AI <62310815+github-advanced-security[bot]@users.noreply.github.com>

Addressing suggestions

509471e

github-advanced-security bot found potential problems Feb 6, 2026

View reviewed changes

apurvabhaleMS added 2 commits February 6, 2026 12:00

Get threshold

99cb5e5

Removed unused variables

2793824

github-advanced-security bot found potential problems Feb 6, 2026

View reviewed changes

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs Fixed Show fixed Hide fixed

src/Microsoft.Health.Fhir.SqlServer/Features/Storage/CachedParameter.cs Fixed Show fixed Hide fixed

apurvabhaleMS added 4 commits February 6, 2026 14:33

Modify how we read from query store

a20f986

Removed unused variables

8bf3867

Merge remote-tracking branch 'origin/main' into personal/abhale/log-i…

e71a72b

…nfo-long-running-queries

Use like %

b5370f2

apurvabhaleMS added Enhancement Enhancement on existing functionality. No-PaaS-breaking-change labels Feb 9, 2026

apurvabhaleMS requested a review from Copilot February 9, 2026 18:44

apurvabhaleMS added the No-ADR ADR not needed label Feb 9, 2026

Copilot started reviewing on behalf of apurvabhaleMS February 9, 2026 18:45 View session

Copilot AI reviewed Feb 9, 2026

View reviewed changes

apurvabhaleMS added 2 commits February 9, 2026 21:17

Added unit tests

b1c345f

New tests and suggestions

0b6db7d

apurvabhaleMS requested a review from Copilot February 10, 2026 19:06

Copilot started reviewing on behalf of apurvabhaleMS February 10, 2026 19:07 View session

Copilot AI reviewed Feb 10, 2026

View reviewed changes

Tests and suggestions

8e18f04

Do not log sql query plan

58926bd

apurvabhaleMS marked this pull request as ready for review February 11, 2026 19:14

apurvabhaleMS requested a review from a team as a code owner February 11, 2026 19:14

SergeyGaluzo reviewed Feb 12, 2026

View reviewed changes

...oft.Health.Fhir.SqlServer.UnitTests/Features/Search/SqlServerSearchServiceQueryStoreTests.cs Outdated Show resolved Hide resolved

Updated unit tests

ec6a5c0

github-advanced-security bot found potential problems Feb 12, 2026

View reviewed changes

...oft.Health.Fhir.SqlServer.UnitTests/Features/Search/SqlServerSearchServiceQueryStoreTests.cs Dismissed Show dismissed Hide dismissed

apurvabhaleMS requested a review from SergeyGaluzo February 13, 2026 21:06

apurvabhaleMS added 2 commits February 13, 2026 13:48

Merge remote-tracking branch 'origin/main' into personal/abhale/log-i…

3aa4fa6

…nfo-long-running-queries

Default time to 2 seconds to log query store details

020c268

github-advanced-security bot found potential problems Feb 13, 2026

View reviewed changes

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs Fixed Show fixed Hide fixed

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs Fixed Show fixed Hide fixed

SergeyGaluzo reviewed Feb 19, 2026

View reviewed changes

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs Show resolved Hide resolved

SergeyGaluzo reviewed Feb 19, 2026

View reviewed changes

src/Microsoft.Health.Fhir.SqlServer/Features/Search/SqlServerSearchService.cs Outdated Show resolved Hide resolved

apurvabhaleMS added 2 commits February 18, 2026 22:59

Merge remote-tracking branch 'origin/main' into personal/abhale/log-i…

5b42166

…nfo-long-running-queries

Addressing comments

082584f

apurvabhaleMS requested a review from Copilot February 19, 2026 07:27

Copilot started reviewing on behalf of apurvabhaleMS February 19, 2026 07:28 View session

Copilot AI reviewed Feb 19, 2026

View reviewed changes

some more suggestions

fa4b494

github-advanced-security bot found potential problems Feb 19, 2026

View reviewed changes

some more suggestions

18d8632

SergeyGaluzo approved these changes Feb 19, 2026

View reviewed changes

apurvabhaleMS enabled auto-merge (squash) February 19, 2026 21:42

feordin approved these changes Feb 19, 2026

View reviewed changes

apurvabhaleMS merged commit ef667cf into main Feb 19, 2026
61 checks passed

apurvabhaleMS deleted the personal/abhale/log-info-long-running-queries branch February 19, 2026 21:43

Conversation

apurvabhaleMS commented Feb 6, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

What’s included

Related issues

Testing

FHIR Team Checklist

Semver Change (docs)

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

apurvabhaleMS commented Feb 14, 2026

Uh oh!

azure-pipelines bot commented Feb 14, 2026

Uh oh!

SergeyGaluzo commented Feb 19, 2026

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

apurvabhaleMS commented Feb 6, 2026 •

edited

Loading