Incident: 2026-02-06 — Production Performance Degradation

Summary

Transportation billers unable to save monthly visits (UI spinner/timeout). Investigation revealed database-wide performance degradation caused by expensive clinician dashboard queries and report queries saturating DTU capacity during business hours.

Field	Value
Severity	SEV2 — Major degradation
Status	Investigating
Reported by	Kisha Pinkney
Investigated by	Leon Geldenhuys
Started	2026-02-06 ~14:00 UTC
Resolved	Pending
Affected users	Transportation billers (confirmed), likely all users
Affected endpoint	`POST Visit/SaveTransportationVisit` (16.2s avg, 617 calls)

Timeline

Time (UTC)	Event
~14:00	Transportation billers report spinner when saving monthly visits
~14:00	DTU usage spikes to 900 DTU (90% of 1,000 limit)
~14:00–15:00	CPU reaches 100%, DTU limit hit for ~10 seconds
~14:18	Tooltip captured: DTU used avg 142.41 (post-spike)
~15:00	Spike subsides; DTU settles to sustained ~470
~18:00	DTU remains at ~470 sustained into overnight
Feb 07	Investigation begins; similar pattern observed — spikes at same time daily
Feb 07	DTU Limit chart reveals scheduled scaling: 500 DTU from 2 AM – 12 PM
Feb 07	Active sessions query shows 28 SSRS-like sessions from DB000004
Feb 07	Query Store (14:00–15:00 window): clinician search (9 min avg), report query (11.7M reads)
Feb 07	Query Store (16:36 precise): `UpdateVisitStatus` N+1 pattern (1,787 calls × 2.3s), visit cross-join (55s CPU)
Feb 07	App Insights: worst `SaveTransportationVisit` = 42,079ms, user KMgQL (Allen, TX)
Feb 07	App Insights: SQL command text not captured — `EnableSqlCommandTextInstrumentation` not configured
Feb 07	App Insights Performance: app-wide degradation — 9 endpoints over 5 seconds, smart detection flagging 3

Investigation

1. Azure Metrics (DTU)

DTU Limit chart revealed a scheduled scaling rule:

Time Window	DTU Limit	DTU Used (peak)	Utilization
Midnight – 2 AM	1,000	~470 sustained	47%
2 AM – 12 PM (scaled down)	500	~470 sustained	94%
12 PM onwards	1,000	900 peak	90%

The database is scaled down to 500 DTU from 2 AM to noon — leaving almost no headroom during morning business hours when users are most active.

Deadlocks: None reported during the spike window.

2. Active Sessions (Saturday snapshot)

Query: sys.dm_exec_sessions joined with sys.dm_exec_requests

program_name	host_name	Sessions	Active Requests
.Net SqlClient Data Provider	WN1LDWK0001KB	19	2
.Net SqlClient Data Provider	vm-jobscheduler	9	2
TdService	DB000004	6	2
Framework Microsoft SqlClient Data Provider	DB000004	28	0
.Net SqlClient Data Provider	WN0LDWK0003AX	17	0
Core .Net SqlClient Data Provider	pd0sdwk001EC2	5	0

Key observations:

DB000004 hosts 28 idle sessions via “Framework Microsoft SqlClient Data Provider” — likely SSRS running on the database server itself
TdService on DB000004 with 2 active requests — unknown service, needs identification
vm-jobscheduler — dedicated Quartz.NET job scheduler VM

3. Query Store Analysis (Spike Window: 14:00–15:00 UTC)

Top CPU consumers during the spike:

#	Query	Executions	Avg CPU	Avg Duration	Avg Reads	Identification
1	`@clinicianuserId, @firstName...`	181	3.6s	9 min	33K	Clinician dashboard/search
2	`@p_linq_0 nvarchar(4000)... SELECT`	42,567	6ms	6ms	415	High-volume EF/LINQ query
3	`select distinct NS.Id, NS.StudentId...`	37	5.4s	1.4s	42K	Student query (parallel exec)
4	`WITH FilteredStudents AS...`	135	594ms	627ms	355K	Student list/grid
5	`@todaysDate, @organizationId, @firstName...`	87	1.1s	480ms	316K	Clinician search by org
8	`@studentFirstNameFilter...`	76	1.2s	604ms	210K	Student name search
9	`@StartDate, @EndDate SELECT DISTINCT S...`	1	40s	49s	11.7M	Single report query
13	`INSERT INTO #tempTripData`	13,033	1.8ms	1.8ms	196	Transportation billing (victim)

Analysis:

Query #1 is the primary offender — 181 executions, each averaging 9 minutes wall time but only 3.6s CPU. The 8.5-minute gap = waiting for locks/IO from other queries. This is a clinician dashboard or search query.
Query #9 — a single report execution consuming 40 seconds CPU and 11.7 million reads. This alone would spike DTU.
Query #13 (transportation billing) — individually fast (1.8ms) but competing for resources while queries #1 and #9 choke the database. The biller’s spinner is a symptom, not the cause.

4. Query Store — Precise Spike Correlation (16:36 UTC)

Narrowed Query Store to the exact time of the worst SaveTransportationVisit request (42 seconds at 4:36 PM):

#	query_id	Query	Avg Duration	Avg CPU	Executions	Impact
1	65638416	`UpdateVisitStatus.Vi...` `@isCallingFromBulkMove`	2.3s	1.3s	1,787	The save operation itself
2	65637656	`@studentId, @startDateForBillingSearch...`	8.7ms	5.1ms	213,341	Billing search (volume)
3	65643379	`@p_linq_0 nvarchar(4000)... SELECT [Limit...]`	19ms	15ms	73,807	EF/LINQ query (volume)
4	65704168	`@visitStartDate, @visitEndDate, @districtSe...`	1.8ms	1.1ms	314,608	Visit date filter (volume)
5	65715521	`@p_linq_0 int, @p_linq_1 datetime2(7)...`	5.9s	19.7s	82	Heavy EF query (parallel)
6	65637655	`@studentId, @startDateForBillingSearch...`	4.4ms	2.5ms	96,663	Billing search variant
7	65637469	`UPDATE ts SET ts.IsRequired = 1 FROM #tempServices`	20ms	0.9ms	20,167	Transportation billing temp
8	65518832	`@todaysDate, @organizationId, @firstName...`	1.8s	1.2s	196	Clinician search by org
9	65243466	`@todaysDate, @clinicianuserId, @firstName...`	983ms	3.7s	283	Clinician search
10	65715544	`SELECT A1.VisitId VisitID1, A2.VisitId VisitID2...`	21.8s	55s	11	Visit cross-join (monster)

Root cause chain identified:

SaveTransportationVisit calls UpdateVisitStatus (query_id 65638416) once per visit in a loop — classic N+1 pattern
Each UpdateVisitStatus takes 2.3 seconds because the database is saturated by:
- Query #10: a visit cross-join consuming 55 seconds of CPU per execution (11 executions)
- Queries #2, #4, #6: 624,000 combined billing search executions creating constant baseline load
Saving ~18 visits sequentially: 18 × 2.3s = 41.4 seconds (matches the observed 42-second request)

Query #10 is the single worst query — SELECT A1.VisitId VisitID1, A2.VisitId VisitID2 with only 11 executions but 55 seconds CPU each. This is a visit-to-visit comparison or duplicate detection query that needs immediate investigation.

5. Full Query Text and Codebase Mapping

Query #10 — Overlapping Activities (55s CPU)

Stored procedure: usp_GetOverlappingVisitList File: Eshars.DbUpgrader/Sql/App/Stored Procedures/usp_GetOverlappingVisitList.sql

SELECT A1.VisitId VisitID1, A2.VisitId VisitID2
INTO #OverlappedActivities
FROM #TempActivities AS A1
INNER JOIN #TempActivities AS A2
    ON A1.ClinicianId = A2.ClinicianId
    AND A1.StartDate < A2.EndDate
    AND A1.EndDate > A2.StartDate
WHERE A1.Id <> A2.Id

Problem: O(N²) self-join on #TempActivities — for each clinician, every activity is compared to every other activity. With large datasets this explodes.

Called by:

BulkMoveJob.cs:335 → VisitService.GetOverlappingVisitList()
VisitService.cs:1863-1874 — passes comma-separated visit IDs to the SP

Query #1 — UpdateVisitStatus (2.3s × 1,787 calls)

Two stored procedures exist:

Single-visit: UpdateVisitStatus (takes @visitId INT) — Eshars.DbUpgrader/Sql/App/Stored Procedures/UpdateVisitStatus.sql
Batch version: sp_GetNextStatusForVisits (takes @visits dbo.UpdateVisitStatusType READONLY TVP) — Eshars.DbUpgrader/Sql/App/Stored Procedures/sp_GetNextStatusForVisits.sql

Both call dbo.GetNextStatusForVisit — a 745-line table-valued function containing eligibility checks (age, 365/95 day rule, Medicaid, consent, special ed, transportation matching, billing limits, Rx requirements, supervisor approval, DNQ checks).

The N+1 call chain:

VisitController.SaveTransportationVisit() (line 2365) — receives List<AddVisitModel>
→ VisitService.SaveTransportationVisits() (line 1438) — loops with visits.ForEach() (line 1457)
→ UpdateVisit() — called per visit inside the loop
→ UpdateVisitStatus SP — calls GetNextStatusForVisit (745 lines) per visit

Key finding: A batch version (sp_GetNextStatusForVisits) already exists and is used by BulkMoveJob. The SaveTransportationVisit endpoint does NOT use it — it calls the single-visit SP in a loop.

6. Application Insights — Request Correlation

Queried SaveTransportationVisit requests sorted by duration:

Timestamp (UTC)	Duration	Result	Performance Bucket
4:36:22 PM	42,079ms	200 OK	30sec-1min
4:34:36 PM	17,999ms	200 OK	15sec-30sec
5:05:56 PM	4,962ms	200 OK	3sec-7sec
4:52:48 PM	3,703ms	200 OK	3sec-7sec
3:38:59 PM	3,688ms	200 OK	3sec-7sec
4:58:00 PM	375ms	200 OK	250ms-500ms
3:00:05 PM	332ms	200 OK	250ms-500ms

Key finding: No requests timed out — all returned 200. The problem is pure slowness, not failures. The 42-second save corresponds to the same user (user_Id: KMgQL, location: Allen, TX) who was on the User Timeline view.

Limitation: App Insights dependency tracking does not capture SQL command text — EnableSqlCommandTextInstrumentation is not configured in ApplicationInsights.config. This prevented direct correlation from the App Insights request to the specific SQL call. Root cause was identified via Query Store timestamp correlation instead.

8. Frontend & Timeout Stack Analysis — Why “Can’t Save”

Users report “can’t save” despite server returning 200 OK. Investigation of the full request pipeline:

Client-side AJAX (Eshars.WebUI/Scripts/app/common/ajaxHelper.ts:19-28):

$.ajax call with no timeout property — jQuery defaults to infinite wait
Spinner shown via AjaxHelper.showAjax("Saving visit(s)") before AJAX call
Spinner hidden in .done() callback (line 2639) AND .fail() callback (line 2822-2824)
.fail() handler also shows generic error toast via handleError()

Server-side configuration (Web.config):

Setting	Value	Effect
`httpRuntime executionTimeout`	1800 (30 min)	Server keeps processing long after client disconnects
`forms timeout`	5400 (90 hrs)	Auth cookie does not expire
`sessionState timeout`	5400 (90 hrs)	Session does not expire
SQL `CommandTimeout`	30 sec (default — no custom override found)	Individual queries can timeout under load

Azure infrastructure:

Layer	Timeout	Configurable?
Azure SQL connection	30 seconds	Yes (connection string)
Azure SQL command	30 seconds (default)	Yes (per-command)

The failure scenario for a full-month save:

A transportation biller saving a full month selects ~44 checkboxes (22 working days × AM+PM). The extractVisitsForSave() function in transportationServices.ts:279-326 creates one visit per checkbox per student.

Scenario	Visits	Time per visit	Total	Result
Normal day	44	~0.5s	~22s	Slow but works
During DTU spike (observed)	18	~2.3s	~42s	Works, but 42s spinner
DTU at 100%	44	~5-10s	220-440s	Some visits exceed 30s SQL timeout → partial save
Multiple students	88+	~2.3s	200+s	Many visits may timeout individually

Per-visit SQL timeout — the primary failure mechanism:

Inside the visits.ForEach() loop, each call goes through AddNewVisit() → UpdateVisitStatus() → GetNextStatusForVisit (745-line TVF)
Default SQL CommandTimeout is 30 seconds (no custom override found in the app)
Under DTU saturation, individual GetNextStatusForVisit calls can exceed 30s → SqlTimeoutException
The per-visit catch block (VisitService.cs:1495) catches this and sets CanBeScheduled = false
Response returns 200 OK with hasErrors = true → client shows partial-save error dialog via showSaveVisitErrorResponses()
Some visits saved, some didn’t → confusing partial-save state for the user
Observed: avg 2.3s per call during spike, but outliers under full saturation can reach 30s+

User experience during degradation:

User clicks Save → spinner shows (“Saving visit(s)”)
Server processes visits one-by-one (N+1 loop), some succeed, some fail with SQL timeout
After 42+ seconds, response arrives with hasErrors = true
User sees error dialog listing failed visits — but some visits DID save
User may retry, creating duplicates for the visits that already saved

ELMAH correlation: Anti-forgery token exceptions were found in ELMAH during the spike window. These are consistent with users who waited a long time, navigated away or refreshed, then retried — the token state became inconsistent between attempts.

6. Application Insights — Slowest Operations (last 24h)

Operation	Avg Duration	Count
POST Visit/SaveTransportationVisit	16.2 sec	617
POST Reports/GetServiceCategories	15.6 sec	4
GET Account/ForgotPasswordConfirmation	8.36 sec	146
GET Students/StudentGoals	7.60 sec	59
POST SAFormSubmittal/SAForm	7.19 sec	98
POST Visit/GetCliniciansForRapidVisits	7.13 sec	1
GET Jobs/Index	6.84 sec	21
POST EDIManagement/GetBillingTransactionFiles	5.72 sec	21
POST Visit/SaveAssessmentVisits	5.61 sec	36

Smart Detection alerts (Insights panel):

Alert	Degradation	Previous Avg	Detected
GET Visit/ShowVisitDetails	144%	357ms	872ms
POST Notifications/GetApproveRejectVisitsCount	129%	893ms	2.05s
POST Message/GetUnreadMessagesCount	202%	372ms	1.12s

The degradation is app-wide, not limited to transportation billing.

7. App Service Configuration

Logging settings on wa-eshars-prod:

Setting	Value
Application logging (Filesystem)	Off
Application logging (Blob)	On — Verbose — `diagnosticsesharsprod` container
Web server logging	File System — 35 MB quota
Detailed error messages	On
Failed request tracing	On
Blob retention period	Not set (accumulating indefinitely)

Root Cause

Primary cause: The SaveTransportationVisit endpoint calls UpdateVisitStatus once per visit in a sequential loop (N+1 pattern). Each call takes 2.3 seconds because the database is saturated by a visit cross-join query (55s CPU per execution) and 624,000+ billing search queries creating constant load.

Why billers “can’t save” (not just “slow save”):

When DTU is at 100%, the N+1 loop processes visits sequentially — each calling GetNextStatusForVisit (745-line TVF). With a default SQL CommandTimeout of 30 seconds, individual visits in the loop start timing out with SqlTimeoutException. These are caught per-visit (VisitService.cs:1495) and marked CanBeScheduled = false. The response returns 200 OK but with hasErrors = true, and the user sees a partial-save error dialog — some visits saved, some didn’t. On retry, the already-saved visits may be duplicated (no idempotency check). Even when no SQL timeouts occur, the 42+ second spinner causes users to abandon and retry, compounding the problem.

The transportation biller’s spinner is a symptom of three compounding issues:

N+1 save pattern — UpdateVisitStatus called per-visit instead of batched. ~18 visits × 2.3s = 42 seconds; full month = 100+ seconds
SQL CommandTimeout (30s) — individual visits in the loop can timeout during DTU saturation, causing partial saves
Visit cross-join query (query_id 65715544) — SELECT A1.VisitId, A2.VisitId runs 11 times at 55s CPU each, saturating the database

Contributing factors:

DTU scaling rule reduces capacity from 1,000 to 500 DTU during 2 AM – 12 PM, leaving almost no headroom when users start their workday
No read replica — report queries and application writes compete on the same database (see RFC-0001)
DashboardService uses writable database context for all 12 pure-read methods, including stored procedures with infinite timeouts (see Read Replica Audit)
28 SSRS sessions from DB000004 — report server appears to run on the database server
SQL CommandTimeout = 30s (default) — individual visits in the N+1 loop can timeout, causing partial saves with confusing error messages
App Insights SQL command text not enabled — EnableSqlCommandTextInstrumentation is not configured, making request-level SQL tracing impossible
No server-side progress/idempotency — no mechanism to resume or detect partial saves, leading to duplicates on retry

Outstanding Questions

~~What is the full query text for query_id 65715544?~~ → usp_GetOverlappingVisitList — O(N²) self-join
~~What is the full query text for query_id 65638416?~~ → UpdateVisitStatus SP calling 745-line GetNextStatusForVisit function
What is TdService running on DB000004?
What is the full query text for query_id 65243466 (clinician dashboard query)?
Who configured the DTU scaling rule and was it intentional?
Is SSRS running on DB000004 (the database server)?
Does this pattern repeat daily? (initial evidence suggests yes — “same time yesterday”)
Why are there 624,000+ billing search queries in a single hour?
Can GetNextStatusForVisit (745 lines) be optimized or precomputed?

Remediation

Immediate (today)

Review and fix the DTU scaling schedule — do not scale below 1,000 during business hours
Get full query text for query_id 65715544 → usp_GetOverlappingVisitList (O(N²) self-join)
Get full query text for query_id 65638416 → UpdateVisitStatus SP calling 745-line GetNextStatusForVisit
Investigate why 624,000+ billing search queries fire in a single hour

Short-term (this sprint)

Refactor VisitService.SaveTransportationVisits to use sp_GetNextStatusForVisits (batch TVP) instead of per-visit UpdateVisitStatus loop — batch version already exists and is used by BulkMoveJob (highest impact fix)
Optimize usp_GetOverlappingVisitList — replace O(N²) self-join with window function approach
Enable SQL command text in App Insights (EnableSqlCommandTextInstrumentation)
Review missing index recommendations from sys.dm_db_missing_index_details
Set blob log retention period on App Service
Implement read replica for report queries (RFC-0001)
Refactor DashboardService to use IUnitOfWork<ReportDbReadOnlyContext> for all 12 read methods
Add ApplicationIntent=ReadOnly to SSRS data source connection strings

Long-term

Move SSRS off the database server if confirmed co-located
Add DTU usage alerting (threshold > 80%)
Build eshars-cli db health command for quick production triage
Create proactive monitoring dashboard (Power BI or Grafana)
Audit all high-volume query patterns for N+1 anti-patterns
Add idempotency keys to visit creation to prevent duplicates on retry
Consider adding a client-side progress indicator or batched save with status callback