PHP failed to ptrace(PEEKDATA) pid 1918: Input/output error (5) 解決

今天網(wǎng)站后臺(tái)出現(xiàn)504,前臺(tái)出現(xiàn)此錯(cuò)誤信息：

[14-May-2016 12:03:44] WARNING: [pool www] child 25347, script '/usr/data/ckl-sapi/baiduNotify.php' (request: "POST /baiduNotify.php") executing too slow (10.818417 sec), logging
[14-May-2016 12:03:44] WARNING: [pool www] child 25269, script '/usr/data/ckl-sapi/baiduNotify.php' (request: "POST /baiduNotify.php") executing too slow (10.819982 sec), logging
[14-May-2016 12:03:44] WARNING: [pool www] child 25268, script '/usr/data/ckl-sapi/baiduNotify.php' (request: "POST /baiduNotify.php") executing too slow (12.392415 sec), logging
[14-May-2016 12:04:14] WARNING: [pool www] child 25369, script '/usr/data/ckl-sapi/baiduNotify.php' (request: "POST /baiduNotify.php") executing too slow (10.802581 sec), logging
[14-May-2016 12:17:33] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 12 total children
[14-May-2016 12:17:34] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 16 children, there are 0 idle, and 17 total children
[14-May-2016 12:17:35] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 32 children, there are 4 idle, and 22 total children

從信息看，應(yīng)該是php進(jìn)程較少：

經(jīng)過(guò)查看發(fā)現(xiàn)進(jìn)程確實(shí)很少，解決如下：

修改配置文件增加進(jìn)程

vim /usr/local/php/etc/php-fpm.ini
pm = dynamic  #動(dòng)態(tài)模式
pm.max_children = 512  #靜態(tài)開(kāi)啟的進(jìn)程數(shù)
pm.start_servers = 128 #動(dòng)態(tài)模式的起始進(jìn)程數(shù)
pm.min_spare_servers = 128 #動(dòng)態(tài)模式最小進(jìn)程數(shù)
pm.max_spare_servers = 512 #動(dòng)態(tài)模式最大進(jìn)程數(shù)

數(shù)值設(shè)置，參考自己的實(shí)際硬件配置，可以參考 內(nèi)存/20M 來(lái)計(jì)算。

重新加載進(jìn)程

/etc/init.d/php-fpm reload

等待了一點(diǎn)時(shí)間發(fā)現(xiàn)又報(bào)錯(cuò)：

[14-May-2016 12:21:29] ERROR: failed to ptrace(PEEKDATA) pid 27077: Input/output error (5)
[14-May-2016 12:22:13] WARNING: [pool www] child 27024, script '/usr/data/ckl-backend/index.php' (request: "GET /index.php") executing too slow (10.384578 sec), logging
[14-May-2016 12:22:13] ERROR: failed to ptrace(PEEKDATA) pid 27024: Input/output error (5)
[14-May-2016 12:23:33] WARNING: [pool www] child 26924, script '/usr/data/ckl-backend/index.php' (request: "GET /index.php") executing too slow (10.986032 sec), logging
[14-May-2016 12:23:33] ERROR: failed to ptrace(PEEKDATA) pid 26924: Input/output error (5)
[14-May-2016 12:26:29] WARNING: [pool www] child 1918, script '/usr/data/ckl-backend/index.php' (request: "GET /index.php") executing too slow (10.408103 sec), logging
[14-May-2016 12:26:29] ERROR: failed to ptrace(PEEKDATA) pid 1918: Input/output error (5)

查找資料如下：

It usrears you have request_slowlog_timeout enabled. This normally takes any request longer than N seconds, logs that it was taking a long time, then logs a stack trace of the script so you can see what it was doing that was taking so long.

In your case, the stack trace (to determine what the script is doing) is failing. If you're running out of processes, it is because either:

After php-fpm stops the process to trace it, the process fails to resume because of the error tracing it

The process is resuming but continues to run forever.

My first guess would be to disable request_slowlog_timeout. Since it's not working right, it may be doing more harm than good. If this doesn't fix the issue of running out of processes, then set the php.ini max_execution_time to something that will kill the script for sure.

大概說(shuō)是設(shè)置了slowlog和php的最大執(zhí)行時(shí)間。

解決：

禁止slowlog

vim php-fpm.conf
;request_slowlog_timeout = 10s
;slowlog = /usr/local/log/php-fpm/ckl-slow.log

修改最大執(zhí)行時(shí)間：

vim php.ini
max_execution_time = 60

重啟進(jìn)程：

/etc/init.d/php-fpm reload

等待一段時(shí)間，發(fā)現(xiàn)一切正常。

查看TCP連接相關(guān)：

# ss -s
Total: 287 (kernel 380)
TCP:   597 (estab 122, closed 563, orphaned 0, synrecv 0, timewait 5630/0), ports 577

Transport Total     IP        IPv6
*         380       -         -        
RAW       0         0         0        
UDP       1         1         0        
TCP       34        34        0        
INET      35        35        0        
FRAG      0         0         0

同時(shí)發(fā)現(xiàn)系統(tǒng)TIMEWAIT 較多，所以?xún)?yōu)化了一些內(nèi)核相關(guān)參數(shù)

# sysct -p
bash: sysct: command not found
[root@sapi etc]# sysctl -p
net.ipv4.ip_forward = 0
net.ipv4.conf.default.rp_filter = 1
net.ipv4.conf.default.accept_source_route = 0
net.ipv4.tcp_max_tw_buckets = 6000
net.ipv4.ip_local_port_range = 1024 65000
net.ipv4.tcp_tw_recycle = 1
net.ipv4.tcp_tw_reuse = 1
net.ipv4.tcp_syncookies = 1
net.ipv4.tcp_max_orphans = 262144
net.ipv4.tcp_keepalive_time = 1200
net.ipv4.tcp_keepalive_intvl = 30
net.ipv4.tcp_keepalive_probes = 3
net.ipv4.tcp_synack_retries = 1
net.ipv4.tcp_syn_retries = 2
net.ipv4.tcp_max_orphans = 262144
net.ipv4.tcp_max_syn_backlog = 262144
net.ipv4.tcp_timestamps = 0
net.core.rmem_max = 16777216
net.core.wmem_max = 16777216
net.ipv4.tcp_rmem = 4096 87380 4194304
net.ipv4.tcp_wmem = 4096 16384 4194304
net.core.wmem_default = 8388608
net.core.rmem_default = 8388608
net.core.rmem_max = 16777216
net.core.wmem_max = 16777216
net.core.somaxconn = 262144
kernel.sysrq = 0
kernel.core_uses_pid = 1
kernel.msgmnb = 65536
kernel.msgmax = 65536
kernel.shmmax = 68719476736
kernel.shmall = 4294967296
vm.swappiness = 0
fs.file-max = 409600

過(guò)一陣再查看：

# ss -s
Total: 281 (kernel 362)
TCP:   520 (estab 22, closed 493, orphaned 0, synrecv 0, timewait 493/0), ports 475

Transport Total     IP        IPv6
*         362       -         -        
RAW       0         0         0        
UDP       1         1         0        
TCP       27        27        0        
INET      28        28        0        
FRAG      0         0         0