Skip to content

Commit 809b82e

Browse files
authored
Add status code and exception info to System.Net.Http events (#84807)
1 parent 34f40ad commit 809b82e

File tree

7 files changed

+72
-35
lines changed

7 files changed

+72
-35
lines changed

src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs

+9-9
Original file line numberDiff line numberDiff line change
@@ -224,7 +224,7 @@ private async Task<string> GetStringAsyncCore(HttpRequestMessage request, Cancel
224224
}
225225
finally
226226
{
227-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
227+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
228228
}
229229
}
230230

@@ -303,7 +303,7 @@ private async Task<byte[]> GetByteArrayAsyncCore(HttpRequestMessage request, Can
303303
}
304304
finally
305305
{
306-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
306+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
307307
}
308308
}
309309

@@ -349,7 +349,7 @@ private async Task<Stream> GetStreamAsyncCore(HttpRequestMessage request, Cancel
349349
}
350350
finally
351351
{
352-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted: false);
352+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted: false);
353353
}
354354
}
355355

@@ -493,7 +493,7 @@ public HttpResponseMessage Send(HttpRequestMessage request, HttpCompletionOption
493493
}
494494
finally
495495
{
496-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
496+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
497497
}
498498
}
499499

@@ -548,7 +548,7 @@ async Task<HttpResponseMessage> Core(
548548
}
549549
finally
550550
{
551-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
551+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
552552
}
553553
}
554554
}
@@ -583,8 +583,6 @@ private static bool ShouldBufferResponse(HttpCompletionOption completionOption,
583583

584584
private void HandleFailure(Exception e, bool telemetryStarted, HttpResponseMessage? response, CancellationTokenSource cts, CancellationToken cancellationToken, CancellationTokenSource pendingRequestsCts)
585585
{
586-
LogRequestFailed(telemetryStarted);
587-
588586
response?.Dispose();
589587

590588
Exception? toThrow = null;
@@ -616,6 +614,8 @@ private void HandleFailure(Exception e, bool telemetryStarted, HttpResponseMessa
616614
e = toThrow = new OperationCanceledException(cancellationToken.IsCancellationRequested ? cancellationToken : cts.Token);
617615
}
618616

617+
LogRequestFailed(e, telemetryStarted);
618+
619619
if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(this, e);
620620

621621
if (toThrow != null)
@@ -635,7 +635,7 @@ private static bool StartSend(HttpRequestMessage request)
635635
return false;
636636
}
637637

638-
private static void FinishSend(CancellationTokenSource cts, bool disposeCts, bool telemetryStarted, bool responseContentTelemetryStarted)
638+
private static void FinishSend(HttpResponseMessage? response, CancellationTokenSource cts, bool disposeCts, bool telemetryStarted, bool responseContentTelemetryStarted)
639639
{
640640
// Log completion.
641641
if (HttpTelemetry.Log.IsEnabled() && telemetryStarted)
@@ -645,7 +645,7 @@ private static void FinishSend(CancellationTokenSource cts, bool disposeCts, boo
645645
HttpTelemetry.Log.ResponseContentStop();
646646
}
647647

648-
HttpTelemetry.Log.RequestStop();
648+
HttpTelemetry.Log.RequestStop(response);
649649
}
650650

651651
// Dispose of the CancellationTokenSource if it was created specially for this request

src/libraries/System.Net.Http/src/System/Net/Http/HttpMessageInvoker.cs

+12-8
Original file line numberDiff line numberDiff line change
@@ -46,18 +46,20 @@ public virtual HttpResponseMessage Send(HttpRequestMessage request, Cancellation
4646
{
4747
HttpTelemetry.Log.RequestStart(request);
4848

49+
HttpResponseMessage? response = null;
4950
try
5051
{
51-
return _handler.Send(request, cancellationToken);
52+
response = _handler.Send(request, cancellationToken);
53+
return response;
5254
}
53-
catch when (LogRequestFailed(telemetryStarted: true))
55+
catch (Exception ex) when (LogRequestFailed(ex, telemetryStarted: true))
5456
{
5557
// Unreachable as LogRequestFailed will return false
5658
throw;
5759
}
5860
finally
5961
{
60-
HttpTelemetry.Log.RequestStop();
62+
HttpTelemetry.Log.RequestStop(response);
6163
}
6264
}
6365
else
@@ -85,18 +87,20 @@ static async Task<HttpResponseMessage> SendAsyncWithTelemetry(HttpMessageHandler
8587
{
8688
HttpTelemetry.Log.RequestStart(request);
8789

90+
HttpResponseMessage? response = null;
8891
try
8992
{
90-
return await handler.SendAsync(request, cancellationToken).ConfigureAwait(false);
93+
response = await handler.SendAsync(request, cancellationToken).ConfigureAwait(false);
94+
return response;
9195
}
92-
catch when (LogRequestFailed(telemetryStarted: true))
96+
catch (Exception ex) when (LogRequestFailed(ex, telemetryStarted: true))
9397
{
9498
// Unreachable as LogRequestFailed will return false
9599
throw;
96100
}
97101
finally
98102
{
99-
HttpTelemetry.Log.RequestStop();
103+
HttpTelemetry.Log.RequestStop(response);
100104
}
101105
}
102106
}
@@ -107,11 +111,11 @@ private static bool ShouldSendWithTelemetry(HttpRequestMessage request) =>
107111
request.RequestUri is Uri requestUri &&
108112
requestUri.IsAbsoluteUri;
109113

110-
internal static bool LogRequestFailed(bool telemetryStarted)
114+
internal static bool LogRequestFailed(Exception exception, bool telemetryStarted)
111115
{
112116
if (HttpTelemetry.Log.IsEnabled() && telemetryStarted)
113117
{
114-
HttpTelemetry.Log.RequestFailed();
118+
HttpTelemetry.Log.RequestFailed(exception);
115119
}
116120
return false;
117121
}

src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs

+25-9
Original file line numberDiff line numberDiff line change
@@ -48,18 +48,34 @@ public void RequestStart(HttpRequestMessage request)
4848
request.VersionPolicy);
4949
}
5050

51-
[Event(2, Level = EventLevel.Informational)]
52-
public void RequestStop()
51+
[NonEvent]
52+
public void RequestStop(HttpResponseMessage? response)
53+
{
54+
RequestStop(response is null ? -1 : (int)response.StatusCode);
55+
}
56+
57+
[Event(2, Level = EventLevel.Informational, Version = 1)]
58+
private void RequestStop(int statusCode)
5359
{
5460
Interlocked.Increment(ref _stoppedRequests);
55-
WriteEvent(eventId: 2);
61+
WriteEvent(eventId: 2, statusCode);
5662
}
5763

58-
[Event(3, Level = EventLevel.Error)]
59-
public void RequestFailed()
64+
[NonEvent]
65+
public void RequestFailed(Exception exception)
6066
{
6167
Interlocked.Increment(ref _failedRequests);
62-
WriteEvent(eventId: 3);
68+
69+
if (IsEnabled(EventLevel.Error, EventKeywords.None))
70+
{
71+
RequestFailed(exceptionMessage: exception.Message);
72+
}
73+
}
74+
75+
[Event(3, Level = EventLevel.Error, Version = 1)]
76+
private void RequestFailed(string exceptionMessage)
77+
{
78+
WriteEvent(eventId: 3, exceptionMessage);
6379
}
6480

6581
[Event(4, Level = EventLevel.Informational)]
@@ -110,10 +126,10 @@ public void ResponseHeadersStart()
110126
WriteEvent(eventId: 11);
111127
}
112128

113-
[Event(12, Level = EventLevel.Informational)]
114-
public void ResponseHeadersStop()
129+
[Event(12, Level = EventLevel.Informational, Version = 1)]
130+
public void ResponseHeadersStop(int statusCode)
115131
{
116-
WriteEvent(eventId: 12);
132+
WriteEvent(eventId: 12, statusCode);
117133
}
118134

119135
[Event(13, Level = EventLevel.Informational)]

src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs

+2-1
Original file line numberDiff line numberDiff line change
@@ -998,7 +998,8 @@ public async Task ReadResponseHeadersAsync(CancellationToken cancellationToken)
998998
Debug.Assert(!wait);
999999
}
10001000

1001-
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop();
1001+
Debug.Assert(_response is not null);
1002+
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop((int)_response.StatusCode);
10021003
}
10031004
catch
10041005
{

src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -669,7 +669,7 @@ public async Task<HttpResponseMessage> SendAsyncCore(HttpRequestMessage request,
669669
ParseHeaderNameValue(this, line.Span, response, isFromTrailer: false);
670670
}
671671

672-
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop();
672+
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop((int)response.StatusCode);
673673

674674
if (allowExpect100ToContinue != null)
675675
{

src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs

+21-5
Original file line numberDiff line numberDiff line change
@@ -409,14 +409,25 @@ private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenE
409409
Assert.Equal(count, starts.Length);
410410

411411
(EventWrittenEventArgs Event, Guid ActivityId)[] stops = events.Where(e => e.Event.EventName == "RequestStop").ToArray();
412-
Assert.All(stops, stopEvent => Assert.Empty(stopEvent.Event.Payload));
412+
foreach (EventWrittenEventArgs stopEvent in stops.Select(e => e.Event))
413+
{
414+
object payload = Assert.Single(stopEvent.Payload);
415+
int statusCode = Assert.IsType<int>(payload);
416+
Assert.Equal(shouldHaveFailures ? -1 : 200, statusCode);
417+
}
413418

414419
ValidateSameActivityIds(starts, stops);
415420

416421
(EventWrittenEventArgs Event, Guid ActivityId)[] failures = events.Where(e => e.Event.EventName == "RequestFailed").ToArray();
417-
Assert.All(failures, failedEvent => Assert.Empty(failedEvent.Event.Payload));
418422
if (shouldHaveFailures)
419423
{
424+
foreach (EventWrittenEventArgs failedEvent in failures.Select(e => e.Event))
425+
{
426+
object payload = Assert.Single(failedEvent.Payload);
427+
string exceptionMessage = Assert.IsType<string>(payload);
428+
Assert.Equal(new OperationCanceledException().Message, exceptionMessage);
429+
}
430+
420431
ValidateSameActivityIds(starts, failures);
421432
}
422433
else
@@ -467,8 +478,8 @@ private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(Even
467478
foreach (EventWrittenEventArgs requestContentStop in requestContentStops.Select(e => e.Event))
468479
{
469480
object payload = Assert.Single(requestContentStop.Payload);
470-
Assert.True(payload is long);
471-
Assert.Equal(requestContentLength.Value, (long)payload);
481+
long contentLength = Assert.IsType<long>(payload);
482+
Assert.Equal(requestContentLength.Value, contentLength);
472483
}
473484

474485
ValidateSameActivityIds(requestContentStarts, requestContentStops);
@@ -479,7 +490,12 @@ private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(Even
479490

480491
(EventWrittenEventArgs Event, Guid ActivityId)[] responseHeadersStops = events.Where(e => e.Event.EventName == "ResponseHeadersStop").ToArray();
481492
Assert.Equal(count, responseHeadersStops.Length);
482-
Assert.All(responseHeadersStops, r => Assert.Empty(r.Event.Payload));
493+
foreach (EventWrittenEventArgs responseHeadersStop in responseHeadersStops.Select(e => e.Event))
494+
{
495+
object payload = Assert.Single(responseHeadersStop.Payload);
496+
int statusCode = Assert.IsType<int>(payload);
497+
Assert.Equal(200, statusCode);
498+
}
483499

484500
ValidateSameActivityIds(responseHeadersStarts, responseHeadersStops);
485501

src/libraries/System.Net.Http/tests/UnitTests/Fakes/HttpTelemetry.cs

+2-2
Original file line numberDiff line numberDiff line change
@@ -11,9 +11,9 @@ public class HttpTelemetry
1111

1212
public void RequestStart(HttpRequestMessage request) { }
1313

14-
public void RequestStop() { }
14+
public void RequestStop(HttpResponseMessage response) { }
1515

16-
public void RequestFailed() { }
16+
public void RequestFailed(Exception exception) { }
1717

1818
public void ResponseContentStart() { }
1919

0 commit comments

Comments
 (0)