PHP-FPM-failed to ptrace(PEEKDATA) pid 123: Input/output error

If you're running PHP-FPM you can see these kind of errors in your PHP-FPM logs.

$ tail -f php-fpm.log
[29-Dec-2015 23:03:10] NOTICE: child 11667 stopped for tracing
[29-Dec-2015 23:03:10] NOTICE: about to trace 11667
[29-Dec-2015 23:03:10] ERROR: failed to ptrace(PEEKDATA) pid 11667: Input/output error (5)
[29-Dec-2015 23:03:10] NOTICE: finished trace of 11667

So, what do they mean?

They are the result of a configuration directive and a flaw in the way PHP-FPM handles requests.

Slowlog stacktraces

If your PHP-FPM configuration contains the request-slowlog-timeout parameter, the PHP-FPM master process will attempt to get a stacktrace of the running process when it exceeds that timeout.

It's a great way to identify 'slow' processes and peek inside the request, to see what happened at that time. It mostly works, too.

On busy servers however, you can see the logs start to fill like this.

[29-Dec-2015 23:03:10] ERROR: failed to ptrace(PEEKDATA) pid 11667: Input/output error (5)
[29-Dec-2015 23:04:10] ERROR: failed to ptrace(PEEKDATA) pid 11668: Input/output error (5)
[29-Dec-2015 23:05:12] ERROR: failed to ptrace(PEEKDATA) pid 11668: Input/output error (5)
...

Avoiding these errors in the logs

First, let me start by saying it's a cosmetic issue: PHP itself isn't having problems. It's not even affected by this. But it can't log the stacktrace that was requested, so it reports this error.

If this bothers you, you can disable it by commenting the following 2 parameters in your PHP-FPM logs:

;slowlog = /var/log/php-fpm/slow.log
;request_slowlog_timeout = 5s

(you comment them by adding a semicolon in front of the line and restarting your PHP-FPM daemon)

That will make the errors disappear. It also stops any kind of slowlogging from ever happening.

What's causing the PEEKDATA error?

I already mentioned it's a result of a flaw in how PHP handles requests. This is explained in more detail here . The gist of it is:

... 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.

FPM slow log sucks

In other words: when PHP's slowlog tries to get an actual stacktrace, it may send a signal to the master process which in turn finds the child process that is slow (which it fork() 'd). However, by the time that happens, the child may have already finished its request and started serving another one.

Or it's not even handling a request at all, because it's finished and waiting for a new incoming request.

This leads to A) a stacktrace of the wrong process or B) the error you see above, a PEEKDATA error because there was no data to peek into.

So take that into account when reviewing PHP FPM slowlogs, too.