feat(agent): add ProfilingHook for opt-in iteration timing

[mohamed-elkholy95]

Summary

• Add ProfilingHook (nanobot/agent/profiling.py) — an AgentHook that logs wall-clock time per LLM iteration and tool names at DEBUG level
• Enable via NANOBOT_PROFILING=1 environment variable
• Env var is read once at AgentLoop.__init__ time — must be set before loop creation, not dynamically togglable at runtime
• Hook-only approach: no inline timing scattered across runner/memory/loop files

Changes after review

• Moved profiling import to module top level (no circular dependency)
• Reverted unrelated defensive list() copy of hooks
• Removed before_execute_tools — redundant with after_iteration which already logs tool names
• Changed _iter_t0 sentinel from 0.0 to None with guard in after_iteration
• Added tests that verify actual timing behavior via mocked perf_counter and log output assertions
• Fixed import sorting (ruff I001)

Test plan

• 7 tests: start time recording, elapsed timing with mock, tool name logging, guard for missing before_iteration, env var checks
• All 1715 tests pass (no regressions)
• ruff check clean

🤖 Generated with Claude Code

[chengyongru]

Review: feat(agent): add ProfilingHook for opt-in iteration timing

结论: Request Changes

架构方向正确——用 hook 做性能分析是干净的做法。以下几点需要修改：

1. import 位置不当（关键问题）

loop.py 中将 import 放在了 __init__ 方法体内：

from nanobot.agent.profiling import ProfilingHook, is_profiling_enabled

这是为了避免循环 import 还是有其他原因？如果没有循环依赖问题，应该放到模块顶部。即使有循环依赖问题，也应该用一个 lazy import 函数或 importlib 方案来处理，而不是在 __init__ 里直接 import。

2. list(hooks or []) 的防御性拷贝

self._extra_hooks: list[AgentHook] = list(hooks or [])

这行额外加了一个 list() 拷贝，原代码是 hooks or []。这个改动是合理的（防止外部修改传入的 list），但和 profiling 功能无关。如果需要这个改动，应该单独提交或在 PR 描述中说明。

3. is_profiling_enabled() 只在 __init__ 时检查一次

NANOBOT_PROFILING 环境变量只在 AgentLoop 初始化时读取。如果用户在运行时修改了这个环境变量，不会生效。PR 描述里提到了 "not import-time — so the env var can be set after module import"，但实际上它只是从 import-time 变成了 init-time，在 long-running process 中仍然无法动态启用/禁用。

这个设计选择本身可以接受（大多数环境变量都是启动时读取），但描述不够准确。

4. 测试不足

• test_after_iteration_runs_without_error 和 test_before_execute_tools_runs_without_error 只验证了"不抛异常"，没有验证 hook 的实际行为（比如日志输出内容、时间记录是否合理）
• 建议增加一个测试验证 after_iteration 实际记录了有意义的时间差（通过 mock time.perf_counter）

5. 没有在 PR 描述中说明 before_execute_tools 的目的

ProfilingHook 实现了 before_execute_tools，但这个方法只打印 "executing tools: [...]" 的 debug 日志。这个信息和 after_iteration 的日志有重叠（after_iteration 已经打印了 tool_names）。建议说明为什么需要两个日志点，或者考虑移除 before_execute_tools。

Nits

• self._iter_t0: float = 0.0 — 用 0.0 作为初始值是合理的，但如果 after_iteration 在 before_iteration 之前被调用，会打印一个巨大的负数。虽然不太可能发生，但加个 guard 更安全。

[chengyongru]

Review: feat(agent): add ProfilingHook for opt-in iteration timing

Verdict: Request Changes

The architectural direction is correct — using a hook for profiling is a clean approach. A few issues to address:

1. Import placement (important)

In loop.py, the import is inside the __init__ method body:

from nanobot.agent.profiling import ProfilingHook, is_profiling_enabled

Is this to avoid circular imports, or is there another reason? If there's no circular dependency, it should be at the module top level. Even if there is, consider a lazy-import function or importlib approach rather than importing directly in __init__.

2. Defensive copy unrelated to profiling

self._extra_hooks: list[AgentHook] = list(hooks or [])

The extra list() copy is a reasonable defensive measure (prevents external mutation of the passed-in list), but it's unrelated to the profiling feature. If needed, it should be a separate commit or at least called out in the PR description.

3. is_profiling_enabled() is checked only once at __init__

The NANOBOT_PROFILING env var is read only when AgentLoop initializes. The PR description says "not import-time — so the env var can be set after module import", but in practice it's only moved from import-time to init-time. In a long-running process, profiling still can't be toggled dynamically.

The design choice itself is fine (most env vars are read at startup), but the description is slightly misleading.

4. Insufficient test assertions

• test_after_iteration_runs_without_error and test_before_execute_tools_runs_without_error only verify "doesn't raise". They don't validate the hook's actual behavior (e.g., log output content, whether timing is reasonable).
• Add a test that verifies after_iteration records a meaningful elapsed time (e.g., by mocking time.perf_counter).

5. before_execute_tools purpose unclear

ProfilingHook implements before_execute_tools, but this method only logs "executing tools: [...]" at DEBUG level. This overlaps with after_iteration, which already logs tool names. Either explain why two log points are needed, or consider removing before_execute_tools.

Nits

• self._iter_t0: float = 0.0 — using 0.0 as a sentinel is fine, but if after_iteration were somehow called before before_iteration, it would log a huge negative number. A guard would be safer.