[release/6.0] Improve tracing of HTTP/2 PINGs (#57930)

* more HTTP/2 PING logging

* test unexpected PING response

Co-authored-by: Anton Firszov <antonfir@gmail.com>

diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs
index b6a33b2..b632761 100644 (file)
--- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs
+++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs
@@ -915,6 +915,8 @@ namespace System.Net.Http
             ReadOnlySpan<byte> pingContent = _incomingBuffer.ActiveSpan.Slice(0, FrameHeader.PingLength);
             long pingContentLong = BinaryPrimitives.ReadInt64BigEndian(pingContent);
 
+            if (NetEventSource.Log.IsEnabled()) Trace($"Received PING frame, content:{pingContentLong} ack: {frameHeader.AckFlag}");
+
             if (frameHeader.AckFlag)
             {
                 ProcessPingAck(pingContentLong);

diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2StreamWindowManager.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2StreamWindowManager.cs
index 4a1f7ee..a9314d1 100644 (file)
--- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2StreamWindowManager.cs
+++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2StreamWindowManager.cs
@@ -213,6 +213,7 @@ namespace System.Net.Http
 
                     // Send a PING
                     _pingCounter--;
+                    if (NetEventSource.Log.IsEnabled()) connection.Trace($"[FlowControl] Sending RTT PING with payload {_pingCounter}");
                     connection.LogExceptions(connection.SendPingAsync(_pingCounter, isAck: false));
                     _pingSentTimestamp = now;
                     _state = State.PingSent;
@@ -223,6 +224,7 @@ namespace System.Net.Http
             {
                 if (_state != State.PingSent && _state != State.TerminatingMayReceivePingAck)
                 {
+                    if (NetEventSource.Log.IsEnabled()) connection.Trace($"[FlowControl] Unexpected PING ACK in state {_state}");
                     ThrowProtocolError();
                 }
 
@@ -236,7 +238,10 @@ namespace System.Net.Http
                 Debug.Assert(payload < 0);
 
                 if (_pingCounter != payload)
+                {
+                    if (NetEventSource.Log.IsEnabled()) connection.Trace($"[FlowControl] Unexpected RTT PING ACK payload {payload}, should be {_pingCounter}.");
                     ThrowProtocolError();
+                }
 
                 RefreshRtt(connection);
                 _state = State.Waiting;

diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.Http2FlowControl.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.Http2FlowControl.cs
index 84ea142..f284918 100644 (file)
--- a/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.Http2FlowControl.cs
+++ b/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.Http2FlowControl.cs
@@ -51,8 +51,10 @@ namespace System.Net.Http.Functional.Tests
             Assert.Equal(WindowSize, (int)entry.Value);
         }
 
-        [Fact]
-        public Task InvalidRttPingResponse_RequestShouldFail()
+        [Theory]
+        [InlineData(0)] // Invalid PING payload
+        [InlineData(1)] // Unexpected PING response
+        public Task BadRttPingResponse_RequestShouldFail(int mode)
         {
             return Http2LoopbackServer.CreateClientAndServerAsync(async uri =>
             {
@@ -67,13 +69,24 @@ namespace System.Net.Http.Functional.Tests
                 (int streamId, _) = await connection.ReadAndParseRequestHeaderAsync();
                 await connection.SendDefaultResponseHeadersAsync(streamId);
                 PingFrame pingFrame = await connection.ReadPingAsync(); // expect an RTT PING
-                await connection.SendPingAckAsync(-6666); // send an invalid PING response
+
+                if (mode == 0)
+                {
+                    // Invalid PING payload
+                    await connection.SendPingAckAsync(-6666); // send an invalid PING response
+                }
+                else
+                {
+                    // Unexpected PING response
+                    await connection.SendPingAckAsync(pingFrame.Data); // send an valid PING response
+                    await connection.SendPingAckAsync(pingFrame.Data - 1); // send a second unexpected PING response
+                }
+
                 await connection.SendResponseDataAsync(streamId, new byte[] { 1, 2, 3 }, true); // otherwise fine response
             },
             NoAutoPingResponseHttp2Options);
         }
 
-
         [OuterLoop("Runs long")]
         [Fact]
         public async Task HighBandwidthDelayProduct_ClientStreamReceiveWindowWindowScalesUp()