Skip to content
Merged
Show file tree
Hide file tree
Changes from 3 commits
Commits
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
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,8 @@ public sealed partial class OpenTelemetryChatClient : DelegatingChatClient

private readonly Histogram<int> _tokenUsageHistogram;
private readonly Histogram<double> _operationDurationHistogram;
private readonly Histogram<double> _timeToFirstChunkHistogram;
private readonly Histogram<double> _timePerOutputChunkHistogram;

private readonly string? _defaultModelId;
private readonly string? _providerName;
Expand Down Expand Up @@ -84,6 +86,20 @@ public OpenTelemetryChatClient(IChatClient innerClient, ILogger? logger = null,
advice: new() { HistogramBucketBoundaries = OpenTelemetryConsts.GenAI.Client.OperationDuration.ExplicitBucketBoundaries }
);

_timeToFirstChunkHistogram = _meter.CreateHistogram<double>(
OpenTelemetryConsts.GenAI.Client.TimeToFirstChunk.Name,
OpenTelemetryConsts.SecondsUnit,
OpenTelemetryConsts.GenAI.Client.TimeToFirstChunk.Description,
advice: new() { HistogramBucketBoundaries = OpenTelemetryConsts.GenAI.Client.TimeToFirstChunk.ExplicitBucketBoundaries }
);

_timePerOutputChunkHistogram = _meter.CreateHistogram<double>(
OpenTelemetryConsts.GenAI.Client.TimePerOutputChunk.Name,
OpenTelemetryConsts.SecondsUnit,
OpenTelemetryConsts.GenAI.Client.TimePerOutputChunk.Description,
advice: new() { HistogramBucketBoundaries = OpenTelemetryConsts.GenAI.Client.TimePerOutputChunk.ExplicitBucketBoundaries }
);

_jsonSerializerOptions = AIJsonUtilities.DefaultOptions;
}

Expand Down Expand Up @@ -167,7 +183,8 @@ public override async IAsyncEnumerable<ChatResponseUpdate> GetStreamingResponseA
_jsonSerializerOptions.MakeReadOnly();

using Activity? activity = CreateAndConfigureActivity(options);
Stopwatch? stopwatch = _operationDurationHistogram.Enabled ? Stopwatch.StartNew() : null;
bool trackChunkTimes = _timeToFirstChunkHistogram.Enabled || _timePerOutputChunkHistogram.Enabled;
Stopwatch? stopwatch = _operationDurationHistogram.Enabled || trackChunkTimes ? Stopwatch.StartNew() : null;
string? requestModelId = options?.ModelId ?? _defaultModelId;

AddInputMessagesTags(messages, options, activity);
Expand All @@ -185,6 +202,8 @@ public override async IAsyncEnumerable<ChatResponseUpdate> GetStreamingResponseA

var responseEnumerator = updates.GetAsyncEnumerator(cancellationToken);
List<ChatResponseUpdate> trackedUpdates = [];
TimeSpan lastChunkElapsed = default;
bool isFirstChunk = true;
Exception? error = null;
try
{
Expand All @@ -206,6 +225,31 @@ public override async IAsyncEnumerable<ChatResponseUpdate> GetStreamingResponseA
throw;
}

if (stopwatch is not null && trackChunkTimes)
Comment thread
stephentoub marked this conversation as resolved.
Resolved
{
TimeSpan currentElapsed = stopwatch.Elapsed;
double delta = (currentElapsed - lastChunkElapsed).TotalSeconds;

if (isFirstChunk)
{
isFirstChunk = false;
if (_timeToFirstChunkHistogram.Enabled)
{
TagList tags = default;
PopulateMetricTags(ref tags, requestModelId, response: null);
Comment thread
stephentoub marked this conversation as resolved.
Resolved
_timeToFirstChunkHistogram.Record(delta, tags);
}
}
else if (_timePerOutputChunkHistogram.Enabled)
{
TagList tags = default;
PopulateMetricTags(ref tags, requestModelId, response: null);
_timePerOutputChunkHistogram.Record(delta, tags);
}

lastChunkElapsed = currentElapsed;
}

trackedUpdates.Add(update);
yield return update;
Activity.Current = activity; // workaround for https://github.com/dotnet/runtime/issues/47802
Expand Down Expand Up @@ -711,26 +755,29 @@ private void TraceResponse(
}

void AddMetricTags(ref TagList tags, string? requestModelId, ChatResponse? response)
{
tags.Add(OpenTelemetryConsts.GenAI.Operation.Name, OpenTelemetryConsts.GenAI.ChatName);
=> PopulateMetricTags(ref tags, requestModelId, response);
}

if (requestModelId is not null)
{
tags.Add(OpenTelemetryConsts.GenAI.Request.Model, requestModelId);
}
private void PopulateMetricTags(ref TagList tags, string? requestModelId, ChatResponse? response)
Comment thread
stephentoub marked this conversation as resolved.
Resolved
Comment thread
stephentoub marked this conversation as resolved.
Resolved
{
tags.Add(OpenTelemetryConsts.GenAI.Operation.Name, OpenTelemetryConsts.GenAI.ChatName);

if (requestModelId is not null)
{
tags.Add(OpenTelemetryConsts.GenAI.Request.Model, requestModelId);
}

tags.Add(OpenTelemetryConsts.GenAI.Provider.Name, _providerName);
tags.Add(OpenTelemetryConsts.GenAI.Provider.Name, _providerName);

if (_serverAddress is string endpointAddress)
{
tags.Add(OpenTelemetryConsts.Server.Address, endpointAddress);
tags.Add(OpenTelemetryConsts.Server.Port, _serverPort);
}
if (_serverAddress is string endpointAddress)
{
tags.Add(OpenTelemetryConsts.Server.Address, endpointAddress);
tags.Add(OpenTelemetryConsts.Server.Port, _serverPort);
}

if (response?.ModelId is string responseModel)
{
tags.Add(OpenTelemetryConsts.GenAI.Response.Model, responseModel);
}
if (response?.ModelId is string responseModel)
{
tags.Add(OpenTelemetryConsts.GenAI.Response.Model, responseModel);
}
}

Expand Down
14 changes: 14 additions & 0 deletions src/Libraries/Microsoft.Extensions.AI/OpenTelemetryConsts.cs
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,20 @@ public static class TokenUsage
public const string Name = "gen_ai.client.token.usage";
public static readonly int[] ExplicitBucketBoundaries = [1, 4, 16, 64, 256, 1_024, 4_096, 16_384, 65_536, 262_144, 1_048_576, 4_194_304, 16_777_216, 67_108_864];
}

public static class TimeToFirstChunk
{
public const string Description = "Measures the time to receive the first chunk in a streaming operation";
public const string Name = "gen_ai.client.operation.time_to_first_chunk";
public static readonly double[] ExplicitBucketBoundaries = OperationDuration.ExplicitBucketBoundaries;
}

public static class TimePerOutputChunk
{
public const string Description = "Measures the time per output chunk in a streaming operation";
public const string Name = "gen_ai.client.operation.time_per_output_chunk";
public static readonly double[] ExplicitBucketBoundaries = OperationDuration.ExplicitBucketBoundaries;
}
}

public static class Conversation
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
using System.Text.RegularExpressions;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Extensions.Diagnostics.Metrics.Testing;
using OpenTelemetry.Trace;
using Xunit;

Expand Down Expand Up @@ -835,6 +836,107 @@ public async Task McpServerToolApprovalContentTypes_SerializedCorrectly()
"""), ReplaceWhitespace(inputMessages));
}

[Fact]
public async Task StreamingChunkMetrics_RecordedForStreamingCalls()
{
var sourceName = Guid.NewGuid().ToString();
var activities = new List<Activity>();
using var tracerProvider = OpenTelemetry.Sdk.CreateTracerProviderBuilder()
.AddSource(sourceName)
.AddInMemoryExporter(activities)
.Build();

using var innerClient = new TestChatClient
{
GetStreamingResponseAsyncCallback = CallbackAsync,
GetServiceCallback = (serviceType, serviceKey) =>
serviceType == typeof(ChatClientMetadata) ? new ChatClientMetadata("testprovider", new Uri("http://localhost:5000/api"), "testmodel") :
null,
};

async static IAsyncEnumerable<ChatResponseUpdate> CallbackAsync(
IEnumerable<ChatMessage> messages, ChatOptions? options, [EnumeratorCancellation] CancellationToken cancellationToken)
{
await Task.Yield();
yield return new ChatResponseUpdate(ChatRole.Assistant, "First") { ResponseId = "id1" };
await Task.Yield();
yield return new ChatResponseUpdate(ChatRole.Assistant, "Second") { ResponseId = "id1" };
await Task.Yield();
yield return new ChatResponseUpdate(ChatRole.Assistant, "Third") { ResponseId = "id1" };
}

using var chatClient = innerClient
.AsBuilder()
.UseOpenTelemetry(null, sourceName)
.Build();

using var timeToFirstChunkCollector = new MetricCollector<double>(null, sourceName, "gen_ai.client.operation.time_to_first_chunk");
using var timePerOutputChunkCollector = new MetricCollector<double>(null, sourceName, "gen_ai.client.operation.time_per_output_chunk");

await foreach (var update in chatClient.GetStreamingResponseAsync([new(ChatRole.User, "Hello")], new ChatOptions { ModelId = "mymodel" }))
{
// consume all updates
}

// time_to_first_chunk: exactly 1 measurement for the first chunk
var ttfcMeasurements = timeToFirstChunkCollector.GetMeasurementSnapshot();
Assert.Single(ttfcMeasurements);
Assert.True(ttfcMeasurements[0].Value > 0);
Assert.True(ttfcMeasurements[0].ContainsTags(
Comment thread
stephentoub marked this conversation as resolved.
Resolved
new KeyValuePair<string, object?>("gen_ai.operation.name", "chat"),
new KeyValuePair<string, object?>("gen_ai.request.model", "mymodel"),
new KeyValuePair<string, object?>("gen_ai.provider.name", "testprovider"),
new KeyValuePair<string, object?>("server.address", "localhost"),
new KeyValuePair<string, object?>("server.port", 5000)));

// time_per_output_chunk: one measurement for each chunk after the first (2 chunks)
var tpocMeasurements = timePerOutputChunkCollector.GetMeasurementSnapshot();
Assert.Equal(2, tpocMeasurements.Count);
foreach (var measurement in tpocMeasurements)
{
Assert.True(measurement.Value > 0);
Assert.True(measurement.ContainsTags(
new KeyValuePair<string, object?>("gen_ai.operation.name", "chat"),
new KeyValuePair<string, object?>("gen_ai.request.model", "mymodel"),
new KeyValuePair<string, object?>("gen_ai.provider.name", "testprovider"),
new KeyValuePair<string, object?>("server.address", "localhost"),
new KeyValuePair<string, object?>("server.port", 5000)));
}
}

[Fact]
public async Task StreamingChunkMetrics_NotRecordedForNonStreamingCalls()
{
var sourceName = Guid.NewGuid().ToString();
var activities = new List<Activity>();
using var tracerProvider = OpenTelemetry.Sdk.CreateTracerProviderBuilder()
.AddSource(sourceName)
.AddInMemoryExporter(activities)
.Build();

using var innerClient = new TestChatClient
{
GetResponseAsyncCallback = async (messages, options, cancellationToken) =>
{
await Task.Yield();
return new ChatResponse(new ChatMessage(ChatRole.Assistant, "Response"));
},
};

using var chatClient = innerClient
.AsBuilder()
.UseOpenTelemetry(null, sourceName)
.Build();

using var timeToFirstChunkCollector = new MetricCollector<double>(null, sourceName, "gen_ai.client.operation.time_to_first_chunk");
using var timePerOutputChunkCollector = new MetricCollector<double>(null, sourceName, "gen_ai.client.operation.time_per_output_chunk");

await chatClient.GetResponseAsync([new(ChatRole.User, "Hello")]);

Assert.Empty(timeToFirstChunkCollector.GetMeasurementSnapshot());
Assert.Empty(timePerOutputChunkCollector.GetMeasurementSnapshot());
}

private sealed class NonSerializableAIContent : AIContent;

private static string ReplaceWhitespace(string? input) => Regex.Replace(input ?? "", @"\s+", " ").Trim();
Expand Down
Loading