[MAF预定义ChatClient中间件-01]LoggingChatClient——在调用LLM前后输出日志

LoggingChatClient是一个预定义的IChatClient中间件，它在调用前后输出日志，帮助我们更好地了解Agent的执行过程。它会记录每次调用的输入和输出，以及调用的时间戳等信息。这对于调试和监控Agent的行为非常有用。

1. 利用LoggingChatClient中间件来记录针对LLM的调用

如果将LoggingChatClient这个中间件至于连接LLM的IChatClient之前，那么针对后者对LLM的调用情况会以日志的形式记录下来。我们可以通过设置不同的日志级别来控制输出的详细程度。在如下的演示程序中，我们利用创建了一个基于OpenAIClient的IChatClient对象。在调用AsBuilder扩展方法将ChatClientBuilder构建出来后，通过调用UseLogging方法来注册LoggingChatClient中间件，并且传入一个ILoggerFactory对象来控制日志的输出。由于我们在创建ILoggerFactory对象的时候设置了日志级别为Debug。

using Azure;
using dotenv.net;
using Microsoft.Agents.AI;
using Microsoft.Extensions.AI;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using OpenAI;

DotEnv.Load();

var model = Environment.GetEnvironmentVariable("MODEL")!;
var apiKey = Environment.GetEnvironmentVariable("API_KEY")!;
var endpoint = Environment.GetEnvironmentVariable("OPENAI_URL")!;

var loggerFactory = new ServiceCollection()
    .AddLogging(logging=>logging
        .SetMinimumLevel(LogLevel.Trace)
        .AddConsole())
    .BuildServiceProvider()
    .GetRequiredService();

var client = new OpenAIClient(
        credential: new AzureKeyCredential(apiKey),
        options: new OpenAIClientOptions { Endpoint = new Uri(endpoint) })
    .GetChatClient(model:model)
    .AsIChatClient()
    .AsBuilder()
    .UseLogging(loggerFactory: loggerFactory)
    .Build();

await client.GetResponseAsync("What is Azure OpenAI?");
Console.ReadLine();

LoggingChatClient的GetResponseAsync方法会在调用前输出一条日志，表示正在调用LLM，并且会记录调用的输入内容；在调用完成后会输出另一条日志，表示调用已经完成，并且会记录调用的输出内容。通过这些日志，我们可以清楚地看到每次调用的输入和输出，以及调用的时间戳等信息。

dbug: Microsoft.Extensions.AI.LoggingChatClient[1723383095]
      GetResponseAsync invoked.
dbug: Microsoft.Extensions.AI.LoggingChatClient[1553703230]
      GetResponseAsync completed.

如果我们将日志等级设置为更低的Trace级别，那么LoggingChatClient还会输出更详细的日志信息，包括调用的输入内容和输出内容等。

var loggerFactory = new ServiceCollection()
    .AddLogging(logging=>logging
        .SetMinimumLevel(LogLevel.Trace)
        .AddConsole())
    .BuildServiceProvider()
    .GetRequiredService();

输出：

trce: Microsoft.Extensions.AI.LoggingChatClient[805843669]
      GetResponseAsync invoked: [
        {
          "role": "user",
          "contents": [
            {
              "$type": "text",
              "text": "What is Azure OpenAI?"
            }
          ]
        }
      ]. Options: null. Metadata: {
        "providerName": "openai",
        "providerUri": "https://eap2410.cognitiveservices.azure.com/openai/v1",
        "defaultModelId": "gpt-5.2-chat"
      }.

trce: Microsoft.Extensions.AI.LoggingChatClient[384896670]
      GetResponseAsync completed: {
        "messages": [
          {
            "createdAt": "2026-05-22T01:28:42+00:00",
            "role": "assistant",
            "contents": [
              {
                "$type": "text",
                "text": "**Azure OpenAI** is Microsoft’s cloud-based service that provides access to advanced AI models (like OpenAI’s GPT, GPT‑4, and image generation models) through the **Microsoft Azure** platform.\n\nIn simple terms, it lets businesses and developers use powerful AI models within Microsoft’s secure cloud environment.\n\n### Key Features:\n- **Access to OpenAI models** (GPT‑4, GPT‑4o, embeddings, image generation, etc.)\n- **Enterprise-grade security and compliance**\n- **Data privacy** — your data isn’t used to train the base models\n- **Integration with Azure services** (Azure AI Search, Azure Functions, Power BI, etc.)\n- **Scalable infrastructure** for production workloads\n\n### What It’s Used For:\n- Chatbots and virtual assistants  \n- Document summarization  \n- Code generation  \n- Data analysis  \n- Image generation  \n- Semantic search and embeddings  \n\n### How It’s Different from OpenAI’s public API:\n- Runs within the **Azure ecosystem**\n- Offers enterprise security controls\n- Regional data hosting options\n- Integrated billing through Azure\n\nIn short:  \n**Azure OpenAI = OpenAI models + Microsoft Azure’s enterprise cloud platform.**"
              }
            ],
            "messageId": "chatcmpl-Di8yoRfX62nycHbngYbn11qNFWvJk"
          }
        ],
        "responseId": "chatcmpl-Di8yoRfX62nycHbngYbn11qNFWvJk",
        "modelId": "gpt-5.2-chat-latest",
        "createdAt": "2026-05-22T01:28:42+00:00",
        "finishReason": "stop",
        "usage": {
          "inputTokenCount": 12,
          "outputTokenCount": 252,
          "totalTokenCount": 264,
          "cachedInputTokenCount": 0,
          "reasoningTokenCount": 0,
          "additionalCounts": {
            "InputTokenDetails.AudioTokenCount": 0,
            "OutputTokenDetails.AudioTokenCount": 0,
            "OutputTokenDetails.AcceptedPredictionTokenCount": 0,
            "OutputTokenDetails.RejectedPredictionTokenCount": 0
          }
        }
      }.

2. LoggingChatClient

LoggingChatClient直接继承自DelegatingChatClient，是一个非常简单的中间件实现，它直接利用构造函数传入的ILogger对象来输出日志信息。DelegatingChatClient在没有出错的情况下只会输出等级分别为Debug和Trace的日志信息，如果最低日志等级设置为Debug，那么就只会输出调用前和调用后的日志；如果最低日志等级设置为Trace，那么就会输出更详细的日志信息，包括调用的输入内容和输出内容等。Trace等级的日志的内容以JSON形式输出，所以它提供了一个JsonSerializerOptions属性来控制日志中输入输出内容的序列化方式。我们可以通过设置这个属性来控制日志中输入输出内容的格式，比如是否使用驼峰命名、是否忽略空值等。

public partial class LoggingChatClient : DelegatingChatClient
{   
    public LoggingChatClient(IChatClient innerClient, ILogger logger);
    public JsonSerializerOptions JsonSerializerOptions { get; set; }

    public override async Task GetResponseAsync(
        IEnumerable messages, 
        ChatOptions? options = null, 
        CancellationToken cancellationToken = default);
    public override async IAsyncEnumerable GetStreamingResponseAsync(
        IEnumerable messages, 
        ChatOptions? options = null, 
        CancellationToken cancellationToken = default);
}

针对GetResponseAsync的日志输出采用如下的逻辑：

• 在调用innerClient的GetResponseAsync方法之前，输出一条Debug/Trace等级的日志，表示正在调用LLM，并且会记录调用的输入内容；
• 在成功调用并得到响应之后，输出另一条Debug/Trace等级的日志，表示调用已经完成，并且会记录调用的输出内容；
• 如果调用过程中发生了异常，那么会输出一条Error等级的日志，表示调用失败，并且会记录异常信息；

针对GetStreamingResponseAsync的日志输出采用如下的逻辑：

• 在调用innerClient的GetStreamingResponseAsync方法之前，输出一条Debug/Trace等级的日志，表示正在调用LLM，并且会记录调用的输入内容；
• 如果调用失败，那么会输出一条Error等级的日志，表示调用失败，并且会记录异常信息；
• GetStreamingResponseAsync会对返回的IAsyncEnumerable进行迭代，对于每一次迭代：
  • 如果成功获取到一个ChatResponseUpdate，并且最低日志等级设置为Trace，那么会输出一条Trace等级的日志，表示获取到了一个更新，并且会记录这个更新的内容；
  • 如果在迭代过程中发生了异常，那么会输出一条Error等级的日志，表示迭代失败，并且会记录异常信息；
• 在迭代完成之后，输出一条Debug等级的日志，表示调用已经完成；

对于我们前面演示的例子，如果我们将日志等级设置为Trace，那么在调用GetStreamingResponseAsync方法时，我们就可以看到每一次迭代获取到的ChatResponseUpdate的内容都被记录在日志中了，这对于调试和监控Agent的行为非常有用。由于这种情况下输出内容容量可能会非常大，所以当我们将日志等级设置为Trace时，得评估一下日志对性能带来得影响。

using Azure;
using dotenv.net;
using Microsoft.Agents.AI;
using Microsoft.Extensions.AI;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using OpenAI;

DotEnv.Load();

var model = Environment.GetEnvironmentVariable("MODEL")!;
var apiKey = Environment.GetEnvironmentVariable("API_KEY")!;
var endpoint = Environment.GetEnvironmentVariable("OPENAI_URL")!;

var loggerFactory = new ServiceCollection()
    .AddLogging(logging=>logging
        .SetMinimumLevel(LogLevel.Trace)
        .AddConsole())
    .BuildServiceProvider()
    .GetRequiredService();

var client = new OpenAIClient(
        credential: new AzureKeyCredential(apiKey),
        options: new OpenAIClientOptions { Endpoint = new Uri(endpoint) })
    .GetChatClient(model:model)
    .AsIChatClient()
    .AsBuilder()
    .UseLogging(loggerFactory: loggerFactory)
    .Build();


await foreach(var update in client.GetStreamingResponseAsync("世界上最深的淡水湖是哪个？在10字内作答！"))
{    
}

输出：

trce: Microsoft.Extensions.AI.LoggingChatClient[805843669]
      GetStreamingResponseAsync invoked: [
        {
          "role": "user",
          "contents": [
            {
              "$type": "text",
              "text": "世界上最深的淡水湖是哪个？在10字内作答！"
            }
          ]
        }
      ]. Options: null. Metadata: {
        "providerName": "openai",
        "providerUri": "https://eap2410.cognitiveservices.azure.com/openai/v1",
        "defaultModelId": "gpt-5.2-chat"
      }.
trce: Microsoft.Extensions.AI.LoggingChatClient[1513570378]
      GetStreamingResponseAsync received update: {
        "contents": [],
        "responseId": "",
        "messageId": "",
        "createdAt": "1970-01-01T00:00:00+00:00",
        "modelId": ""
      }
trce: Microsoft.Extensions.AI.LoggingChatClient[1513570378]
      GetStreamingResponseAsync received update: {
        "role": "assistant",
        "contents": [
          {
            "$type": "text",
            "text": ""
          }
        ],
        "responseId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "messageId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "createdAt": "2026-05-22T02:03:39+00:00",
        "modelId": ""
      }
trce: Microsoft.Extensions.AI.LoggingChatClient[1513570378]
      GetStreamingResponseAsync received update: {
        "role": "assistant",
        "contents": [
          {
            "$type": "text",
            "text": "贝"
          }
        ],
        "responseId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "messageId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "createdAt": "2026-05-22T02:03:39+00:00",
        "modelId": ""
      }
trce: Microsoft.Extensions.AI.LoggingChatClient[1513570378]
      GetStreamingResponseAsync received update: {
        "role": "assistant",
        "contents": [
          {
            "$type": "text",
            "text": "加"
          }
        ],
        "responseId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "messageId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "createdAt": "2026-05-22T02:03:39+00:00",
        "modelId": ""
      }
trce: Microsoft.Extensions.AI.LoggingChatClient[1513570378]
      GetStreamingResponseAsync received update: {
        "role": "assistant",
        "contents": [
          {
            "$type": "text",
            "text": "尔"
          }
        ],
        "responseId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "messageId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "createdAt": "2026-05-22T02:03:39+00:00",
        "modelId": ""
      }
trce: Microsoft.Extensions.AI.LoggingChatClient[1513570378]
      GetStreamingResponseAsync received update: {
        "role": "assistant",
        "contents": [
          {
            "$type": "text",
            "text": "湖"
          }
        ],
        "responseId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "messageId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "createdAt": "2026-05-22T02:03:39+00:00",
        "modelId": ""
      }
trce: Microsoft.Extensions.AI.LoggingChatClient[1513570378]
      GetStreamingResponseAsync received update: {
        "role": "assistant",
        "contents": [],
        "responseId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "messageId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "createdAt": "2026-05-22T02:03:39+00:00",
        "finishReason": "stop",
        "modelId": ""
      }
trce: Microsoft.Extensions.AI.LoggingChatClient[1513570378]
      GetStreamingResponseAsync received update: {
        "role": "assistant",
        "contents": [
          {
            "$type": "usage",
            "details": {
              "inputTokenCount": 24,
              "outputTokenCount": 78,
              "totalTokenCount": 102,
              "cachedInputTokenCount": 0,
              "reasoningTokenCount": 64,
              "additionalCounts": {
                "InputTokenDetails.AudioTokenCount": 0,
                "OutputTokenDetails.AudioTokenCount": 0,
                "OutputTokenDetails.AcceptedPredictionTokenCount": 0,
                "OutputTokenDetails.RejectedPredictionTokenCount": 0
              }
            }
          }
        ],
        "responseId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "messageId": "chatcmpl-Di9WdprY6ZgpHqiLY25t8Y23kmsRa",
        "createdAt": "2026-05-22T02:03:39+00:00",
        "finishReason": "stop",
        "modelId": ""
      }
dbug: Microsoft.Extensions.AI.LoggingChatClient[1553703230]
      GetStreamingResponseAsync completed.

3. 利用Source Generator生成日志输出代码

日志是典型得高频操作，尤其是当我们将日志等级设置得很低得时候更是如此，所以针对日志输出的每一个微小的细节都会高倍放大，比如字符串拼接和值类型转换成引用类型导致的装箱等。在此方面，Source Generator就能派上用场了。我们可以利用Source Generator来生成日志输出的代码，从而避免手写日志输出代码可能带来的性能问题。Microsoft.Extensions.Logging库已经提供了一个名为LoggerMessageAttribute的Source Generator，我们可以利用它来生成日志输出的代码。

LoggingChatClient涉及的日志输出被定义成对应的方法，并在这些方法上使用LoggerMessageAttribute特性来标记日志的级别和消息模板。LoggerMessageAttribute特性会告诉Source Generator生成对应的日志输出代码，从而避免了手写日志输出代码可能带来的性能问题。这也是LoggingChatClient被定义成partial类的原因。

public partial class LoggingChatClient : DelegatingChatClient
{ 
    [LoggerMessage(LogLevel.Debug, "{MethodName} invoked.")]
    private partial void LogInvoked(string methodName);

    [LoggerMessage(LogLevel.Trace, "{MethodName} invoked: {Messages}. Options: {ChatOptions}. Metadata: {ChatClientMetadata}.")]
    private partial void LogInvokedSensitive(string methodName, string messages, string chatOptions, string chatClientMetadata);

    [LoggerMessage(LogLevel.Debug, "{MethodName} completed.")]
    private partial void LogCompleted(string methodName);

    [LoggerMessage(LogLevel.Trace, "{MethodName} completed: {ChatResponse}.")]
    private partial void LogCompletedSensitive(string methodName, string chatResponse);

    [LoggerMessage(LogLevel.Trace, "GetStreamingResponseAsync received update: {ChatResponseUpdate}")]
    private partial void LogStreamingUpdateSensitive(string chatResponseUpdate);

    [LoggerMessage(LogLevel.Debug, "{MethodName} canceled.")]
    private partial void LogInvocationCanceled(string methodName);

    [LoggerMessage(LogLevel.Error, "{MethodName} failed.")]
    private partial void LogInvocationFailed(string methodName, Exception error);
}

4. UseLogging扩展方法

UseLogging是一个ChatClientBuilder的扩展方法，它提供了一种简便的方式来注册LoggingChatClient中间件。我们只需要在构建IChatClient对象的时候调用UseLogging方法，并传入一个ILoggerFactory对象来控制日志的输出，就可以轻松地将LoggingChatClient中间件添加到我们的IChatClient对象中了。除此之外，UseLogging方法还提供了一个可选的configure参数，它允许我们在注册LoggingChatClient中间件的时候对其进行一些额外的配置，比如设置JsonSerializerOptions属性来控制日志中输入输出内容的序列化方式等。

public static class LoggingChatClientBuilderExtensions
{
    public static ChatClientBuilder UseLogging(
        this ChatClientBuilder builder,
        ILoggerFactory? loggerFactory = null,
        Action? configure = null);
}