Obsolete:Using xdebug for php stack traces

From Wikitech
This page contains historical information. It may be outdated or unreliable.
See WikimediaDebug for current information. 2012

Uses

  • When mediawiki 1.21wmf6 was released on commonswiki, the logs showed a large spike on php out of memory issues, and nothing was being logged to our fatal.log.

Installing and Configuring xdebug

  • Install
apt-get install php5-xdebug
  • Configure
vi /etc/php5/conf.d/xdebug.ini
zend_extension=/usr/lib/php5/20090626/xdebug.so
xdebug.max_nesting_level=1000 ; the default nesting level of 100 isn't very mediawiki friendly
xdebug.show_mem_delta=1
xdebug.collect_params=4
xdebug.dump_globals=on
xdebug.collect_vars=on
xdebug.show_local_vars=on
/etc/init.d/apache2 restart
  • The above options add the arguments to function calls in the trace. In this case, it was very helpful for identifying the issue.

Stack trace

  • Stack traces will appear in the standard php error log, currently on fenari:/h/w/l/syslog/apache.log
  • In this example case, xdebug was configured on one production apache, and the apache.log was tailed, grepping for its ip address.
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP Fatal error:  Allowed memory size of 183500800 bytes exhausted (tried to  allocate 256 bytes) in /usr/local/apache/common-local/php-1.21wmf6/includes/Title.php on line 328
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP Stack trace:
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   1. {main}() /usr/local/apache/common-local/live-1.5/api.php:0
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   2. require() /usr/local/apache/common-local/live-1.5/api.php:3
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   3. ApiMain->execute() /usr/local/apache/common-local/php-1.21wmf6/api.php:77
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   4. ApiMain->executeActionWithErrorHandling() /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiMain.php:349
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   5. ApiMain->executeAction() /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiMain.php:372
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   6. ApiQuery->execute() /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiMain.php:825
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   7. ApiPageSet->execute() /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiQuery.php:312
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   8. ApiPageSet->initFromTitles($titles = array (0 => 'File:World Map Index of perception of corruption 2010.svg')) /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiPageSet.php:303
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP   9. ApiPageSet->resolvePendingRedirects() /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiPageSet.php:432
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP  10. ApiPageSet->getRedirectTargets() /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiPageSet.php:597
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP  11. ApiPageSet->resolveIdsToRedirectTargets($redirectIDs = array (0 => 23064614), $profileDB = 'profileDB') /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiPageSet.php:627
Dec 12 21:49:10 10.0.2.218 apache2[9373]: PHP  12. Title::makeTitle($ns = '6', $title = 'World_Map_Index_of_perception_of_corruption.svg', $fragment = , $interwiki = ) /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiPageSet.php:682
  • In the above case, Title::makeTitle was constantly OOM'ing on what was essentially an empty constructor. As such, what came before was highly suspect.
  • The following instantly stood out:
PHP  11. ApiPageSet->resolveIdsToRedirectTargets($redirectIDs = array (0 => 23064614), $profileDB = 'profileDB') /usr/local/apache/common-local/php-1.21wmf6/includes/api/ApiPageSet.php:627
  • Looking at a diff of ApiPageSet between wmf5 and wmf6 showed that resolveIdsToRedirectTargets() was refactored before the wmf6 release and profileDB was being set by default where it wasn't before. That commit was then pulled up and reviewed in gerrit, and was indeed the root cause.
  • In cases where the root cause doesn't jump out, xdebug can also be configured to produce kcachegrind files on a local apache, for very in depth inspection.

After

  • If enabling xdebug on a production apache, make sure to disable and restart apache there when done. Its costly to leave enabled when configured as above.