Skip to content
Draft
Show file tree
Hide file tree
Changes from all 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 @@ -5,6 +5,7 @@
using System.Collections.Generic;
using System.Diagnostics;
using System.Diagnostics.CodeAnalysis;
using System.Diagnostics.Metrics;
using System.Linq;
using System.Runtime.CompilerServices;
using System.Runtime.ExceptionServices;
Expand Down Expand Up @@ -79,6 +80,10 @@ public class FunctionInvokingChatClient : DelegatingChatClient
/// <remarks>This component does not own the instance and should not dispose it.</remarks>
private readonly ActivitySource? _activitySource;

/// <summary>The <c>gen_ai.execute_tool.duration</c> histogram, or <see langword="null"/> if no <see cref="Meter"/> is available.</summary>
/// <remarks>This component does not own the underlying <see cref="Meter"/> and should not dispose it.</remarks>
private readonly Histogram<double>? _executeToolDurationHistogram;

/// <summary>
/// Initializes a new instance of the <see cref="FunctionInvokingChatClient"/> class.
/// </summary>
Expand All @@ -90,6 +95,11 @@ public FunctionInvokingChatClient(IChatClient innerClient, ILoggerFactory? logge
{
_logger = (ILogger?)loggerFactory?.CreateLogger<FunctionInvokingChatClient>() ?? NullLogger.Instance;
_activitySource = innerClient.GetService<ActivitySource>();
if (innerClient.GetService<Meter>() is Meter meter)
{
_executeToolDurationHistogram = OtelMetricHelpers.CreateGenAIExecuteToolDurationHistogram(meter);
}

FunctionInvocationServices = functionInvocationServices;
}

Expand All @@ -101,7 +111,8 @@ public FunctionInvokingChatClient(IChatClient innerClient, ILoggerFactory? logge
invokeAgentActivity =>
invokeAgentActivity is not null
? invokeAgentActivity.GetCustomProperty(OpenTelemetryChatClient.SensitiveDataEnabledCustomKey) as string is OpenTelemetryChatClient.SensitiveDataEnabledTrueValue
: InnerClient.GetService<OpenTelemetryChatClient>()?.EnableSensitiveData is true);
: InnerClient.GetService<OpenTelemetryChatClient>()?.EnableSensitiveData is true,
_executeToolDurationHistogram);

/// <summary>
/// Gets or sets the <see cref="FunctionInvocationContext"/> for the current function invocation.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -129,6 +129,7 @@ protected override void Dispose(bool disposing)
/// <inheritdoc/>
public override object? GetService(Type serviceType, object? serviceKey = null) =>
serviceType == typeof(ActivitySource) ? _activitySource :
serviceType == typeof(Meter) ? _meter :
base.GetService(serviceType, serviceKey);

/// <inheritdoc/>
Expand Down Expand Up @@ -328,6 +329,24 @@ public override async IAsyncEnumerable<ChatResponseUpdate> GetStreamingResponseA
_ = activity.AddTag(OpenTelemetryConsts.GenAI.Request.PresencePenalty, presencePenalty);
}

if (options.Reasoning?.Effort is ReasoningEffort reasoningEffort)
{
// The spec recommends emitting the exact string sent to the provider; the provider-agnostic
// layer only has the abstract ReasoningEffort, so emit a normalized token for it. A provider
// package can override with its exact wire value (e.g. OpenAI sends "xhigh" for ExtraHigh).
string reasoningLevel = reasoningEffort switch
{
ReasoningEffort.None => "none",
ReasoningEffort.Low => "low",
ReasoningEffort.Medium => "medium",
ReasoningEffort.High => "high",
ReasoningEffort.ExtraHigh => "extra_high",
_ => reasoningEffort.ToString().ToLowerInvariant(),
};

_ = activity.AddTag(OpenTelemetryConsts.GenAI.Request.ReasoningLevel, reasoningLevel);
}

if (options.Seed is long seed)
{
_ = activity.AddTag(OpenTelemetryConsts.GenAI.Request.Seed, seed);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Diagnostics.Metrics;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
Expand All @@ -22,6 +23,7 @@ internal sealed class FunctionInvocationProcessor
{
private readonly ILogger _logger;
private readonly ActivitySource? _activitySource;
private readonly Histogram<double>? _executeToolDurationHistogram;
private readonly Func<FunctionInvocationContext, CancellationToken, ValueTask<object?>> _invokeFunction;
private readonly Func<Activity?, bool> _isSensitiveDataEnabled;

Expand All @@ -36,16 +38,19 @@ internal sealed class FunctionInvocationProcessor
/// Receives the invoke agent activity (or null if not in agent context).
/// Returns true if sensitive data should be logged/tagged, false otherwise.
/// </param>
/// <param name="executeToolDurationHistogram">The optional <c>gen_ai.execute_tool.duration</c> histogram to record tool execution durations on.</param>
public FunctionInvocationProcessor(
ILogger logger,
ActivitySource? activitySource,
Func<FunctionInvocationContext, CancellationToken, ValueTask<object?>> invokeFunction,
Func<Activity?, bool>? isSensitiveDataEnabled = null)
Func<Activity?, bool>? isSensitiveDataEnabled = null,
Histogram<double>? executeToolDurationHistogram = null)
{
_logger = logger;
_activitySource = activitySource;
_invokeFunction = invokeFunction;
_isSensitiveDataEnabled = isSensitiveDataEnabled ?? (_ => false);
_executeToolDurationHistogram = executeToolDurationHistogram;
}

/// <summary>
Expand Down Expand Up @@ -199,15 +204,18 @@ private async Task<FunctionInvocationResult> ProcessSingleFunctionCallAsync(
}

object? result = null;
string? errorType = null;
try
{
result = await _invokeFunction(context, cancellationToken).ConfigureAwait(false);
}
catch (Exception e)
{
errorType = e.GetType().FullName;

if (activity is not null)
{
_ = activity.SetTag(OpenTelemetryConsts.Error.Type, e.GetType().FullName)
_ = activity.SetTag(OpenTelemetryConsts.Error.Type, errorType)
.SetStatus(ActivityStatusCode.Error, e.Message);
}

Expand All @@ -224,6 +232,19 @@ private async Task<FunctionInvocationResult> ProcessSingleFunctionCallAsync(
}
finally
{
if (_executeToolDurationHistogram is { Enabled: true } executeToolDurationHistogram)
{
TagList tags = default;
tags.Add(OpenTelemetryConsts.GenAI.Tool.Name, context.Function.Name);
tags.Add(OpenTelemetryConsts.GenAI.Tool.Type, OpenTelemetryConsts.ToolTypeFunction);
if (errorType is not null)
{
tags.Add(OpenTelemetryConsts.Error.Type, errorType);
}

executeToolDurationHistogram.Record(FunctionInvocationHelpers.GetElapsedTime(startingTimestamp).TotalSeconds, tags);
}

bool loggedResult = false;
if (enableSensitiveData || traceLoggingEnabled)
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,4 +23,12 @@ public static Histogram<double> CreateGenAIOperationDurationHistogram(Meter mete
OpenTelemetryConsts.SecondsUnit,
OpenTelemetryConsts.GenAI.Client.OperationDuration.Description,
advice: new() { HistogramBucketBoundaries = OpenTelemetryConsts.GenAI.Client.OperationDuration.ExplicitBucketBoundaries });

/// <summary>Creates the standard <c>gen_ai.execute_tool.duration</c> histogram on <paramref name="meter"/>.</summary>
public static Histogram<double> CreateGenAIExecuteToolDurationHistogram(Meter meter) =>
meter.CreateHistogram<double>(
OpenTelemetryConsts.GenAI.ExecuteTool.Duration.Name,
OpenTelemetryConsts.SecondsUnit,
OpenTelemetryConsts.GenAI.ExecuteTool.Duration.Description,
advice: new() { HistogramBucketBoundaries = OpenTelemetryConsts.GenAI.ExecuteTool.Duration.ExplicitBucketBoundaries });
}
11 changes: 11 additions & 0 deletions src/Libraries/Microsoft.Extensions.AI/OpenTelemetryConsts.cs
Original file line number Diff line number Diff line change
Expand Up @@ -126,6 +126,7 @@ public static class Request
public const string Model = "gen_ai.request.model";
public const string MaxTokens = "gen_ai.request.max_tokens";
public const string PresencePenalty = "gen_ai.request.presence_penalty";
public const string ReasoningLevel = "gen_ai.request.reasoning.level";
public const string Seed = "gen_ai.request.seed";
public const string StopSequences = "gen_ai.request.stop_sequences";
public const string Stream = "gen_ai.request.stream";
Expand Down Expand Up @@ -163,6 +164,16 @@ public static class Call
}
}

public static class ExecuteTool
{
public static class Duration
{
public const string Description = "Measures the duration of a tool execution.";
public const string Name = "gen_ai.execute_tool.duration";
public static readonly double[] ExplicitBucketBoundaries = [0.01, 0.02, 0.04, 0.08, 0.16, 0.32, 0.64, 1.28, 2.56, 5.12, 10.24, 20.48, 40.96, 81.92];
}
}

public static class Usage
{
public const string InputTokens = "gen_ai.usage.input_tokens";
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Diagnostics.Metrics;
using System.Runtime.CompilerServices;
using System.Threading;
using System.Threading.Tasks;
Expand Down Expand Up @@ -67,6 +68,10 @@ internal sealed class FunctionInvokingRealtimeClientSession : IRealtimeClientSes
/// <remarks>This component does not own the instance and should not dispose it.</remarks>
private readonly ActivitySource? _activitySource;

/// <summary>The <c>gen_ai.execute_tool.duration</c> histogram, or <see langword="null"/> if no <see cref="Meter"/> is available.</summary>
/// <remarks>This component does not own the underlying <see cref="Meter"/> and should not dispose it.</remarks>
private readonly Histogram<double>? _executeToolDurationHistogram;

/// <summary>The inner session to delegate to.</summary>
private readonly IRealtimeClientSession _innerSession;

Expand All @@ -86,14 +91,20 @@ public FunctionInvokingRealtimeClientSession(IRealtimeClientSession innerSession
_client = Throw.IfNull(client);
_logger = (ILogger?)loggerFactory?.CreateLogger<FunctionInvokingRealtimeClientSession>() ?? NullLogger.Instance;
_activitySource = innerSession.GetService<ActivitySource>();
if (innerSession.GetService<Meter>() is Meter meter)
{
_executeToolDurationHistogram = OtelMetricHelpers.CreateGenAIExecuteToolDurationHistogram(meter);
}

FunctionInvocationServices = functionInvocationServices;
}

/// <summary>Gets the function invocation processor, creating it lazily.</summary>
private FunctionInvocationProcessor Processor => field ??= new FunctionInvocationProcessor(
_logger,
_activitySource,
InvokeFunctionAsync);
InvokeFunctionAsync,
executeToolDurationHistogram: _executeToolDurationHistogram);

/// <summary>
/// Gets or sets the <see cref="FunctionInvocationContext"/> for the current function invocation.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -168,6 +168,7 @@ public async ValueTask DisposeAsync()

return
serviceType == typeof(ActivitySource) ? _activitySource :
serviceType == typeof(Meter) ? _meter :
serviceKey is null && serviceType.IsInstanceOfType(this) ? this :
_innerSession.GetService(serviceType, serviceKey);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Diagnostics.Metrics.Testing;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Testing;
using OpenTelemetry.Trace;
Expand Down Expand Up @@ -1164,6 +1165,39 @@ async Task InvokeAsync(Func<Task> work)
}
}

[Fact]
public async Task ExecuteToolDurationMetricRecorded()
{
string sourceName = Guid.NewGuid().ToString();

List<ChatMessage> plan =
[
new ChatMessage(ChatRole.User, "hello"),
new ChatMessage(ChatRole.Assistant, [new FunctionCallContent("callId1", "Func1", new Dictionary<string, object?> { ["arg1"] = "value1" })]),
new ChatMessage(ChatRole.Tool, [new FunctionResultContent("callId1", result: "Result 1")]),
new ChatMessage(ChatRole.Assistant, "world"),
];

ChatOptions options = new()
{
Tools = [AIFunctionFactory.Create(() => "Result 1", "Func1")]
};

Func<ChatClientBuilder, ChatClientBuilder> configure = b => b.Use(c =>
new FunctionInvokingChatClient(new OpenTelemetryChatClient(c, sourceName: sourceName)));

using var executeToolDurationCollector = new MetricCollector<double>(null, sourceName, "gen_ai.execute_tool.duration");

await InvokeAndAssertAsync(options, plan, configurePipeline: configure);

var measurement = Assert.Single(executeToolDurationCollector.GetMeasurementSnapshot());
Assert.True(measurement.Value >= 0);
Assert.True(measurement.ContainsTags(
new KeyValuePair<string, object?>("gen_ai.tool.name", "Func1"),
new KeyValuePair<string, object?>("gen_ai.tool.type", "function")));
Assert.False(measurement.Tags.ContainsKey("error.type"));
}

[Fact]
public async Task SupportsConsecutiveStreamingUpdatesWithFunctionCalls()
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -130,6 +130,7 @@ async static IAsyncEnumerable<ChatResponseUpdate> CallbackAsync(
ResponseFormat = ChatResponseFormat.Json,
Temperature = 6.0f,
Seed = 42,
Reasoning = new() { Effort = ReasoningEffort.High },
StopSequences = ["hello", "world"],
AdditionalProperties = new()
{
Expand Down Expand Up @@ -178,6 +179,7 @@ async static IAsyncEnumerable<ChatResponseUpdate> CallbackAsync(
Assert.Equal(5.0f, activity.GetTagItem("gen_ai.request.presence_penalty"));
Assert.Equal(6.0f, activity.GetTagItem("gen_ai.request.temperature"));
Assert.Equal(7, activity.GetTagItem("gen_ai.request.top_k"));
Assert.Equal("high", activity.GetTagItem("gen_ai.request.reasoning.level"));
Assert.Equal(123, activity.GetTagItem("gen_ai.request.max_tokens"));
Assert.Equal("""["hello", "world"]""", activity.GetTagItem("gen_ai.request.stop_sequences"));
Assert.Equal(enableSensitiveData ? "value1" : null, activity.GetTagItem("service_tier"));
Expand Down
Loading