PHP под С-шным дебаггером: копаемся внутри Zend Engine

Как-то пришлось мне столкнуться с проблемой: веб-краулер на PHP работает себе нормально, работает, а потом вдруг (через 3-6 часов работы) перестает что-либо делать и начинает кушать 100% CPU. Как искать такую проблему? Как узнать, где он зацикливается? А что если подключиться к PHP сишным дебаггером и узнать оттуда все, что необходимо? Подробности под катом.

Что вообще можно сделать в такой ситуации?

Вариантов тут не очень много: можно расставить по всему скрипту записи в логи и смотреть, на какой он остановился. Из этого можно как-то предположить где и как он зависает. Это очень долго — расставил запись в логи, поймал зависон, посмотрел, инфы не хватило, расставляем еще больше записей и т.д. — поэтому этот вариант я оставил на потом, если никакой другой не подойдет.
Использовать xdebug для этого не получится — насколько я понимаю, у него нету функционала подключения к уже работающему PHP-скрипту. А если запустить скрипт уже под xdebug, то опять же не получится нажать «run» и потом, когда он зависнет, нажать «pause» — в xdebug можно путешествовать только по брейкпоинтам (поправьте меня, если я не прав тут).

Идея — можно попробовать использовать GDB!

Основная работа у меня связана с PHP, но частенько приходится писать и на C++ под GCC (что мне, надо сказать, очень нравится). Есть опыт отладки c++ программ прямо на сервере при помощи gdb — это не очень-то и сложно на самом деле, отладчик gdb достаточно удобный для консольной программы. Так почему бы не попробовать отладить с его помощью наш PHP-скрипт? Заодно и во внутренностях PHP можно немного поковыряться по-живому.

Что нам необходимо

Нужен ssh-доступ на сервер. root не нужен — мы можем все делать локально. Итак:

GDB

Можно попросить админа его поставить, либо скомпилить и поставить самому локально. Я попросил админа.

PHP, собранный с отладочной информацией

На самом деле debug-версия не нужна. Все что необходимо — это чтобы PHP был собран с ключом "-g". По каким-то причинам PHP 5.2.17 собрался у меня не в debug сборке с этим ключом, что очень облегчило дело — мне удалось заюзать те же экстеншены, что используются и для обычной версии. Насколько я понял, если бы я собрал PHP в debug-версии, то заюзать эти же экстеншены мне не удалось бы — пришлось бы юзать те, что собрались бы вместе с PHP.
Забегая вперед, скажу, что для сборки PHP мне еще понадобился libxml2. Плюс оказалось, что проблема была в libcurl, поэтому дополнительно я еще собрал libcurl в debug-сборке, чтобы залезть внутрь его.
Итак, собираем (пишу по памяти, поэтому могут быть неточности):

$ wget <libxml2 download url>
$ tar -xzf libxml2-2.7.8.tar.gz
$ cd libxml2-2.7.8
$ ./configure --prefix=$HOME/libs
$ make && make install

$ wget <libcurl download url>
$ tar -xzf curl-7.18.2.tar.gz
$ cd curl-7.18.2
$ ./configure --prefix=$HOME/libs --enable-debug
$ make && make install

Со сборкой PHP немного сложнее — нужно еще указать пути к php.ini-файлам в debian, путь к собранному libxml2 и путь к собранному libcurl:

$ wget <php-5.2.17 download url>
$ tar -xzf php-5.2.17.tar.gz
$ cd php-5.2.17
$ ./configure --disable-debug --with-config-file-path=/etc/php5/cli
--with-config-file-scan-dir=/etc/php5/cli/conf.d 
--with-libxml-dir=$HOME/libs --disable-pdo --with-curl=$HOME/libs
$ make

Повторюсь еще раз. Скомпилить PHP с --disable-debug (при этом все-равно была указана опция компилятора -g) и заюзать все готовые модули мне показалось проще, чем ставить PHP полностью со всеми модулями локально. Поэтому я не делал make install. Возможно лучше будет сконфигурировать его с опцией --prefix=$HOME/libs и сделать make install, но того, что я сделал выше, оказалось достаточно для моих целей.
Все скомпилировали — запускаем PHP. Тут тоже не все так гладко: я сходу не нашел опции, чтобы указать ему, где лежат экстеншены, поэтому пришлось указывать эту директорию каждый раз при запуске PHP:

$ php/php-5.2.17/sapi/cli/php -d extension_dir=/usr/lib/php5/20060613
PHP Warning:  Module 'curl' already loaded in Unknown on line 0

Ошибочка с curl понятна — мы скомпилили PHP уже со встроенным curl модулем, поэтому при попытке подключить внешний curl.so вылазит такая ошибка. Ничего страшного, в общем-то.
Со сборкой все, можно запускать и ловить багу.

Собственно, запуск и дебаг

Чтобы не грузить читателя лишней информацией, я сделал небольшой скриптик на PHP, на котором можно посмотреть возможности дебага через gdb:

<?php

class A {
        protected $_a = NULL;
        public function __construct($a) {
                $this->_a = $a;
        }
        public function run() {
                while (true) {
                        sleep(1);
                }
        }
}

class B {
        protected $_a = NULL;
        protected $_b = NULL;
        public function __construct() {
                $this->_b = rand(1000, 9999);
                $this->_a = new A(rand(1000, 9999));
        }
        public function run() {
                $this->_a->run();
        }
}

$b = new B;
$b->run();

Итак, запускаем скрипт:

$ php/php-5.2.17/sapi/cli/php -d extension_dir=/usr/lib/php5/20060613 test/test.php

смотрим PID нашего процесса и запускаем GDB в другом терминале:

$ ps auwx | grep test.php
$ gdb
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
......
This GDB was configured as "x86_64-linux-gnu".
(gdb) 

Аттачимся к нашему процессу:

(gdb) attach 7455
Attaching to process 7455
Reading symbols from /<homedir>/php/php-5.2.17/sapi/cli/php...done.
.....
Reading symbols from /<homedir>/libs/lib/libcurl.so.4...done.
Loaded symbols for /<homedir>/libs/lib/libcurl.so.4
.....
0x00007fd9e6c22040 in nanosleep () from /lib/libc.so.6
(gdb) 

Если мы видим строку Reading symbols from [lib].....done — значит все прошло хорошо, и мы сможем спокойно дебажить этот бинарник.
Смотрим backtrace
(gdb) bt
#0 0x00007fd9e6c22040 in nanosleep () from /lib/libc.so.6
#1 0x00007fd9e6c21e97 in sleep () from /lib/libc.so.6
#2 0x0000000000587277 in zif_sleep (ht=1, return_value=0x278c010, return_value_ptr=0x0, this_ptr=0x0,
return_value_used=0) at /[homedir]/php/php-5.2.17/ext/standard/basic_functions.c:4794
#3 0x000000000068a733 in zend_do_fcall_common_helper_SPEC (execute_data=0x7fff0b7d6310)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:200
#4 0x0000000000690204 in ZEND_DO_FCALL_SPEC_CONST_HANDLER (execute_data=0x7fff0b7d6310)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:1740
#5 0x000000000068a221 in execute (op_array=0x278ad38)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:92
#6 0x00007fd9e655b90f in zend_oe () from /usr/lib/php5/20060613/ZendOptimizer.so
#7 0x000000000068a886 in zend_do_fcall_common_helper_SPEC (execute_data=0x7fff0b7d6570)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:234
#8 0x000000000068b3af in ZEND_DO_FCALL_BY_NAME_SPEC_HANDLER (execute_data=0x7fff0b7d6570)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:322
#9 0x000000000068a221 in execute (op_array=0x278b8c0)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:92
#10 0x00007fd9e655b90f in zend_oe () from /usr/lib/php5/20060613/ZendOptimizer.so
#11 0x000000000068a886 in zend_do_fcall_common_helper_SPEC (execute_data=0x7fff0b7d68a0)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:234
#12 0x000000000068b3af in ZEND_DO_FCALL_BY_NAME_SPEC_HANDLER (execute_data=0x7fff0b7d68a0)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:322
#13 0x000000000068a221 in execute (op_array=0x2787b88)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:92
#14 0x00007fd9e655b90f in zend_oe () from /usr/lib/php5/20060613/ZendOptimizer.so
#15 0x0000000000665598 in zend_execute_scripts (type=8, retval=0x0, file_count=3)
at /[homedir]/php/php-5.2.17/Zend/zend.c:1134
#16 0x0000000000615608 in php_execute_script (primary_file=0x7fff0b7d8ee0)
at /[homedir]/php/php-5.2.17/main/main.c:2036
#17 0x00000000006dfa82 in main (argc=4, argv=0x7fff0b7d90f8)
at /[homedir]/php/php-5.2.17/sapi/cli/php_cli.c:1165
(gdb)

В первую очередь нас интересуют фреймы внутри execute() [Zend/zend_vm_execute.h:92]. Это вызовы PHP-функций. Как узнать, где мы находимся в данный момент в PHP-скрипте:
(gdb) f 13
#13 0x000000000068a221 in execute (op_array=0x2d3fb88)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:92
92 if (EX(opline)->handler(&execute_data TSRMLS_CC) > 0) {
(gdb) print execute_data.function_state.function->common.scope->name
$20 = 0x2d423a0 "B"
(gdb) print execute_data.function_state.function->common.function_name
$21 = 0x2d43790 "run"
(gdb) print execute_data.opline->lineno
$22 = 28
(gdb) f 9
#9 0x000000000068a221 in execute (op_array=0x2d438c0)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:92
92 if (EX(opline)->handler(&execute_data TSRMLS_CC) > 0) {
(gdb) print execute_data.function_state.function->common.scope->name
$23 = 0x2d42380 "A"
(gdb) print execute_data.function_state.function->common.function_name
$24 = 0x2d44c48 "run"
(gdb) print execute_data.opline->lineno
$25 = 23
(gdb) f 5
#5 0x000000000068a221 in execute (op_array=0x2d42d38)
at /[homedir]/php/php-5.2.17/Zend/zend_vm_execute.h:92
92 if (EX(opline)->handler(&execute_data TSRMLS_CC) > 0) {
(gdb) print execute_data.function_state.function->common.function_name
$26 = 0x770781 "sleep"
(gdb) print execute_data.opline->lineno
$27 = 10
(gdb)

Несколько пояснений: f [номер] перебрасывает нас в определенный фрейм, print [четатам] — вывести символ, находящийся в области видимости этого фрейма.
В примере выше мы получили имя класса, имя метода/функции и номер строки, где она вызывается (в фрейме 5 имя класса не определено, потому что это встроенная функция sleep()). Фактически мы получили backtrace PHP-скрипта. Уже исходя из этой информации можно понять, откуда растут ноги у неуловимого бага, описанного в начале статьи.

На сегодня все. Если будет интерес к теме, в следующий раз расскажу, как посмотреть содержимое переменных и как устроены массивы в PHP. Спасибо за внимание. Надеюсь, кому-то материал был интересен.