Profiling slow running PHP processes in production with PHP-FPM's slow log
Symfony offers a great range of debugging tools for developers. Just like Xdebug, they have a high overhead and are available in production environments due to the overhead. Or if they are enabled, that might very well be the reason for your performance trouble.
Blackfire is another option for debugging. It offers comprehensive debugging tools and can be ran in production environments. Blackfire is not at every request, so it can be difficult to debug slow running PHP processes.
Users are coming to your site or web application and using it in ways that you probably never thought possible. For data persistence level issues the LAMP community has for the longest time relied on the MySQL slow log, a log that gets filled with queries that take over a set time.
MySQL slow log enables developers to catch slow running queries and eZ Platform / Publish developers have likely used it many times before. For PHP users running Nginx, Apache or others with PHP-FPM there is a similar option for PHP. This allows debugging reasons for crashes or slowdowns even afterwards.
By enabling PHP-FPM slow log developers can get a trace of what functions are running longer than a specified time. Configuring a separate PHP-FPM pool for areas experiencing problems can be useful as well as setting hooking up scripts with auto_prepend_file and auto_append_file options.
This is an example of a slow log that appeared when clearing caches via legacy admin on eZ Publish 5.4:
[17-Dec-2015 22:10:24] [pool admin] pid 26652 script_filename = /var/www/html/web/index.php [0x00007f39114b2cf8] scandir() /var/www/html/vendor/tedivm/stash/src/Stash/Utilities.php:149 [0x00007f39114b2b78] deleteRecursive() /var/www/html/vendor/tedivm/stash/src/Stash/Driver/FileSystem.php:348 [0x00007f39114b2a00] clear() /var/www/html/vendor/tedivm/stash/src/Stash/Driver/Composite.php:148 [0x00007f39114b28b0] actOnAll() /var/www/html/vendor/tedivm/stash/src/Stash/Driver/Composite.php:115 [0x00007f39114b27d8] clear() /var/www/html/vendor/tedivm/stash/src/Stash/Item.php:205 [0x00007f39114b26d8] executeClear() /var/www/html/vendor/tedivm/stash/src/Stash/Item.php:190 [0x00007f39114b25c8] clear() /var/www/html/vendor/ezsystems/ezpublish-kernel/eZ/Publish/Core/Persistence/Cache/CacheServiceDecorator.php:69 [0x00007f39114b2490] clear() /var/www/html/vendor/ezsystems/ezpublish-kernel/eZ/Bundle/EzPublishLegacyBundle/Cache/PersistenceCachePurger.php:176 [0x00007f39114b2358] content() /var/www/html/ezpublish/cache/prod/ezpublishProdProjectContainer.php:84207 [0x00007fffc92ff140] content() unknown:0 [0x00007f39114b2208] call_user_func_array() /var/www/html/ezpublish_legacy/kernel/private/classes/ezpevent.php:165 [0x00007f39114b2098] filter() /var/www/html/ezpublish_legacy/kernel/classes/ezcontentcachemanager.php:772 [0x00007f39114b1f60] clearNodeViewCacheArray() /var/www/html/ezpublish_legacy/kernel/classes/ezcontentcachemanager.php:699 [0x00007f39114b1e28] clearObjectViewCache() /var/www/html/ezpublish_legacy/kernel/classes/ezcontentcachemanager.php:811 [0x00007f39114b1cf0] clearObjectViewCacheIfNeeded() /var/www/html/ezpublish_legacy/kernel/classes/ezcontentcachemanager.php:1065 [0x00007f39114b1bd8] clearContentCacheIfNeeded() /var/www/html/ezpublish_legacy/kernel/content/ezcontentoperationcollection.php:245 [0x00007fffc93002f0] clearObjectViewCache() unknown:0 [0x00007f39114b1a40] call_user_func_array() /var/www/html/ezpublish_legacy/lib/ezutils/classes/ezmoduleoperationinfo.php:829 [0x00007f39114b1678] executeClassMethod() /var/www/html/ezpublish_legacy/lib/ezutils/classes/ezmoduleoperationinfo.php:530 [0x00007f39114b12f0] executeBody() /var/www/html/ezpublish_legacy/lib/ezutils/classes/ezmoduleoperationinfo.php:216
Maybe the Blackfire team can add a low overhead timer to enable slow logging in the future?