Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Use new PipeWriter Json overloads #55740

Merged
merged 6 commits into from
Jul 12, 2024
Merged

Use new PipeWriter Json overloads #55740

merged 6 commits into from
Jul 12, 2024

Conversation

BrennanConroy
Copy link
Member

No description provided.

@dotnet-issue-labeler dotnet-issue-labeler bot added the area-mvc Includes: MVC, Actions and Controllers, Localization, CORS, most templates label May 15, 2024
@davidfowl
Copy link
Member

How's the perf 😄

@BrennanConroy
Copy link
Member Author

/benchmark mvcjsoninput2k aspnet-citrine-win mvc

@pr-benchmarks PR Benchmarks
Copy link

pr-benchmarks bot commented May 15, 2024

Benchmark started for mvcjsoninput2k on aspnet-citrine-win with mvc. Logs: link

@pr-benchmarks PR Benchmarks
Copy link

pr-benchmarks bot commented May 15, 2024

An error occurred, please check the logs

@BrennanConroy
Copy link
Member Author

Json400k

Some highlights:

orig PR
Max Time in GC (%) 50.00 0.00
Max Allocation Rate (B/sec) 556,877,008 174,337,648
Requests/sec 10,468 11,796
Requests 157,726 178,125
Mean latency (ms) 24.51 22.02
Read throughput (MB/s) 3,993.60 4,505.60
Json400k full comparison
application orig PR
Max CPU Usage (%) 99 97
Max Cores usage (%) 2,776 2,710
Max Working Set (MB) 615 541
Max Private Memory (MB) 1,772 1,394
Max CPU Usage (%) 99 97
Max Working Set (MB) 644 567
Max GC Heap Size (MB) 927 524
Size of committed memory by the GC (MB) 967 571
Max Number of Gen 0 GCs / sec 3.00 1.00
Max Number of Gen 1 GCs / sec 3.00 1.00
Max Number of Gen 2 GCs / sec 3.00 1.00
Max Gen 0 GC Budget (MB) 353 353
Max Time in GC (%) 50.00 0.00
Max Gen 0 Size (B) 37,819,984 33,837,872
Max Gen 1 Size (B) 8,545,520 7,586,216
Max Gen 2 Size (B) 3,330,152 2,555,136
Max LOH Size (B) 497,838,352 101,466,040
Max POH Size (B) 103,427,936 101,722,256
Max Allocation Rate (B/sec) 556,877,008 174,337,648
Max GC Heap Fragmentation (%) 584% 1,390%
Max Lock Contention (#/s) 31 69
Max ThreadPool Threads Count 48 48
Max ThreadPool Queue Length 118 50
Max ThreadPool Items (#/s) 33,745 59,246
Max Active Timers 1 1
IL Jitted (B) 314,010 320,324
Methods Jitted 3,250 3,365
Load Working Set - P90 (MB) 615 541
Load CPU Usage - P90 (%) 99 85
load orig PR
Max CPU Usage (%) 24 42
Max Cores usage (%) 665 1,184
First Request (ms) 133 136
Requests/sec 10,468 11,796
Requests 157,726 178,125
Mean latency (ms) 24.51 22.02
Max latency (ms) 81.26 128.84
Read throughput (MB/s) 3,993.60 4,505.60
Latency 50th (ms) 23.84 22.13
Latency 75th (ms) 26.78 29.45
Latency 90th (ms) 31.41 36.88
Latency 99th (ms) 47.20 55.13

MVCJsonOutput2M

Some lowlights:

orig PR
Max CPU Usage (%) 27 15
Max Working Set (MB) 178 455
Max Allocation Rate (B/sec) 2,917,704 25,409,048
Requests/sec 501 369
Requests 7,559 5,561
Mean latency (ms) 7.99 10.81
Read throughput (MB/s) 1,003.52 737.25
MVCJsonOutput2M full comparison
application orig PR
Max CPU Usage (%) 27 15
Max Cores usage (%) 751 429
Max Working Set (MB) 170 434
Max Private Memory (MB) 390 642
Build Time (ms) 3,429 3,278
Start Time (ms) 254 306
Published Size (KB) 99,082 99,082
Symbols Size (KB) 25 25
.NET Core SDK Version 9.0.100-preview.5.24264.22 9.0.100-preview.5.24264.22
ASP.NET Core Version 9.0.0-preview.5.24256.2+da3aa27233a2 9.0.0-preview.5.24256.2+da3aa27233a2
.NET Runtime Version 9.0.0-preview.5.24264.10+426edd093a8d 9.0.0-preview.5.24264.10+426edd093a8d
Max CPU Usage (%) 27 15
Max Working Set (MB) 178 455
Max GC Heap Size (MB) 81 345
Size of committed memory by the GC (MB) 0 363
Max Number of Gen 0 GCs / sec 0.00 1.00
Max Number of Gen 1 GCs / sec 0.00 0.00
Max Number of Gen 2 GCs / sec 0.00 0.00
Max Gen 0 GC Budget (MB) 353 353
Max Time in GC (%) 0.00 0.00
Max Gen 0 Size (B) 0 2,941,048
Max Gen 1 Size (B) 0 4,086,016
Max Gen 2 Size (B) 0 0
Max LOH Size (B) 0 98,384
Max POH Size (B) 0 19,206,896
Max Allocation Rate (B/sec) 2,917,704 25,409,048
Max GC Heap Fragmentation (%) 0% 1,135%
# of Assemblies Loaded 104 104
Max Exceptions (#/s) 17 11
Max Lock Contention (#/s) 5 2
Max ThreadPool Threads Count 11 9
Max ThreadPool Queue Length 1 0
Max ThreadPool Items (#/s) 73,533 2,656
Max Active Timers 1 1
IL Jitted (B) 415,433 555,020
Methods Jitted 4,383 7,157
Load Working Set - P90 (MB) 170 434
Load CPU Usage - P90 (%) 26 12
load orig PR
Max CPU Usage (%) 5 3
Max Cores usage (%) 149 98
Max Working Set (MB) 53 53
Max Private Memory (MB) 158 158
Build Time (ms) 5,737 3,469
Start Time (ms) 0 0
Published Size (KB) 72,259 72,259
Symbols Size (KB) 0 0
.NET Core SDK Version 8.0.300 8.0.300
ASP.NET Core Version 8.0.5+c9e3996173ce 8.0.5+c9e3996173ce
.NET Runtime Version 8.0.5+087e15321bb7 8.0.5+087e15321bb7
First Request (ms) 216 297
Requests/sec 501 369
Requests 7,559 5,561
Mean latency (ms) 7.99 10.81
Max latency (ms) 18.54 25.82
Bad responses 0 0
Socket errors 0 0
Read throughput (MB/s) 1,003.52 737.25
Latency 50th (ms) 7.72 9.89
Latency 75th (ms) 7.91 10.63
Latency 90th (ms) 8.32 14.17
Latency 99th (ms) 14.21 18.44

Will need to look into what's wrong with the MVC case. A quick glance at wire shark does show Pipes sending 65k at a time, whereas Stream sends in ~14k, ~59k, and ~29k chunks so there might be some window acking slowdown in the 65k case?

@davidfowl
Copy link
Member

This:

aspnetcore/src/Servers/Kestrel/Core/src/Internal/Http/Http1OutputProducer.cs

Lines 753 to 754 in 9203f25

_currentSegment = new byte[sizeHint];
_currentSegmentOwner = null;

@BrennanConroy BrennanConroy mentioned this pull request May 22, 2024
Merged
@dotnet-policy-service dotnet-policy-service bot added the pending-ci-rerun When assigned to a PR indicates that the CI checks should be rerun label May 25, 2024
@build-analysis build-analysis bot mentioned this pull request Jun 19, 2024
Open
3 tasks
halter73
halter73 approved these changes Jul 1, 2024
View reviewed changes
Copy link
Member

@halter73 halter73 left a comment

Choose a reason for hiding this comment

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

We didn't add this API not to use it. We can always revert if it regresses some scenario we didn't realize, but it looks good to me.

Do we have updated MVCJsonOutput2M numbers that show the calls to StartAsync fixed the regression?

src/Http/Http.Extensions/src/HttpResponseJsonExtensions.cs
return WriteAsJsonAsyncSlow(response.Body, value, options, response.HttpContext.RequestAborted);
return WriteAsJsonAsyncSlow(startTask, response.BodyWriter, value, options,
ignoreOCE: !cancellationToken.CanBeCanceled,
cancellationToken.CanBeCanceled ? cancellationToken : response.HttpContext.RequestAborted);
Copy link
Member

Choose a reason for hiding this comment

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

The "Slow" path is normal one right, since the middleware doesn't pass a cancellation token?

I think it would be better to change WriteAsJsonAsync not pass in RequestAborted by default similar to WriteAsync. Essentially serializing JSON data to /dev/null should be faster most of the time than handling an OCE anyway unless you're doing something unusual like IAsyncEnumerable serialization, where you would probably want to explicitly pass in RequestAborted.

Right now, the only way to get the fast pass is to pass in a token from a cancellable source and then not cancel it. Passing in RequestAborted explicitly mostly works for this, but that's annoying and could result in OCEs in your logs that you don't want.

@JamesNK @Tratcher do you have opinions on not passing in RequestAborted by default?

src/Http/Http.Extensions/src/HttpResponseJsonExtensions.cs
if (!response.HasStarted)
{
// Flush headers before starting Json serialization. This avoids an extra layer of buffering before the first flush.
startTask = response.StartAsync(cancellationToken);
Copy link
Member

Choose a reason for hiding this comment

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

It'd be nice to get some HTTP/2 numbers too. I don't think this optimization helps in that case, but it probably doesn't hurt either. @sebastienros Do we have any HTTP/2 scenarios that use WriteAsJsonAsync?

@BrennanConroy
Copy link
Member Author

Do we have updated MVCJsonOutput2M numbers that show the calls to StartAsync fixed the regression?

I think it was the incorrect flushing in Json. I did run this a couple weeks ago and the regression was gone.

The "Slow" path is normal one right, since the middleware doesn't pass a cancellation token?

That's kind of funny 😆

opinions on not passing in RequestAborted by default?

This was already this way before this PR, so something to follow up on?

@BrennanConroy
Copy link
Member Author

Merging so perf CI can let us know what improves and what doesn't.

@BrennanConroy BrennanConroy merged commit cd24d14 into main Jul 12, 2024
26 checks passed
@BrennanConroy BrennanConroy deleted the brecon/pipe branch July 12, 2024 20:26
@dotnet-policy-service dotnet-policy-service bot added this to the 9.0-preview7 milestone Jul 12, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@davidfowl davidfowl davidfowl left review comments

@halter73 halter73 halter73 approved these changes

@captainsafia captainsafia Awaiting requested review from captainsafia captainsafia is a code owner

@JamesNK JamesNK Awaiting requested review from JamesNK JamesNK is a code owner

@mgravell mgravell Awaiting requested review from mgravell mgravell is a code owner

Assignees
No one assigned
Labels
area-mvc Includes: MVC, Actions and Controllers, Localization, CORS, most templates pending-ci-rerun When assigned to a PR indicates that the CI checks should be rerun
Projects
None yet
Milestone
9.0-preview7
Development

Successfully merging this pull request may close these issues.
3 participants
@BrennanConroy @davidfowl @halter73