Debugging a running PHP process by attaching GDB

Tech

We are noticing that some of our requests are starting to get slow and server load increases. Checking the process list of our server, for example with htop reveals that our FPM workers are taking up all of our CPU time.

Checking the health with our basic toolset of lsof to show open network connections and strace to show syscalls does not reveal any activity. This means that the workers are spending time processing data without any externally visible activity. This could be an infinite loop or just an inefficient algorithm.

Unfortunately, we were never able to reproduce the issue ourselves, so our regular PHP debugging toolkit in our development setup doesn’t work. How can we get additional information from these processes when we catch them red-handed?

Using a system-level debugger, specifically gdb, comes to the rescue. On common Linux distributions, it is available within the aptly named package gdb. We’re using Debian Trixie for this post but have made available instructions for other distributions at the bottom.

Let’s start by installing gdb:

apt install gdb

Besides gdb, we also need debug symbols for PHP. These debug symbols allow gdb to map the processor instructions back to the statements and variables in the C source code of PHP. Since we are using Debian Trixie’s native PHP 8.4 packages, these debug symbols are available with debuginfod, which we enable by setting an environment variable:

export DEBUGINFOD_URLS="https://debuginfod.debian.net"

Setup is now finished, and we can launch gdb using the gdb command. We need the PID of one of our stuck workers, 7154 in this case, and then use attach $pid (thus attach 7154) to attach to the worker. Note that the worker will be completely frozen while we look at it in gdb; thus, the request that is currently processed might run into timeouts depending on how long the worker is stopped with gdb. Use detach after extracting all the relevant information to let it continue running from where it stopped.

The bt command allows you to retrieve a C-level backtrace, which can already provide some insight.

# gdb
(gdb) attach 7154
Attaching to process 7154
Reading symbols from /usr/sbin/php-fpm8.4...

This GDB supports auto-downloading debuginfo from the following URLs:
  
Enable debuginfod for this session? (y or [n]) y
[…]
0x000055ae695bc9aa in execute_ex (ex=0x7f20d3414330) at ./Zend/zend_vm_execute.h:61167
warning: 61167	./Zend/zend_vm_execute.h: No such file or directory
(gdb) bt
#0  0x000055ae695bf264 in ZEND_ADD_SPEC_TMPVARCV_TMPVARCV_HANDLER () at ./Zend/zend_vm_execute.h:14023
#1  execute_ex (ex=0x60) at ./Zend/zend_vm_execute.h:60460
#2  0x000055ae695ba345 in zend_execute (op_array=op_array@entry=0x7f20d3467000, return_value=return_value@entry=0x0)
    at ./Zend/zend_vm_execute.h:64308
#3  0x000055ae69625814 in zend_execute_script (type=type@entry=8, retval=retval@entry=0x0, 
    file_handle=file_handle@entry=0x7fff00207980) at ./Zend/zend.c:1934
#4  0x000055ae694b8c50 in php_execute_script_ex (primary_file=, retval=retval@entry=0x0)
    at ./main/main.c:2575
#5  0x000055ae694b8edb in php_execute_script (primary_file=) at ./main/main.c:2615
#6  0x000055ae69337251 in main (argc=, argv=) at ./sapi/fpm/fpm/fpm_main.c:1932

We are stuck in ZEND_ADD_SPEC_TMPVARCV_TMPVARCV_HANDLER from zend_vm_execute.h, meaning we are adding two values in userland code, but additions can happen everywhere, which is not particularly useful to find out what is going wrong. It would be nice if we could find out which line of PHP code is currently being executed. Ideally with a full PHP-level stacktrace.

Turns out this is possible! PHP provides an official gdb script that provides helpful commands to retrieve information from PHP. It’s available as .gdbinit in the root of the php/php-src repository. We’ll need to make sure to select the right branch, PHP-8.4 in our case: https://github.com/php/php-src/blob/PHP-8.4/.gdbinit

After placing it somewhere convenient on the server, we load it into gdb using the source command:

(gdb) source /tmp/.gdbinit

Now the zbacktrace function will be available, which will output a stacktrace containing the names of the PHP functions rather than the C code executed internally.

(gdb) zbacktrace
[0x7f20d34143c0] FibonacciService->__invoke(3) /var/www/html/fibonacci.php:10 
[0x7f20d3414330] FibonacciService->__invoke(4) /var/www/html/fibonacci.php:9 
[0x7f20d34142a0] FibonacciService->__invoke(5) /var/www/html/fibonacci.php:9 
[0x7f20d3414210] FibonacciService->__invoke(6) /var/www/html/fibonacci.php:9 
[0x7f20d3414180] FibonacciService->__invoke(7) /var/www/html/fibonacci.php:9 
[0x7f20d34140f0] FibonacciService->__invoke(8) /var/www/html/fibonacci.php:9 
[0x7f20d3414060] FibonacciService->__invoke(9) /var/www/html/fibonacci.php:9 
[0x7f20d3413fd0] FibonacciService->__invoke(11) /var/www/html/fibonacci.php:10 
[0x7f20d3413f40] FibonacciService->__invoke(12) /var/www/html/fibonacci.php:9 
[0x7f20d3413eb0] FibonacciService->__invoke(14) /var/www/html/fibonacci.php:10 
[0x7f20d3413e20] FibonacciService->__invoke(15) /var/www/html/fibonacci.php:9 
[0x7f20d3413d90] FibonacciService->__invoke(16) /var/www/html/fibonacci.php:9 
[0x7f20d3413d00] FibonacciService->__invoke(18) /var/www/html/fibonacci.php:10 
[0x7f20d3413c70] FibonacciService->__invoke(20) /var/www/html/fibonacci.php:10 
[0x7f20d3413be0] FibonacciService->__invoke(21) /var/www/html/fibonacci.php:9 
[0x7f20d3413b50] FibonacciService->__invoke(22) /var/www/html/fibonacci.php:9 
[0x7f20d3413ac0] FibonacciService->__invoke(23) /var/www/html/fibonacci.php:9 
[0x7f20d3413a30] FibonacciService->__invoke(24) /var/www/html/fibonacci.php:9 
[0x7f20d34139a0] FibonacciService->__invoke(25) /var/www/html/fibonacci.php:9 
[0x7f20d3413910] FibonacciService->__invoke(26) /var/www/html/fibonacci.php:9 
[0x7f20d3413880] FibonacciService->__invoke(28) /var/www/html/fibonacci.php:10 
[0x7f20d34137f0] FibonacciService->__invoke(30) /var/www/html/fibonacci.php:10 
[0x7f20d3413760] FibonacciService->__invoke(31) /var/www/html/fibonacci.php:9 
[0x7f20d34136d0] FibonacciService->__invoke(33) /var/www/html/fibonacci.php:10 
[0x7f20d3413640] FibonacciService->__invoke(35) /var/www/html/fibonacci.php:10 
[0x7f20d34135b0] FibonacciService->__invoke(36) /var/www/html/fibonacci.php:9 
[0x7f20d3413520] FibonacciService->__invoke(37) /var/www/html/fibonacci.php:9 
[0x7f20d3413490] FibonacciService->__invoke(39) /var/www/html/fibonacci.php:10 
[0x7f20d3413400] FibonacciService->__invoke(40) /var/www/html/fibonacci.php:9 
[0x7f20d3413370] FibonacciService->__invoke(41) /var/www/html/fibonacci.php:9 
[0x7f20d34132e0] FibonacciService->__invoke(42) /var/www/html/fibonacci.php:9 
[0x7f20d3413250] FibonacciService->__invoke(43) /var/www/html/fibonacci.php:9 
[0x7f20d34131c0] FibonacciService->__invoke(44) /var/www/html/fibonacci.php:9 
[0x7f20d3413130] FibonacciService->__invoke(45) /var/www/html/fibonacci.php:9 
[0x7f20d3413020] (main) /var/www/html/fibonacci.php:26 

Oh, that is nice. Apparently we are stuck evaluating a deep tree of Fibonacci numbers. Let’s check what data they are working on. We can print all local variables (internally called “CV”) using the print_cvs command, which also was provided by the .gdbinit script. We’ll need to pass the ID of the stack frame we’re interested in, FibonacciService->__invoke(33) in this case:

(gdb) print_cvs 0x7f20d34136d0
Compiled variables count: 3

[0] '$n'
[0x7f20d3413720] long: 33
[1] '$n1'
[0x7f20d3413730] long: 2178309
[2] '$n2'
[0x7f20d3413740] UNDEF

$n is 33 (which makes sense). It already calculated $n1 which is 2178309, the 32nd Fibonacci number, $n2 (the 31st) is not yet available, which also makes sense, since the function would be finished already otherwise – except for the addition, which should be so fast that it is challenging to catch reliably.

Now we know why the worker is using so much CPU, but we still don’t know what data was included in the request (e.g., $_GET parameters) to reach this situation. This information is available from the superglobals. To access them, we first need to obtain a list of all global variables using the print_global_vars command:


(gdb) print_global_vars
Hash(6)[0x55ae697e3e90]: {
  [0] "_GET" => [0x7f20d3461200] (refcount=2) array: 
  [1] "_POST" => [0x7f20d3461220] (refcount=2) array: 
  [2] "_COOKIE" => [0x7f20d3461240] (refcount=2) array: 
  [3] "_FILES" => [0x7f20d3461260] (refcount=2) array: 
  [4] "n" => [0x7f20d3461280] indirect: [0x7f20d3413070] long: 45

  [5] "service" => [0x7f20d34612a0] indirect: [0x7f20d3413080] (refcount=35) object(FibonacciService) #1

}

Afterwards, we can print out an individual variable using the printzv command with the variable pointer as the parameter ($_GET in this case):


(gdb) printzv 0x7f20d3461200
[0x7f20d3461200] (refcount=2) array:     Hash(1)[0x7f20d345b000]: {
      [0] "n" => [0x7f20d345c180] (refcount=1) string: 45
}

Okay, our script was accessed with ?n=45 as the query string. Testing this in our development setup confirms it hangs, which means we can now start debugging and optimizing it!

Appendix

Debian Native Packages

The Debian Wiki explains how to get a backtrace. The easiest solution is by enabling debuginfod, as we have done above:

export DEBUGINFOD_URLS="<https://debuginfod.debian.net>"

Alternatively the main/debug APT archive needs to be enabled and the corresponding -dbgsym package for each PHP package needs to be installed. Most importantly the phpX.Y-cli-dbgsym or phpX.Y-fpm-dbgsym package is required, since it provides the debug symbols for the Zend Engine.

Debian with Sury’s PPA

The -dbgsym packages need to be installed as explained in the section for Debian Native Packages. No changes to the sources list are required, since the -dbgsym packages are part of the main archive.

Ubuntu Native Packages

On recent Ubuntu versions debuginfod is enabled by default and everything should work out of the box. In other cases, the Ubuntu Server documentation about debuginfod explains the setup.

Ubuntu with Sury’s PPA

The main/debug APT archive needs to be enabled by adding the main/debug component to your sources list of the PPA and -dbgsym packages need to be installed, as explained in the section for Debian Native Packages.

The Ubuntu Wiki on Debugging Program Crashes provides more detail.

RockyLinux Native Packages

debuginfod is enabled by default, but it appears to be unavailable in our test. Instead debuginfo packages can manually be installed via:

dnf debuginfo-install php-cli […]

AlmaLinux Native Packages

debuginfod does not appear to be set up. Debuginfo packages can be installed as explained in the section for RockyLinux Native packages.

Docker

No prebuilt debug symbols are available. Instead the Dockerfiles available in the docker-library/php GitHub repository need to be modified to remove the logic that strips the debug symbols and the Docker image needs to be rebuilt from the modified Dockerfile.

More details are available in docker-library/php#1538.

What’s next?

  1. Sign Up for our Newsletter if you don’t want to miss the next post on our blog.
  2. Start your 14 days free trial of Tideways for effortless performance insights into your PHP application.

About the author

Tim Düsterhus