I/O Error with PHP5-FPM, ptrace(PEEKDATA) failed

Question

I got a lot of these:

[NOTICE] child 19214 stopped for tracing 
[NOTICE] about to trace 19214 
[ERROR] ptrace(PEEKDATA) failed: Input/output error (5) 
[NOTICE] finished trace of 19214 
[WARNING] [pool www] child 19208, script 'blahblah.php' executing too slow (30.041419 sec), logging 
[NOTICE] child 19208 stopped for tracing 
[NOTICE] about to trace 19208 
[ERROR] ptrace(PEEKDATA) failed: Input/output error (5) 
[NOTICE] finished trace of 19208 
[WARNING] [pool www] child 19218, script 'blahblah.php' executing too slow (30.035029 sec), logging 

And when php reaches max children (at least I presume that's the case) it stops "working"... now I know I can increase max_children (currently set to 9) but there's a way to stop php from "dying"?

I'm on a VPS with 1 core and 512 MB of RAM (PHP5-FPM 5.4.4 + APC 3.1.10).

---

After disabling the slow log I'm now getting:

WARNING: [pool www] child 1684 exited on signal 15 (SIGTERM) after 77.802376 seconds from start
NOTICE:  [pool www] child 1694 started
WARNING: [pool www] child 1377, script 'blahblah.php' (request: "GET /blahblah.php") execution timed out (38.291440 sec), terminating
WARNING: [pool www] child 1377 exited on signal 15 (SIGTERM) after 2750.295279 seconds from start
NOTICE:  [pool www] child 1696 started
WARNING: [pool www] child 1722, script 'blahblah.php' (request: "POST /blahblah.php") execution timed out (39.653910 sec), terminating
WARNING: [pool www] child 1722 exited on signal 15 (SIGTERM) after 793.953090 seconds from start

I think it's not normal that these scripts are so slow.. You suggest to play with max_execution_time?

Solution 1

It appears 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:

1. After php-fpm stops the process to trace it, the process fails to resume because of the error tracing it
2. 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.

Solution 2

A more valid explanation to the ptrace(PEEKDATA) failed seems to be this -

... the worker is free to go when the master is determining slow execution. When stopping to be traced, it may have completed that execution and is in any stage serving another request, so the tracer gets the chance of failure or worse, dumping out the stack of an irrelevant execution.

from FPM Slowlog sucks which explains the entire mess in much greater detail.