需对请求生命周期各阶段分段耗时采集:一、用内置trace面板快速定位开发瓶颈;二、自定义中间件划分六阶段计时并写入日志;三、监听数据库事件统计sql耗时分布;四、用debug门面打点实现代码块级细粒度分析;五、注入x-response-time头并聚合分析p50/p90/p99。

如果您在ThinkPHP应用中观察到部分请求响应明显延迟,但无法判断耗时集中于框架启动、数据库查询、模板渲染还是业务逻辑环节,则需对请求生命周期各阶段进行分段耗时采集。以下是实现请求耗时分布统计分析的多种方法:
一、使用内置Trace调试面板(开发环境)
该方式依赖ThinkPHP调试模式,在HTML页面响应中自动注入可视化性能面板,展示SQL执行、文件加载、模板解析、内存占用及各阶段耗时占比,适用于快速定位开发阶段瓶颈。
1、确认config/app.php中app_debug配置值为true。
2、确保请求头包含Accept: text/html,Postman或curl需手动添加此头,否则面板不渲染。
3、访问任意HTML页面(非API接口),页面底部将显示Trace面板,其中总耗时下方按模块展开各阶段时间分布,SQL查询耗时与模板渲染耗时可直接对比。
二、自定义中间件分段计时
通过在请求进入、控制器执行前后、响应发送前插入时间戳,可将整个生命周期划分为“框架初始化→路由匹配→中间件执行→控制器调用→视图渲染→响应发送”六个逻辑段,每段耗时独立记录并写入日志。
1、创建中间件App\Middleware\TimingMiddleware.php,在handle()方法开头记录$start = microtime(true)。
2、在$request->filter()之后、$response = $next($request)之前记录$afterRoute = microtime(true)。
3、在$response->send()调用前记录$beforeSend = microtime(true)。
4、构造结构化数组:['route' => $afterRoute - $start, 'controller' => $afterController - $afterRoute, 'view' => $beforeSend - $afterController],并写入日志文件,字段名统一为duration_ms。
三、监听数据库事件捕获SQL耗时分布
数据库查询常是耗时主因,但单条SQL慢不等于整体慢;通过Db::listen()捕获所有查询及其毫秒级耗时,可统计慢SQL占比、平均查询耗时、最大单次查询耗时等分布指标。
1、在app/bootstrap.php或App\Providers\AppServiceProvider@register()中调用Db::listen(function ($sql, $time, $explain) { ... })。
2、在回调内将$time(单位:毫秒)与当前请求URI、时间戳一起存入临时数组$_SESSION['db_times'][] = $time(仅调试环境启用)。
3、响应发送前遍历该数组,计算count、array_sum、max、array_filter($times, fn($t) => $t > 500),输出慢查询数量/总查询数及慢查询平均耗时。
四、利用Debug门面进行代码块级耗时打点
当怀疑某段循环、远程调用或文件处理逻辑拖慢响应时,可在控制器或模型中手动插入多个Debug::remark()标记,实现细粒度耗时切片,避免全局统计掩盖局部热点。
1、在业务逻辑起始处调用Debug::remark('logic_start')。
2、在数据库查询后调用Debug::remark('db_end'),在HTTP请求返回后调用Debug::remark('http_end'),在循环结束时调用Debug::remark('loop_end')。
3、依次调用Debug::time('logic_start', 'db_end')、Debug::time('db_end', 'http_end')、Debug::time('http_end', 'loop_end'),结果以毫秒为单位返回,各段差值即为对应环节真实耗时。
五、注入X-Response-Time响应头并聚合分析
在每次响应头部写入总耗时,配合Nginx日志中的$upstream_response_time字段,可交叉验证PHP层真实执行时间,并用于后续离线统计各URI的P50/P90/P99耗时分布。
1、在App\Providers\AppServiceProvider@boot()中监听think\ResponseSend事件。
2、从$_SERVER['REQUEST_TIME_FLOAT']获取起点,在事件回调内取当前microtime(true)为终点,计算差值$cost。
3、调用$response->header('X-Response-Time', round($cost * 1000, 2) . 'ms'),确保该头出现在所有响应中。
4、配置Nginx日志格式,新增字段$sent_http_x_response_time,使用Logstash或awk脚本提取各URI的耗时列表,运行sort -n | awk '{a[NR]=$1} END {print a[int(NR*0.5)], a[int(NR*0.9)], a[int(NR*0.99)]}'获取分布值。
php免费学习视频:立即使用
踏上前端学习之旅,开启通往精通之路!从前端基础到项目实战,循序渐进,一步一个脚印,迈向巅峰!











