diff --git a/dotnet/src/Agents/Abstractions/AgentChat.cs b/dotnet/src/Agents/Abstractions/AgentChat.cs index 7e7dea00a805..9c834380a8f4 100644 --- a/dotnet/src/Agents/Abstractions/AgentChat.cs +++ b/dotnet/src/Agents/Abstractions/AgentChat.cs @@ -81,7 +81,7 @@ public async IAsyncEnumerable GetChatMessagesAsync( { this.SetActivityOrThrow(); // Disallow concurrent access to chat history - this.Logger.LogDebug("[{MethodName}] Source: {MessageSourceType}/{MessageSourceId}", nameof(GetChatMessagesAsync), agent?.GetType().Name ?? "primary", agent?.Id ?? "primary"); + this.Logger.LogAgentChatGetChatMessages(nameof(GetChatMessagesAsync), agent); try { @@ -163,10 +163,7 @@ public void AddChatMessages(IReadOnlyList messages) } } - if (this.Logger.IsEnabled(LogLevel.Debug)) // Avoid boxing if not enabled - { - this.Logger.LogDebug("[{MethodName}] Adding Messages: {MessageCount}", nameof(AddChatMessages), messages.Count); - } + this.Logger.LogAgentChatAddingMessages(nameof(AddChatMessages), messages.Count); try { @@ -178,10 +175,7 @@ public void AddChatMessages(IReadOnlyList messages) var channelRefs = this._agentChannels.Select(kvp => new ChannelReference(kvp.Value, kvp.Key)); this._broadcastQueue.Enqueue(channelRefs, messages); - if (this.Logger.IsEnabled(LogLevel.Information)) // Avoid boxing if not enabled - { - this.Logger.LogInformation("[{MethodName}] Added Messages: {MessageCount}", nameof(AddChatMessages), messages.Count); - } + this.Logger.LogAgentChatAddedMessages(nameof(AddChatMessages), messages.Count); } finally { @@ -205,7 +199,7 @@ protected async IAsyncEnumerable InvokeAgentAsync( { this.SetActivityOrThrow(); // Disallow concurrent access to chat history - this.Logger.LogDebug("[{MethodName}] Invoking agent {AgentType}: {AgentId}", nameof(InvokeAgentAsync), agent.GetType(), agent.Id); + this.Logger.LogAgentChatInvokingAgent(nameof(InvokeAgentAsync), agent.GetType(), agent.Id); try { @@ -217,7 +211,7 @@ protected async IAsyncEnumerable InvokeAgentAsync( List messages = []; await foreach (ChatMessageContent message in channel.InvokeAsync(agent, cancellationToken).ConfigureAwait(false)) { - this.Logger.LogTrace("[{MethodName}] Agent message {AgentType}: {Message}", nameof(InvokeAgentAsync), agent.GetType(), message); + this.Logger.LogAgentChatInvokedAgentMessage(nameof(InvokeAgentAsync), agent.GetType(), agent.Id, message); // Add to primary history this.History.Add(message); @@ -241,7 +235,7 @@ protected async IAsyncEnumerable InvokeAgentAsync( .Select(kvp => new ChannelReference(kvp.Value, kvp.Key)); this._broadcastQueue.Enqueue(channelRefs, messages.Where(m => m.Role != AuthorRole.Tool).ToArray()); - this.Logger.LogInformation("[{MethodName}] Invoked agent {AgentType}: {AgentId}", nameof(InvokeAgentAsync), agent.GetType(), agent.Id); + this.Logger.LogAgentChatInvokedAgent(nameof(InvokeAgentAsync), agent.GetType(), agent.Id); } finally { @@ -254,7 +248,7 @@ async Task GetOrCreateChannelAsync() AgentChannel? channel = await this.SynchronizeChannelAsync(channelKey, cancellationToken).ConfigureAwait(false); if (channel is null) { - this.Logger.LogDebug("[{MethodName}] Creating channel for {AgentType}: {AgentId}", nameof(InvokeAgentAsync), agent.GetType(), agent.Id); + this.Logger.LogAgentChatCreatingChannel(nameof(InvokeAgentAsync), agent.GetType(), agent.Id); channel = await agent.CreateChannelAsync(cancellationToken).ConfigureAwait(false); @@ -265,7 +259,7 @@ async Task GetOrCreateChannelAsync() await channel.ReceiveAsync(this.History, cancellationToken).ConfigureAwait(false); } - this.Logger.LogInformation("[{MethodName}] Created channel for {AgentType}: {AgentId}", nameof(InvokeAgentAsync), agent.GetType(), agent.Id); + this.Logger.LogAgentChatCreatedChannel(nameof(InvokeAgentAsync), agent.GetType(), agent.Id); } return channel; diff --git a/dotnet/src/Agents/Abstractions/AggregatorAgent.cs b/dotnet/src/Agents/Abstractions/AggregatorAgent.cs index 00964fdc9e57..6eb31ee190ac 100644 --- a/dotnet/src/Agents/Abstractions/AggregatorAgent.cs +++ b/dotnet/src/Agents/Abstractions/AggregatorAgent.cs @@ -3,7 +3,6 @@ using System.Collections.Generic; using System.Threading; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; namespace Microsoft.SemanticKernel.Agents; @@ -46,12 +45,12 @@ protected internal override IEnumerable GetChannelKeys() /// protected internal override Task CreateChannelAsync(CancellationToken cancellationToken) { - this.Logger.LogDebug("[{MethodName}] Creating channel {ChannelType}", nameof(CreateChannelAsync), nameof(AggregatorChannel)); + this.Logger.LogAggregatorAgentCreatingChannel(nameof(CreateChannelAsync), nameof(AggregatorChannel)); AgentChat chat = chatProvider.Invoke(); AggregatorChannel channel = new(chat); - this.Logger.LogInformation("[{MethodName}] Created channel {ChannelType} ({ChannelMode}) with: {AgentChatType}", nameof(CreateChannelAsync), nameof(AggregatorChannel), this.Mode, chat.GetType()); + this.Logger.LogAggregatorAgentCreatedChannel(nameof(CreateChannelAsync), nameof(AggregatorChannel), this.Mode, chat.GetType()); return Task.FromResult(channel); } diff --git a/dotnet/src/Agents/Abstractions/Logging/AgentChatLogMessages.cs b/dotnet/src/Agents/Abstractions/Logging/AgentChatLogMessages.cs new file mode 100644 index 000000000000..314d68ce8cd8 --- /dev/null +++ b/dotnet/src/Agents/Abstractions/Logging/AgentChatLogMessages.cs @@ -0,0 +1,135 @@ +// Copyright (c) Microsoft. All rights reserved. +using System; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class AgentChatLogMessages +{ + /// + /// Logs retrieval of messages. + /// + private static readonly Action s_logAgentChatGetChatMessages = + LoggerMessage.Define( + logLevel: LogLevel.Debug, + eventId: 0, + "[{MethodName}] Source: {MessageSourceType}/{MessageSourceId}."); + public static void LogAgentChatGetChatMessages( + this ILogger logger, + string methodName, + Agent? agent) + { + if (logger.IsEnabled(LogLevel.Debug)) + { + if (null == agent) + { + s_logAgentChatGetChatMessages(logger, methodName, "primary", "primary", null); + } + else + { + s_logAgentChatGetChatMessages(logger, methodName, agent.GetType().Name, agent.Id, null); + } + } + } + + /// + /// Logs adding messages (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Adding Messages: {MessageCount}.")] + public static partial void LogAgentChatAddingMessages( + this ILogger logger, + string methodName, + int messageCount); + + /// + /// Logs added messages (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Adding Messages: {MessageCount}.")] + public static partial void LogAgentChatAddedMessages( + this ILogger logger, + string methodName, + int messageCount); + + /// + /// Logs invoking agent (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Invoking agent {AgentType}/{AgentId}.")] + public static partial void LogAgentChatInvokingAgent( + this ILogger logger, + string methodName, + Type agentType, + string agentId); + + /// + /// Logs invoked agent message + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Trace, + Message = "[{MethodName}] Agent message {AgentType}/{AgentId}: {Message}.")] + public static partial void LogAgentChatInvokedAgentMessage( + this ILogger logger, + string methodName, + Type agentType, + string agentId, + ChatMessageContent message); + + /// + /// Logs invoked agent (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Invoked agent {AgentType}/{AgentId}.")] + public static partial void LogAgentChatInvokedAgent( + this ILogger logger, + string methodName, + Type agentType, + string agentId); + + /// + /// Logs creating agent channel (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Creating channel for {AgentType}: {AgentId}")] + public static partial void LogAgentChatCreatingChannel( + this ILogger logger, + string methodName, + Type agentType, + string agentId); + + /// + /// Logs created agent channel (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Created channel for {AgentType}: {AgentId}")] + public static partial void LogAgentChatCreatedChannel( + this ILogger logger, + string methodName, + Type agentType, + string agentId); +} diff --git a/dotnet/src/Agents/Abstractions/Logging/AggregatorAgentLogMessages.cs b/dotnet/src/Agents/Abstractions/Logging/AggregatorAgentLogMessages.cs new file mode 100644 index 000000000000..df8a752a098c --- /dev/null +++ b/dotnet/src/Agents/Abstractions/Logging/AggregatorAgentLogMessages.cs @@ -0,0 +1,45 @@ +// Copyright (c) Microsoft. All rights reserved. +using System; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class AggregatorAgentLogMessages +{ + /// + /// Logs creating channel (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Creating channel {ChannelType}.")] + public static partial void LogAggregatorAgentCreatingChannel( + this ILogger logger, + string methodName, + string channelType); + + /// + /// Logs created channel (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Created channel {ChannelType} ({ChannelMode}) with: {AgentChatType}.")] + public static partial void LogAggregatorAgentCreatedChannel( + this ILogger logger, + string methodName, + string channelType, + AggregatorMode channelMode, + Type agentChatType); +} diff --git a/dotnet/src/Agents/Core/AgentGroupChat.cs b/dotnet/src/Agents/Core/AgentGroupChat.cs index d017322e6d21..928326745b97 100644 --- a/dotnet/src/Agents/Core/AgentGroupChat.cs +++ b/dotnet/src/Agents/Core/AgentGroupChat.cs @@ -72,12 +72,12 @@ public override async IAsyncEnumerable InvokeAsync([Enumerat this.IsComplete = false; } - this.Logger.LogDebug("[{MethodName}] Invoking chat: {Agents}", nameof(InvokeAsync), string.Join(", ", this.Agents.Select(a => $"{a.GetType()}:{a.Id}"))); + this.Logger.LogAgentGroupChatInvokingAgents(nameof(InvokeAsync), this.Agents); for (int index = 0; index < this.ExecutionSettings.TerminationStrategy.MaximumIterations; index++) { // Identify next agent using strategy - this.Logger.LogDebug("[{MethodName}] Selecting agent: {StrategyType}", nameof(InvokeAsync), this.ExecutionSettings.SelectionStrategy.GetType()); + this.Logger.LogAgentGroupChatSelectingAgent(nameof(InvokeAsync), this.ExecutionSettings.SelectionStrategy.GetType()); Agent agent; try @@ -86,11 +86,11 @@ public override async IAsyncEnumerable InvokeAsync([Enumerat } catch (Exception exception) { - this.Logger.LogError(exception, "[{MethodName}] Unable to determine next agent.", nameof(InvokeAsync)); + this.Logger.LogAgentGroupChatNoAgentSelected(nameof(InvokeAsync), exception); throw; } - this.Logger.LogInformation("[{MethodName}] Agent selected {AgentType}: {AgentId} by {StrategyType}", nameof(InvokeAsync), agent.GetType(), agent.Id, this.ExecutionSettings.SelectionStrategy.GetType()); + this.Logger.LogAgentGroupChatSelectedAgent(nameof(InvokeAsync), agent.GetType(), agent.Id, this.ExecutionSettings.SelectionStrategy.GetType()); // Invoke agent and process messages along with termination await foreach (var message in base.InvokeAgentAsync(agent, cancellationToken).ConfigureAwait(false)) @@ -110,7 +110,7 @@ public override async IAsyncEnumerable InvokeAsync([Enumerat } } - this.Logger.LogDebug("[{MethodName}] Yield chat - IsComplete: {IsComplete}", nameof(InvokeAsync), this.IsComplete); + this.Logger.LogAgentGroupChatYield(nameof(InvokeAsync), this.IsComplete); } /// @@ -143,7 +143,7 @@ public async IAsyncEnumerable InvokeAsync( { this.EnsureStrategyLoggerAssignment(); - this.Logger.LogDebug("[{MethodName}] Invoking chat: {AgentType}: {AgentId}", nameof(InvokeAsync), agent.GetType(), agent.Id); + this.Logger.LogAgentGroupChatInvokingAgent(nameof(InvokeAsync), agent.GetType(), agent.Id); if (isJoining) { @@ -161,7 +161,7 @@ public async IAsyncEnumerable InvokeAsync( yield return message; } - this.Logger.LogDebug("[{MethodName}] Yield chat - IsComplete: {IsComplete}", nameof(InvokeAsync), this.IsComplete); + this.Logger.LogAgentGroupChatYield(nameof(InvokeAsync), this.IsComplete); } /// diff --git a/dotnet/src/Agents/Core/Chat/AggregatorTerminationStrategy.cs b/dotnet/src/Agents/Core/Chat/AggregatorTerminationStrategy.cs index 8f04f53c8923..ca83ce407cbb 100644 --- a/dotnet/src/Agents/Core/Chat/AggregatorTerminationStrategy.cs +++ b/dotnet/src/Agents/Core/Chat/AggregatorTerminationStrategy.cs @@ -3,7 +3,6 @@ using System.Linq; using System.Threading; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; namespace Microsoft.SemanticKernel.Agents.Chat; @@ -39,10 +38,7 @@ public sealed class AggregatorTerminationStrategy(params TerminationStrategy[] s /// protected override async Task ShouldAgentTerminateAsync(Agent agent, IReadOnlyList history, CancellationToken cancellationToken = default) { - if (this.Logger.IsEnabled(LogLevel.Debug)) // Avoid boxing if not enabled - { - this.Logger.LogDebug("[{MethodName}] Evaluating termination for {Count} strategies: {Mode}", nameof(ShouldAgentTerminateAsync), this._strategies.Length, this.Condition); - } + this.Logger.LogAggregatorTerminationStrategyEvaluating(nameof(ShouldAgentTerminateAsync), this._strategies.Length, this.Condition); var strategyExecution = this._strategies.Select(s => s.ShouldTerminateAsync(agent, history, cancellationToken)); diff --git a/dotnet/src/Agents/Core/Chat/KernelFunctionSelectionStrategy.cs b/dotnet/src/Agents/Core/Chat/KernelFunctionSelectionStrategy.cs index b405ddc03736..d912ed147eb6 100644 --- a/dotnet/src/Agents/Core/Chat/KernelFunctionSelectionStrategy.cs +++ b/dotnet/src/Agents/Core/Chat/KernelFunctionSelectionStrategy.cs @@ -5,7 +5,6 @@ using System.Text.Json; using System.Threading; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; namespace Microsoft.SemanticKernel.Agents.Chat; @@ -70,11 +69,11 @@ public sealed override async Task NextAsync(IReadOnlyList agents, { this.HistoryVariableName, JsonSerializer.Serialize(history) }, // TODO: GitHub Task #5894 }; - this.Logger.LogDebug("[{MethodName}] Invoking function: {PluginName}.{FunctionName}.", nameof(NextAsync), this.Function.PluginName, this.Function.Name); + this.Logger.LogKernelFunctionSelectionStrategyInvokingFunction(nameof(NextAsync), this.Function.PluginName, this.Function.Name); FunctionResult result = await this.Function.InvokeAsync(this.Kernel, arguments, cancellationToken).ConfigureAwait(false); - this.Logger.LogInformation("[{MethodName}] Invoked function: {PluginName}.{FunctionName}: {ResultType}", nameof(NextAsync), this.Function.PluginName, this.Function.Name, result.ValueType); + this.Logger.LogKernelFunctionSelectionStrategyInvokedFunction(nameof(NextAsync), this.Function.PluginName, this.Function.Name, result.ValueType); string? agentName = this.ResultParser.Invoke(result); if (string.IsNullOrEmpty(agentName)) diff --git a/dotnet/src/Agents/Core/Chat/KernelFunctionTerminationStrategy.cs b/dotnet/src/Agents/Core/Chat/KernelFunctionTerminationStrategy.cs index 5145fdded7c2..e86cf9b5a09f 100644 --- a/dotnet/src/Agents/Core/Chat/KernelFunctionTerminationStrategy.cs +++ b/dotnet/src/Agents/Core/Chat/KernelFunctionTerminationStrategy.cs @@ -5,7 +5,6 @@ using System.Text.Json; using System.Threading; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; namespace Microsoft.SemanticKernel.Agents.Chat; @@ -70,11 +69,11 @@ protected sealed override async Task ShouldAgentTerminateAsync(Agent agent { this.HistoryVariableName, JsonSerializer.Serialize(history) }, // TODO: GitHub Task #5894 }; - this.Logger.LogDebug("[{MethodName}] Invoking function: {PluginName}.{FunctionName}.", nameof(ShouldAgentTerminateAsync), this.Function.PluginName, this.Function.Name); + this.Logger.LogKernelFunctionTerminationStrategyInvokingFunction(nameof(ShouldAgentTerminateAsync), this.Function.PluginName, this.Function.Name); FunctionResult result = await this.Function.InvokeAsync(this.Kernel, arguments, cancellationToken).ConfigureAwait(false); - this.Logger.LogInformation("[{MethodName}] Invoked function: {PluginName}.{FunctionName}: {ResultType}", nameof(ShouldAgentTerminateAsync), this.Function.PluginName, this.Function.Name, result.ValueType); + this.Logger.LogKernelFunctionTerminationStrategyInvokedFunction(nameof(ShouldAgentTerminateAsync), this.Function.PluginName, this.Function.Name, result.ValueType); return this.ResultParser.Invoke(result); } diff --git a/dotnet/src/Agents/Core/Chat/RegExTerminationStrategy.cs b/dotnet/src/Agents/Core/Chat/RegExTerminationStrategy.cs index 55fdae8e813d..2745a325ee88 100644 --- a/dotnet/src/Agents/Core/Chat/RegExTerminationStrategy.cs +++ b/dotnet/src/Agents/Core/Chat/RegExTerminationStrategy.cs @@ -4,7 +4,6 @@ using System.Text.RegularExpressions; using System.Threading; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; namespace Microsoft.SemanticKernel.Agents.Chat; @@ -44,7 +43,7 @@ public RegexTerminationStrategy(params Regex[] expressions) { Verify.NotNull(expressions); - this._expressions = expressions.OfType().ToArray(); + this._expressions = expressions; } /// @@ -53,26 +52,23 @@ protected override Task ShouldAgentTerminateAsync(Agent agent, IReadOnlyLi // Most recent message if (history.Count > 0 && history[history.Count - 1].Content is string message) { - if (this.Logger.IsEnabled(LogLevel.Debug)) // Avoid boxing if not enabled - { - this.Logger.LogDebug("[{MethodName}] Evaluating expressions: {ExpressionCount}", nameof(ShouldAgentTerminateAsync), this._expressions.Length); - } + this.Logger.LogRegexTerminationStrategyEvaluating(nameof(ShouldAgentTerminateAsync), this._expressions.Length); // Evaluate expressions for match foreach (var expression in this._expressions) { - this.Logger.LogDebug("[{MethodName}] Evaluating expression: {Expression}", nameof(ShouldAgentTerminateAsync), expression); + this.Logger.LogRegexTerminationStrategyEvaluatingExpression(nameof(ShouldAgentTerminateAsync), expression); if (expression.IsMatch(message)) { - this.Logger.LogInformation("[{MethodName}] Expression matched: {Expression}", nameof(ShouldAgentTerminateAsync), expression); + this.Logger.LogRegexTerminationStrategyMatchedExpression(nameof(ShouldAgentTerminateAsync), expression); return Task.FromResult(true); } } } - this.Logger.LogInformation("[{MethodName}] No expression matched.", nameof(ShouldAgentTerminateAsync)); + this.Logger.LogRegexTerminationStrategyNoMatch(nameof(ShouldAgentTerminateAsync)); return Task.FromResult(false); } diff --git a/dotnet/src/Agents/Core/Chat/SequentialSelectionStrategy.cs b/dotnet/src/Agents/Core/Chat/SequentialSelectionStrategy.cs index 030297a90957..878cd7530eed 100644 --- a/dotnet/src/Agents/Core/Chat/SequentialSelectionStrategy.cs +++ b/dotnet/src/Agents/Core/Chat/SequentialSelectionStrategy.cs @@ -2,7 +2,6 @@ using System.Collections.Generic; using System.Threading; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; namespace Microsoft.SemanticKernel.Agents.Chat; @@ -34,19 +33,11 @@ public override Task NextAsync(IReadOnlyList agents, IReadOnlyList this._index = 0; } - if (this.Logger.IsEnabled(LogLevel.Debug)) // Avoid boxing if not enabled - { - this.Logger.LogDebug("[{MethodName}] Prior agent index: {AgentIndex} / {AgentCount}.", nameof(NextAsync), this._index, agents.Count); - } - var agent = agents[this._index]; - this._index = (this._index + 1) % agents.Count; + this.Logger.LogSequentialSelectionStrategySelectedAgent(nameof(NextAsync), this._index, agents.Count, agent.Id); - if (this.Logger.IsEnabled(LogLevel.Information)) // Avoid boxing if not enabled - { - this.Logger.LogInformation("[{MethodName}] Current agent index: {AgentIndex} / {AgentCount}", nameof(NextAsync), this._index, agents.Count); - } + this._index = (this._index + 1) % agents.Count; return Task.FromResult(agent); } diff --git a/dotnet/src/Agents/Core/Chat/TerminationStrategy.cs b/dotnet/src/Agents/Core/Chat/TerminationStrategy.cs index 843327d77f6a..b50f6bd96d11 100644 --- a/dotnet/src/Agents/Core/Chat/TerminationStrategy.cs +++ b/dotnet/src/Agents/Core/Chat/TerminationStrategy.cs @@ -55,19 +55,19 @@ public abstract class TerminationStrategy /// True to terminate chat loop. public async Task ShouldTerminateAsync(Agent agent, IReadOnlyList history, CancellationToken cancellationToken = default) { - this.Logger.LogDebug("[{MethodName}] Evaluating termination for agent {AgentType}: {AgentId}.", nameof(ShouldTerminateAsync), agent.GetType(), agent.Id); + this.Logger.LogTerminationStrategyEvaluatingCriteria(nameof(ShouldTerminateAsync), agent.GetType(), agent.Id); // `Agents` must contain `agent`, if `Agents` not empty. if ((this.Agents?.Count ?? 0) > 0 && !this.Agents!.Any(a => a.Id == agent.Id)) { - this.Logger.LogInformation("[{MethodName}] {AgentType} agent out of scope for termination: {AgentId}.", nameof(ShouldTerminateAsync), agent.GetType(), agent.Id); + this.Logger.LogTerminationStrategyAgentOutOfScope(nameof(ShouldTerminateAsync), agent.GetType(), agent.Id); return false; } bool shouldTerminate = await this.ShouldAgentTerminateAsync(agent, history, cancellationToken).ConfigureAwait(false); - this.Logger.LogInformation("[{MethodName}] Evaluated termination for agent {AgentType}: {AgentId} - {Termination}", nameof(ShouldTerminateAsync), agent.GetType(), agent.Id, shouldTerminate); + this.Logger.LogTerminationStrategyEvaluatedCriteria(nameof(ShouldTerminateAsync), agent.GetType(), agent.Id, shouldTerminate); return shouldTerminate; } diff --git a/dotnet/src/Agents/Core/ChatCompletionAgent.cs b/dotnet/src/Agents/Core/ChatCompletionAgent.cs index b84d29494b8e..990154b139e4 100644 --- a/dotnet/src/Agents/Core/ChatCompletionAgent.cs +++ b/dotnet/src/Agents/Core/ChatCompletionAgent.cs @@ -3,7 +3,6 @@ using System.Runtime.CompilerServices; using System.Threading; using System.Threading.Tasks; -using Microsoft.Extensions.Logging; using Microsoft.SemanticKernel.ChatCompletion; namespace Microsoft.SemanticKernel.Agents; @@ -33,7 +32,7 @@ public override async IAsyncEnumerable InvokeAsync( int messageCount = chat.Count; - this.Logger.LogDebug("[{MethodName}] Invoking {ServiceType}.", nameof(InvokeAsync), chatCompletionService.GetType()); + this.Logger.LogAgentChatServiceInvokingAgent(nameof(InvokeAsync), this.Id, chatCompletionService.GetType()); IReadOnlyList messages = await chatCompletionService.GetChatMessageContentsAsync( @@ -42,10 +41,7 @@ await chatCompletionService.GetChatMessageContentsAsync( this.Kernel, cancellationToken).ConfigureAwait(false); - if (this.Logger.IsEnabled(LogLevel.Information)) // Avoid boxing if not enabled - { - this.Logger.LogInformation("[{MethodName}] Invoked {ServiceType} with message count: {MessageCount}.", nameof(InvokeAsync), chatCompletionService.GetType(), messages.Count); - } + this.Logger.LogAgentChatServiceInvokedAgent(nameof(InvokeAsync), this.Id, chatCompletionService.GetType(), messages.Count); // Capture mutated messages related function calling / tools for (int messageIndex = messageCount; messageIndex < chat.Count; messageIndex++) @@ -77,7 +73,7 @@ public override async IAsyncEnumerable InvokeStream int messageCount = chat.Count; - this.Logger.LogDebug("[{MethodName}] Invoking {ServiceType}.", nameof(InvokeAsync), chatCompletionService.GetType()); + this.Logger.LogAgentChatServiceInvokingAgent(nameof(InvokeAsync), this.Id, chatCompletionService.GetType()); IAsyncEnumerable messages = chatCompletionService.GetStreamingChatMessageContentsAsync( @@ -86,10 +82,7 @@ public override async IAsyncEnumerable InvokeStream this.Kernel, cancellationToken); - if (this.Logger.IsEnabled(LogLevel.Information)) - { - this.Logger.LogInformation("[{MethodName}] Invoked {ServiceType} with streaming messages.", nameof(InvokeAsync), chatCompletionService.GetType()); - } + this.Logger.LogAgentChatServiceInvokedStreamingAgent(nameof(InvokeAsync), this.Id, chatCompletionService.GetType()); // Capture mutated messages related function calling / tools for (int messageIndex = messageCount; messageIndex < chat.Count; messageIndex++) diff --git a/dotnet/src/Agents/Core/Logging/AgentGroupChatLogMessages.cs b/dotnet/src/Agents/Core/Logging/AgentGroupChatLogMessages.cs new file mode 100644 index 000000000000..03b9d27f1c8d --- /dev/null +++ b/dotnet/src/Agents/Core/Logging/AgentGroupChatLogMessages.cs @@ -0,0 +1,103 @@ +// Copyright (c) Microsoft. All rights reserved. +using System; +using System.Collections.Generic; +using System.Diagnostics.CodeAnalysis; +using System.Linq; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class AgentGroupChatLogMessages +{ + /// + /// Logs invoking agent (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Invoking chat: {AgentType}: {AgentId}")] + public static partial void LogAgentGroupChatInvokingAgent( + this ILogger logger, + string methodName, + Type agentType, + string agentId); + + /// + /// Logs invoking agents (started). + /// + private static readonly Action s_logAgentGroupChatInvokingAgents = + LoggerMessage.Define( + logLevel: LogLevel.Debug, + eventId: 0, + "[{MethodName}] Invoking chat: {Agents}"); + public static void LogAgentGroupChatInvokingAgents( + this ILogger logger, + string methodName, + IEnumerable agents) + { + if (logger.IsEnabled(LogLevel.Debug)) + { + s_logAgentGroupChatInvokingAgents(logger, methodName, string.Join(", ", agents.Select(a => $"{a.GetType()}:{a.Id}")), null); + } + } + + /// + /// Logs selecting agent (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Selecting agent: {StrategyType}.")] + public static partial void LogAgentGroupChatSelectingAgent( + this ILogger logger, + string methodName, + Type strategyType); + + /// + /// Logs Unable to select agent. + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Error, + Message = "[{MethodName}] Unable to determine next agent.")] + public static partial void LogAgentGroupChatNoAgentSelected( + this ILogger logger, + string methodName, + Exception exception); + + /// + /// Logs selected agent (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Agent selected {AgentType}: {AgentId} by {StrategyType}")] + public static partial void LogAgentGroupChatSelectedAgent( + this ILogger logger, + string methodName, + Type agentType, + string agentId, + Type strategyType); + + /// + /// Logs yield chat. + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Yield chat - IsComplete: {IsComplete}")] + public static partial void LogAgentGroupChatYield( + this ILogger logger, + string methodName, + bool isComplete); +} diff --git a/dotnet/src/Agents/Core/Logging/AggregatorTerminationStrategyLogMessages.cs b/dotnet/src/Agents/Core/Logging/AggregatorTerminationStrategyLogMessages.cs new file mode 100644 index 000000000000..777ec8806ec7 --- /dev/null +++ b/dotnet/src/Agents/Core/Logging/AggregatorTerminationStrategyLogMessages.cs @@ -0,0 +1,31 @@ +// Copyright (c) Microsoft. All rights reserved. +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents.Chat; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class AggregatorTerminationStrategyLogMessages +{ + /// + /// Logs invoking agent (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Evaluating termination for {StrategyCount} strategies: {AggregationMode}")] + public static partial void LogAggregatorTerminationStrategyEvaluating( + this ILogger logger, + string methodName, + int strategyCount, + AggregateTerminationCondition aggregationMode); +} diff --git a/dotnet/src/Agents/Core/Logging/ChatCompletionAgentLogMessages.cs b/dotnet/src/Agents/Core/Logging/ChatCompletionAgentLogMessages.cs new file mode 100644 index 000000000000..038c19359cc8 --- /dev/null +++ b/dotnet/src/Agents/Core/Logging/ChatCompletionAgentLogMessages.cs @@ -0,0 +1,59 @@ +// Copyright (c) Microsoft. All rights reserved. +using System; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class ChatCompletionAgentLogMessages +{ + /// + /// Logs invoking agent (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Agent #{AgentId} Invoking service {ServiceType}.")] + public static partial void LogAgentChatServiceInvokingAgent( + this ILogger logger, + string methodName, + string agentId, + Type serviceType); + + /// + /// Logs invoked agent (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Agent #{AgentId} Invoked service {ServiceType} with message count: {MessageCount}.")] + public static partial void LogAgentChatServiceInvokedAgent( + this ILogger logger, + string methodName, + string agentId, + Type serviceType, + int messageCount); + + /// + /// Logs invoked streaming agent (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Agent #{AgentId} Invoked service {ServiceType}.")] + public static partial void LogAgentChatServiceInvokedStreamingAgent( + this ILogger logger, + string methodName, + string agentId, + Type serviceType); +} diff --git a/dotnet/src/Agents/Core/Logging/KernelFunctionSelectionStrategyLogMessages.cs b/dotnet/src/Agents/Core/Logging/KernelFunctionSelectionStrategyLogMessages.cs new file mode 100644 index 000000000000..c846f5e2534e --- /dev/null +++ b/dotnet/src/Agents/Core/Logging/KernelFunctionSelectionStrategyLogMessages.cs @@ -0,0 +1,46 @@ +// Copyright (c) Microsoft. All rights reserved. +using System; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents.Chat; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class KernelFunctionStrategyLogMessages +{ + /// + /// Logs invoking function (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Invoking function: {PluginName}.{FunctionName}.")] + public static partial void LogKernelFunctionSelectionStrategyInvokingFunction( + this ILogger logger, + string methodName, + string? pluginName, + string functionName); + + /// + /// Logs invoked function (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Invoked function: {PluginName}.{FunctionName}: {ResultType}")] + public static partial void LogKernelFunctionSelectionStrategyInvokedFunction( + this ILogger logger, + string methodName, + string? pluginName, + string functionName, + Type? resultType); +} diff --git a/dotnet/src/Agents/Core/Logging/KernelFunctionTerminationStrategyLogMessages.cs b/dotnet/src/Agents/Core/Logging/KernelFunctionTerminationStrategyLogMessages.cs new file mode 100644 index 000000000000..61a4dea167b5 --- /dev/null +++ b/dotnet/src/Agents/Core/Logging/KernelFunctionTerminationStrategyLogMessages.cs @@ -0,0 +1,46 @@ +// Copyright (c) Microsoft. All rights reserved. +using System; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents.Chat; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class KernelFunctionTerminationStrategyLogMessages +{ + /// + /// Logs invoking function (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Invoking function: {PluginName}.{FunctionName}.")] + public static partial void LogKernelFunctionTerminationStrategyInvokingFunction( + this ILogger logger, + string methodName, + string? pluginName, + string functionName); + + /// + /// Logs invoked function (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Invoked function: {PluginName}.{FunctionName}: {ResultType}")] + public static partial void LogKernelFunctionTerminationStrategyInvokedFunction( + this ILogger logger, + string methodName, + string? pluginName, + string functionName, + Type? resultType); +} diff --git a/dotnet/src/Agents/Core/Logging/RegExTerminationStrategyLogMessages.cs b/dotnet/src/Agents/Core/Logging/RegExTerminationStrategyLogMessages.cs new file mode 100644 index 000000000000..a748158252b7 --- /dev/null +++ b/dotnet/src/Agents/Core/Logging/RegExTerminationStrategyLogMessages.cs @@ -0,0 +1,66 @@ +// Copyright (c) Microsoft. All rights reserved. +using System.Diagnostics.CodeAnalysis; +using System.Text.RegularExpressions; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents.Chat; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class RegExTerminationStrategyLogMessages +{ + /// + /// Logs begin evaluation (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Evaluating expressions: {ExpressionCount}")] + public static partial void LogRegexTerminationStrategyEvaluating( + this ILogger logger, + string methodName, + int expressionCount); + + /// + /// Logs evaluating expression (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Evaluating expression: {Expression}")] + public static partial void LogRegexTerminationStrategyEvaluatingExpression( + this ILogger logger, + string methodName, + Regex expression); + + /// + /// Logs expression matched (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Expression matched: {Expression}")] + public static partial void LogRegexTerminationStrategyMatchedExpression( + this ILogger logger, + string methodName, + Regex expression); + + /// + /// Logs no match (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] No expression matched.")] + public static partial void LogRegexTerminationStrategyNoMatch( + this ILogger logger, + string methodName); +} diff --git a/dotnet/src/Agents/Core/Logging/SequentialSelectionStrategyLogMessages.cs b/dotnet/src/Agents/Core/Logging/SequentialSelectionStrategyLogMessages.cs new file mode 100644 index 000000000000..e201dddcd9c0 --- /dev/null +++ b/dotnet/src/Agents/Core/Logging/SequentialSelectionStrategyLogMessages.cs @@ -0,0 +1,32 @@ +// Copyright (c) Microsoft. All rights reserved. +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents.Chat; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class SequentialSelectionStrategyLogMessages +{ + /// + /// Logs selected agent (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Selected agent ({AgentIndex} / {AgentCount}): {AgentId}")] + public static partial void LogSequentialSelectionStrategySelectedAgent( + this ILogger logger, + string methodName, + int agentIndex, + int agentCount, + string agentId); +} diff --git a/dotnet/src/Agents/Core/Logging/TerminationStrategyLogMessages.cs b/dotnet/src/Agents/Core/Logging/TerminationStrategyLogMessages.cs new file mode 100644 index 000000000000..adbf5ad7b689 --- /dev/null +++ b/dotnet/src/Agents/Core/Logging/TerminationStrategyLogMessages.cs @@ -0,0 +1,59 @@ +// Copyright (c) Microsoft. All rights reserved. +using System; +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents.Chat; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class TerminationStrategyLogMessages +{ + /// + /// Logs evaluating criteria (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Evaluating termination for agent {AgentType}: {AgentId}.")] + public static partial void LogTerminationStrategyEvaluatingCriteria( + this ILogger logger, + string methodName, + Type agentType, + string agentId); + + /// + /// Logs agent out of scope. + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] {AgentType} agent out of scope for termination: {AgentId}.")] + public static partial void LogTerminationStrategyAgentOutOfScope( + this ILogger logger, + string methodName, + Type agentType, + string agentId); + + /// + /// Logs evaluated criteria (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Evaluated termination for agent {AgentType}: {AgentId} - {TerminationResult}")] + public static partial void LogTerminationStrategyEvaluatedCriteria( + this ILogger logger, + string methodName, + Type agentType, + string agentId, + bool terminationResult); +} diff --git a/dotnet/src/Agents/OpenAI/AssistantThreadActions.cs b/dotnet/src/Agents/OpenAI/AssistantThreadActions.cs index 37649844a230..b1be5bb52765 100644 --- a/dotnet/src/Agents/OpenAI/AssistantThreadActions.cs +++ b/dotnet/src/Agents/OpenAI/AssistantThreadActions.cs @@ -18,7 +18,6 @@ namespace Microsoft.SemanticKernel.Agents.OpenAI; /// internal static class AssistantThreadActions { - /*AssistantsClient client, string threadId, OpenAIAssistantConfiguration.PollingConfiguration pollingConfiguration*/ private const string FunctionDelimiter = "-"; private static readonly HashSet s_messageRoles = @@ -152,7 +151,7 @@ public static async IAsyncEnumerable InvokeAsync( ToolDefinition[]? tools = [.. agent.Tools, .. agent.Kernel.Plugins.SelectMany(p => p.Select(f => f.ToToolDefinition(p.Name, FunctionDelimiter)))]; - logger.LogDebug("[{MethodName}] Creating run for agent/thrad: {AgentId}/{ThreadId}", nameof(InvokeAsync), agent.Id, threadId); + logger.LogOpenAIAssistantCreatingRun(nameof(InvokeAsync), threadId); CreateRunOptions options = new(agent.Id) @@ -164,7 +163,7 @@ public static async IAsyncEnumerable InvokeAsync( // Create run ThreadRun run = await client.CreateRunAsync(threadId, options, cancellationToken).ConfigureAwait(false); - logger.LogInformation("[{MethodName}] Created run: {RunId}", nameof(InvokeAsync), run.Id); + logger.LogOpenAIAssistantCreatedRun(nameof(InvokeAsync), run.Id, threadId); // Evaluate status and process steps and messages, as encountered. HashSet processedStepIds = []; @@ -184,7 +183,7 @@ public static async IAsyncEnumerable InvokeAsync( // Is tool action required? if (run.Status == RunStatus.RequiresAction) { - logger.LogDebug("[{MethodName}] Processing run steps: {RunId}", nameof(InvokeAsync), run.Id); + logger.LogOpenAIAssistantProcessingRunSteps(nameof(InvokeAsync), run.Id, threadId); // Execute functions in parallel and post results at once. FunctionCallContent[] activeFunctionSteps = steps.Data.SelectMany(step => ParseFunctionStep(agent, step)).ToArray(); @@ -205,14 +204,11 @@ public static async IAsyncEnumerable InvokeAsync( await client.SubmitToolOutputsToRunAsync(run, toolOutputs, cancellationToken).ConfigureAwait(false); } - if (logger.IsEnabled(LogLevel.Information)) // Avoid boxing if not enabled - { - logger.LogInformation("[{MethodName}] Processed #{MessageCount} run steps: {RunId}", nameof(InvokeAsync), activeFunctionSteps.Length, run.Id); - } + logger.LogOpenAIAssistantProcessedRunSteps(nameof(InvokeAsync), activeFunctionSteps.Length, run.Id, threadId); } // Enumerate completed messages - logger.LogDebug("[{MethodName}] Processing run messages: {RunId}", nameof(InvokeAsync), run.Id); + logger.LogOpenAIAssistantProcessingRunMessages(nameof(InvokeAsync), run.Id, threadId); IEnumerable completedStepsToProcess = steps @@ -289,19 +285,16 @@ public static async IAsyncEnumerable InvokeAsync( processedStepIds.Add(completedStep.Id); } - if (logger.IsEnabled(LogLevel.Information)) // Avoid boxing if not enabled - { - logger.LogInformation("[{MethodName}] Processed #{MessageCount} run messages: {RunId}", nameof(InvokeAsync), messageCount, run.Id); - } + logger.LogOpenAIAssistantProcessedRunMessages(nameof(InvokeAsync), messageCount, run.Id, threadId); } while (RunStatus.Completed != run.Status); - logger.LogInformation("[{MethodName}] Completed run: {RunId}", nameof(InvokeAsync), run.Id); + logger.LogOpenAIAssistantCompletedRun(nameof(InvokeAsync), run.Id, threadId); // Local function to assist in run polling (participates in method closure). async Task> PollRunStatusAsync() { - logger.LogInformation("[{MethodName}] Polling run status: {RunId}", nameof(PollRunStatusAsync), run.Id); + logger.LogOpenAIAssistantPollingRunStatus(nameof(PollRunStatusAsync), run.Id, threadId); int count = 0; @@ -324,7 +317,7 @@ async Task> PollRunStatusAsync() } while (s_pollingStatuses.Contains(run.Status)); - logger.LogInformation("[{MethodName}] Run status is {RunStatus}: {RunId}", nameof(PollRunStatusAsync), run.Status, run.Id); + logger.LogOpenAIAssistantPolledRunStatus(nameof(PollRunStatusAsync), run.Status, run.Id, threadId); return await client.GetRunStepsAsync(run, cancellationToken: cancellationToken).ConfigureAwait(false); } diff --git a/dotnet/src/Agents/OpenAI/Logging/AssistantThreadActionsLogMessages.cs b/dotnet/src/Agents/OpenAI/Logging/AssistantThreadActionsLogMessages.cs new file mode 100644 index 000000000000..bc7c8d9919f0 --- /dev/null +++ b/dotnet/src/Agents/OpenAI/Logging/AssistantThreadActionsLogMessages.cs @@ -0,0 +1,138 @@ +// Copyright (c) Microsoft. All rights reserved. +using System.Diagnostics.CodeAnalysis; +using Azure.AI.OpenAI.Assistants; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents.OpenAI; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging . +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class AssistantThreadActionsLogMessages +{ + /// + /// Logs creating run (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Creating run for thread: {ThreadId}.")] + public static partial void LogOpenAIAssistantCreatingRun( + this ILogger logger, + string methodName, + string threadId); + + /// + /// Logs created run (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Created run for thread: {RunId}/{ThreadId}.")] + public static partial void LogOpenAIAssistantCreatedRun( + this ILogger logger, + string methodName, + string runId, + string threadId); + + /// + /// Logs completed run (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Completed run for thread: {RunId}/{ThreadId}.")] + public static partial void LogOpenAIAssistantCompletedRun( + this ILogger logger, + string methodName, + string runId, + string threadId); + + /// + /// Logs processing run steps (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Processing run steps for thread: {RunId}/{ThreadId}.")] + public static partial void LogOpenAIAssistantProcessingRunSteps( + this ILogger logger, + string methodName, + string runId, + string threadId); + + /// + /// Logs processed run steps (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Processed #{stepCount} run steps: {RunId}/{ThreadId}.")] + public static partial void LogOpenAIAssistantProcessedRunSteps( + this ILogger logger, + string methodName, + int stepCount, + string runId, + string threadId); + + /// + /// Logs processing run messages (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Processing run messages for thread: {RunId}/{ThreadId}.")] + public static partial void LogOpenAIAssistantProcessingRunMessages( + this ILogger logger, + string methodName, + string runId, + string threadId); + + /// + /// Logs processed run messages (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Processed #{MessageCount} run steps: {RunId}/{ThreadId}.")] + public static partial void LogOpenAIAssistantProcessedRunMessages( + this ILogger logger, + string methodName, + int messageCount, + string runId, + string threadId); + + /// + /// Logs polling run status (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Polling run status for thread: {RunId}/{ThreadId}.")] + public static partial void LogOpenAIAssistantPollingRunStatus( + this ILogger logger, + string methodName, + string runId, + string threadId); + + /// + /// Logs polled run status (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Run status is {RunStatus}: {RunId}/{ThreadId}.")] + public static partial void LogOpenAIAssistantPolledRunStatus( + this ILogger logger, + string methodName, + RunStatus runStatus, + string runId, + string threadId); +} diff --git a/dotnet/src/Agents/OpenAI/Logging/OpenAIAssistantAgentLogMessages.cs b/dotnet/src/Agents/OpenAI/Logging/OpenAIAssistantAgentLogMessages.cs new file mode 100644 index 000000000000..1f85264ed9c4 --- /dev/null +++ b/dotnet/src/Agents/OpenAI/Logging/OpenAIAssistantAgentLogMessages.cs @@ -0,0 +1,43 @@ +// Copyright (c) Microsoft. All rights reserved. +using System.Diagnostics.CodeAnalysis; +using Microsoft.Extensions.Logging; + +namespace Microsoft.SemanticKernel.Agents.OpenAI; + +#pragma warning disable SYSLIB1006 // Multiple logging methods cannot use the same event id within a class + +/// +/// Extensions for logging invocations. +/// +/// +/// This extension uses the to +/// generate logging code at compile time to achieve optimized code. +/// +[ExcludeFromCodeCoverage] +internal static partial class OpenAIAssistantAgentLogMessages +{ + /// + /// Logs creating channel (started). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Debug, + Message = "[{MethodName}] Creating assistant thread for {ChannelType}.")] + public static partial void LogOpenAIAssistantAgentCreatingChannel( + this ILogger logger, + string methodName, + string channelType); + + /// + /// Logs created channel (complete). + /// + [LoggerMessage( + EventId = 0, + Level = LogLevel.Information, + Message = "[{MethodName}] Created assistant thread for {ChannelType}: #{ThreadId}.")] + public static partial void LogOpenAIAssistantAgentCreatedChannel( + this ILogger logger, + string methodName, + string channelType, + string threadId); +} diff --git a/dotnet/src/Agents/OpenAI/OpenAIAssistantAgent.cs b/dotnet/src/Agents/OpenAI/OpenAIAssistantAgent.cs index b46cdb013c18..31c0bb1c0de7 100644 --- a/dotnet/src/Agents/OpenAI/OpenAIAssistantAgent.cs +++ b/dotnet/src/Agents/OpenAI/OpenAIAssistantAgent.cs @@ -282,17 +282,19 @@ protected override IEnumerable GetChannelKeys() /// protected override async Task CreateChannelAsync(CancellationToken cancellationToken) { - this.Logger.LogDebug("[{MethodName}] Creating assistant thread", nameof(CreateChannelAsync)); + this.Logger.LogOpenAIAssistantAgentCreatingChannel(nameof(CreateChannelAsync), nameof(OpenAIAssistantChannel)); AssistantThread thread = await this._client.CreateThreadAsync(cancellationToken).ConfigureAwait(false); - this.Logger.LogInformation("[{MethodName}] Created assistant thread: {ThreadId}", nameof(CreateChannelAsync), thread.Id); - - return - new OpenAIAssistantChannel(this._client, thread.Id, this._config.Polling) + OpenAIAssistantChannel channel = + new(this._client, thread.Id, this._config.Polling) { Logger = this.LoggerFactory.CreateLogger() }; + + this.Logger.LogOpenAIAssistantAgentCreatedChannel(nameof(CreateChannelAsync), nameof(OpenAIAssistantChannel), thread.Id); + + return channel; } internal void ThrowIfDeleted()