Skip to content

Pre-size the HttpLogging parameter lists - #70181

Merged
DeagleGross merged 14 commits into
mainfrom
perf/httplogging
Nov 10, 2026
Merged

DeagleGross merged 14 commits into
mainfrom
perf/httplogging

Conversation

@davidfowl

@davidfowl davidfowl commented Oct 31, 2026 •

Copy link
Copy Markdown
Member

Pre-size the HttpLogging parameter lists

  • You've read the Contributor Guide and Code of Conduct.
  • You've included unit or integration tests for your change, where applicable.
  • You've included inline docs for your change, where applicable.
  • There's an open issue for the PR that you are making. If you'd like to propose a new feature or change, please open an issue to discuss the change or find an existing issue.

Pre-size the HttpLoggingMiddleware parameter lists to avoid array growth.

Description

For each logged request, HttpLoggingMiddleware adds the request properties and every request header to HttpLoggingInterceptorContext.InternalParameters, and later adds the status code and every response header. That list can't be pooled because the HttpLog state may be kept by a logger. Every request starts with an empty list, so it grows 0 → 4 → 8 → 16 (→ 32) and throws away each intermediate KeyValuePair<string, object?>[].

Before adding parameters, the list reserves room with List.EnsureCapacity(Count + constant + Headers.Count), counting headers only when they are logged:

  • Request (in InvokeInternal): Count + 6 (Protocol, Method, Scheme, PathBase, Path, QueryString), plus Request.Headers.Count when RequestHeaders is enabled.
  • Response (in LogResponseHeadersCore, the shared path used by the middleware, ResponseBufferingStream and UpgradeFeatureLoggingDecorator): Count + 1 (StatusCode), plus Response.Headers.Count when ResponseHeaders is enabled. Nothing is reserved when no response properties or headers are enabled.

The reservation can overshoot by a few slots when only some properties are enabled, which is cheaper than keeping a per-field count in sync with the AddParameter calls. Count already includes any parameters interceptors added. Only the list's capacity changes. Its contents, order, log output and the Parameters view seen by interceptors are identical. No public API changes.

Tests

  • dotnet test src/Middleware/HttpLogging/test: 146/146 pass (re-run after review feedback).
  • New ManyHeadersAndInterceptorParameters_AllLoggedInOrder (separate and combined logs): 20 request and 20 response headers plus interceptor-added parameters. It asserts the exact log lines in order, which crosses several growth boundaries.

Benchmark (3 interleaved rounds)

The benchmark is committed in src/Middleware/HttpLogging/perf/Microbenchmarks/HttpLoggingMiddlewareBenchmark.cs. It builds the real AddHttpLogging + UseHttpLogging pipeline with an enabled logger that calls the formatter, like a console sink, without doing any I/O. Each op is a new DefaultHttpContext with 10 request headers, and the endpoint sets 3 response headers.

Result (after switching to EnsureCapacity in bf9a8a9): allocations drop in every round: −256 B per request with default fields (4,272 → 4,016 B) and −288 B with CombineLogs (4,632 → 4,344 B). The earlier exact sizing saved slightly more (−272 / −480 B). With CombineLogs, the response stage now grows the list once more instead of using slots reserved by the request stage. The mean was lower in all 6 PR rounds (−4% to −13%), but several confidence intervals overlap and ContextOnly itself moves ±6% between rounds on this 2-core machine. I'm treating this as an allocation-only improvement, not a confirmed time win.

Benchmark Round main Mean PR Mean Δ time main Allocated PR Allocated
ContextOnly 1 517.9 ns ±22.3 504.4 ns ±26.3 -2.6% 2,016 B 2,016 B
ContextOnly 2 524.8 ns ±37.5 535.3 ns ±13.9 +2.0% 2,016 B 2,016 B
ContextOnly 3 536.1 ns ±39.4 502.4 ns ±9.9 -6.3% 2,016 B 2,016 B
DefaultFields 1 1,818.4 ns ±196.5 1,587.5 ns ±52.4 -12.7% 4,272 B 4,016 B
DefaultFields 2 1,708.5 ns ±95.5 1,634.3 ns ±53.7 -4.3% 4,272 B 4,016 B
DefaultFields 3 1,645.4 ns ±37.3 1,551.5 ns ±22.3 -5.7% 4,272 B 4,016 B
CombineLogs 1 1,654.4 ns ±82.0 1,541.4 ns ±39.0 -6.8% 4,632 B 4,344 B
CombineLogs 2 1,678.1 ns ±126.5 1,602.8 ns ±39.3 -4.5% 4,632 B 4,344 B
CombineLogs 3 1,688.9 ns ±114.5 1,524.8 ns ±30.7 -9.7% 4,632 B 4,344 B

BenchmarkDotNet v0.13.0, InProcess (--config perflab), 5 warmup + 15 measured iterations, Server GC. Rounds ran in the order main, PR, main, PR, main, PR. Both builds use the same benchmark source; "main" is this PR's merge base (4f556f7) and "PR" is bf9a8a9. Allocated is exact bytes per op from the JSON exporter. Machine: AMD EPYC 9V74, 2 cores, Ubuntu 24.04 (container), .NET SDK 12.0.100-alpha.1.26521.103, runtime 12.0.0 (12.0.26.52911).

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Copilot AI balanced review requested due to automatic review settings October 31, 2026 10:31
@github-actions github-actions Bot added the area-middleware Includes: URL rewrite, redirect, response cache/compression, session, and other general middlewares label Oct 31, 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.

🟡 Changes recommended

The capacity reservations overallocate request storage and allocate unused response arrays in some logging configurations, causing unnecessary allocations on every request.

2 open issues
What changed in this PR

This PR pre-sizes HTTP logging parameter lists to reduce intermediate array allocations while preserving log contents and ordering.

Changes:

  • Reserves capacity before collecting request and response properties and headers.
  • Adds parameterized coverage for header and interceptor-parameter ordering with separate and combined logs.
File Description
src/​Middleware/​HttpLogging/​test/​HttpLoggingMiddlewareTests.cs Tests exact log ordering with many headers and interceptor-added parameters.
src/​Middleware/​HttpLogging/​src/​HttpLoggingMiddleware.cs Adds a shared capacity helper and request/response reservations.

Review effort: Balanced

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

/azp run aspnetcore-components-e2e

Only aspnetcore-components-e2e (Mono server) failed, on ServerRoutingTest.NavigationLock_CanBlockExternalNavigation (URL assertion on external navigation). This is a known flake. In my last ~8 e2e runs on unrelated PRs it failed 3 times (#70177 and #70173 here, plus #70107 and #67015 elsewhere), roughly 35%. This PR only changes HttpLoggingMiddleware list sizing and doesn't touch Components.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

@azure-pipelines

Copy link
Copy Markdown
No pipelines are associated with this pull request.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

/azp run returned "No pipelines are associated", so I pushed empty commit a012c09 to retrigger CI. The only failure was the known flake ServerRoutingTest.NavigationLock_CanBlockExternalNavigation (Mono server). It failed in about 3 of the last ~8 e2e runs I've observed, including on unrelated #70107 and #67015.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

aspnetcore-ci passed on the previous run. I pushed empty commit 5a87c35 to retrigger the e2e pipeline, which failed only (Mono client and WebAssembly) on:

  • VirtualizationTest.VariableHeight_HtmlTable_DoesNotProduceNestedTrElements
  • RedirectionTest.NavigationException_InAsyncContext_DoesNotBecomeUnobservedTaskException

Both are currently failing on unrelated PRs too: #69752 (RDG-only), #70068, #70173's previous run and #70177. Over the e2e runs I've watched today they hit about 1 in 3 runs. This PR only changes HttpLoggingMiddleware.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

The (Mono client and WebAssembly) e2e leg failed again on the same two tests: RedirectionTest.NavigationException_InAsyncContext_DoesNotBecomeUnobservedTaskException and VirtualizationTest.VariableHeight_HtmlTable_DoesNotProduceNestedTrElements. This PR can't affect them. Nothing under src/Components references HttpLogging or W3CLogging (grep -r "HttpLogging\|W3CLogging" src/Components returns nothing), and the change is confined to HttpLoggingMiddleware.cs. The same leg also failed on #69752 earlier today and later passed there, and it currently passes on #70106, #70173, #69557, #70176 and #70169. I pushed empty commit 53a3020 to retrigger.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

aspnetcore-ci and aspnetcore-quarantined-pr passed on 53a3020. The only failure was ServerRoutingTest.NavigationLock_CanBlockExternalNavigation in the (Mono server) e2e leg, the same flake as the first run here and on #70177, #70107 and #67015. Across the e2e runs on my PRs today it has failed 4 of ~12 runs. I pushed empty commit da32160 to retrigger.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

aspnetcore-ci (Platform tests Test: macOS) failed during restore with an infrastructure error: NU1301 ... nodename nor servname provided, or not known (pkgs.dev.azure.com:443), a DNS failure on the agent, in SignalR projects this PR doesn't touch. I pushed empty commit 95a5749 to retrigger.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

On 95a5749, aspnetcore-ci and aspnetcore-quarantined-pr passed again. Only the (Mono server) e2e leg failed: ServerRoutingTest.NavigationLock_CanBlockExternalNavigation and ServerVirtualizationTest.CancelsOutdatedRefreshes_Async. Across the 7 most recently updated PRs, that leg currently fails on 3, including unrelated #70106 and #70144, so the failure rate is about 40%. Nothing in src/Components uses HttpLogging. I pushed empty commit 9d8da48 to retrigger.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

…69494)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

CI on 9d8da48 failed only on BlazorTemplates.Tests.BlazorWebTemplateTest.BlazorWebTemplate_ConditionalPasskeyRegistration (Windows Server x64 platform tests). That test is a known intermittent Playwright failure on Windows, tracked in open issue #69494 ("Response body is not available for a response that was navigated away from"). The template doesn't use HttpLogging or W3CLogging, and all three Blazor E2E legs passed on that run. I pushed empty commit de89bec to retrigger aspnetcore-ci.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

CI on de89bec failed only on tests unrelated to this HttpLogging change:

The previous failure (BlazorWebTemplate_ConditionalPasskeyRegistration, #69494) passed on this run. I pushed empty commit 6a6fc86 to retrigger.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

…ocess)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

On 6a6fc86, all three Blazor E2E legs, the platform tests and the quarantined pipeline passed. The only failure was Microsoft.AspNetCore.Server.IIS.NewHandler.FunctionalTests.ShutdownTests.ConfigurationTouchedStress_InProcess, an IIS in-process shutdown stress test (src/Servers/IIS/IIS/test/Common.LongTests/ShutdownTests.cs). It doesn't involve HttpLogging, and ShutdownTests have a history of quarantines for intermittent failures (#38951). Every check has now passed on at least one run of this PR's code; the failures across reruns were each a different known-intermittent test. I pushed empty commit 14e8401 to retrigger.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

…ble)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Copy link
Copy Markdown
Member Author

On 14e8401, aspnetcore-ci passed (including Helix, platform tests and the Windows templates leg), and so did aspnetcore-quarantined-pr. The only failures were two Blazor E2E tests, on the Mono server and Mono client/WebAssembly legs:

  • ServerRoutingTest.NavigationLock_CanBlockExternalNavigation
  • VirtualizationTest.VariableHeight_HtmlTable_DoesNotProduceNestedTrElements

Both have failed intermittently on earlier runs of this PR and passed on others (all three E2E legs were green on 6a6fc86 and 9d8da48). They also fail on unrelated PRs such as #69752 and #70068. Nothing under src/Components references HttpLogging. I pushed empty commit d29a09a to retrigger.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

@PureWeen

PureWeen commented Nov 1, 2026

Copy link
Copy Markdown
Member

/review

Adds a Microsoft.AspNetCore.HttpLogging.Microbenchmarks project that runs
the UseHttpLogging pipeline with default fields and with CombineLogs, using
an enabled logger that formats every message.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@davidfowl davidfowl added the agent:working An AI agent is actively working on this issue/PR label Nov 6, 2026 — with Copilot SWE Agent
@davidfowl davidfowl removed the agent:working An AI agent is actively working on this issue/PR label Nov 6, 2026

@DeagleGross DeagleGross left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

update bencmark after change as always

@davidfowl davidfowl added the agent:working An AI agent is actively working on this issue/PR label Nov 9, 2026 — with Copilot SWE Agent

davidfowl commented Nov 9, 2026 •

Copy link
Copy Markdown
Member Author

ASP.NET Core Perf 2 stopped because the EnsureCapacity review feedback is addressed in bf9a8a9.

🤖 Posted by ASP.NET Core Perf 2 (AI Agent)

Replace the per-field counting with Count + a small constant + Headers.Count
(headers only when enabled), as suggested in review.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@davidfowl davidfowl removed the agent:working An AI agent is actively working on this issue/PR label Nov 9, 2026
@DeagleGross
DeagleGross merged commit 1830fd7 into main Nov 10, 2026
30 checks passed
@DeagleGross
DeagleGross deleted the perf/httplogging branch November 10, 2026 09:56
@github-actions

Copy link
Copy Markdown
Contributor

✅ No documentation PR was created.

Confidence that documentation is needed: 3%

No docs needed: internal performance refactoring of HttpLoggingMiddleware (tests, benchmark, internal source only); no public API or behavior change.

Documentation surfaces considered

  • Conceptual article: Not required — Internal allocation optimization; output, order, and API unchanged.
  • Migration guidance: Not required — No user action needed when upgrading.
  • Breaking change: Not required — No compatibility impact; only list capacity changes.

This branch was previously deployed

1 inactive deployment
copilot-pat-pool — bf9a8a98 Deployed Nov 10, 2026 by DeagleGross via conclusion #261
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area-middleware Includes: URL rewrite, redirect, response cache/compression, session, and other general middlewares

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants