API返回延迟,FPM重启后恢复之后又重现 问题解决方案

背景

重启FPM

重新分析定位问题

日志定位

查看nginx日志

  nginx 日志 格式，添加详细的 各个时间段的相应

  log_format main '$remote_addr [$host] - $remote_user [$time_local] $request upstream_response_time: $upstream_response_time
   request_time: $request_time upstream_connect_time: $upstream_connect_time upstream_header_time:$upstream_header_time
  $status $body_bytes_sent $http_referer $http_user_agent ';

  添加了
        upstream_response_time
        upstream_connect_time
        upstream_header_time

  含义如下:
        request_time
              nginx服务，从发起请求的客户端获取到第一个字节开始，到返回给客户端最后一个字节，日志写入文件后，所经过的时间。单位为秒。
        upstream_connect_time
              nginx服务，从与上游服务开始建立连接，到连接建立成功，所经过的时间。单位为秒。
        upstream_header_time
              nginx服务，从与上游服务开始建立连接，到接收到响应返回头的第一个字节，所经过的时间。单位为秒。
        upstream_response_time
              nginx服务，从与上游服务开始建立连接，到接收完响应返回的最后一个字节，所经过的时间。单位为秒

        ![](https://img2020.cnblogs.com/blog/385704/202007/385704-20200728162028181-1944819290.jpg
        [参考链接](https://juejin.im/post/5d26eb16f265da1bd522f8d6)

  程序真正的运行时间 = $upstream_header_time - $upstream_connect_time
  $request_time 中包含了数据返回时间
  $request_time 中包含了日志打印的时间

  nginx 日志显示
  xxx [xxx] - - [11/Jul/2020:13:36:45 +0000] POST /xxx/xxx HTTP/1.1 upstream_response_time: 3.048 request_time: 3.048 upstream_connect_time: 0.000 upstream_header_time:3.048 200 98 - Dalvik/2.1.0 (Linux; U; Android 8.1.0; vivo 1808 Build/O11019)
  从中可以看出确实是 上游服务FPM 返回延迟了

配置 FPM 慢日志

lowlog = /xxx/www-slow.log request_slowlog_timeout = 1s

文件描述符

思考

strace调试跟踪

问题修复

总结