Finding (performance) issues in PHP using GDB

Has it ever happened to you when a specific web request keeps loading and loading? Can't figure out where the code is crashing into a segfault? Say no more. You can use a tool called GDB for various complex things. It's a debugger for binary applications which can do a lot more, and we're just going to scratch the surface in one specific way. A way that unveils the exact functions, lines and parameters it's running.

When a web request caused PHP to segfault, I figured I could ask the kernel to make a core dump and read the backtrace whenever this happens.

Let's set up an environment to test core dumping on segfaults.

FROM ubuntu:20.04

RUN apt-get update && \
    apt-get install nano gdb ubuntu-dbgsym-keyring php-cli -y

RUN  printf "deb http://ddebs.ubuntu.com focal main restricted universe multiverse\ndeb http://ddebs.ubuntu.com focal-updates main restricted universe multiverse\ndeb http://ddebs.ubuntu.com focal-proposed main restricted universe multiverse" > /etc/apt/sources.list.d/ddebs.list

RUN apt-get update && \
    apt-get install libargon2-1-dbgsym libc6-dbg libgcc-s1-dbgsym libicu66-dbgsym liblzma5-dbgsym libpcre2-8-0-dbgsym libsodium23-dbgsym libssl1.1-dbgsym libstdc++6-dbgsym libxml2-dbgsym php7.4-cli-dbgsym zlib1g-dbgsym nano -y
Dockerfile for testing env

Start it up.

root@pc:~# docker build . -t coredumps:latest
...
root@pc:~# mkdir /coredumps
root@pc:~# docker run \
  --rm -it \
  --ulimit core=-1 \
  -v /coredumps:/coredumps \
  coredumps:latest
root@ee967362b789:/# cd
Running a container with core dumps enabled.

Now create a PHP script where a loop will trigger the segfault.

<?php

function make() {
    it();
}

Class TestMe {
    public function __tostring() {
        return "".$this;
    }
}

function it() {
    jump();
}

function jump() {
    (string) new TestMe();
}

make();
Segfaulting PHP code (Inspired by jolicode)

Run it, and you'll see a segfault:

root@ee967362b789:/# php index.php
Segmentation fault
Segfaulting

Now let's make it dump its core! For the container to make a core dump, you'll need to change the host, and it'll also save the core dump on the host. Be sure to check if you started the container with --ulimit core=-1.

root@pc:~# echo '/coredumps/core.%e.%p' > /proc/sys/kernel/core_pattern
Enabling and sending core dumps to a directory

When rerunning the PHP code, the output has changed.

root@ee967362b789:~# php crash.php
Segmentation fault (core dumped)
root@ee967362b789:/# ls /coredumps/
core.php.13
Creating a core dump

Let's load it up in GDB!

root@ee967362b789:/# gdb php /coredumps/core.php.13
....
....
(gdb) bt
#0  zend_call_method (object=0x7f64cef39770, obj_ce=<optimized out>, obj_ce@entry=0x7f64cee03100, fn_proxy=fn_proxy@entry=0x7f64cee03238, function_name=function_name@entry=0x555c2e7922ba "__tostring",
    function_name_len=function_name_len@entry=10, retval_ptr=retval_ptr@entry=0x7ffd05a45100, param_count=0, arg1=0x0, arg2=0x0) at ./Zend/zend_interfaces.c:103
#1  0x0000555c2e6e02cd in zend_std_cast_object_tostring (readobj=<optimized out>, writeobj=0x7ffd05a45150, type=<optimized out>) at ./Zend/zend_object_handlers.c:1799
#2  0x0000555c2e6a54fe in __zval_get_string_func (try=0 '\000', op=0x7f64cef39770) at ./Zend/zend_operators.c:895
#3  zval_get_string_func (op=<optimized out>) at ./Zend/zend_operators.c:925
#4  0x0000555c2e6a592d in concat_function (result=0x7f64cef39780, op1=<optimized out>, op2=op2@entry=0x7f64cef39770) at ./Zend/zend_operators.c:1852
#5  0x0000555c2e6f4e62 in ZEND_CONCAT_SPEC_CONST_TMPVAR_HANDLER () at ./Zend/zend_vm_execute.h:7480
#6  0x0000555c2e72fa7f in execute_ex (ex=0x7ffd05a45030) at ./Zend/zend_vm_execute.h:54491
#7  0x0000555c2e69f75f in zend_call_function (fci=fci@entry=0x7ffd05a45400, fci_cache=0x7f64cee8d0c0, fci_cache@entry=0x7ffd05a453e0) at ./Zend/zend_execute_API.c:812
#8  0x0000555c2e6ca66c in zend_call_method (object=0x7f64cef39700, obj_ce=<optimized out>, obj_ce@entry=0x7f64cee03100, fn_proxy=fn_proxy@entry=0x7f64cee03238,
    function_name=function_name@entry=0x555c2e7922ba "__tostring", function_name_len=function_name_len@entry=10, retval_ptr=retval_ptr@entry=0x7ffd05a454d0, param_count=0, arg1=0x0, arg2=0x0)
    at ./Zend/zend_interfaces.c:103
    
Backtrace of the PHP process

Right now, it's hard to make sense of this backtrace. Let's load up the gdb init file from the PHP people, making it a lot more readable. (grab it from here)

root@ee967362b789:/# nano ~/.gdbinit
root@ee967362b789:/# gdb php /coredumps/core.php.13
....
....
(gdb) zbacktrace
[0x7f64cef39720] TestMe->__tostring() /crash.php:9
[0x7ffd05a45340] ???
[0x7f64cef396b0] TestMe->__tostring() /crash.php:9
[0x7ffd05a45710] ???
[0x7f64cef39640] TestMe->__tostring() /crash.php:9
...
... Goes brrrr
...
[0x7f64cee131c0] TestMe->__tostring() /crash.php:9
[0x7ffd0623ecc0] ???
[0x7f64cee13140] jump() /crash.php:18
[0x7f64cee130e0] it() /crash.php:14
[0x7f64cee13080] make() /crash.php:4
[0x7f64cee13020] (main) /crash.php:21
gdb init file from PHP

That's more like it. Now we can see it's crashing on line 9 of the PHP file we created. We can also directly jump into GDB to overcome the need for a core dump file.

root@ee967362b789:/# gdb --args php crash.php
...
...
(gdb) run
Starting program: /usr/bin/php crash.php
warning: Error disabling address space randomization: Operation not permitted
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Program received signal SIGSEGV, Segmentation fault.
0x0000560043641265 in zend_call_function (fci=fci@entry=0x7ffc0d9c80f0, fci_cache=fci_cache@entry=0x7ffc0d9c80d0) at ./Zend/zend_execute_API.c:677
677     ./Zend/zend_execute_API.c: No such file or directory.
(gdb) zbacktrace
[0x7f39071398e0] TestMe->__tostring() /crash.php:9
[0x7ffc0d9c8400] ???
[0x7f3907139870] TestMe->__tostring() /crash.php:9
[0x7ffc0d9c87d0] ???
[0x7f3907139800] TestMe->__tostring() /crash.php:9
...
... Goes brrrr again
...
[0x7f39071396b0] TestMe->__tostring() /crash.php:9
[0x7ffc0e1c2cc0] ???
[0x7f3907013140] jump() /crash.php:18
[0x7f39070130e0] it() /crash.php:14
[0x7f3907013080] make() /crash.php:4
[0x7f3907013020] (main) /crash.php:21
Directly run in GDB

If there is a need for $_SERVER variables, then add the following wrapper script:

#!/bin/bash

export REQUEST_URI=/myuri
export SERVER_NAME=www.example.com
export HTTP_HOST=www.example.com
export DOCUMENT_ROOT=/
export DOCUMENT_URI=/myuri
export SCRIPT_NAME=/myuri
export REQUEST_METHOD=GET
export HTTP_X_FORWARDED_PROTO=https
export REQUEST_SCHEME=https

gdb --args php crash.php
Fake CGI request

If the process is already running, you can use gcore to dump the core and check what it was doing.

root@ee967362b789:/# php crash.php &
[1] 55
root@ee967362b789:/# ps aux
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0   4248  3576 pts/0    Ss   20:52   0:00 bash
root        37  0.3  0.0   4248  3344 pts/1    Ss   21:18   0:00 /bin/bash
root        45  0.0  0.0   5900  2904 pts/1    R+   21:18   0:00 ps aux
root        55  0.0  0.0  58940 17076 pts/0    S+   21:17   0:00 php crash.php
root@ee967362b789:/# gcore 55
...
Saved corefile core.55
[Inferior 1 (process 55) detached]
root@ee967362b789:/# gdb php ./core.55
...
...
(gdb) zbacktrace
[0x7f14d7c130f0] sleep(60) [internal function]
[0x7f14d7c13080] make() /crash.php:4
[0x7f14d7c13020] (main) /crash.php:22
root@ee967362b789:/# cat -n crash.php
     1  <?php
     2
     3  function make() {
     4      sleep(60);
     5      it();
     6  }
     7
     8  Class TestMe {
     9      public function __tostring() {
    10          return "".$this;
    11      }
    12  }
    13
    14  function it() {
    15      jump();
    16  }
    17
    18  function jump() {
    19      (string) new TestMe();
    20  }
    21
    22  make();
GDB with gcore dumps

We can see it's currently sleeping on line 4 of the PHP file.