Req #53434 [Ana->Csd]: More details for slow requests

Edit report at http://bugs.php.net/bug.php?id=53434&edit=1 ID: 53434 Updated by: fat@php.net Reported by: webmaster_apc at colnect dot com Summary: More details for slow requests -Status: Analyzed +Status: Closed Type: Feature/Change Request Package: FPM related Operating System: gentoo linux PHP Version: 5.3.1RC1 Assigned To: fat Block user comment: N Private report: N New Comment: This bug has been fixed in SVN. Snapshots of the sources are packaged every three hours; this change will be in the next snapshot. You can grab the snapshot at http://snaps.php.net/. Thank you for the report, and for helping us make PHP better. I've added the request method and the request uri in the slowlog timeout and slowlog terminated log message: [29-Jan-2011 12:41:59.741208] WARNING: pid 32110, fpm_request_check_timed_out(), line 147: [pool www_chroot] child 32111, script '/html/test8.php' (request: "GET /chroot/test8.php") executing too slow (1.051049 sec), logging [29-Jan-2011 12:42:00.783410] WARNING: pid 32110, fpm_request_check_timed_out(), line 157: [pool www_chroot] child 32111, script '/html/test8.php' (request: "GET /chroot/test8.php") execution timed out (2.092626 sec), terminating Previous Comments: ------------------------------------------------------------------------ [2011-01-29 12:41:47] fat@php.net Automatic comment from SVN on behalf of fat Revision: http://svn.php.net/viewvc/?view=revision&revision=307843 Log: - Fixed bug #53434 (php-fpm slowlog now also logs the original request). - Fixed the missing peace of code on revision 307842 ------------------------------------------------------------------------ [2011-01-29 12:38:21] fat@php.net Automatic comment from SVN on behalf of fat Revision: http://svn.php.net/viewvc/?view=revision&revision=307842 Log: - Fixed bug #53434 (php-fpm slowlog now also logs the original request). ------------------------------------------------------------------------ [2010-12-06 09:26:15] fat@php.net Oh hell yes ... I did not understand your need. I'll see how complicated this is to add the request which triggers the slowlog entries. ------------------------------------------------------------------------ [2010-12-06 09:25:40] webmaster_apc at colnect dot com This may help. In the normal log I get: Dec 06 08:03:36.147792 [WARNING] [pool www] child 23560, script '/var/xxx/web/index.php' executing too slow (30.069499 sec), logging Dec 06 08:03:36.147904 [NOTICE] child 23560 stopped for tracing Dec 06 08:03:36.147911 [NOTICE] about to trace 23560 Dec 06 08:03:36.148064 [ERROR] ptrace(PEEKDATA) failed: Input/output error (5) Dec 06 08:03:36.148127 [NOTICE] finished trace of 23560 ------------------------------------------------------------------------ [2010-12-06 09:21:42] webmaster_apc at colnect dot com I have more messages in the slow log indicated the script which was running at the time but NOT the HTTP request send. For example: [0x00007f38694a0b78] flush() /var/xxx/lib/misc/scriptControl.class.php:15 [0x00007f38694a03c8] set_time_limit() /var/xxx/apps/modules/repairs/actions/actions.class.php:68 [0x00007f386949fd00] executeRecreateThumbnails() /var/xxx/cache/prod/config/config_core_compile.yml.php:490 [0x00007f386949fa30] execute() /var/xxx/cache/prod/config/config_core_compile.yml.php:990 [0x00007f386949f6d8] executeAction() /var/xxx/cache/prod/config/config_core_compile.yml.php:985 [0x00007f386949ef80] handleAction() /var/xxx/cache/prod/config/config_core_compile.yml.php:971 [0x00007f386949ea68] execute() /var/xxx/cache/prod/config/config_core_compile.yml.php:1066 [0x00007f386949e400] execute() /var/xxx/lib/vendor/symfony/lib/filter/sfCommonFilter.class.php:29 [0x00007f386949dee8] execute() /var/xxx/cache/prod/config/config_core_compile.yml.php:1066 [0x00007f386949db98] execute() /var/xxx/apps/lib/extraSecurityFilter.class.php:31 [0x00007f386949d680] execute() /var/xxx/cache/prod/config/config_core_compile.yml.php:1066 [0x00007f386949d3e0] execute() /var/xxx/cache/prod/config/config_core_compile.yml.php:1033 I don't know how to include my configuration. The output of ./configure is too long to be pasted here. ------------------------------------------------------------------------ The remainder of the comments for this report are too long. To view the rest of the comments, please view the bug report online at http://bugs.php.net/bug.php?id=53434 -- Edit this bug report at http://bugs.php.net/bug.php?id=53434&edit=1