ThinkPHP3.2运行时间记录不准,是因为计时终点未覆盖模板渲染、输出缓冲刷新及HTTP响应发送等SAPI层收尾阶段,仅依赖$GLOBALS['_beginTime']导致结果偏短20ms~200ms;正确做法是在index.php末尾用register_shutdown_function捕获进程退出前真实耗时,误差可控制在±2ms内。

ThinkPHP3.2运行时间记录不准,是因为直接用microtime(true) - $GLOBALS['_beginTime']计算时,起点虽在框架入口已埋下,但实际执行路径中存在未被覆盖的耗时环节——比如模板渲染、输出缓冲结束、HTTP响应发送等阶段完全游离于该计时范围之外,导致最终显示值比真实请求耗时短20ms~200ms不等。
根本原因:计时起点与终点不匹配
框架在ThinkPHP.php开头设置$GLOBALS['_beginTime'] = microtime(TRUE),这确实是整个应用生命周期的最早可捕获时刻。但终点常被误设在控制器末尾或display()调用后,此时:
① 模板引擎仍在解析变量、执行{:get_runtime()}等函数;
② 输出缓冲(output buffering)尚未flush()或ob_end_flush();
立即学习“PHP免费学习笔记(深入)”;
③ PHP脚本虽已退出,但Web服务器(如Apache/Nginx)仍需将响应体打包、压缩、写入socket——这部分时间彻底丢失。
【$GLOBALS['_beginTime']只覆盖PHP用户态启动,不包含SAPI层收尾】。这是所有基于该变量的手动计时必然失准的核心前提。
常见错误写法及后果
方法一:在模板里直接写<?php echo round(microtime(true)-$GLOBALS['_beginTime'],4); ?>s
这行代码执行时,模板已编译完成、变量已替换,但响应头可能未发出、内容尚未真正送达浏览器。实测偏差常达80ms以上,尤其开启Gzip或使用Nginx fastcgi_buffer时更严重。
方法二:在Common/function.php中封装get_runtime()并在display()后调用
错在display()只是把渲染结果存入输出缓冲,并非发送动作。缓冲区大小、是否自动刷新、是否启用ob_gzhandler都会让这个“终点”漂移。
正确埋点位置:必须卡在SAPI关机钩子
第一步:在应用入口文件index.php末尾添加关机函数
register_shutdown_function(function() {
$duration = round((microtime(true) - $GLOBALS['_beginTime']) * 1000, 2);
error_log('[RUNTIME] ' . $_SERVER['REQUEST_URI'] . ' → ' . $duration . "ms\n", 3, RUNTIME_PATH . 'log/runtime.log');
});
第二步:确保RUNTIME_PATH可写,且日志目录存在
第三步:访问任意接口,检查Runtime/Log/runtime.log中记录的时间值
此方式能捕获到PHP进程真正退出前的最后一刻,涵盖模板渲染、缓冲输出、异常终止等全部路径,误差稳定控制在±2ms内。注意不要在register_shutdown_function里调用echo或header(),会触发警告并中断记录。



















