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

[http] Add http.client.request.duration metric and .NET Framework support #4870

Merged
Merged
Show file tree
Hide file tree
Changes from 45 commits
Commits
Show all changes
55 commits
Select commit Hold shift + click to select a range
17d67e0
snapshot
matt-hensley Sep 15, 2023
800a71d
null actvitiy is tracing is disabled
matt-hensley Sep 15, 2023
4a9239e
setup metics without tracing
matt-hensley Sep 15, 2023
d7b2472
only emit when there is a listener
matt-hensley Sep 15, 2023
46de1a9
modify tests for netfx
matt-hensley Sep 15, 2023
4e445b5
always capture response status code
matt-hensley Sep 18, 2023
f0ca432
Merge branch 'main' into net462httpclientmetricsv3
matt-hensley Sep 18, 2023
bed7b2b
undo conditional extraction
matt-hensley Sep 18, 2023
ba04ac0
activity duration or stopwatch
matt-hensley Sep 18, 2023
48c354a
activity duration or stopwatch
matt-hensley Sep 18, 2023
872ce63
Merge branch 'net462httpclientmetricsv3' of https://github.com/matt-h…
matt-hensley Sep 18, 2023
6999167
activity may be null here
matt-hensley Sep 18, 2023
42e9022
duration -> durationMs for now
matt-hensley Sep 18, 2023
527106f
StartTimestamp handling
matt-hensley Sep 18, 2023
e31f687
adopt taglist
matt-hensley Sep 18, 2023
01840c0
using directive is unnecessary
matt-hensley Sep 18, 2023
9ef2915
using directive is unnecessary
matt-hensley Sep 18, 2023
47fc955
Merge branch 'net462httpclientmetricsv3' of https://github.com/matt-h…
matt-hensley Sep 18, 2023
d9ca497
remove URL attribute
matt-hensley Sep 18, 2023
308ca8f
status enum to int
matt-hensley Sep 18, 2023
480940e
remove ternary
matt-hensley Sep 19, 2023
27ad5ab
early return if tracing and metrics are not enabled
matt-hensley Sep 19, 2023
025c02d
set activity
matt-hensley Sep 19, 2023
dfaa8f7
Update src/OpenTelemetry.Instrumentation.Http/Implementation/HttpWebR…
matt-hensley Sep 19, 2023
ad10683
Merge branch 'net462httpclientmetricsv3' of https://github.com/matt-h…
matt-hensley Sep 19, 2023
8bd64ef
Update src/OpenTelemetry.Instrumentation.Http/Implementation/HttpWebR…
matt-hensley Sep 19, 2023
6ca5c9d
Update src/OpenTelemetry.Instrumentation.Http/Implementation/HttpWebR…
matt-hensley Sep 19, 2023
61a01f7
Merge branch 'net462httpclientmetricsv3' of https://github.com/matt-h…
matt-hensley Sep 19, 2023
b4dd250
flag name change
matt-hensley Sep 19, 2023
bca1361
remove Moq from test
matt-hensley Sep 19, 2023
5200afb
need to pick context off current activity for propagator to work
matt-hensley Sep 19, 2023
4d15ca6
extra line
matt-hensley Sep 19, 2023
dd07ca0
modify tests to handle metrics and/or tracing on/off
matt-hensley Sep 19, 2023
fc47558
null handling
matt-hensley Sep 19, 2023
9ae0193
null check for safety, tests don't blow up here for some reason?
matt-hensley Sep 20, 2023
9c4c3b5
Merge branch 'main' into net462httpclientmetricsv3
matt-hensley Sep 20, 2023
dcdde2c
remove note that netfx does not have metrics
matt-hensley Sep 20, 2023
a063be1
changelog entry
matt-hensley Sep 20, 2023
7ce3c51
correct whitespace
matt-hensley Sep 22, 2023
bef3862
Merge branch 'main' into net462httpclientmetricsv3
matt-hensley Sep 22, 2023
812ad91
reorder methods per linter
matt-hensley Sep 22, 2023
2cfc3e2
putting the combinations in one test is causing intermittent failures
matt-hensley Sep 22, 2023
051cb42
Merge branch 'main' into net462httpclientmetricsv3
matt-hensley Sep 23, 2023
0f37992
lift null checks
matt-hensley Sep 23, 2023
86c8ab0
make this isn't hit when tracing is disabled
matt-hensley Sep 23, 2023
7704a82
Update src/OpenTelemetry.Instrumentation.Http/CHANGELOG.md
matt-hensley Sep 25, 2023
7e03ca7
Merge branch 'main' into net462httpclientmetricsv3
matt-hensley Sep 25, 2023
0ce3ced
modify test to ensure duration was written
matt-hensley Sep 26, 2023
5218b65
Fixes, tweaks, and cleanup.
CodeBlanch Sep 27, 2023
e70629b
Code review.
CodeBlanch Sep 29, 2023
616f299
Add support for http.client.request.duration.
CodeBlanch Oct 2, 2023
1502d64
Update src/OpenTelemetry.Instrumentation.Http/Implementation/HttpHand…
CodeBlanch Oct 2, 2023
34e39f4
MD lint.
CodeBlanch Oct 2, 2023
9f1f887
Merge branch 'net462httpclientmetricsv3' of https://github.com/matt-h…
CodeBlanch Oct 2, 2023
f2e864b
Merge branch 'main' into net462httpclientmetricsv3
CodeBlanch Oct 2, 2023
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
2 changes: 2 additions & 0 deletions src/OpenTelemetry.Instrumentation.Http/CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,8 @@

## Unreleased

* Added support for publishing `http.client.duration` metric on .NET Framework
matt-hensley marked this conversation as resolved.
Show resolved Hide resolved

## 1.5.1-beta.1

Released 2023-Jul-20
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
#if NETFRAMEWORK
using System.Collections;
using System.Diagnostics;
using System.Diagnostics.Metrics;
using System.Net;
using System.Reflection;
using System.Reflection.Emit;
Expand All @@ -39,12 +40,15 @@ internal static class HttpWebRequestActivitySource
internal static readonly AssemblyName AssemblyName = typeof(HttpWebRequestActivitySource).Assembly.GetName();
internal static readonly string ActivitySourceName = AssemblyName.Name + ".HttpWebRequest";
internal static readonly string ActivityName = ActivitySourceName + ".HttpRequestOut";
internal static readonly string MeterInstrumentationName = AssemblyName.Name;

internal static readonly Func<HttpWebRequest, string, IEnumerable<string>> HttpWebRequestHeaderValuesGetter = (request, name) => request.Headers.GetValues(name);
internal static readonly Action<HttpWebRequest, string, string> HttpWebRequestHeaderValuesSetter = (request, name, value) => request.Headers.Add(name, value);

private static readonly Version Version = AssemblyName.Version;
private static readonly ActivitySource WebRequestActivitySource = new ActivitySource(ActivitySourceName, Version.ToString());
private static readonly Meter WebRequestMeter = new Meter(MeterInstrumentationName, Version.ToString());
private static readonly Histogram<double> HttpClientDuration;

private static HttpClientInstrumentationOptions options;

Expand Down Expand Up @@ -87,6 +91,7 @@ static HttpWebRequestActivitySource()
PerformInjection();

Options = new HttpClientInstrumentationOptions();
HttpClientDuration = WebRequestMeter.CreateHistogram<double>("http.client.duration", "ms", "Measures the duration of outbound HTTP requests.");
}
catch (Exception ex)
{
Expand Down Expand Up @@ -157,6 +162,8 @@ private static void AddRequestTagsAndInstrumentRequest(HttpWebRequest request, A
[MethodImpl(MethodImplOptions.AggressiveInlining)]
private static void AddResponseTags(HttpWebResponse response, Activity activity)
{
Debug.Assert(activity != null, "Activity must not be null");

if (activity.IsAllDataRequested)
{
if (emitOldAttributes)
Expand Down Expand Up @@ -185,6 +192,8 @@ private static void AddResponseTags(HttpWebResponse response, Activity activity)
[MethodImpl(MethodImplOptions.AggressiveInlining)]
private static void AddExceptionTags(Exception exception, Activity activity)
{
Debug.Assert(activity != null, "Activity must not be null");

if (!activity.IsAllDataRequested)
{
return;
Expand Down Expand Up @@ -265,10 +274,13 @@ private static bool IsRequestInstrumented(HttpWebRequest request)

private static void ProcessRequest(HttpWebRequest request)
{
if (!WebRequestActivitySource.HasListeners() || !Options.EventFilterHttpWebRequest(request))
// There are subscribers to the ActivitySource and no user-provided filter is
// filtering this request.
var enableTracing = WebRequestActivitySource.HasListeners() && Options.EventFilterHttpWebRequest(request);

if (!enableTracing && !HttpClientDuration.Enabled)
{
// No subscribers to the ActivitySource or User provider Filter is
// filtering this request.
// Tracing and metrics are not enabled, so we can skip generating signals
// Propagation must still be done in such cases, to allow
// downstream services to continue from parent context, if any.
// Eg: Parent could be the Asp.Net activity.
Expand All @@ -283,37 +295,41 @@ private static void ProcessRequest(HttpWebRequest request)
return;
}

var activity = WebRequestActivitySource.StartActivity(ActivityName, ActivityKind.Client);
Activity activity = null;

if (enableTracing)
{
activity = WebRequestActivitySource.StartActivity(ActivityName, ActivityKind.Client);
}

var activityContext = Activity.Current?.Context ?? default;

// Propagation must still be done in all cases, to allow
// downstream services to continue from parent context, if any.
// Eg: Parent could be the Asp.Net activity.
InstrumentRequest(request, activityContext);
if (activity == null)
{
// There is a listener but it decided not to sample the current request.
return;
}

IAsyncResult asyncContext = writeAResultAccessor(request);
if (asyncContext != null)
{
// Flow here is for [Begin]GetRequestStream[Async].

AsyncCallbackWrapper callback = new AsyncCallbackWrapper(request, activity, asyncCallbackAccessor(asyncContext));
AsyncCallbackWrapper callback = new AsyncCallbackWrapper(request, activity, asyncCallbackAccessor(asyncContext), Stopwatch.GetTimestamp());
asyncCallbackModifier(asyncContext, callback.AsyncCallback);
}
else
{
// Flow here is for [Begin]GetResponse[Async] without a prior call to [Begin]GetRequestStream[Async].

asyncContext = readAResultAccessor(request);
AsyncCallbackWrapper callback = new AsyncCallbackWrapper(request, activity, asyncCallbackAccessor(asyncContext));
AsyncCallbackWrapper callback = new AsyncCallbackWrapper(request, activity, asyncCallbackAccessor(asyncContext), Stopwatch.GetTimestamp());
asyncCallbackModifier(asyncContext, callback.AsyncCallback);
}

AddRequestTagsAndInstrumentRequest(request, activity);
if (activity != null)
{
AddRequestTagsAndInstrumentRequest(request, activity);
}
}

private static void HookOrProcessResult(HttpWebRequest request)
Expand All @@ -340,26 +356,32 @@ private static void HookOrProcessResult(HttpWebRequest request)
if (endCalledAccessor.Invoke(readAsyncContext) || readAsyncContext.CompletedSynchronously)
{
// We need to process the result directly because the read callback has already fired. Force a copy because response has likely already been disposed.
ProcessResult(readAsyncContext, null, writeAsyncContextCallback.Activity, resultAccessor(readAsyncContext), true);
ProcessResult(readAsyncContext, null, writeAsyncContextCallback.Activity, resultAccessor(readAsyncContext), true, request, writeAsyncContextCallback.StartTimestamp);
return;
}

// Hook into the result callback if it hasn't already fired.
AsyncCallbackWrapper callback = new AsyncCallbackWrapper(writeAsyncContextCallback.Request, writeAsyncContextCallback.Activity, asyncCallbackAccessor(readAsyncContext));
AsyncCallbackWrapper callback = new AsyncCallbackWrapper(writeAsyncContextCallback.Request, writeAsyncContextCallback.Activity, asyncCallbackAccessor(readAsyncContext), Stopwatch.GetTimestamp());
asyncCallbackModifier(readAsyncContext, callback.AsyncCallback);
}

private static void ProcessResult(IAsyncResult asyncResult, AsyncCallback asyncCallback, Activity activity, object result, bool forceResponseCopy)
private static void ProcessResult(IAsyncResult asyncResult, AsyncCallback asyncCallback, Activity activity, object result, bool forceResponseCopy, HttpWebRequest request, long startTimestamp)
{
HttpStatusCode? httpStatusCode = null;

// Activity may be null if we are not tracing in these cases:
// 1. No listeners
// 2. Request was filtered out
// 3. Request was not sampled
// We could be executing on a different thread now so restore the activity if needed.
if (Activity.Current != activity)
if (activity != null && Activity.Current != activity)
matt-hensley marked this conversation as resolved.
Show resolved Hide resolved
{
Activity.Current = activity;
}

try
{
if (result is Exception ex)
if (activity != null && result is Exception ex)
{
AddExceptionTags(ex, activity);
}
Expand All @@ -382,11 +404,21 @@ private static void ProcessResult(IAsyncResult asyncResult, AsyncCallback asyncC
isWebSocketResponseAccessor(response), connectionGroupNameAccessor(response),
});

AddResponseTags(responseCopy, activity);
if (activity != null)
{
AddResponseTags(responseCopy, activity);
}

httpStatusCode = responseCopy.StatusCode;
}
else
{
AddResponseTags(response, activity);
if (activity != null)
{
AddResponseTags(response, activity);
}

httpStatusCode = response.StatusCode;
}
}
}
Expand All @@ -395,7 +427,37 @@ private static void ProcessResult(IAsyncResult asyncResult, AsyncCallback asyncC
HttpInstrumentationEventSource.Log.FailedProcessResult(ex);
}

activity.Stop();
activity?.Stop();

if (HttpClientDuration.Enabled)
{
double durationMs = 0;

if (activity != null)
{
durationMs = activity.Duration.TotalMilliseconds;
}
else
{
var endTimestamp = Stopwatch.GetTimestamp();
var durationS = (endTimestamp - startTimestamp) / Stopwatch.Frequency;
durationMs = durationS * 1000;
vishweshbankwar marked this conversation as resolved.
Show resolved Hide resolved
}

TagList tags = default;
tags.Add(SemanticConventions.AttributeHttpFlavor, HttpTagHelper.GetFlavorTagValueFromProtocolVersion(request.ProtocolVersion));
tags.Add(SemanticConventions.AttributeHttpMethod, request.Method);
tags.Add(SemanticConventions.AttributeHttpScheme, request.RequestUri.Scheme);
tags.Add(SemanticConventions.AttributeNetPeerName, request.RequestUri.Host);
tags.Add(SemanticConventions.AttributeNetPeerPort, request.RequestUri.Port);

if (httpStatusCode.HasValue)
{
tags.Add(SemanticConventions.AttributeHttpStatusCode, (int)httpStatusCode.Value);
}

HttpClientDuration.Record(durationMs, tags);
Copy link
Member

@vishweshbankwar vishweshbankwar Oct 2, 2023

Choose a reason for hiding this comment

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

We need to use different histogram based on the configured option

metricsEmitOldAttributes - > http.client.duration
metricsEmitNewAttributes -> http.client.request.duration

Copy link
Contributor

Choose a reason for hiding this comment

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

I think this PR is focused on adding metrics to NetFx, where my PR was adding the NEW metric to the library. I don't think we should try to accomplish both goals in a single PR. :)

Copy link
Member

@vishweshbankwar vishweshbankwar Oct 2, 2023

Choose a reason for hiding this comment

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

@TimothyMothra I think it is ok to do this here as your PR only updates HttpHandlerMetricsDiagnosticListener. But we need two different Histograms for this to be correct.

Copy link
Member

Choose a reason for hiding this comment

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

If the style is "dupe" what happens? You get both old + new histograms each with the full set of tags? Or you get old histogram with the old tags and new histogram with the new tags?

Copy link
Member

Choose a reason for hiding this comment

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

you get old histogram with the old tags and new histogram with the new tags

This^

Copy link
Member

Choose a reason for hiding this comment

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

These HttpClient tests currently are exercising both the .NET Framework & .NET/Core style instrumentations. If we make this change here the tests will start failing for the .NET/Core style. I'm thinking we should tackle both on @TimothyMothra's PR?

Copy link
Member

Choose a reason for hiding this comment

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

Could we remove the new conventions from here then?

Copy link
Contributor

@TimothyMothra TimothyMothra Oct 2, 2023

Choose a reason for hiding this comment

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

If the style is "dupe" what happens? You get both old + new histograms each with the full set of tags? Or you get old histogram with the old tags and new histogram with the new tags?

We would emit old metric using old histogram and old attributes (http.client.duration + miliseconds) AND new metric using new histogram and new attributes (http.client.request.duration + seconds).

Copy link
Member

Choose a reason for hiding this comment

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

Could we remove the new conventions from here then?

I just pulled @TimothyMothra's work from #4891 into this PR. Seemed like more work to remove it all and then put it back in.

Copy link
Contributor

Choose a reason for hiding this comment

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

I just pulled @TimothyMothra's work from #4891 into this PR.

😲

}
}

private static void PrepareReflectionObjects()
Expand Down Expand Up @@ -1109,11 +1171,12 @@ public override void Clear()
/// </summary>
private sealed class AsyncCallbackWrapper
{
public AsyncCallbackWrapper(HttpWebRequest request, Activity activity, AsyncCallback originalCallback)
public AsyncCallbackWrapper(HttpWebRequest request, Activity activity, AsyncCallback originalCallback, long startTimestamp)
{
this.Request = request;
this.Activity = activity;
this.OriginalCallback = originalCallback;
this.StartTimestamp = startTimestamp;
}

public HttpWebRequest Request { get; }
Expand All @@ -1122,12 +1185,21 @@ public AsyncCallbackWrapper(HttpWebRequest request, Activity activity, AsyncCall

public AsyncCallback OriginalCallback { get; }

public long StartTimestamp { get; }

public void AsyncCallback(IAsyncResult asyncResult)
{
object result = resultAccessor(asyncResult);
if (result is Exception || result is HttpWebResponse)
{
ProcessResult(asyncResult, this.OriginalCallback, this.Activity, result, false);
ProcessResult(
asyncResult,
this.OriginalCallback,
this.Activity,
result,
forceResponseCopy: false,
this.Request,
this.StartTimestamp);
}

this.OriginalCallback?.Invoke(asyncResult);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -14,8 +14,11 @@
// limitations under the License.
// </copyright>

#if NETFRAMEWORK
#else
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Options;
#endif
using OpenTelemetry.Instrumentation.Http;
using OpenTelemetry.Instrumentation.Http.Implementation;
using OpenTelemetry.Internal;
Expand Down Expand Up @@ -52,9 +55,13 @@ public static MeterProviderBuilder AddHttpClientInstrumentation(
// Filter - makes sense for metric instrumentation
// Enrich - do we want a similar kind of functionality for metrics?
// RecordException - probably doesn't make sense for metric instrumentation

#if NETFRAMEWORK
builder.AddMeter(HttpWebRequestActivitySource.MeterInstrumentationName);
#else
builder.AddMeter(HttpClientMetrics.InstrumentationName);
return builder.AddInstrumentation(sp => new HttpClientMetrics(
builder.AddInstrumentation(sp => new HttpClientMetrics(
sp.GetRequiredService<IOptionsMonitor<HttpClientMetricInstrumentationOptions>>().CurrentValue));
#endif
return builder;
}
}
3 changes: 0 additions & 3 deletions src/OpenTelemetry.Instrumentation.Http/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -67,9 +67,6 @@ public class Program

#### Metrics

> **Note**
> Metrics are not available for .NET Framework.

The following example demonstrates adding `HttpClient` instrumentation with the
extension method `.AddHttpClientInstrumentation()` on `MeterProviderBuilder` to
a console application. This example also sets up the OpenTelemetry Console
Expand Down
Loading
Loading