Skip to content

Commit

Permalink
Activities for Http Connections, Dns, Sockets and SslStream (#103922)
Browse files Browse the repository at this point in the history
Final design: #103922 (comment)
  • Loading branch information
antonfirsov committed Jul 13, 2024
1 parent ac0eeb0 commit ee5770d
Show file tree
Hide file tree
Showing 36 changed files with 1,458 additions and 204 deletions.
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";
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)
{
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

0 comments on commit ee5770d

Please sign in to comment.