Skip to content

Commit c4e57fb

Browse files
rainsxngrainsxng
authored
Add measures and tags with mediator object to the HttpClientLatencyLogEnricher (#6783)
1 parent 3cce027 commit c4e57fb

File tree

11 files changed

+481
-57
lines changed

11 files changed

+481
-57
lines changed

‎src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/HttpClientLatencyTelemetryExtensions.cs‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,9 @@ public static IServiceCollection AddHttpClientLatencyTelemetry(this IServiceColl
3333
_ = services.AddSingleton<HttpRequestLatencyListener>();
3434
_ = services.AddSingleton<HttpClientLatencyContext>();
3535
_ = services.AddTransient<HttpLatencyTelemetryHandler>();
36+
_ = services.AddSingleton<HttpLatencyMediator>();
37+
_ = services.RegisterMeasureNames(HttpMeasures.Measures);
38+
_ = services.RegisterTagNames(HttpTags.Tags);
3639
_ = services.AddHttpClientLogEnricher<HttpClientLatencyLogEnricher>();
3740

3841
return services.ConfigureAll<HttpClientFactoryOptions>(

‎src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpClientLatencyLogEnricher.cs‎

Lines changed: 97 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -23,62 +23,140 @@ internal sealed class HttpClientLatencyLogEnricher : IHttpClientLogEnricher
2323
{
2424
private static readonly ObjectPool<StringBuilder> _builderPool = PoolFactory.SharedStringBuilderPool;
2525
private readonly HttpClientLatencyContext _latencyContext;
26-
26+
private readonly HttpLatencyMediator _httpLatencyMediator;
2727
private readonly CheckpointToken _enricherInvoked;
2828

29-
public HttpClientLatencyLogEnricher(HttpClientLatencyContext latencyContext, ILatencyContextTokenIssuer tokenIssuer)
29+
public HttpClientLatencyLogEnricher(
30+
HttpClientLatencyContext latencyContext,
31+
ILatencyContextTokenIssuer tokenIssuer,
32+
HttpLatencyMediator httpLatencyMediator)
3033
{
3134
_latencyContext = latencyContext;
35+
_httpLatencyMediator = httpLatencyMediator;
3236
_enricherInvoked = tokenIssuer.GetCheckpointToken(HttpCheckpoints.EnricherInvoked);
3337
}
3438

35-
public void Enrich(IEnrichmentTagCollector collector, HttpRequestMessage request, HttpResponseMessage? response, Exception? exception)
39+
public void Enrich(IEnrichmentTagCollector collector, HttpRequestMessage? request, HttpResponseMessage? response, Exception? exception)
3640
{
3741
if (response != null)
3842
{
3943
var lc = _latencyContext.Get();
40-
lc?.AddCheckpoint(_enricherInvoked);
41-
42-
StringBuilder stringBuilder = _builderPool.Get();
43-
44-
// Add serverName, checkpoints to outgoing http logs.
45-
AppendServerName(response.Headers, stringBuilder);
46-
_ = stringBuilder.Append(',');
4744

4845
if (lc != null)
4946
{
50-
AppendCheckpoints(lc, stringBuilder);
47+
// Add the checkpoint
48+
lc.AddCheckpoint(_enricherInvoked);
49+
50+
// Use the mediator to record all metrics
51+
_httpLatencyMediator.RecordEnd(lc, response);
5152
}
5253

53-
collector.Add("LatencyInfo", stringBuilder.ToString());
54+
StringBuilder stringBuilder = _builderPool.Get();
55+
56+
try
57+
{
58+
/* Add version, serverName, checkpoints, and measures to outgoing http logs.
59+
* Schemas: 1) ServerName,CheckpointName,CheckpointValue
60+
* 2) v1.0,ServerName,TagName,TagValue,CheckpointName,CheckpointValue,MetricName,MetricValue
61+
*/
62+
63+
// Add version
64+
_ = stringBuilder.Append("v1.0");
65+
_ = stringBuilder.Append(',');
66+
67+
// Add server name
68+
AppendServerName(response.Headers, stringBuilder);
69+
_ = stringBuilder.Append(',');
70+
71+
// Add tags, checkpoints, and measures
72+
if (lc != null)
73+
{
74+
AppendTags(lc, stringBuilder);
75+
_ = stringBuilder.Append(',');
76+
77+
AppendCheckpoints(lc, stringBuilder);
78+
_ = stringBuilder.Append(',');
5479

55-
_builderPool.Return(stringBuilder);
80+
AppendMeasures(lc, stringBuilder);
81+
}
82+
83+
collector.Add("LatencyInfo", stringBuilder.ToString());
84+
}
85+
finally
86+
{
87+
_builderPool.Return(stringBuilder);
88+
}
5689
}
5790
}
5891

5992
private static void AppendServerName(HttpHeaders headers, StringBuilder stringBuilder)
6093
{
6194
if (headers.TryGetValues(TelemetryConstants.ServerApplicationNameHeader, out var values))
6295
{
63-
_ = stringBuilder.Append(values!.First());
96+
_ = stringBuilder.Append(values.First());
6497
}
6598
}
6699

67100
private static void AppendCheckpoints(ILatencyContext latencyContext, StringBuilder stringBuilder)
68101
{
102+
const int MillisecondsPerSecond = 1000;
103+
69104
var latencyData = latencyContext.LatencyData;
70-
for (int i = 0; i < latencyData.Checkpoints.Length; i++)
105+
var checkpointCount = latencyData.Checkpoints.Length;
106+
107+
for (int i = 0; i < checkpointCount; i++)
71108
{
72109
_ = stringBuilder.Append(latencyData.Checkpoints[i].Name);
73110
_ = stringBuilder.Append('/');
74111
}
75112

76113
_ = stringBuilder.Append(',');
77-
for (int i = 0; i < latencyData.Checkpoints.Length; i++)
114+
115+
for (int i = 0; i < checkpointCount; i++)
116+
{
117+
var cp = latencyData.Checkpoints[i];
118+
_ = stringBuilder.Append((long)Math.Round(((double)cp.Elapsed / cp.Frequency) * MillisecondsPerSecond));
119+
_ = stringBuilder.Append('/');
120+
}
121+
}
122+
123+
private static void AppendMeasures(ILatencyContext latencyContext, StringBuilder stringBuilder)
124+
{
125+
var latencyData = latencyContext.LatencyData;
126+
var measureCount = latencyData.Measures.Length;
127+
128+
for (int i = 0; i < measureCount; i++)
129+
{
130+
_ = stringBuilder.Append(latencyData.Measures[i].Name);
131+
_ = stringBuilder.Append('/');
132+
}
133+
134+
_ = stringBuilder.Append(',');
135+
136+
for (int i = 0; i < measureCount; i++)
137+
{
138+
_ = stringBuilder.Append(latencyData.Measures[i].Value);
139+
_ = stringBuilder.Append('/');
140+
}
141+
}
142+
143+
private static void AppendTags(ILatencyContext latencyContext, StringBuilder stringBuilder)
144+
{
145+
var latencyData = latencyContext.LatencyData;
146+
var tagCount = latencyData.Tags.Length;
147+
148+
for (int i = 0; i < tagCount; i++)
149+
{
150+
_ = stringBuilder.Append(latencyData.Tags[i].Name);
151+
_ = stringBuilder.Append('/');
152+
}
153+
154+
_ = stringBuilder.Append(',');
155+
156+
for (int i = 0; i < tagCount; i++)
78157
{
79-
var ms = ((double)latencyData.Checkpoints[i].Elapsed / latencyData.Checkpoints[i].Frequency) * 1000;
80-
_ = stringBuilder.Append(ms);
158+
_ = stringBuilder.Append(latencyData.Tags[i].Value);
81159
_ = stringBuilder.Append('/');
82160
}
83161
}
84-
}
162+
}

‎src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpLatencyMediator.cs‎

Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,39 @@
1+
// Licensed to the .NET Foundation under one or more agreements.
2+
// The .NET Foundation licenses this file to you under the MIT license.
3+
4+
#if NET
5+
using System.Net.Http;
6+
using Microsoft.Extensions.Diagnostics.Latency;
7+
8+
namespace Microsoft.Extensions.Http.Latency.Internal;
9+
10+
/// <summary>
11+
/// Mediator for HTTP latency operations that coordinates recording HTTP metrics in a latency context.
12+
/// </summary>
13+
internal sealed class HttpLatencyMediator
14+
{
15+
private readonly MeasureToken _gcPauseTime;
16+
private readonly TagToken _httpVersionTag;
17+
18+
public HttpLatencyMediator(ILatencyContextTokenIssuer tokenIssuer)
19+
{
20+
_gcPauseTime = tokenIssuer.GetMeasureToken(HttpMeasures.GCPauseTime);
21+
_httpVersionTag = tokenIssuer.GetTagToken(HttpTags.HttpVersion);
22+
}
23+
24+
public void RecordStart(ILatencyContext latencyContext)
25+
{
26+
latencyContext.RecordMeasure(_gcPauseTime, (long)System.GC.GetTotalPauseDuration().TotalMilliseconds * -1L);
27+
}
28+
29+
public void RecordEnd(ILatencyContext latencyContext, HttpResponseMessage? response = null)
30+
{
31+
latencyContext.AddMeasure(_gcPauseTime, (long)System.GC.GetTotalPauseDuration().TotalMilliseconds);
32+
33+
if (response != null)
34+
{
35+
latencyContext.SetTag(_httpVersionTag, response.Version.ToString());
36+
}
37+
}
38+
}
39+
#endif

‎src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpLatencyMediator.netfx.cs‎

Lines changed: 27 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,27 @@
1+
// Licensed to the .NET Foundation under one or more agreements.
2+
// The .NET Foundation licenses this file to you under the MIT license.
3+
#if !NET
4+
5+
using System.Net.Http;
6+
using Microsoft.Extensions.Diagnostics.Latency;
7+
8+
namespace Microsoft.Extensions.Http.Latency.Internal;
9+
10+
internal sealed class HttpLatencyMediator
11+
{
12+
private readonly TagToken _httpVersionTag;
13+
14+
public HttpLatencyMediator(ILatencyContextTokenIssuer tokenIssuer)
15+
{
16+
_httpVersionTag = tokenIssuer.GetTagToken(HttpTags.HttpVersion);
17+
}
18+
19+
public void RecordEnd(ILatencyContext latencyContext, HttpResponseMessage? response = null)
20+
{
21+
if (response != null)
22+
{
23+
latencyContext?.SetTag(_httpVersionTag, response.Version.ToString());
24+
}
25+
}
26+
}
27+
#endif

‎src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpLatencyTelemetryHandler.cs‎

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,14 +21,20 @@ internal sealed class HttpLatencyTelemetryHandler : DelegatingHandler
2121
private readonly ILatencyContextProvider _latencyContextProvider;
2222
private readonly CheckpointToken _handlerStart;
2323
private readonly string _applicationName;
24+
#if NET
25+
private readonly HttpLatencyMediator _latencyMediator;
26+
#endif
2427

2528
public HttpLatencyTelemetryHandler(HttpRequestLatencyListener latencyListener, ILatencyContextTokenIssuer tokenIssuer, ILatencyContextProvider latencyContextProvider,
26-
IOptions<HttpClientLatencyTelemetryOptions> options, IOptions<ApplicationMetadata> appMetadata)
29+
IOptions<HttpClientLatencyTelemetryOptions> options, IOptions<ApplicationMetadata> appMetadata, HttpLatencyMediator latencyTelemetryMediator)
2730
{
2831
_latencyListener = latencyListener;
2932
_latencyContextProvider = latencyContextProvider;
3033
_handlerStart = tokenIssuer.GetCheckpointToken(HttpCheckpoints.HandlerRequestStart);
3134
_applicationName = appMetadata.Value.ApplicationName;
35+
#if NET
36+
_latencyMediator = latencyTelemetryMediator;
37+
#endif
3238

3339
if (options.Value.EnableDetailedLatencyBreakdown)
3440
{
@@ -42,6 +48,10 @@ protected async override Task<HttpResponseMessage> SendAsync(HttpRequestMessage
4248
context.AddCheckpoint(_handlerStart);
4349
_latencyListener.LatencyContext.Set(context);
4450

51+
#if NET
52+
_latencyMediator.RecordStart(context);
53+
#endif
54+
4555
_ = request.Headers.TryAddWithoutValidation(TelemetryConstants.ClientApplicationNameHeader, _applicationName);
4656

4757
return await base.SendAsync(request, cancellationToken).ConfigureAwait(false);

‎src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpMeasures.cs‎

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,16 @@
1+
// Licensed to the .NET Foundation under one or more agreements.
2+
// The .NET Foundation licenses this file to you under the MIT license.
3+
4+
namespace Microsoft.Extensions.Http.Latency.Internal;
5+
6+
internal static class HttpMeasures
7+
{
8+
public const string GCPauseTime = "gcp";
9+
public const string ConnectionInitiated = "coni";
10+
11+
public static readonly string[] Measures =
12+
[
13+
GCPauseTime,
14+
ConnectionInitiated
15+
];
16+
}

0 commit comments

Comments
 (0)