Stopwatch 必须打在 Doctrine 查询执行边界上,即在 getResult() 或 executeQuery() 调用前后 start/lap,而非整个方法边界;需用 'database' 等 category 分组,并结合 Profiler 的 Stopwatch 标签页分析耗时分布,避免循环内高频启停。

Stopwatch 必须打在 Doctrine 执行边界上
Stopwatch 不是测整个控制器方法的,它要卡在 $em->getRepository()->find() 或 $qb->getQuery()->getResult() 的真实执行点。否则你看到的是“PHP 处理 + SQL 执行 + 对象映射”混在一起的耗时,根本分不清慢在哪。
常见错误是只在方法开头 $stopwatch->start('user_load')、结尾 $stopwatch->stop('user_load')——这掩盖了内部差异,比如 800ms 里可能只有 120ms 是 SQL 执行,剩下全是循环映射或 Twig 渲染。
- 正确做法:在查询语句真正发出前 start,在结果返回后 lap 或 stop
- 对
getResult()打点:$stopwatch->start('db_user_list'); $users = $query->getResult(); $stopwatch->lap('db_user_list'); - 对原生 SQL 查询也一样:
$stopwatch->start('raw_sql_count'); $conn->executeQuery(...); $stopwatch->lap('raw_sql_count');
用 category 分组避免日志干扰
Stopwatch 支持按 category 区分逻辑域,不加 category 容易被其他打点淹没。Doctrine 相关耗时统一归到 database 类别,调试时可直接在 Profiler 的 “Stopwatch” 标签页筛选查看。
- 启动时指定 category:
$stopwatch->start('user_repo_find', 'database') - 第三方 API 调用用
api,模板渲染用twig,严格隔离便于横向对比 - 不要为每个
findOneBy()都单独命名,高频调用建议合并统计(如db_user_fetch统计所有用户单查)
结合 Profiler 的 Stopwatch 标签页交叉验证
Stopwatch 数据只有在 %kernel.debug% === true 且 Profiler 启用时才可见。光写代码不看 Profiler 就等于没埋点。
- 访问页面后点击底部工具栏 → “Stopwatch” 标签页 → 点击 “database” category 过滤
- 重点关注
duration列:超过 100ms 的条目要立刻点开,看是否对应 N+1 中的某次重复查询 - 如果某
db_user_load出现 15 次,每次 80–120ms,基本锁定是循环内调用 Repository 导致的 N+1,不是单条 SQL 慢
别在循环里高频 start/stop
Stopwatch 本身有开销,尤其在 for 循环里反复调用 start() 和 stop() 会显著拖慢性能,甚至让原本 200ms 的请求变成 2s。
- 循环内只做一次 start,用
lap()记录各次迭代耗时,最后再 stop - 更推荐改用计数器逻辑:记录总次数 + 总耗时,算平均值,避免干扰主线程
- 生产环境务必关闭 Stopwatch(Profiler 默认不启用),开发环境也仅在复现问题时临时开启
getResult() 前后的耗时差,往往比 SQL 执行本身还长,那是 Doctrine 映射实体的代价。


















