Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Activities for Http Connections, Dns, Sockets and SslStream #103922

Merged
merged 50 commits into from
Jul 13, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
50 commits
Select commit Hold shift + click to select a range
4e740d0
Activities for Http Connection, Dns, Sockets and Tls
antonfirsov Jun 24, 2024
3945fe4
address review feedback
antonfirsov Jun 25, 2024
f40ce38
Merge branch 'main' into connection-activities-05
antonfirsov Jun 25, 2024
08bc611
resolve conflicts
antonfirsov Jun 25, 2024
e2cf15e
get rid of finally block
antonfirsov Jun 25, 2024
e963ed2
Merge branch 'main' into connection-activities-05
antonfirsov Jul 1, 2024
133c7b7
Merge branch 'main' into connection-activities-05
antonfirsov Jul 5, 2024
5119f9c
System.Net.NameResolution: record tags and ActivityStatusCode
antonfirsov Jul 5, 2024
4b1ffa8
set DNS activity DisplayName
antonfirsov Jul 5, 2024
5e0e971
Socket Activity tags
antonfirsov Jul 6, 2024
4988004
emit attributes on SslStream Activity
antonfirsov Jul 6, 2024
7777b68
connection setup activity graph
antonfirsov Jul 8, 2024
fd60820
emit tags on http connection activities
antonfirsov Jul 8, 2024
b730434
Merge branch 'connection-activities-05' of https://github.com/antonfi…
antonfirsov Jul 8, 2024
4ce1499
fix MacOS failure
antonfirsov Jul 8, 2024
ecce03b
adjustments
antonfirsov Jul 8, 2024
c109253
Merge branch 'main' into connection-activities-05
antonfirsov Jul 9, 2024
dc563ad
consolidate connection setup Activity error handling into a single ca…
antonfirsov Jul 9, 2024
c099441
address more review feedback
antonfirsov Jul 9, 2024
17e62a0
merge stuff
antonfirsov Jul 9, 2024
2d8bee3
emit the link on the request span instead of wait_for_connection
antonfirsov Jul 10, 2024
55b1eea
Merge branch 'main' into connection-activities-05
antonfirsov Jul 10, 2024
9995e27
adjust System.Net.NameResolution
antonfirsov Jul 10, 2024
c2c7c87
adjust System.Net.Sockets naming, add UDS test
antonfirsov Jul 10, 2024
8acab55
replace the _connectActivity field with a CWT
antonfirsov Jul 10, 2024
afe1648
Adjust SslStream tracing
antonfirsov Jul 10, 2024
96f1f18
ActivityKind
antonfirsov Jul 10, 2024
a9cd814
adjust HTTP Activities
antonfirsov Jul 10, 2024
f4548ff
Merge branch 'main' into connection-activities-05
antonfirsov Jul 10, 2024
576842c
SocketsHttpHandler_DiagnosticsTest_Http3
antonfirsov Jul 10, 2024
f04ab6e
WIP h3
antonfirsov Jul 10, 2024
7b94039
adjust to main
antonfirsov Jul 10, 2024
1c5e772
implement H/3 connection diagnostics
antonfirsov Jul 11, 2024
3d6911c
Merge branch 'main' into connection-activities-05
antonfirsov Jul 11, 2024
8c008e1
actually use the same ActivitySource for ConnectionSetup & WaitForCon…
antonfirsov Jul 11, 2024
e829df2
*handshake
antonfirsov Jul 11, 2024
7c94ae8
Update src/libraries/System.Net.NameResolution/src/System/Net/NameRes…
antonfirsov Jul 11, 2024
92afed7
Merge branch 'connection-activities-05' of https://github.com/antonfi…
antonfirsov Jul 11, 2024
06896bf
fix H3 logic based on feedback
antonfirsov Jul 11, 2024
b455d17
ConnectionSetupDiagnostics -> ConnectionSetupDistributedTracing
antonfirsov Jul 11, 2024
0d231ba
Merge branch 'main' into connection-activities-05
antonfirsov Jul 11, 2024
56e8cb3
suggestion
antonfirsov Jul 12, 2024
870eae5
suggestion
antonfirsov Jul 12, 2024
de774dd
suggestion
antonfirsov Jul 12, 2024
284734b
Merge branch 'main' into connection-activities-05
antonfirsov Jul 12, 2024
b1ef7f3
implement 'network.transport'
antonfirsov Jul 12, 2024
d99734f
SslStream: move Activity management code to NetSecurityTelemetry
antonfirsov Jul 12, 2024
ae587f7
readd assertion and add comment
antonfirsov Jul 12, 2024
9443cd2
Merge branch 'main' into connection-activities-05
antonfirsov Jul 12, 2024
c9a5ad2
Merge branch 'main' into connection-activities-05
antonfirsov Jul 13, 2024
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
136 changes: 136 additions & 0 deletions src/libraries/Common/tests/System/Net/ActivityRecorder.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,136 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Text;
using Xunit;

namespace System.Net.Test.Common
{
internal class ActivityRecorder : IDisposable
{
private string _activitySourceName;
private string _activityName;

private readonly ActivityListener _listener;
private List<Activity> _finishedActivities = new();

public Predicate<Activity> Filter { get; set; } = _ => true;
public bool VerifyParent { get; set; } = true;
public Activity ExpectedParent { get; set; }

public int Started { get; private set; }
public int Stopped { get; private set; }
public Activity LastStartedActivity { get; private set; }
public Activity LastFinishedActivity { get; private set; }
public IEnumerable<Activity> FinishedActivities => _finishedActivities;

public ActivityRecorder(string activitySourceName, string activityName)
{
_activitySourceName = activitySourceName;
_activityName = activityName;
_listener = new ActivityListener
{
ShouldListenTo = (activitySource) => activitySource.Name == _activitySourceName,
Sample = (ref ActivityCreationOptions<ActivityContext> options) => ActivitySamplingResult.AllData,
ActivityStarted = (activity) => {
if (activity.OperationName == _activityName && Filter(activity))
{
if (VerifyParent)
{
Assert.Same(ExpectedParent, activity.Parent);
}

Started++;
LastStartedActivity = activity;
}
},
ActivityStopped = (activity) => {
if (activity.OperationName == _activityName && Filter(activity))
{
if (VerifyParent)
{
Assert.Same(ExpectedParent, activity.Parent);
}

Stopped++;
LastFinishedActivity = activity;
_finishedActivities.Add(activity);
}
}
};

ActivitySource.AddActivityListener(_listener);
}

public void Dispose() => _listener.Dispose();

public void VerifyActivityRecorded(int times)
{
Assert.Equal(times, Started);
Assert.Equal(times, Stopped);
}

public Activity VerifyActivityRecordedOnce()
{
VerifyActivityRecorded(1);
return LastFinishedActivity;
}
}

internal static class ActivityAssert
{
public static KeyValuePair<string, object> HasTag(Activity activity, string name)
{
KeyValuePair<string, object> tag = activity.TagObjects.SingleOrDefault(t => t.Key == name);
if (tag.Key is null)
{
Assert.Fail($"The Activity tags should contain {name}.");
}
return tag;
}

public static void HasTag<T>(Activity activity, string name, T expectedValue)
{
KeyValuePair<string, object> tag = HasTag(activity, name);
Assert.Equal(expectedValue, (T)tag.Value);
}

public static void HasTag<T>(Activity activity, string name, Func<T, bool> verifyValue)
{
T? value = (T?)activity.TagObjects.SingleOrDefault(t => t.Key == name).Value;
Assert.False(value is null, $"The Activity tags should contain {name}.");
Assert.True(verifyValue(value));
}

public static void HasNoTag(Activity activity, string name)
{
bool contains = activity.TagObjects.Any(t => t.Key == name);
Assert.False(contains, $"The Activity tags should not contain {name}.");
}

public static void FinishedInOrder(Activity first, Activity second)
{
Assert.True(first.StartTimeUtc + first.Duration < second.StartTimeUtc + second.Duration, $"{first.OperationName} should stop before {second.OperationName}");
}

public static string CamelToSnake(string camel)
{
if (string.IsNullOrEmpty(camel)) return camel;
StringBuilder bld = new();
bld.Append(char.ToLower(camel[0]));
for (int i = 1; i < camel.Length; i++)
{
char c = camel[i];
if (char.IsUpper(c))
{
bld.Append('_');
}
bld.Append(char.ToLower(c));
}
return bld.ToString();
}
}
}
1 change: 1 addition & 0 deletions src/libraries/System.Net.Http/src/System.Net.Http.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -175,6 +175,7 @@
<Compile Include="System\Net\Http\Headers\AltSvcHeaderParser.cs" />
<Compile Include="System\Net\Http\Headers\AltSvcHeaderValue.cs" />
<Compile Include="System\Net\Http\Headers\KnownHeader.Http2And3.cs" />
<Compile Include="System\Net\Http\SocketsHttpHandler\ConnectionPool\ConnectionSetupDistributedTracing.cs" />
<Compile Include="System\Net\Http\SocketsHttpHandler\ConnectionPool\HttpConnectionPool.cs" />
<Compile Include="System\Net\Http\SocketsHttpHandler\ConnectionPool\HttpConnectionPool.Http1.cs" />
<Compile Include="System\Net\Http\SocketsHttpHandler\ConnectionPool\HttpConnectionPool.Http2.cs" />
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ namespace System.Net.Http
internal sealed class DiagnosticsHandler : HttpMessageHandlerStage
{
private static readonly DiagnosticListener s_diagnosticListener = new DiagnosticListener(DiagnosticsHandlerLoggingStrings.DiagnosticListenerName);
private static readonly ActivitySource s_activitySource = new ActivitySource(DiagnosticsHandlerLoggingStrings.Namespace);
internal static readonly ActivitySource s_activitySource = new ActivitySource(DiagnosticsHandlerLoggingStrings.RequestNamespace);

private readonly HttpMessageHandler _innerHandler;
private readonly DistributedContextPropagator _propagator;
Expand Down Expand Up @@ -58,14 +58,14 @@ private static bool IsEnabled()
Activity? activity = null;
if (s_activitySource.HasListeners())
{
activity = s_activitySource.StartActivity(DiagnosticsHandlerLoggingStrings.ActivityName, ActivityKind.Client);
activity = s_activitySource.StartActivity(DiagnosticsHandlerLoggingStrings.RequestActivityName, ActivityKind.Client);
}

if (activity is null &&
(Activity.Current is not null ||
s_diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ActivityName, request)))
s_diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.RequestActivityName, request)))
{
activity = new Activity(DiagnosticsHandlerLoggingStrings.ActivityName).Start();
activity = new Activity(DiagnosticsHandlerLoggingStrings.RequestActivityName).Start();
}

return activity;
Expand Down Expand Up @@ -134,9 +134,9 @@ private async ValueTask<HttpResponseMessage> SendAsyncCore(HttpRequestMessage re
}

// Only send start event to users who subscribed for it.
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ActivityStartName))
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.RequestActivityStartName))
{
Write(diagnosticListener, DiagnosticsHandlerLoggingStrings.ActivityStartName, new ActivityStartData(request));
Write(diagnosticListener, DiagnosticsHandlerLoggingStrings.RequestActivityStartName, new ActivityStartData(request));
}
}

Expand Down Expand Up @@ -214,10 +214,29 @@ await _innerHandler.SendAsync(request, cancellationToken).ConfigureAwait(false)
}
}

if (activity.IsAllDataRequested)
{
// Add standard tags known at request completion.
if (response is not null)
{
activity.SetTag("http.response.status_code", DiagnosticsHelper.GetBoxedStatusCode((int)response.StatusCode));
activity.SetTag("network.protocol.version", DiagnosticsHelper.GetProtocolVersionString(response.Version));
}

if (DiagnosticsHelper.TryGetErrorType(response, exception, out string? errorType))
{
activity.SetTag("error.type", errorType);

// The presence of error.type indicates that the conditions for setting Error status are also met.
// https://github.com/open-telemetry/semantic-conventions/blob/v1.26.0/docs/http/http-spans.md#status
activity.SetStatus(ActivityStatusCode.Error);
}
}

// Only send stop event to users who subscribed for it.
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ActivityStopName))
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.RequestActivityStopName))
{
Write(diagnosticListener, DiagnosticsHandlerLoggingStrings.ActivityStopName, new ActivityStopData(response, request, taskStatus));
Write(diagnosticListener, DiagnosticsHandlerLoggingStrings.RequestActivityStopName, new ActivityStopData(response, request, taskStatus));
}

activity.Stop();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,12 +9,16 @@ namespace System.Net.Http
internal static class DiagnosticsHandlerLoggingStrings
{
public const string DiagnosticListenerName = "HttpHandlerDiagnosticListener";
public const string Namespace = "System.Net.Http";
public const string RequestWriteNameDeprecated = Namespace + ".Request";
public const string ResponseWriteNameDeprecated = Namespace + ".Response";
public const string ExceptionEventName = Namespace + ".Exception";
public const string ActivityName = Namespace + ".HttpRequestOut";
public const string ActivityStartName = ActivityName + ".Start";
public const string ActivityStopName = ActivityName + ".Stop";
public const string RequestNamespace = "System.Net.Http";
public const string RequestWriteNameDeprecated = RequestNamespace + ".Request";
public const string ResponseWriteNameDeprecated = RequestNamespace + ".Response";
public const string ExceptionEventName = RequestNamespace + ".Exception";
public const string RequestActivityName = RequestNamespace + ".HttpRequestOut";
public const string RequestActivityStartName = RequestActivityName + ".Start";
public const string RequestActivityStopName = RequestActivityName + ".Stop";

public const string ConnectionsNamespace = "Experimental.System.Net.Http.Connections";
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Experimental?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It turned out that our solution results is an unexpected volume of span links for tools like Azure Monitor, blowing up their UI, see open-telemetry/opentelemetry-specification#4130.

We need to work with OTel and Azure Monitor to introduce a standard way for categorizing links so visualization tools can distinguish them. The plan is to drive this work forward in order to stabilize the feature in .NET 10.

public const string ConnectionSetupActivityName = ConnectionsNamespace + ".ConnectionSetup";
public const string WaitForConnectionActivityName = ConnectionsNamespace + ".WaitForConnection";
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -67,7 +67,7 @@ public static bool TryGetErrorType(HttpResponseMessage? response, Exception? exc

// In case the status code indicates a client or a server error, return the string representation of the status code.
// See the paragraph Status and the definition of 'error.type' in
// https://github.com/open-telemetry/semantic-conventions/blob/2bad9afad58fbd6b33cc683d1ad1f006e35e4a5d/docs/http/http-spans.md
// https://github.com/open-telemetry/semantic-conventions/blob/release/v1.23.x/docs/http/http-spans.md#Status
if (statusCode >= 400 && statusCode <= 599)
{
errorType = GetErrorStatusCodeString(statusCode);
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,98 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

using System.Collections.Generic;
using System.Diagnostics;
using System.Threading;

namespace System.Net.Http
{
// Implements distributed tracing logic for managing the "HTTP connection_setup" and "HTTP wait_for_connection" Activities.
internal static class ConnectionSetupDistributedTracing
{
private static readonly ActivitySource s_connectionsActivitySource = new ActivitySource(DiagnosticsHandlerLoggingStrings.ConnectionsNamespace);

public static Activity? StartConnectionSetupActivity(bool isSecure, HttpAuthority authority)
{
Activity? activity = null;
if (s_connectionsActivitySource.HasListeners())
{
// Connection activities should be new roots and not parented under whatever
// request happens to be in progress when the connection is started.
Activity.Current = null;
activity = s_connectionsActivitySource.StartActivity(DiagnosticsHandlerLoggingStrings.ConnectionSetupActivityName);
}

if (activity is not null)
{
activity.DisplayName = $"HTTP connection_setup {authority.HostValue}:{authority.Port}";
if (activity.IsAllDataRequested)
{
activity.SetTag("server.address", authority.HostValue);
activity.SetTag("server.port", authority.Port);
activity.SetTag("url.scheme", isSecure ? "https" : "http");
}
}

return activity;
}

public static void StopConnectionSetupActivity(Activity activity, Exception? exception, IPEndPoint? remoteEndPoint)
{
Debug.Assert(activity is not null);
if (exception is not null)
{
ReportError(activity, exception);
}
else
{
if (activity.IsAllDataRequested && remoteEndPoint is not null)
{
activity.SetTag("network.peer.address", remoteEndPoint.Address.ToString());
}
}

activity.Stop();
}

public static void ReportError(Activity? activity, Exception exception)
{
Debug.Assert(exception is not null);
if (activity is null) return;
activity.SetStatus(ActivityStatusCode.Error);

if (activity.IsAllDataRequested)
{
DiagnosticsHelper.TryGetErrorType(null, exception, out string? errorType);
Debug.Assert(errorType is not null, "DiagnosticsHelper.TryGetErrorType() should succeed whenever an exception is provided.");
activity.SetTag("error.type", errorType);
}
}

public static Activity? StartWaitForConnectionActivity(HttpAuthority authority)
{
Activity? activity = s_connectionsActivitySource.StartActivity(DiagnosticsHandlerLoggingStrings.WaitForConnectionActivityName);
if (activity is not null)
{
activity.DisplayName = $"HTTP wait_for_connection {authority.HostValue}:{authority.Port}";
}

return activity;
}

public static void AddConnectionLinkToRequestActivity(Activity connectionSetupActivity)
{
Debug.Assert(connectionSetupActivity is not null);

// We only support links for request activities created by the "System.Net.Http" ActivitySource.
if (DiagnosticsHandler.s_activitySource.HasListeners())
{
Activity? requestActivity = Activity.Current;
if (requestActivity?.Source == DiagnosticsHandler.s_activitySource)
{
requestActivity.AddLink(new ActivityLink(connectionSetupActivity.Context));
}
}
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -294,14 +294,14 @@ private async Task InjectNewHttp11ConnectionAsync(RequestQueue<HttpConnection>.Q

internal async ValueTask<HttpConnection> CreateHttp11ConnectionAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken)
{
(Stream stream, TransportContext? transportContext, IPEndPoint? remoteEndPoint) = await ConnectAsync(request, async, cancellationToken).ConfigureAwait(false);
return await ConstructHttp11ConnectionAsync(async, stream, transportContext, request, remoteEndPoint, cancellationToken).ConfigureAwait(false);
(Stream stream, TransportContext? transportContext, Activity? activity, IPEndPoint? remoteEndPoint) = await ConnectAsync(request, async, cancellationToken).ConfigureAwait(false);
return await ConstructHttp11ConnectionAsync(async, stream, transportContext, request, activity, remoteEndPoint, cancellationToken).ConfigureAwait(false);
}

private async ValueTask<HttpConnection> ConstructHttp11ConnectionAsync(bool async, Stream stream, TransportContext? transportContext, HttpRequestMessage request, IPEndPoint? remoteEndPoint, CancellationToken cancellationToken)
private async ValueTask<HttpConnection> ConstructHttp11ConnectionAsync(bool async, Stream stream, TransportContext? transportContext, HttpRequestMessage request, Activity? activity, IPEndPoint? remoteEndPoint, CancellationToken cancellationToken)
antonfirsov marked this conversation as resolved.
Show resolved Hide resolved
{
Stream newStream = await ApplyPlaintextFilterAsync(async, stream, HttpVersion.Version11, request, cancellationToken).ConfigureAwait(false);
return new HttpConnection(this, newStream, transportContext, remoteEndPoint);
return new HttpConnection(this, newStream, transportContext, activity, remoteEndPoint);
}

private void HandleHttp11ConnectionFailure(HttpConnectionWaiter<HttpConnection>? requestWaiter, Exception e)
Expand Down
Loading