php-fpm处理时间很快，但nginx upstream_time却很长

Question

问题描述

最近线上一个PHP服务接口出现大量超时，开始以为业务处理慢。追查原因后发现PHP的业务处理并不慢，只是nginx收到php处理结果的时间慢。
比如：php-fpm access log记录请求处理时间 90ms,nginx日志显示php处理时间1s,差了10倍,一直没找到原因。

注：php-fpm 和 nginx 处于一台服务器
nginx 监听80端口，php-fpm监听9000端口
nginx fastcgi_pass 127.0.0.1:9000

问题出现的环境背景及自己尝试过哪些方法

最近几天大量出现这个问题，服务器无压力，qps < 30
接口逻辑会查一次mysql,请求2次外网http API，整体处理时间100ms左右。
并不是每次请求都会有问题，只是最近今天出现概率变大

相关代码

php-fpm access log:
127.0.0.1 - 14/Jan/2021:18:14:31 +0800 "POST /inner/video/getMetaByVideoUrl" 200 86.510 70f03cc97ec7da080ad1537811c49e1e 2048 11.56%

注：70f03cc97ec7da080ad1537811c49e1e 是traceID 用来追踪请求, 86.510 是php-fpm记录的请求时间 单位ms

nginx acces log:
{"@timestamp":"2021-01-14T18:14:32+08:00","server_addr":"xxxx","remote_addr":"xxxx","scheme":"-","host":"image.prod.xxxx.lan","http_host":"image.prod.xxxx.lan","trace_id":"70f03cc97ec7da080ad1537811c49e1e","hostname":"dqd-image-web01.bj.ks","method":"POST","uri":"/inner/video/getMetaByVideoUrl","url":"/index.php","protocol":"HTTP/1.1","status":200,"size":82,"request_time":1.088,"upstream_time":"1.088","upstream_host":"127.0.0.1:9000","referer":"-","agent":"-","xff":"-","uuid":"-","authorization":"-","lang":"-","sign":"-","usertag":"-"}

注：upstream_time 对应nginx $upstream_response_time 1.088s

这是典型的例子 php处理时间 86ms,nginx 处理时间1s

出现这条记录的时候服务器负载0.06,无网络波动,内存磁盘均没有异常

你期待的结果是什么？实际看到的错误信息又是什么？

希望找到解决办法

Answer 1

nginx 和 PHP 在同一台机器的话,反向代理建议走 unix socket,你可以监控一下你的网络的端口使用情况.

Answer 2

可以尝试在执行完毕后手动执行 fastcgi_finish_request() 试试看