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. Спасибо за внимание. Надеюсь, кому-то материал был интересен.
    Метки:
    Поделиться публикацией
    Комментарии 41
    • +1
      Спасибо за статью. Возникала такая проблема, но и в голову не пришло воспользоваться gdb.
      • +9
        На сегодня все. Если будет интерес к теме, в следующий раз расскажу, как посмотреть содержимое переменных и как устроены массивы в PHP
        Очень интересно
      • +5
        Так а проблему то свою изначальную решили?
        • +7
          Проблему изначальную не решил, потому что она не в PHP-скрипте моем была — зацикливается внутри libcurl. Каким-то образом linked list, хранящий в себе все хендлеры загрузок, превращается в кольцо, поэтому обход этого списка через while(curr) {blabla; curr = curr->next;} никогда не заканчивается. Отписался им в рассылку по этому поводу (вот, жду модерации). Без gdb я бы этого никогда не узнал )
          • НЛО прилетело и опубликовало эту надпись здесь
            • +1
              Если curl подвисает в бесконечном цикле без системных вызовов — что вы ожидаете увидеть?
              • НЛО прилетело и опубликовало эту надпись здесь
                • 0
                  Ядро не занимается инспекцией кода user-level, это не его дело. Висит приложение в цикле или нет — не ядра дело, оно не знает, что приложение в цикле делает.

                  Не забудьте поставить ту-же версию curl.
              • +1
                В syslog не смотрел, но согласен с davinchi: ничего там не должно оказаться по идее.
              • 0
                Попробуйте другую (более старую) версию curl. Посмотрите, повторяется ли ошибка.

                Скорее всего это связано с race condition, нужно искать где curl забывает защищать списки mutex'ами.
                • 0
                  Я еще не проверил, повторяется ли эта ошибка в версии 7.22. Написал в рассыку, там говорят, тоже похожую проблему наблюдали, но в транке она уже якобы решена. Вот ссылка, если интересно: curl.haxx.se/mail/lib-2011-10/0061.html
                  Тут еще другая штука — мне было необходимо узнать, это у меня проблема или нет. Узнал, что в libcurl — теперь это не мое дело (разве что ради интереса поколупать в свободное время), потому что мы не можем физически собирать для каждого проекта-граббера патченный libcurl. Проще и дешевле написать демона, который после нескольких минут отсутствия записей в логах будет просто прибивать зациклившийся процесс.
                  За наводку на race condition спасибо, если будет время поковыряю посмотрю. Я как-то об этом и не подумал, хотя вроде же в PHP все в одном потоке идет.
                  • 0
                    Просто попробуйте собрать cURL из транка, если с ним повторяется — можно дальше в листе ругаться, если нет — profit!
            • +14
              Иногда чтобы найти причину проблемы достаточно strace -f -p $pid
              • 0
                Спасибо, буду иметь ввиду.
                • 0
                  В данном случае не поможет — системных вызовов не делается, strace не покажет ничего.
                • +1
                  Спасибо. А посмотреть зазенденые файлы не пробовали?
                  • 0
                    Пока что не ставил такую задачу перед собой. Не думаю, что там чего интересного будет, хотя разобраться и понять, как это работает — не помешало бы, наверное. Для общего развития.
                    • +1
                      dezend есть уже давно :)
                  • +3
                    В Дебиан можно было не пересобирать php, а поставить пакет php5-dbg
                    • 0
                      Не совсем хотелось ставить глобально дебаг-версию PHP на полубоевом сервере
                      • +1
                        Прочитал как «полуебовом сервере». Кажется, пора идти спать.
                        • 0
                          Так оно только хедеры ставит. Сам бинарь php не меняется, экстеншены тоже.
                          • +1
                            Если честно, я до конца не разобрался, что именно кроме .h-файлов и утилит типа phpize ставится пакетом php5-dev и чем отличаются пакеты php5-dev в ubuntu от этого php5-dbg на debian (или может быть это два разных пакета, имеющиеся на обоих системах). Но. Если он не меняет бинарник php, то отдебажить его не получится — нужно, чтобы бинарник был собран с ключом -g (в него должна быть включена информация для дебаггера), и наличие хедеров никак тут не поможет.
                            • 0
                              Да, был неправ, спутал -dev и -dbg. Тем не менее, -dbg не заменяет бинари, а ставит файлы в /usr/lib/debug/
                              • 0
                                Эти символы и нужны gdb или другим дебаггерам, чтобы показать читаемый stacktrace. Насчет ключа -g не знаю, нужно будет почитать…
                              • 0
                                -dbg предоставляет информацию для отладки помещая её в специальное место, где и ищет её gdb.
                                Местоположение и название пакетов зависят от дистрибутива.
                        • 0
                          статья зачетная,
                          только вот на реальном хостинге компилить пхп с ключом -d не хотелось бы — это раз
                          для реал-тайм мониторинга используем пимбу — это два.
                          • 0
                            для этого и компилил локально php с ключом -g, чтобы использовать его только для ловли бага на одном только скрипте. Все остальные кроны, веб-интерфейс, а так же остальные сайты на этом сервере, по-прежнему работают на основном, не пересобранном php, посталенном стандартным способом.
                            • +4
                              Не понимаю почему все думают, что «сборка == установка».
                              У меня 5 разных версий по крону собираются каждый день, но при этом ни одной не установлено — зачем?
                              Для дебага или тестирования не надо ничего ставить, достаточно собрать всё в один бинарник (но не делать make install!) и его запускать.
                              • 0
                                Тони, ты бы лучше человека поправил с «пимбой» :).
                            • +1
                              >Все что необходимо — это чтобы PHP был собран с ключом "-g".

                              На самом деле очень желательно -g3 и еще -O0 к нему в добавок.
                              Ибо без них многие нужные в дебаге переменные оптимизируются и выходит вот такое:
                              (gdb) p var
                              var =

                              В `man gcc` уровни опций -g и -O описаны довольно подробно.

                              >По каким-то причинам PHP 5.2.17 собрался у меня не в debug сборке с этим ключом
                              Понятно по каким - если он упадёт, то в корке хоть что-то должно быть читабельное, иначе не о чем будет баг-репорты писать в Дебиан.
                              • 0
                                там было «var = <value optimized out>»
                                • 0
                                  Насколько я понимаю, желательно все-таки -O0, -g3 не очень-то и нужно (по крайней мере я в манах когда про -g читал, понял это будто какая-то дополнительная инфа)

                                  По поводу сборки PHP не совсем понял. Тот, который ставился из пакетов не имел дебажной инфы в себе, а тот который я просто скомпилил с --disable-debug почему-то имел при компиляции ключи помойму -g -O2, если я не ошибаюсь. Т.е. вроде как и оптимизация на полную, и вроде как и дебаг-инфа включается. Впрочем, я не стал загоняться сильно — мне хватило такого. Если вы поясните точнее почему это так как есть, буду благодарен.
                                  • +3
                                    Разница в этом:
                                    -g (то же, что и -g1):
                                    Level 1 produces minimal information, enough for making backtraces in parts of the program that you don't plan to debug.

                                    Т.е. так прямо в мануале и написано, что -g — это если вы не планируете дебажить, это так, для бэктрэйса максимум.

                                    -g3:
                                    Level 3 includes extra information, such as all the macro definitions present in the program. Some debuggers support macro expansion when you -g3.

                                    Почувствуйте разницу. Здесь точно всё-всё останется, даже макросы. Но и размер бинарника будет соотв-щий.

                                    "-g -O2" — это универсальные дефолтовые ключи сборки, так везде.
                                    Зачем нужен -g я только что уже сказал.
                                    -O2 — это неэкстремальные оптимизации, как раз для сферического продакшена в вакууме.
                                    Есть еще и -O3, см. man gcc.
                                    • 0
                                      Спасибо за пояснения. Не очень силен я в этом.
                                • +1
                                  Кстати, для отладки под Apache, скажем тех же PHP-модулей, есть полезный ключик для него — "-X". Помогло при отладке, когда с консоли PHP-модуль работал нормально, а под Apache упорно валился.
                                  • +1
                                    Вот тут есть подробные инструкции на (почти?) все случаи жизни: bugs.php.net/bugs-generating-backtrace.php
                                    • +1
                                      Кстати именно с этой страницы развилась моя идея «а давайте влезем в работающий скрипт из gdb»
                                  • НЛО прилетело и опубликовало эту надпись здесь

                                    Только полноправные пользователи могут оставлять комментарии. Войдите, пожалуйста.