Wrap the PipeWriter used by Kestrel's output writing logic #12081

halter73 · 2019-07-11T02:53:04Z

Kestrel's Http2FrameWriter expects to be able to append more data to the combined TCP-connection-level PipeWriter even there's currently an ongoing call to PipeWriter.FlushAsync() that's only being observed by another stream or streams. Http1OutputProducer also expects to be able to be able to append during flush in order to provide legacy support for unawaited calls to Response.Body.WriteAsync().

There's currently an issue with DefaultPipeWriter where this usage doesn't always work as intended which has lead to some HTTP/2 output corruption. This is also generally much more difficult to support than simply requiring that FlushAsync() always be awaited before calling GetMemory/Span() again. For this reason, we're likely to change DefaultPipeWriter to always throw when GetMemory/Span() is called before the last call to FlushAsync() completes.

This change adds a PipeWriter decorator called ConcurrentPipeWriter (better names welcome but at least it's internal) meant to exclusively be use by Kestrel's Http2FrameWriter and Http1OutputProducer. For the most part ConcurrentPipeWriter is strictly passthrough, but if a flush is pending and GetMemory/Span() is called, it copies the logic from corefx's StreamPipeWriter to manually build up a linked-list of pending data to be flush. Like DefaultPipeWriter today, anyone currently awaiting a flush will see their flush completion delayed until the data appended during the flush also gets flushed.

The effect of the ConcurrentPipeWriter on the PipeWriter being decorated is that it looks to the inner PipeWriter like it's being called by a regular write loop despite Http2FrameWriter/Http1OutputProducer's admittedly unusual usage of the ConcurrentPipeWriter.

Partially Addresses #11804

davidfowl · 2019-07-11T04:30:35Z

One thing you can do to get some extra coverage for free would be to swap the PipeWriter back to the StreamPipeWriter. It in theory should work with this decorator now.

src/Servers/Kestrel/Core/src/Internal/Infrastructure/PipeWriterHelpers/ConcurrentPipeWriter.cs

davidfowl · 2019-07-11T07:25:33Z

src/Servers/Kestrel/Core/src/Middleware/Internal/DuplexPipeStreamAdapter.cs


-        public override ValueTask DisposeAsync()
+        protected override void Dispose(bool disposing)


Remove dispose. DisposeAsync should be enough (in my original debugging, base.DisposeAsync will just call Dispose).

Wouldn't that make DuplexStreamAdapter.Close()/Dispose() no-op while DuplexStreamAdapter.DisposeAsync() would actually cleanup? That seems bad to me.

https://github.com/dotnet/corefx/blob/ac154845e79c6154c2b502aa3cdd4410e1b5f2b0/src/Common/src/CoreLib/System/IO/Stream.cs#L210-L234

If anything, I would remove DisposeAsync() since the default implementation of Stream.DisposeAsync() calls Stream.Dispose(). Do you want me to do that instead?

We’re going to make it CompleteAsync eventually though so i rather keep it

davidfowl · 2019-07-11T07:25:56Z

src/Servers/Kestrel/Core/src/Internal/Infrastructure/PipeWriterHelpers/TimingPipeFlusher.cs

@@ -21,15 +21,6 @@ internal class TimingPipeFlusher
        private readonly ITimeoutControl _timeoutControl;
        private readonly IKestrelTrace _log;

-        private readonly object _flushLock = new object();


So much cleaner 😄

src/Servers/Kestrel/Core/src/Internal/Infrastructure/PipeWriterHelpers/ConcurrentPipeWriter.cs

davidfowl · 2019-07-11T07:31:35Z

src/Servers/Kestrel/Core/src/Internal/Infrastructure/PipeWriterHelpers/ConcurrentPipeWriter.cs

+        private BufferSegment _tail;
+        private Memory<byte> _tailMemory;
+        private int _tailBytesBuffered;
+        private int _bytesBuffered;


This should be a long, though in practice I dunno if that will matter, you'd probably OOM first 😄

Technically, you're right. We should probably change it to a long in StreamPipeWriter too.

Tratcher · 2019-07-11T16:00:52Z

Like DefaultPipeWriter today, anyone currently awaiting a flush will see their flush completion delayed until the data appended during the flush also gets flushed.

Can't this lead to a kind of starvation? E.g. one code path like response bodies consistently waits for flushes, where another like responses without bodies consistently appends without flushing. The latter would always get prioritized over the former.

Why not let the flush complete normally and have new data wait for the next flush? That might be simpler to implement as well.

src/Servers/Kestrel/Core/src/Internal/Infrastructure/PipeWriterHelpers/ConcurrentPipeWriter.cs

jkotalik · 2019-07-11T16:17:18Z

src/Servers/Kestrel/Core/src/Internal/Infrastructure/PipeWriterHelpers/TimingPipeFlusher.cs

@@ -9,7 +9,7 @@
 using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http;
 using Microsoft.Extensions.Logging;

-namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
+namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure.PipeWriterHelpers


nit: Idk if we should have this in the PipeWriterHelpers namespace.

The only reason I did this is because Kestrel Core's Infrastructure directory was getting pretty large, particularly with the addition of BufferSegment, and I wanted to namespace to match the directory structure.

I guess TimingPipeFlusher could go back to the Infrastructure directory, but if feels more related to the other stuff in the PipeWriterHelpers folder in my opinion.

jkotalik · 2019-07-11T16:19:21Z

src/Servers/Kestrel/Core/test/Http2FrameWriterTests.cs

@@ -41,7 +41,7 @@ public async Task WriteWindowUpdate_UnsetsReservedBit()
        {
            // Arrange
            var pipe = new Pipe(new PipeOptions(_dirtyMemoryPool, PipeScheduler.Inline, PipeScheduler.Inline));
-            var frameWriter = new Http2FrameWriter(pipe.Writer, null, null, null, null, null, null, new Mock<IKestrelTrace>().Object);
+            var frameWriter = new Http2FrameWriter(pipe.Writer, null, null, null, null, null, null, _dirtyMemoryPool, new Mock<IKestrelTrace>().Object);


jkotalik · 2019-07-11T16:19:59Z

src/Servers/Kestrel/Core/test/ConcurrentPipeWriterTests.cs

+
+                var flushTask0 = concurrentPipeWriter.FlushAsync();
+
+                concurrentPipeWriter.GetMemory();


bold move to call GetMemory without looking at the length 😄

halter73 · 2019-07-11T21:48:57Z

Can't this lead to a kind of starvation? E.g. one code path like response bodies consistently waits for flushes, where another like responses without bodies consistently appends without flushing. The latter would always get prioritized over the former.

Why not let the flush complete normally and have new data wait for the next flush? That might be simpler to implement as well.

What I like about the current implementation is that we don't have to maintain a queue of TaskCompletionSources and keep track of which buffers correspond to which calls to flush. Instead we let a single TaskCompletionSource manage the only queue of every awaiting flusher.

If there's a codepath that's consistently appending without flushing, they'll effectively get prioritized no matter what since there's no way for that codepath to observe backpressure unless we block in GetMemory() or something which we decided we're not doing.

src/Servers/Kestrel/Transport.Libuv/test/LibuvOutputConsumerTests.cs

src/Servers/Kestrel/Core/src/Internal/Infrastructure/PipeWriterHelpers/ConcurrentPipeWriter.cs

This reverts commit 6de357e. # Conflicts: # src/Servers/Kestrel/Core/src/Internal/Http2/Http2FrameWriter.cs # src/Servers/Kestrel/Core/src/Middleware/Internal/DuplexPipeStreamAdapter.cs

This reverts commit 1b4cc4e.

halter73 · 2019-07-17T00:41:52Z

Pipelined Plaintext Physical Servers (master):

Description	RPS	CPU (%)	Memory (MB)	Avg. Latency (ms)	Startup (ms)	First Request (ms)	Latency (ms)
√	4,912,446	89	53	0.78202	349.9177	96.5003	0.315
√	4,875,139	94	53	1.34	356.3113	96.4683	0.333
√	4,868,069	89	52	1.7	350.6418	96.3498	0.3367

Pipelined Plaintext Physical Servers (halter73/concurrent-pipewriter):

Description	RPS	CPU (%)	Memory (MB)	Avg. Latency (ms)	Startup (ms)	First Request (ms)	Latency (ms)
√	4,730,116	92	52	1.83	348.1635	96.783	0.3778
√	4,836,873	89	52	1.25	349.2496	97.0053	0.3307
√	4,811,783	90	51	1.67	342.6237	97.5256	0.3324

BenchmarkDriver command and runtime versions

dotnet run -- --server http://<Physical Windows Server>:5001 --client http://<Physical Linux Client>:5002 -j ../../src/Benchmarks/benchmarks.plaintext.json -n Plaintext --webHost KestrelSockets -i 3 -dotnet "Latest" -aspnet "Latest" --self-contained --output-file C:\dev\aspnet\AspNetCore\artifacts\bin\Microsoft.AspNetCore.Server.Kestrel.Core\Release\netcoreapp3.0\*

...

Runtime:                     3.0.0-preview8-27914-06
ASP.NET Core:                3.0.0-preview8.19366.5

On average this works out to about a 2% perf regression in the techempower pipelined plaintext benchmark.

The pipelined plaintext benchmark is probably one of the most impacted benchmarks since Http1OutputProducer now writes through the ConcurrentPipeWriter which results in two additional uncontested calls to Monitor.Enter/Exit per response. This is because the ConcurrentPipeWriter.GetMemory() and ConcurrentPipeWriter.Advance() each acquire a lock. The lock taken in ConcurrentPipeWriter.FlushAsync() simply replaces the lock that was previously taken by TimingPipeFlusher.

If we're concerned about this 2% perf regression, we could consider passing the lock used by Http1/2OutputProducer and Http2FrameWriter to the ConcurrentPipeWriter ctor to use for it's own locking. If we did this, the ConcurrentPipeWriter could assume the correct lock was already taken any time GetMemory(), Advance() or FlushAsync() is called. That would mean the ConcurrentPipeWriter would only need to acquire a lock itself if it need to do a "background" flush which should never happen in the pipelined plaintext benchmark.

We could try the lock sharing as a follow up PR too.

halter73 · 2019-07-17T05:16:56Z

Do you want to approve this @davidfowl?

halter73 · 2019-07-17T05:26:56Z

If it makes you feel better here are the benchmark results for the ConcurrentPipeWriter w/ the lock sharing.

Description	RPS	CPU (%)	Memory (MB)	Avg. Latency (ms)	Startup (ms)	First Request (ms)	Latency (ms)
√	4,844,989	91	51	1.33	349.997	118.0152	0.1255
√	4,937,008	92	52	1.13	351.6509	98.6947	0.1248
√	4,933,612	92	53	1	344.8211	97.1101	0.1193

So I'm confident we can get the perf back.

halter73 requested review from davidfowl, Tratcher and jkotalik July 11, 2019 02:53

halter73 requested a review from analogrelay as a code owner July 11, 2019 02:53