[HTTP/3] Stress QUIC mangled data

[ManickaP]

While investigating System.Net.Http.HttpRequestException: The server returned an invalid or unrecognized response. and similar errors with H/3 stress I noticed that data sent from the server do not correspond to the data received on the client. Specifically, the first 2 bytes get mangled:

// Data from server from StreamSend
2022-07-24 15:33:11.189 +02:00 [DBG] 13:33:11.1891745[Info] thisOrContextObject: QuicStream#28784787, memberName: WriteAsync, message: [strm][0x7FB794029990] SEND 012C0000D9561D53756E2C203234204A756C20323032322031333A33333A313120474D545F4D074B65737472656C00417F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E
// Data from client from RECEIVE event
13:33:11.1977316[Info] thisOrContextObject: QuicStream#27524287, memberName: HandleEventReceive, message:                           [strm][0x7FB7E801A860] RECEIVE 422C0000D9561D53756E2C203234204A756C20323032322031333A33333A313120474D545F4D074B65737472656C00417F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E

// Server
2022-07-24 16:22:07.122 +02:00 [DBG] 14:22:07.1225155[Info] thisOrContextObject: QuicStream#64247531, memberName: WriteAsync, message: [strm][0x7F6BD401BAC0] SEND    012C0000D9561D53756E2C203234204A756C20323032322031343A32323A303620474D545F4D074B65737472656C0040C4000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F40414243
// Client
14:22:07.1297277[Info] thisOrContextObject: QuicStream#19014160, memberName: HandleEventReceive, message:                              [strm][0x7F6B840233B0] RECEIVE 6B6B0000D9561D53756E2C203234204A756C20323032322031343A32323A303620474D545F4D074B65737472656C0040C4000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F40414243

Happens only with "GET Aborted" as far as I can tell, fairly regularly.

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

Tagging subscribers to this area: @dotnet/ncl
See info in area-owners.md if you want to be subscribed.

Issue Details

---

While investigating System.Net.Http.HttpRequestException: The server returned an invalid or unrecognized response. and similar errors with H/3 stress I noticed that data sent from the server do not correspond to the data received on the client. Specifically, the first 2 bytes get mangled:

// Data from server from StreamSend
2022-07-24 15:33:11.189 +02:00 [DBG] 13:33:11.1891745[Info] thisOrContextObject: QuicStream#28784787, memberName: WriteAsync, message: [strm][0x7FB794029990] SEND 012C0000D9561D53756E2C203234204A756C20323032322031333A33333A313120474D545F4D074B65737472656C00417F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E
// Data from client from RECEIVE event
13:33:11.1977316[Info] thisOrContextObject: QuicStream#27524287, memberName: HandleEventReceive, message:                           [strm][0x7FB7E801A860] RECEIVE 422C0000D9561D53756E2C203234204A756C20323032322031333A33333A313120474D545F4D074B65737472656C00417F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E

// Server
2022-07-24 16:22:07.122 +02:00 [DBG] 14:22:07.1225155[Info] thisOrContextObject: QuicStream#64247531, memberName: WriteAsync, message: [strm][0x7F6BD401BAC0] SEND    012C0000D9561D53756E2C203234204A756C20323032322031343A32323A303620474D545F4D074B65737472656C0040C4000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F40414243
// Client
14:22:07.1297277[Info] thisOrContextObject: QuicStream#19014160, memberName: HandleEventReceive, message:                              [strm][0x7F6B840233B0] RECEIVE 6B6B0000D9561D53756E2C203234204A756C20323032322031343A32323A303620474D545F4D074B65737472656C0040C4000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F40414243

Happens only with "GET Aborted" as far as I can tell, fairly regularly.

Author:	ManickaP
Assignees:	-
Labels:	area-System.Net.Http
Milestone:	-

[ManickaP]

 endpoints.MapGet("/abort", async context =>
{
    // Server writes some content, then aborts the connection
    string content = CreateResponseContent(context);
    await context.Response.WriteAsync(content.Substring(0, content.Length / 2));
    context.Abort();
});

Root cause of the problem is that we unblock WriteAsync as part of Abort which lets the caller reuse the memory passed to MsQuic. This is possible to happen in parallel on Kestrel due indirection between app calling Reponse.WriteAsync and the actual transport doing QuicStream.WriteAsync since there is pipeline in between.

So we either need to wait for SEND_COMPLETE or do our own buffer copy.

Also we had this problem before as well as it seems:

runtime/src/libraries/System.Net.Quic/src/System/Net/Quic/Implementations/MsQuic/MsQuicStream.cs

Lines 620 to 623 in 9c37a3b

	if (_state.SendState == SendState.None || _state.SendState == SendState.Pending)
	{
	shouldCompleteSends = true;
	}

[ManickaP]

Mulling this over, I think we need to do a copy. In case of a cancellation, we also unblock the waiter before we get SEND_COMPLETE which might overwrite data in the buffer passed to MsQuic. And we certainly cannot wait for the event in case of a cancellation, that would made it useless.

[wfurt]

If new cancel/abort, can we wait for notification from MsQuic? It feels like that should not be too long as all should be processable locally. If we copy, we will alway pay penalty for (hopefully) rare case.

[ManickaP]

It nullifies the cancel, since we're basically waiting for send confirmation (it should be fast for internal buffering but might block if msquic has full buffers). As a result cancel wouldn't do anything, we might just ignore it.

[CarnaViire]

If new cancel/abort, can we wait for notification from MsQuic?

It nullifies the cancel, since we're basically waiting for send confirmation (it should be fast for internal buffering but might block if msquic has full buffers). As a result cancel wouldn't do anything, we might just ignore it.

I believe MsQuic would stop waiting and it would deliver the event SEND_COMPLETED(Canceled=1) as soon as it can... at least that's my understanding of the code https://github.com/microsoft/msquic/blob/41a42f0fbf51f217a6bee11e8955a8f1ac179b38/src/core/stream_send.c#L159-L165