善用php-fpm日志定位性能问题

本文主要介绍linux环境下的nginx/tengine+php环境部署下的php-fpm日志开启及协助进行性能问题定位

1. 了解nginx、fastcgi、php-fpm、php之间的关系

一、fastCGI？

　　fastCGI是由CGI（common gateway interface，通用网关接口）发展而来，是http服务器（nginx、apache）和动态脚本语言（php）之间的通信接口。记住，fastCGI只是一个接口。

　　fastCGI的优点：fastCGI采用C/S结构，可以将http服务器和动态脚本解析服务器分离（二者可以部署在不同的服务器上），让http服务器专一处理静态请求和转发动态请求到脚本解析服务器；脚本解析服务器则专一处理动态脚本的请求。

 

二、nginx+fastCGI

　　nginx不支持对外部程序的直接调用或者解析，必须通过fastCGI进行调用。nginx收到CGI请求之后，fastCGI接口在脚本解析服务器上，启动一个或者多个守护进程对动态脚本进行解析。

 

三、php-fpm

　　fastCGI进程管理器/引擎：即对动态脚本进行实际解析的守护进程，由fastCGI启动。这里，php-fpm就是支持解析php的一个fastCGI进程管理器/引擎。

 

总结：

　　fastCGI是nginx和php之间的一个通信接口，该接口实际处理过程通过启动php-fpm进程来解析php脚本，即php-fpm相当于一个动态应用服务器，从而实现nginx动态解析php。因此，如果nginx服务器需要支持php解析，需要在nginx.conf中增加php的配置：将php脚本转发到fastCGI进程监听的IP地址和端口（php-fpm.conf中指定）。同时，php安装的时候，需要开启支持fastCGI选项，并且编译安装php-fpm补丁/扩展，同时，需要启动php-fpm进程，才可以解析nginx通过fastCGI转发过来的php脚本。

1. Php-fpm日志分类

由上述介绍可以比较清晰的了解，php的所有请求都是通过php-fpm进行的，因此我们除了关注php自身的日志外，重点需要关注php-fpm的相关日志，才可以更加清晰和直观的了解php的实际运行过程，php-fpm的相关日志也是本文介绍的重点。

Php-fpm的日志分两类：两个error.log和一个slow.log，下面针对这两个log分别作说明

1. 1. php-fpm的日志配置

第一步：通过命令find / -name php-fpm.conf 查找php-fpm的主配置文件位置

第二步：通过vim编辑该配置文件，开启error.log,设置如下（可根据实际需要更改log_level）

 

 

第三步：在当前主配置文件中查找子配置文件（通常在配置文件开头，可以搜索include）

 

第四步：打开子配置文件

 

第五步：打开该自配置文件中的error_log 和 slow_log

 

 

上述设置了log的位置及请求响应超时时间为2s，即会将响应时间超过2s的请求记录至log中。

上述设置完成之后在/var/log/php-fpm目录下可以看到三个日志文件:

 

1. 1. php-fpm的日志作用说明

    针对error.log

其中error.log的作用是记录php-fpm自身服务的启动记录，但是当打开了request_slowlog_timeout的相关配置后，超过request_slowlog_timeout时间参数的请求也同样会记录至error.log文件中，我们可以通过这里记录的超时请求与压测中实际发现的请求作对比，进一步缩小实际超时的请求。如下为一个error.log的示例

 

从上述示例中可以看到，日志中记录了慢请求实际去请求的文件及当前请求的线程id

    针对www-error.log

该文件主要是记录php代码在运行中发生的错误，并可以定位到具体类和具体的代码行数。当php代码出现问题时可以在该日志文件中找到出问题的代码

如手动编写一段有问题的php代码：

 

在前端页面进行一次调用，发现页面展示空白，此时查找www-error.log，可以看到如下错误提示：

 

即提示/data/nginx/html/test.php 文件在第2行存在未定义的内容phpinfo。

 

我们修改第2行代码为下面的代码，前段页面即恢复正常

 

在放一个xx项目的www-error.log的内容，方便大家参考理解：

 

    针对www-slow.log

php-fpm慢日志slowlog设置可以让开发者和测试很好的查找哪些php进程速度过慢而导致的网站问题，方便的找到问题的所在。该方法同样适用于排查nginx的500、502问题根源，当nginx收到如上错误码时，可以确定后端php-fpm解析php出了某种问题，比如，执行错误，执行超时。

慢日志会记录下进程号，脚本名称，具体哪个文件哪行代码的哪个函数执行时间过长。记录比较详细。

我们以xx项目的一个www-slow.log为例进行说明

 

在该日志中第一行为进程id

第二行为请求入口文件

后面的内容按照顺序依次为超时请求所调用的方法名及方法在代码中的详细位置，可以看出记录是很清晰的

 

2.3php-fpm的日志使用方法（以压测php程序做说明）

1、在做性能测试的过程我们会对性能场景进行压测，从而初步判断哪个场景有问题

2、将有问题的场景可以单独拿出来进行压测

3、设置php-fpm的slow日志，将请求超时时间先设置较大的值（数据参考根据超时明显的transaction的90% time）

4、然后结合上面介绍的三个日志，找出慢请求和报错请求（慢请求也可以通过lr自带的分析工具进行提取）

5、针对报错的请求，如果是程序代码问题，可以在www-error.log中直接看到报错的代码位置，如果是服务问题，则需要将重点转向监控服务（后期有相关文档介绍服务的监控和排错）

6、针对慢请求，则可以在www-slow.log中根据请求入口，提取慢请求所调用的函数及顺序，交由开发做后续优化。

7、上述步骤完成之后，在进一步缩小请求超时时间，重新上述3~6的步骤。知道所有的transaction降至期望的响应时间范围内为止。

附录：

php-fpm.conf重要参数详解

pid = run/php-fpm.pid

#pid设置，默认在安装目录中的var/run/php-fpm.pid，建议开启

 

error_log = log/php-fpm.log

#错误日志，默认在安装目录中的var/log/php-fpm.log

 

log_level = notice

#错误级别. 可用级别为: alert（必须立即处理）, error（错误情况）, warning（警告情况）, notice（一般重要信息）, debug（调试信息）. 默认: notice.

 

emergency_restart_threshold = 60

emergency_restart_interval = 60s

#表示在emergency_restart_interval所设值内出现SIGSEGV或者SIGBUS错误的php-cgi进程数如果超过 emergency_restart_threshold个，php-fpm就会优雅重启。这两个选项一般保持默认值。

 

process_control_timeout = 0

#设置子进程接受主进程复用信号的超时时间. 可用单位: s(秒), m(分), h(小时), 或者 d(天) 默认单位: s(秒). 默认值: 0.

 

daemonize = yes

#后台执行fpm,默认值为yes，如果为了调试可以改为no。在FPM中，可以使用不同的设置来运行多个进程池。 这些设置可以针对每个进程池单独设置。

 

listen = 127.0.0.1:9000

#fpm监听端口，即nginx中php处理的地址，一般默认值即可。可用格式为: 'ip:port', 'port', '/path/to/unix/socket'. 每个进程池都需要设置.

 

listen.backlog = -1

#backlog数，-1表示无限制，由操作系统决定，此行注释掉就行。backlog含义参考：http://www.3gyou.cc/?p=41

 

listen.allowed_clients = 127.0.0.1

#允许访问FastCGI进程的IP，设置any为不限制IP，如果要设置其他主机的nginx也能访问这台FPM进程，listen处要设置成本地可被访问的IP。默认值是any。每个地址是用逗号分隔. 如果没有设置或者为空，则允许任何服务器请求连接

 

listen.owner = www

listen.group = www

listen.mode = 0666

#unix socket设置选项，如果使用tcp方式访问，这里注释即可。

 

user = www

group = www

#启动进程的帐户和组

 

pm = dynamic #对于专用服务器，pm可以设置为static。

#如何控制子进程，选项有static和dynamic。如果选择static，则由pm.max_children指定固定的子进程数。如果选择dynamic，则由下开参数决定：

pm.max_children #，子进程最大数

pm.start_servers #，启动时的进程数

pm.min_spare_servers #，保证空闲进程数最小值，如果空闲进程小于此值，则创建新的子进程

pm.max_spare_servers #，保证空闲进程数最大值，如果空闲进程大于此值，此进行清理

 

pm.max_requests = 1000

#设置每个子进程重生之前服务的请求数. 对于可能存在内存泄漏的第三方模块来说是非常有用的. 如果设置为 '0' 则一直接受请求. 等同于 PHP_FCGI_MAX_REQUESTS 环境变量. 默认值: 0.

 

pm.status_path = /status

#FPM状态页面的网址. 如果没有设置, 则无法访问状态页面. 默认值: none. munin监控会使用到

 

ping.path = /ping

#FPM监控页面的ping网址. 如果没有设置, 则无法访问ping页面. 该页面用于外部检测FPM是否存活并且可以响应请求. 请注意必须以斜线开头 (/)。

 

ping.response = pong

#用于定义ping请求的返回相应. 返回为 HTTP 200 的 text/plain 格式文本. 默认值: pong.

 

request_terminate_timeout = 0

#设置单个请求的超时中止时间. 该选项可能会对php.ini设置中的'max_execution_time'因为某些特殊原因没有中止运行的脚本有用. 设置为 '0' 表示 'Off'.当经常出现502错误时可以尝试更改此选项。

 

request_slowlog_timeout = 10s

#当一个请求该设置的超时时间后，就会将对应的PHP调用堆栈信息完整写入到慢日志中. 设置为 '0' 表示 'Off'

 

slowlog = log/$pool.log.slow

#慢请求的记录日志,配合request_slowlog_timeout使用

 

rlimit_files = 1024

#设置文件打开描述符的rlimit限制. 默认值: 系统定义值默认可打开句柄是1024，可使用 ulimit -n查看，ulimit -n 2048修改。

 

rlimit_core = 0

#设置核心rlimit最大限制值. 可用值: 'unlimited' 、0或者正整数. 默认值: 系统定义值.

 

chroot =

#启动时的Chroot目录. 所定义的目录需要是绝对路径. 如果没有设置, 则chroot不被使用.

 

chdir =

#设置启动目录，启动时会自动Chdir到该目录. 所定义的目录需要是绝对路径. 默认值: 当前目录，或者/目录（chroot时）

 

catch_workers_output = yes

#重定向运行过程中的stdout和stderr到主要的错误日志文件中. 如果没有设置, stdout 和 stderr 将会根据FastCGI的规则被重定向到 /dev/null . 默认值: 空

 

php-fpm常见配置引起的错误及解决办法（逐渐收集中）

1. request_terminate_timeout引起的资源问题

 

request_terminate_timeout的值如果设置为0或者过长的时间，可能会引起file_get_contents的资源问题。

解决办法是request_terminate_timeout设置为10s或者一个合理的值，或者给file_get_contents加一个超时参数。

 

2、max_requests参数配置不当，可能会引起间歇性502错误：

 

设置每个子进程重生之前服务的请求数. 对于可能存在内存泄漏的第三方模块来说是非常有用的. 如果设置为 ’0′ 则一直接受请求. 等同于 PHP_FCGI_MAX_REQUESTS 环境变量. 默认值: 0.
该配置的意思是，当一个 PHP-CGI 进程处理的请求数累积到一定数目后，自动重启该进程。

 

目前我们的解决方法是，把这个值尽量设置大些，尽可能减少 PHP-CGI 重新 SPAWN 的次数，同时也能提高总体性能。在我们自己实际的生产环境中发现，内存泄漏并不明显，因此我们将这个值设置得非常大（204800）。大家要根据自己的实际情况设置这个值，不能盲目地加大。