AI Agent 执行了 20 次工具调用，到底卡在哪里？用 Trace ID 实现 AI 应用链路追踪

前言

现在的 AI Agent 已经能够完成很多复杂任务。

例如，让一个 AI Agent 自动开发并发布网页，它可能需要经历：

• 分析用户需求

• 生成项目代码

• 安装依赖

• 运行测试

• 启动本地服务

• 生成浏览器截图

• 上传代码仓库

• 调用发布接口

如果整个任务成功完成，通常不会有什么问题。

但如果 AI Agent 执行到第 20 次工具调用时突然失败，开发者应该如何快速判断原因？

是模型生成了错误参数？

是某个工具执行超时？

还是外部 API 返回了异常？

如果系统只保存普通的终端输出，开发者可能需要翻阅大量日志才能找到真正的问题。

这让我想到一个传统分布式系统中非常重要的技术：链路追踪（Distributed Tracing）。

本文介绍如何利用 Trace ID、结构化日志和执行耗时统计，为 AI Agent 建立基础的可观测能力。

一、为什么普通日志不够用？

假设一个 AI Agent 执行以下操作：

10:00:01 开始任务
10:00:03 文件创建成功
10:00:06 调用模型
10:00:09 执行工具
10:00:12 请求失败
10:00:15 重试成功
10:00:18 任务完成

这些日志能说明发生过什么，却没有明确回答：

哪个任务产生了这些日志？

失败的是哪个工具？

失败前模型做了什么？

重试是否使用了相同参数？

如果多个用户同时执行任务，日志还可能互相交错。

因此，仅仅记录时间和操作名称已经不够。

我们需要给每次任务分配一个唯一标识。

这就是 Trace ID 的作用。

二、Trace ID 是什么？

Trace ID 可以理解为一次完整任务的追踪编号。

例如：

Trace ID: abc123

用户请求
   ↓
模型理解任务
   ↓
工具 A：读取文件
   ↓
工具 B：执行测试
   ↓
工具 C：上传代码
   ↓
返回结果

整条任务链上的日志都使用同一个 Trace ID。

这样，无论中间调用了多少工具，都可以通过这个编号找到相关记录。

在更完整的分布式链路追踪系统中，还会使用 Span ID。

两者区别如下：

例如，一个 AI Agent 任务可以包含多个 Span：

Trace: 8f21ab

├── Span 1：模型推理
├── Span 2：读取项目文件
├── Span 3：执行功能测试
└── Span 4：调用发布 API

如果 Span 4 发生超时，开发者就可以直接定位对应操作，而不需要从头阅读所有日志。

三、为什么 AI Agent 特别需要链路追踪？

传统 Web API 通常有相对固定的执行流程。

但 AI Agent 的执行路径可能由模型动态决定。

例如，同样是开发一个网页工具：

第一次执行可能调用 8 次工具。

第二次执行可能因为环境问题调用 25 次。

第三次执行可能在安装依赖时陷入重复尝试。

因此，AI Agent 更需要记录实际执行过程。

我认为至少应该关注四类信息。

第一，模型调用。

记录模型名称、请求耗时、Token 消耗和调用状态。

第二，工具调用。

记录工具名称、耗时、成功或失败状态。

第三，外部依赖。

例如网络 API、数据库和代码仓库接口的响应情况。

第四，任务结果。

记录最终成功、失败、阻断或结果未知的状态。

需要注意，记录这些信息并不意味着把完整的提示词、用户输入和工具输出全部保存下来。

对于可能包含个人信息或访问凭据的数据，应当遵循最小化记录原则。

四、Python 实战：实现一个简单的 Trace ID 追踪器

下面使用 Python 标准库构建一个最小示例。

不需要安装第三方依赖，也不需要调用真实大模型 API。

首先创建一个文件：

trace_demo.py

然后编写以下代码：

import contextvars
import json
import time
import uuid

# 当前任务的 Trace ID
trace_id = contextvars.ContextVar(
    "trace_id",
    default="-"
)


def log_event(event, **fields):
    record = {
        "trace_id": trace_id.get(),
        "event": event,
        **fields
    }

    print(
        json.dumps(
            record,
            ensure_ascii=False
        )
    )


def run_step(name, function):
    start = time.perf_counter()

    log_event(
        "step_start",
        step=name
    )

    try:
        result = function()

        duration = (
            time.perf_counter() - start
        ) * 1000

        log_event(
            "step_end",
            step=name,
            status="success",
            duration_ms=round(duration, 2)
        )

        return result

    except Exception as error:
        duration = (
            time.perf_counter() - start
        ) * 1000

        log_event(
            "step_end",
            step=name,
            status="failed",
            duration_ms=round(duration, 2),
            error_type=type(error).__name__
        )

        raise


def run_agent_task():
    token = trace_id.set(
        uuid.uuid4().hex
    )

    try:
        log_event("task_start")

        data = run_step(
            "parse_input",
            lambda: {"topic": "AI Agent"}
        )

        answer = run_step(
            "mock_model",
            lambda: f"关于{data['topic']}的模拟回答"
        )

        log_event(
            "task_end",
            status="success"
        )

        return answer

    finally:
        trace_id.reset(token)


if __name__ == "__main__":
    result = run_agent_task()
    print("最终结果：", result)

这段代码实现了几个核心功能：

1. 为每次任务生成独立的 Trace ID。

2. 使用 contextvars 保存当前任务标识。

3. 记录每个步骤的开始和结束。

4. 统计工具执行耗时。

5. 发生异常时记录异常类型。

6. 输出 JSON 格式的结构化日志。

这里使用的是同步演示程序，尚未实现完整的 Span ID 层级关系或跨服务传播协议。

五、运行后能看到什么？

执行：

python trace_demo.py

正常情况下，会输出类似下面的日志：

{"trace_id":"abc123","event":"task_start"}
{"trace_id":"abc123","event":"step_start","step":"parse_input"}
{"trace_id":"abc123","event":"step_end","step":"parse_input","status":"success","duration_ms":0.01}
{"trace_id":"abc123","event":"step_start","step":"mock_model"}
{"trace_id":"abc123","event":"step_end","step":"mock_model","status":"success","duration_ms":0.02}
{"trace_id":"abc123","event":"task_end","status":"success"}

上面的 Trace ID 和耗时仅用于展示输出结构，实际运行时会不同。

与普通日志相比，结构化日志有一个明显优势：

它更容易被程序读取和分析。

例如，我们可以根据 trace_id 找出属于同一个任务的日志，根据 status 筛选失败操作，再利用 duration_ms 分析耗时。

如果未来接入日志收集平台，也不需要重新设计所有日志内容。

六、如何定位 AI Agent 的重复工具调用？

假设某次 AI Agent 任务产生以下记录：

<text>以上为假设数据。</text>

通过这张表，可以立即发现：

install_dependency 调用了 6 次，而且占用了大量时间。

接下来，就可以进一步检查这 6 次调用的错误类型和参数差异。

如果多次错误完全相同，就需要判断 Agent 是否陷入了无效重试。

如果每次失败都是因为不同的缺失依赖，那么可以考虑在流程开始时集中检查系统依赖，减少逐个安装的开销。

这说明：

链路追踪不仅能够帮助排查失败，还可以找到自动化任务中的效率瓶颈。

七、除了耗时，还应该记录哪些指标？

对于生产环境中的 AI Agent，可以考虑记录以下指标。

其中，P95 表示大约 95% 的观测值不超过对应数值。

例如，一个工具的平均耗时只有 1 秒，但 P95 达到 15 秒，就说明部分请求可能明显偏慢。

对于用户体验来说，这种长尾延迟同样值得关注。

另外，需要将“工具调用成功率”和“最终任务完成率”分开统计。

因为所有工具都正常执行，也不一定意味着最终结果符合用户要求。

八、为什么日志不能记录所有内容？

在 AI Agent 开发中，记录完整调用内容虽然方便排查，但也可能产生安全风险。

例如：

• 模型上下文中包含用户个人信息。

• 工具参数中包含 API Token。

• 终端输出中包含临时访问密钥。

• 文件路径暴露内部项目结构。

• 数据库返回结果包含敏感业务数据。

因此，建议使用白名单方式选择日志字段。

例如，只记录：

{
  "trace_id": "abc123",
  "tool": "publish_work",
  "status": "failed",
  "duration_ms": 1200,
  "error_type": "TimeoutError"
}

而不要直接记录完整的认证请求。

对于错误定位，可以保留服务端请求 ID、脱敏错误码、调用阶段等信息。

如果确实需要记录详细载荷，也应当设置明确的访问权限、保留期限和敏感数据处理机制。

日志的目标是帮助定位问题，而不是把所有运行数据无差别地保存下来。

九、如何从简单日志升级到完整链路追踪？

对于初学者或小型项目，前面的 JSON 日志已经能够提供一定帮助。

但如果系统涉及多个服务，例如：

前端页面
    ↓
Agent 服务
    ↓
模型 API
    ↓
工具执行服务
    ↓
云平台 API

仅靠单进程里的 Trace ID 变量就不够了。

此时需要将追踪上下文在不同服务之间传递。

一种常见的工程方案是使用 OpenTelemetry。

它提供了用于采集和传播 Trace、Metric 等遥测数据的标准化工具和接口。

在完整的系统中，可以为模型调用、工具执行、数据库操作和外部 HTTP 请求分别建立 Span。

之后使用支持链路追踪的后端查看完整执行过程。

但并不是所有项目一开始都需要引入完整的可观测平台。

对于简单的 AI 工具，先把日志结构化、保留任务标识和必要的执行指标，通常是更容易落地的起点。

十、总结

随着 AI Agent 能够执行越来越复杂的任务，开发者面临的一个新问题是：

当 Agent 自动调用了大量工具后，我们是否还能清楚地知道它做过什么？

如果只有自然语言执行报告和零散的终端日志，就很难快速定位故障。

通过 Trace ID、结构化日志和工具耗时统计，可以为 AI Agent 建立基础的追踪能力。

本文主要总结了几个实践原则：

1. 为每次任务生成唯一 Trace ID。

2. 为关键工具调用记录执行状态和耗时。

3. 利用结构化日志定位失败和重复调用。

4. 区分工具调用成功与最终业务成功。

5. 避免在日志中保存密钥和敏感数据。

6. 根据项目复杂度逐步引入完整链路追踪方案。

我认为，AI Agent 的工程化不仅是让模型能够执行更多操作，也包括让开发者能够理解和控制这些操作。

真正可靠的 AI Agent，不应该是一个只会自动执行任务的黑盒，而应该是一个能够被观察、被定位问题、被持续优化的系统。