diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs b/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs index 83f4ab8db11660..c5e8ce8860465a 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs @@ -229,7 +229,7 @@ private async Task GetStringAsyncCore(HttpRequestMessage request, Cancel } finally { - FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted); + FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted); } } @@ -308,7 +308,7 @@ private async Task GetByteArrayAsyncCore(HttpRequestMessage request, Can } finally { - FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted); + FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted); } } @@ -354,7 +354,7 @@ private async Task GetStreamAsyncCore(HttpRequestMessage request, Cancel } finally { - FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted: false); + FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted: false); } } @@ -498,7 +498,7 @@ public HttpResponseMessage Send(HttpRequestMessage request, HttpCompletionOption } finally { - FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted); + FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted); } } @@ -553,7 +553,7 @@ async Task Core( } finally { - FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted); + FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted); } } } @@ -585,8 +585,6 @@ private static bool ShouldBufferResponse(HttpCompletionOption completionOption, private void HandleFailure(Exception e, bool telemetryStarted, HttpResponseMessage? response, CancellationTokenSource cts, CancellationToken cancellationToken, CancellationTokenSource pendingRequestsCts) { - LogRequestFailed(telemetryStarted); - response?.Dispose(); Exception? toThrow = null; @@ -625,6 +623,8 @@ private void HandleFailure(Exception e, bool telemetryStarted, HttpResponseMessa e = toThrow = new OperationCanceledException(cancellationToken.IsCancellationRequested ? cancellationToken : cts.Token); } + LogRequestFailed(e, telemetryStarted); + if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(this, e); if (toThrow != null) @@ -644,7 +644,7 @@ private static bool StartSend(HttpRequestMessage request) return false; } - private static void FinishSend(CancellationTokenSource cts, bool disposeCts, bool telemetryStarted, bool responseContentTelemetryStarted) + private static void FinishSend(HttpResponseMessage? response, CancellationTokenSource cts, bool disposeCts, bool telemetryStarted, bool responseContentTelemetryStarted) { // Log completion. if (HttpTelemetry.Log.IsEnabled() && telemetryStarted) @@ -654,7 +654,7 @@ private static void FinishSend(CancellationTokenSource cts, bool disposeCts, boo HttpTelemetry.Log.ResponseContentStop(); } - HttpTelemetry.Log.RequestStop(); + HttpTelemetry.Log.RequestStop(response); } // Dispose of the CancellationTokenSource if it was created specially for this request diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/HttpMessageInvoker.cs b/src/libraries/System.Net.Http/src/System/Net/Http/HttpMessageInvoker.cs index a06da5b9ed5a27..ceb93c06a2aae2 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/HttpMessageInvoker.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/HttpMessageInvoker.cs @@ -41,18 +41,20 @@ public virtual HttpResponseMessage Send(HttpRequestMessage request, Cancellation { HttpTelemetry.Log.RequestStart(request); + HttpResponseMessage? response = null; try { - return _handler.Send(request, cancellationToken); + response = _handler.Send(request, cancellationToken); + return response; } - catch when (LogRequestFailed(telemetryStarted: true)) + catch (Exception ex) when (LogRequestFailed(ex, telemetryStarted: true)) { // Unreachable as LogRequestFailed will return false throw; } finally { - HttpTelemetry.Log.RequestStop(); + HttpTelemetry.Log.RequestStop(response); } } else @@ -78,18 +80,20 @@ static async Task SendAsyncWithTelemetry(HttpMessageHandler { HttpTelemetry.Log.RequestStart(request); + HttpResponseMessage? response = null; try { - return await handler.SendAsync(request, cancellationToken).ConfigureAwait(false); + response = await handler.SendAsync(request, cancellationToken).ConfigureAwait(false); + return response; } - catch when (LogRequestFailed(telemetryStarted: true)) + catch (Exception ex) when (LogRequestFailed(ex, telemetryStarted: true)) { // Unreachable as LogRequestFailed will return false throw; } finally { - HttpTelemetry.Log.RequestStop(); + HttpTelemetry.Log.RequestStop(response); } } } @@ -100,11 +104,11 @@ private static bool ShouldSendWithTelemetry(HttpRequestMessage request) => request.RequestUri is Uri requestUri && requestUri.IsAbsoluteUri; - internal static bool LogRequestFailed(bool telemetryStarted) + internal static bool LogRequestFailed(Exception exception, bool telemetryStarted) { if (HttpTelemetry.Log.IsEnabled() && telemetryStarted) { - HttpTelemetry.Log.RequestFailed(); + HttpTelemetry.Log.RequestFailed(exception); } return false; } diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs b/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs index 131748bddf5a8c..d85862dbfb7825 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs @@ -50,18 +50,34 @@ public void RequestStart(HttpRequestMessage request) request.VersionPolicy); } - [Event(2, Level = EventLevel.Informational)] - public void RequestStop() + [NonEvent] + public void RequestStop(HttpResponseMessage? response) + { + RequestStop(response is null ? -1 : (int)response.StatusCode); + } + + [Event(2, Level = EventLevel.Informational, Version = 1)] + private void RequestStop(int statusCode) { Interlocked.Increment(ref _stoppedRequests); - WriteEvent(eventId: 2); + WriteEvent(eventId: 2, statusCode); } - [Event(3, Level = EventLevel.Error)] - public void RequestFailed() + [NonEvent] + public void RequestFailed(Exception exception) { Interlocked.Increment(ref _failedRequests); - WriteEvent(eventId: 3); + + if (IsEnabled(EventLevel.Error, EventKeywords.None)) + { + RequestFailed(exceptionMessage: exception.Message); + } + } + + [Event(3, Level = EventLevel.Error, Version = 1)] + private void RequestFailed(string exceptionMessage) + { + WriteEvent(eventId: 3, exceptionMessage); } [Event(4, Level = EventLevel.Informational)] @@ -112,10 +128,10 @@ public void ResponseHeadersStart() WriteEvent(eventId: 11); } - [Event(12, Level = EventLevel.Informational)] - public void ResponseHeadersStop() + [Event(12, Level = EventLevel.Informational, Version = 1)] + public void ResponseHeadersStop(int statusCode) { - WriteEvent(eventId: 12); + WriteEvent(eventId: 12, statusCode); } [Event(13, Level = EventLevel.Informational)] diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs index 7557ece3e264e0..89cacb066ece5b 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs @@ -1024,7 +1024,8 @@ public async Task ReadResponseHeadersAsync(CancellationToken cancellationToken) Debug.Assert(!wait); } - if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop(); + Debug.Assert(_response is not null); + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop((int)_response.StatusCode); } catch { diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs index 4d95a94488851d..56fe374b3bef2b 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs @@ -352,7 +352,7 @@ private async Task ReadResponseAsync(CancellationToken cancellationToken) _headerState = HeaderState.TrailingHeaders; - if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop(); + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop((int)_response.StatusCode); } private async Task SendContentAsync(HttpContent content, CancellationToken cancellationToken) diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs index d0bef3bc27a23a..95749c4fa950c1 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs @@ -666,7 +666,7 @@ public async Task SendAsyncCore(HttpRequestMessage request, ParseHeaderNameValue(this, line.Span, response, isFromTrailer: false); } - if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop(); + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop((int)response.StatusCode); if (allowExpect100ToContinue != null) { diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 38785e38f45591..e3b79bd00d465e 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -6,7 +6,6 @@ using System.Diagnostics.Tracing; using System.IO; using System.Linq; -using System.Net.Quic; using System.Net.Test.Common; using System.Text; using System.Threading; @@ -412,14 +411,25 @@ private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenE Assert.Equal(count, starts.Length); (EventWrittenEventArgs Event, Guid ActivityId)[] stops = events.Where(e => e.Event.EventName == "RequestStop").ToArray(); - Assert.All(stops, stopEvent => Assert.Empty(stopEvent.Event.Payload)); + foreach (EventWrittenEventArgs stopEvent in stops.Select(e => e.Event)) + { + object payload = Assert.Single(stopEvent.Payload); + int statusCode = Assert.IsType(payload); + Assert.Equal(shouldHaveFailures ? -1 : 200, statusCode); + } ValidateSameActivityIds(starts, stops); (EventWrittenEventArgs Event, Guid ActivityId)[] failures = events.Where(e => e.Event.EventName == "RequestFailed").ToArray(); - Assert.All(failures, failedEvent => Assert.Empty(failedEvent.Event.Payload)); if (shouldHaveFailures) { + foreach (EventWrittenEventArgs failedEvent in failures.Select(e => e.Event)) + { + object payload = Assert.Single(failedEvent.Payload); + string exceptionMessage = Assert.IsType(payload); + Assert.Equal(new OperationCanceledException().Message, exceptionMessage); + } + ValidateSameActivityIds(starts, failures); } else @@ -470,8 +480,8 @@ private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(Even foreach (EventWrittenEventArgs requestContentStop in requestContentStops.Select(e => e.Event)) { object payload = Assert.Single(requestContentStop.Payload); - Assert.True(payload is long); - Assert.Equal(requestContentLength.Value, (long)payload); + long contentLength = Assert.IsType(payload); + Assert.Equal(requestContentLength.Value, contentLength); } ValidateSameActivityIds(requestContentStarts, requestContentStops); @@ -482,7 +492,12 @@ private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(Even (EventWrittenEventArgs Event, Guid ActivityId)[] responseHeadersStops = events.Where(e => e.Event.EventName == "ResponseHeadersStop").ToArray(); Assert.Equal(count, responseHeadersStops.Length); - Assert.All(responseHeadersStops, r => Assert.Empty(r.Event.Payload)); + foreach (EventWrittenEventArgs responseHeadersStop in responseHeadersStops.Select(e => e.Event)) + { + object payload = Assert.Single(responseHeadersStop.Payload); + int statusCode = Assert.IsType(payload); + Assert.Equal(200, statusCode); + } ValidateSameActivityIds(responseHeadersStarts, responseHeadersStops); diff --git a/src/libraries/System.Net.Http/tests/UnitTests/Fakes/HttpTelemetry.cs b/src/libraries/System.Net.Http/tests/UnitTests/Fakes/HttpTelemetry.cs index 5667687e632e2f..26ac057e31bd8d 100644 --- a/src/libraries/System.Net.Http/tests/UnitTests/Fakes/HttpTelemetry.cs +++ b/src/libraries/System.Net.Http/tests/UnitTests/Fakes/HttpTelemetry.cs @@ -11,9 +11,9 @@ public class HttpTelemetry public void RequestStart(HttpRequestMessage request) { } - public void RequestStop() { } + public void RequestStop(HttpResponseMessage response) { } - public void RequestFailed() { } + public void RequestFailed(Exception exception) { } public void ResponseContentStart() { }