Skip to content

Commit 048467b

Browse files
MihaZupanMihaZupan
authored
Add status code and exception info to System.Net.Http events (#84036)
* Add status code and exception info to System.Net.Http events * Update HttpTelemetry fake
1 parent dbd4233 commit 048467b

File tree

8 files changed

+99
-37
lines changed

8 files changed

+99
-37
lines changed

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

Lines changed: 9 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -227,7 +227,7 @@ private async Task<string> GetStringAsyncCore(HttpRequestMessage request, Cancel
227227
}
228228
finally
229229
{
230-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
230+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
231231
}
232232
}
233233

@@ -306,7 +306,7 @@ private async Task<byte[]> GetByteArrayAsyncCore(HttpRequestMessage request, Can
306306
}
307307
finally
308308
{
309-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
309+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
310310
}
311311
}
312312

@@ -352,7 +352,7 @@ private async Task<Stream> GetStreamAsyncCore(HttpRequestMessage request, Cancel
352352
}
353353
finally
354354
{
355-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted: false);
355+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted: false);
356356
}
357357
}
358358

@@ -496,7 +496,7 @@ public HttpResponseMessage Send(HttpRequestMessage request, HttpCompletionOption
496496
}
497497
finally
498498
{
499-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
499+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
500500
}
501501
}
502502

@@ -551,7 +551,7 @@ async Task<HttpResponseMessage> Core(
551551
}
552552
finally
553553
{
554-
FinishSend(cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
554+
FinishSend(response, cts, disposeCts, telemetryStarted, responseContentTelemetryStarted);
555555
}
556556
}
557557
}
@@ -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;
@@ -623,6 +621,8 @@ private void HandleFailure(Exception e, bool telemetryStarted, HttpResponseMessa
623621
e = toThrow = CancellationHelper.CreateOperationCanceledException(e, cancellationToken.IsCancellationRequested ? cancellationToken : cts.Token);
624622
}
625623

624+
LogRequestFailed(e, telemetryStarted);
625+
626626
if (NetEventSource.Log.IsEnabled()) NetEventSource.Error(this, e);
627627

628628
if (toThrow != null)
@@ -642,7 +642,7 @@ private static bool StartSend(HttpRequestMessage request)
642642
return false;
643643
}
644644

645-
private static void FinishSend(CancellationTokenSource cts, bool disposeCts, bool telemetryStarted, bool responseContentTelemetryStarted)
645+
private static void FinishSend(HttpResponseMessage? response, CancellationTokenSource cts, bool disposeCts, bool telemetryStarted, bool responseContentTelemetryStarted)
646646
{
647647
// Log completion.
648648
if (HttpTelemetry.Log.IsEnabled() && telemetryStarted)
@@ -652,7 +652,7 @@ private static void FinishSend(CancellationTokenSource cts, bool disposeCts, boo
652652
HttpTelemetry.Log.ResponseContentStop();
653653
}
654654

655-
HttpTelemetry.Log.RequestStop();
655+
HttpTelemetry.Log.RequestStop(response);
656656
}
657657

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

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

Lines changed: 12 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -41,18 +41,20 @@ public virtual HttpResponseMessage Send(HttpRequestMessage request, Cancellation
4141
{
4242
HttpTelemetry.Log.RequestStart(request);
4343

44+
HttpResponseMessage? response = null;
4445
try
4546
{
46-
return _handler.Send(request, cancellationToken);
47+
response = _handler.Send(request, cancellationToken);
48+
return response;
4749
}
48-
catch when (LogRequestFailed(telemetryStarted: true))
50+
catch (Exception ex) when (LogRequestFailed(ex, telemetryStarted: true))
4951
{
5052
// Unreachable as LogRequestFailed will return false
5153
throw;
5254
}
5355
finally
5456
{
55-
HttpTelemetry.Log.RequestStop();
57+
HttpTelemetry.Log.RequestStop(response);
5658
}
5759
}
5860
else
@@ -78,18 +80,20 @@ static async Task<HttpResponseMessage> SendAsyncWithTelemetry(HttpMessageHandler
7880
{
7981
HttpTelemetry.Log.RequestStart(request);
8082

83+
HttpResponseMessage? response = null;
8184
try
8285
{
83-
return await handler.SendAsync(request, cancellationToken).ConfigureAwait(false);
86+
response = await handler.SendAsync(request, cancellationToken).ConfigureAwait(false);
87+
return response;
8488
}
85-
catch when (LogRequestFailed(telemetryStarted: true))
89+
catch (Exception ex) when (LogRequestFailed(ex, telemetryStarted: true))
8690
{
8791
// Unreachable as LogRequestFailed will return false
8892
throw;
8993
}
9094
finally
9195
{
92-
HttpTelemetry.Log.RequestStop();
96+
HttpTelemetry.Log.RequestStop(response);
9397
}
9498
}
9599
}
@@ -100,11 +104,11 @@ private static bool ShouldSendWithTelemetry(HttpRequestMessage request) =>
100104
request.RequestUri is Uri requestUri &&
101105
requestUri.IsAbsoluteUri;
102106

103-
internal static bool LogRequestFailed(bool telemetryStarted)
107+
internal static bool LogRequestFailed(Exception exception, bool telemetryStarted)
104108
{
105109
if (HttpTelemetry.Log.IsEnabled() && telemetryStarted)
106110
{
107-
HttpTelemetry.Log.RequestFailed();
111+
HttpTelemetry.Log.RequestFailed(exception);
108112
}
109113
return false;
110114
}

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

Lines changed: 41 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,11 @@ internal sealed partial class HttpTelemetry : EventSource
1313
{
1414
public static readonly HttpTelemetry Log = new HttpTelemetry();
1515

16+
public static class Keywords
17+
{
18+
public const EventKeywords RequestFailedDetailed = (EventKeywords)1;
19+
}
20+
1621
private long _startedRequests;
1722
private long _stoppedRequests;
1823
private long _failedRequests;
@@ -50,18 +55,39 @@ public void RequestStart(HttpRequestMessage request)
5055
request.VersionPolicy);
5156
}
5257

53-
[Event(2, Level = EventLevel.Informational)]
54-
public void RequestStop()
58+
[NonEvent]
59+
public void RequestStop(HttpResponseMessage? response)
60+
{
61+
RequestStop(response is null ? -1 : (int)response.StatusCode);
62+
}
63+
64+
[Event(2, Level = EventLevel.Informational, Version = 1)]
65+
private void RequestStop(int statusCode)
5566
{
5667
Interlocked.Increment(ref _stoppedRequests);
57-
WriteEvent(eventId: 2);
68+
WriteEvent(eventId: 2, statusCode);
5869
}
5970

60-
[Event(3, Level = EventLevel.Error)]
61-
public void RequestFailed()
71+
[NonEvent]
72+
public void RequestFailed(Exception exception)
6273
{
6374
Interlocked.Increment(ref _failedRequests);
64-
WriteEvent(eventId: 3);
75+
76+
if (IsEnabled(EventLevel.Error, EventKeywords.None))
77+
{
78+
RequestFailed(exceptionMessage: exception.Message);
79+
80+
if (IsEnabled(EventLevel.Error, Keywords.RequestFailedDetailed))
81+
{
82+
RequestFailedDetailed(exception: exception.ToString());
83+
}
84+
}
85+
}
86+
87+
[Event(3, Level = EventLevel.Error, Version = 1)]
88+
private void RequestFailed(string exceptionMessage)
89+
{
90+
WriteEvent(eventId: 3, exceptionMessage);
6591
}
6692

6793
[Event(4, Level = EventLevel.Informational)]
@@ -112,10 +138,10 @@ public void ResponseHeadersStart()
112138
WriteEvent(eventId: 11);
113139
}
114140

115-
[Event(12, Level = EventLevel.Informational)]
116-
public void ResponseHeadersStop()
141+
[Event(12, Level = EventLevel.Informational, Version = 1)]
142+
public void ResponseHeadersStop(int statusCode)
117143
{
118-
WriteEvent(eventId: 12);
144+
WriteEvent(eventId: 12, statusCode);
119145
}
120146

121147
[Event(13, Level = EventLevel.Informational)]
@@ -130,6 +156,12 @@ public void ResponseContentStop()
130156
WriteEvent(eventId: 14);
131157
}
132158

159+
[Event(15, Level = EventLevel.Error, Keywords = Keywords.RequestFailedDetailed)]
160+
private void RequestFailedDetailed(string exception)
161+
{
162+
WriteEvent(eventId: 15, exception);
163+
}
164+
133165
[NonEvent]
134166
public void Http11ConnectionEstablished()
135167
{

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

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1024,7 +1024,8 @@ public async Task ReadResponseHeadersAsync(CancellationToken cancellationToken)
10241024
Debug.Assert(!wait);
10251025
}
10261026

1027-
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop();
1027+
Debug.Assert(_response is not null);
1028+
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop((int)_response.StatusCode);
10281029
}
10291030
catch
10301031
{

‎src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -352,7 +352,7 @@ private async Task ReadResponseAsync(CancellationToken cancellationToken)
352352

353353
_headerState = HeaderState.TrailingHeaders;
354354

355-
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop();
355+
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop((int)_response.StatusCode);
356356
}
357357

358358
private async Task SendContentAsync(HttpContent content, CancellationToken cancellationToken)

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

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -696,7 +696,7 @@ public async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, boo
696696
await FillForHeadersAsync(async).ConfigureAwait(false);
697697
}
698698

699-
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop();
699+
if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop((int)response.StatusCode);
700700

701701
if (allowExpect100ToContinue != null)
702702
{

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

Lines changed: 31 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,6 @@
66
using System.Diagnostics.Tracing;
77
using System.IO;
88
using System.Linq;
9-
using System.Net.Quic;
109
using System.Net.Test.Common;
1110
using System.Text;
1211
using System.Threading;
@@ -412,19 +411,40 @@ private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenE
412411
Assert.Equal(count, starts.Length);
413412

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

417421
ValidateSameActivityIds(starts, stops);
418422

419423
(EventWrittenEventArgs Event, Guid ActivityId)[] failures = events.Where(e => e.Event.EventName == "RequestFailed").ToArray();
420-
Assert.All(failures, failedEvent => Assert.Empty(failedEvent.Event.Payload));
424+
(EventWrittenEventArgs Event, Guid ActivityId)[] detailedFailures = events.Where(e => e.Event.EventName == "RequestFailedDetailed").ToArray();
421425
if (shouldHaveFailures)
422426
{
427+
foreach (EventWrittenEventArgs failedEvent in failures.Select(e => e.Event))
428+
{
429+
object payload = Assert.Single(failedEvent.Payload);
430+
string exceptionMessage = Assert.IsType<string>(payload);
431+
Assert.Equal(new OperationCanceledException().Message, exceptionMessage);
432+
}
433+
434+
foreach (EventWrittenEventArgs failedEvent in detailedFailures.Select(e => e.Event))
435+
{
436+
object payload = Assert.Single(failedEvent.Payload);
437+
string exception = Assert.IsType<string>(payload);
438+
Assert.StartsWith("System.Threading.Tasks.TaskCanceledException", exception);
439+
}
440+
423441
ValidateSameActivityIds(starts, failures);
442+
ValidateSameActivityIds(starts, detailedFailures);
424443
}
425444
else
426445
{
427446
Assert.Empty(failures);
447+
Assert.Empty(detailedFailures);
428448
}
429449
}
430450

@@ -470,8 +490,8 @@ private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(Even
470490
foreach (EventWrittenEventArgs requestContentStop in requestContentStops.Select(e => e.Event))
471491
{
472492
object payload = Assert.Single(requestContentStop.Payload);
473-
Assert.True(payload is long);
474-
Assert.Equal(requestContentLength.Value, (long)payload);
493+
long contentLength = Assert.IsType<long>(payload);
494+
Assert.Equal(requestContentLength.Value, contentLength);
475495
}
476496

477497
ValidateSameActivityIds(requestContentStarts, requestContentStops);
@@ -482,7 +502,12 @@ private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(Even
482502

483503
(EventWrittenEventArgs Event, Guid ActivityId)[] responseHeadersStops = events.Where(e => e.Event.EventName == "ResponseHeadersStop").ToArray();
484504
Assert.Equal(count, responseHeadersStops.Length);
485-
Assert.All(responseHeadersStops, r => Assert.Empty(r.Event.Payload));
505+
foreach (EventWrittenEventArgs responseHeadersStop in responseHeadersStops.Select(e => e.Event))
506+
{
507+
object payload = Assert.Single(responseHeadersStop.Payload);
508+
int statusCode = Assert.IsType<int>(payload);
509+
Assert.Equal(200, statusCode);
510+
}
486511

487512
ValidateSameActivityIds(responseHeadersStarts, responseHeadersStops);
488513

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

Lines changed: 2 additions & 2 deletions
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)