Copilot Adoption: make the page load on a large tenant - #393
Open
sambetts wants to merge 4 commits into
Open
Conversation
…ed before and after a change Release 1810 fixed the two slowest Copilot Adoption queries, but the page is still slow on a large tenant. Optimising it further needs a number that can be produced before a change and again after it, on the same data, without a customer in the loop. That is what this adds. The test drives the REAL CopilotAdoptionService end to end rather than a copy of the SQL. Copied SQL measures a snapshot that rots silently the moment CopilotAdoptionSql is edited, and it would miss the C# scoring step entirely. It reports the per-step breakdown the service already records in CopilotAdoptionDiagnostics - the same instrumentation the page and App Insights use. Those step names are compile-time constants and every value is a duration or a count, so the output carries no tenant data and is safe to attach to a PR or an issue. Details: - Medians over N timed runs with a cold run done first and discarded, matching the discipline the SQL benchmarks in this repo already use. - Measures every window the page offers (7/28/90/180) by default, because a fix that only helps one window is not a fix - the window drives how much of copilot_chats each query reads. - Flags any step at or above 95% of CopilotAdoptionService.QueryTimeoutSecs. Such a step almost certainly FAILED and returned nothing rather than genuinely taking that long, and a fast run made of failed steps is not an improvement - that was the whole substance of issue #360. - Optional concurrent callers, to prove the web layer's shared-analysis cache still de-duplicates. If the measured time scales with the caller count, that de-duplication has broken. - Writes results to JSON and, given COPILOTPERF_BASELINE, diffs against an earlier run per window and per step, failing the run if the total regressed beyond a tolerance. So it can gate a change rather than merely describe it. - Read-only, and generates nothing: point it at a database seeded by UserActivityStressTest, which already scales to a large tenant. - Fully env-var driven (COPILOTPERF_*, STRESS_NONINTERACTIVE), so before/after runs are repeatable and scriptable - which BaseStressTest was explicitly designed for. First baseline on a synthetic large-tenant bench, 28-day window, total 22,811 ms: WeeklyTrend 7,683 ms 33.7% LicensedUsers 7,506 ms 32.9% LicenceOpportunities 3,578 ms 15.7% UnlicensedPopulation 2,569 ms 11.3% AgentEstate 969 ms 4.2% Scoring / UsageByApp / ResourceTypes <300 ms each Worth noting for whoever picks this up: WeeklyTrend is now the slowest step and 1810 never touched it, while LicenceOpportunities - the step that motivated the columnstore migration - has dropped to fourth. The steps run sequentially, so WeeklyTrend and LicensedUsers together are about two thirds of the wait. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 2501834a-7651-4bf0-85d5-00ce8dec9e68
…ve the trend query The page took minutes and then failed with "taking longer than expected". Two independent causes, only one of which was the database. 1. Every request from one browser ran one at a time. Global.asax.cs forced SessionStateBehavior.Required on every request and declared an empty Session_Start. Declaring Session_Start is what makes ASP.NET persist the new session and issue the ASP.NET_SessionId cookie; Required then makes SessionStateModule take an exclusive per-session lock for the duration of each request. Nothing in the solution reads or writes Session or TempData - sign-in is OIDC in an auth cookie - so this bought nothing. It is invisible on fast pages and fatal on this one. The SPA polls three endpoints, each of which parks for up to FirstResponseBudget waiting for the shared analysis. Serialised, the site answers one poll per budget while three arrive per budget, so the queue grows without bound and response times climb by a whole budget per round until the client's polling ceiling trips. A browser trace of the failure shows the signature exactly: consecutive completions spaced one budget apart, never overlapping, across three separate connections with near-zero stalled time - so the server was serialising, not the browser queueing. Reproduced under IIS Express with three concurrent requests to an async handler with a 2s budget: Required + Session_Start = 6,287ms with handler starts 2s apart; Disabled = 2,146ms with all three starting together. 2. WeeklyAdoptionTrendSql joined per chat row what it only needed per user. Whether a user holds a seat, and whether they are a guest, are properties of the user, not of the interaction - but both lookups were joined before the aggregate, recomputing the same answer for every interaction a user had in the week. The first pass now touches nothing but copilot_chats and the two lookups run once per (week, user). Measured on a synthetic customer-shaped bench: 6-month window: 5,551ms -> 2,322ms elapsed (2.4x), CPU 21.1s -> 12.5s 12-month window: 11,523ms -> 4,643ms elapsed (2.5x), CPU 44.7s -> 24.7s Logical reads are unchanged within 1% - the same index pages are read either way, and the saving is join and aggregation CPU, which is the resource that runs out on a tier-capped database. Verified row-for-row identical against the previous query with EXCEPT in both directions. Also here: - The independent steps now run concurrently, bounded by MaxConcurrentSteps (default 2). The gain is real but modest and the measurement is in the code: overlapping does not create database capacity, and both the gain and the per-step inflation saturate at 2. It is kept low on purpose because overlapping makes each step about twice as slow, moving every step twice as close to QueryTimeoutSecs - and a step that hits that timeout degrades to a warning and silently drops a whole section, which is a worse outcome than being slow. - Step side-effects (warnings, the SQL tab, incomplete-data reasons) are buffered per step and merged in step order rather than written directly. Those collections are a plain List and Dictionary, so concurrent writers would corrupt them - and locking alone would leave their order decided by whichever query finished first, which would fill the workbook export's before/after comparison with reordering noise. - LicenceTypes and DataSourceProbes had names in CopilotAdoptionSteps but were never timed, so the first two database round trips were invisible and every other step's share of the total was overstated. Both are now recorded. - The perf harness gains a COPILOTPERF_MAXSTEPS knob so the concurrency can be measured rather than asserted, and its report prints sum-of-steps and the overlap factor instead of claiming the steps run sequentially. End to end on the bench at 28 days: 19,440ms sequential before, 12,945ms after. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 5528ba52-694f-4006-a89c-a914ea6d31e0
…act table four times
Query Store on a customer database showed every slow plan in this report touching copilot_chats
FOUR times. The cause is the same in each: a CTE over copilot_chats that several separate
aggregates then select from. SQL Server does not materialise a CTE, it expands it at every
reference, so the window scan runs once per reference. WeeklyAdoptionTrendSql already documents
this rule; these two violated it, and one of them carried a comment asserting the opposite
("one projected pass").
Both now read copilot_chats once into a grain temp table and aggregate that.
AgentUsageSql - the step that was hitting the 90s command timeout and silently dropping the whole
agent section from the report:
copilot_chats logical reads 234,007 -> 33,945 (6.9x fewer)
spool (worktable) reads 13,223 -> 0
CPU 6,845 ms -> 1,861 ms (3.7x less)
elapsed 2,127 ms -> 920 ms (2.3x faster)
UnlicensedUsageRowsSql - the single most expensive thing the report did:
logical reads 150,506,448 -> 26,037
duration 1,066,710 ms -> 3,370 ms
The read collapse there is far larger than the repeated reference alone accounts for, because
evaluating the CTE four times also pushed the optimiser into a much worse plan for the licence and
guest lookups.
Both measured at production scale on the database that exhibited the problem, and both verified
row-for-row identical against the previous shape with EXCEPT in both directions.
A temp table rather than another CTE, deliberately. Rolling the agent aggregates up with
COUNT(DISTINCT) over a single CTE was also measured and was 4.6x WORSE - it reintroduced exactly
the spool the original multi-CTE shape had been written to avoid. Materialising once is what gets
both: no repeated scan and no spool.
Note for future benchmarking: the synthetic bench does NOT reproduce the agent win and measures it
slightly slower, because the generator emits roughly one grain row per interaction where real usage
repeats. When the grain does not compress there is nothing to gain from materialising it. The
generator needs fixing before the bench is trusted on that query again.
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Copilot-Session: 5528ba52-694f-4006-a89c-a914ea6d31e0
…ps distorting headline figures A query that failed or timed out was recorded in the diagnostics as having SUCCEEDED. SafeAsync converts a failure into a warning and returns null, so the step runner's try/catch never saw an exception and the step was timed as a normal completion. A section that silently vanished from the report was therefore indistinguishable from one that was simply fast. That is not academic. During this work a syntactically broken query showed up in the performance harness as a step that had got 6.5x faster, because it failed instantly and the failure was invisible. StepOutput now records whether any of its queries failed, and the step is marked failed accordingly. Verified end to end by hiding a table the report needs: the step is now reported as FAILED at 5ms and the harness fails the run, where previously it was reported as a success. Also raises two row caps that had become binding on a real tenant, now that the interaction-table fixes have removed the query cost that justified them: - MaxAgents 500 -> 5000. A tenant with more agents than the cap had its inventory, its "agents to retire" count and its health breakdown reduced to whichever agents were busiest. Those are the figures an agent clean-up is run from. - MaxOpportunityCandidates 5000 -> 50000, matching its sibling caps. The "recommended for a licence" headline is a COUNT of this list, so a tenant with more candidates than the cap saw a KPI that was simply the cap value - a number that looks like a finding and is actually a limit. The opportunity cap is not free: on a synthetic 200k-user tenant that query roughly doubled (5,242ms -> 12,146ms) because it returns ten times the rows. That bench has far more unlicensed candidates than a real tenant, and the step has ample headroom since the interaction-table fixes landed, so a correct headline is worth the cost. The better fix - taking the headline count from its own cheap aggregate and leaving the returned list small - is noted in the code as deferred. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 5528ba52-694f-4006-a89c-a914ea6d31e0
sambetts
force-pushed
the
sambetts/copilot-adoption-page-speed
branch
from
September 1, 2026 15:35
fb830e2 to
a90b631
Compare
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Addresses #360. Related to #392 (found while diagnosing this, but a separate defect in the user import — not fixed here).
The Copilot Adoption page did not load on a large tenant: minutes of "Analysing Copilot adoption…" followed by "the analysis is taking longer than expected". Two independent causes, only one of which was SQL.
Measured end to end on the customer tenant that exhibited the problem, via three test builds:
At 16 s every endpoint now returns
200on its first request, insideFirstResponseBudget, so the polling loop never engages.1. The web app processed one request at a time, per browser
Global.asax.cscalledSetSessionStateBehavior(SessionStateBehavior.Required)on every request and declared an (empty)Session_Start. DeclaringSession_Startis what makes ASP.NET persist the new session and issue theASP.NET_SessionIdcookie;Requiredthen makesSessionStateModuletake an exclusive per-session lock for the duration of each request. Every request carrying one browser's cookie was therefore serialised.Nothing in the solution reads or writes
SessionorTempData(grepped the whole solution); sign-in is OIDC held in an auth cookie. The line dates from the initial code commit and never had a purpose.Invisible on fast pages, fatal on this one: the SPA polls three endpoints concurrently and each poll parks for up to the 20 s first-response budget. Serialised, the site answers one poll per budget while three arrive per budget, so the queue grows without bound.
Evidence. A browser trace of the failure shows 32 consecutive completions spaced 19.4–21.2 s apart, never overlapping, across three separate TCP connections with ~4 ms of stalled time — server-side serialisation, not browser connection queueing. Response times climbed 20 → 35 → 76 → 137 → 177 s until the client gave up.
Reproduced under IIS Express with three concurrent requests to an async handler with a 2 s budget:
sessionModeRequired+Session_Start(production)Disabled(this PR)Reviewer hotspot: this changes request handling for the whole web app, not just this page. The argument that it is safe is the absence of any
Session/TempDatausage — worth a second pair of eyes on that claim.2. Three queries read the interaction table four times each
Each defined a CTE over
copilot_chatsand then selected from it in four separate aggregates. SQL Server does not materialise a CTE — it expands it at every reference — so the scan ran four times.WeeklyAdoptionTrendSqlalready documents this rule; these violated it, andAgentUsageSqlcarried a comment asserting the opposite ("one projected pass").Confirmed on the customer database from Query Store: every slow plan showed four separate operators against
copilot_chats.Fixed in two of them by reading the table once into a grain temp table and aggregating that:
AgentUsageSqlcopilot_chatslogical readsUnlicensedUsageRowsSqlThe unlicensed read collapse is far larger than the repeated reference alone accounts for: evaluating the CTE four times also pushed the optimiser into a much worse plan for the licence and guest lookups.
Both verified row-for-row identical against the previous shape with
EXCEPTin both directions, on the customer database (500 and 7,480 rows respectively, zero differences each way).Separately,
WeeklyAdoptionTrendSqlwas joining the seat list anddbo.usersper chat row to answer two questions that are constant per user. Both lookups moved below the aggregate: 2.4–2.5× faster elapsed, ~45% less CPU, logical reads unchanged (the win is join/aggregation CPU), verified identical viaEXCEPT.3. Steps now run concurrently, bounded
AnalyseAsyncran ten steps sequentially, so the page cost their sum with each step allowed up toQueryTimeoutSecs. They are independent, so they now overlap, bounded byMaxConcurrentSteps(default 2).Deliberately low, and the measurement is in the code: overlapping does not create database capacity, and both the gain and the per-step inflation saturate at 2 (28-day window: 14,674 ms sequential → 12,945 ms at 2 → 12,470 ms at 4). Going to 4 buys another 3% for twice the concurrent load on a database shared with the importer. Overlapping also makes each step ~2× slower, moving every step ~2× closer to the query timeout — and a step that hits it degrades to a warning and silently drops a whole section.
Step side-effects (warnings, the SQL tab, incomplete-data reasons) are buffered per step in
StepOutputand merged in step order. Those collections are a plainList/Dictionary, so concurrent writers would corrupt them; locking alone would leave their order decided by whichever query finished first, which would fill the workbook export's before/after comparison with reordering noise.4. A failed step is now reported as failed
SafeAsyncconverts a query failure into a warning and returns null, so the step runner'stry/catchnever saw an exception and the step was timed as a normal completion. A section that silently vanished was indistinguishable from one that was simply fast.This is not academic: during this work a syntactically broken query showed up in the performance harness as a step that had got 6.5× faster, because it failed instantly and the failure was invisible.
StepOutputnow records whether any of its queries failed. Verified by hiding a table the report needs: the step is reportedFAILEDat 5 ms and the harness fails the run, where previously it was a success.5. Two row caps that had become binding
Both existed because the queries were slow. They are not any more, and both were distorting headline figures on a real tenant:
MaxAgents500 → 5000. The inventory, the "agents to retire" count and the health breakdown were all reduced to whichever agents were busiest — the figures an agent clean-up is run from.MaxOpportunityCandidates5000 → 50000, matching its siblings. The "recommended for a licence" headline is aCOUNTof this list, so a tenant with more candidates than the cap saw a KPI that was simply the cap value.Cost, measured: the opportunity query roughly doubles on a synthetic 200k-user tenant (5,242 → 12,146 ms) because it returns ten times the rows. That bench has far more unlicensed candidates than a real tenant and the step has ample headroom now. The better fix — taking the headline count from its own cheap aggregate and leaving the returned list small — is noted in the code as deferred.
Performance harness
Tests.FakeDataGen/StressTests/CopilotAdoptionPerfTest.csdrives the realCopilotAdoptionService(not copied SQL), reports per-step medians with a discarded cold run, writes JSON and diffs against a baseline so it can gate a change.COPILOTPERF_MAXSTEPSmakes the step concurrency measurable rather than asserted.It deliberately does not use
ConnectionStringAnalyticsDbContextFactory: that passesautoUpdate: true, which installsMigrateDatabaseToLatestVersion. A measurement harness must never alter the schema of the database it is measuring — pointed at a restored copy of a customer database it would silently start migrating it. A local non-migrating factory is used instead.Schema, config and compatibility
BaseSolutionInstallConfigchange, so noCONFIG_VERSIONbump.Testing
InstallerTestConfig.json, 8 need real Azure/Graph credentials). Only the threeCopilotAdoption*Tests.csfiles reference the changed code.What was measured and rejected
Recorded because the negative results are as useful as the positive ones, and two of them are counter-intuitive:
AgentUsageSqlrolled up withCOUNT(DISTINCT)over a single CTE — 4.6× worse. It reintroduced exactly the spool the original multi-CTE shape was written to avoid. Materialising once is what gets both no repeated scan and no spool.LicensedUsersSqlgiven the same grain treatment — 3.2× worse on the bench, so not included. That bench has a far larger licensed population than a real tenant, so the intermediate does not pay for itself there. It still has the four-reference defect and is ~5 s in production, not failing; it needs a production A/B before it ships.Deferred
LicensedUsersSql(above).ResourceTypesneeds no work: it went 53,941 → 944 ms without being touched, once the two pathological queries stopped monopolising the database. Its slowness was contention (3.4 s CPU against 53.9 s elapsed).