PHP :: Bug #68115 :: php-fpm process stuck in a loop (Zend/zend_vm

Bug #68115	php-fpm process stuck in a loop (Zend/zend_vm_execute.h execute)
Submitted:	2014-09-29 09:20 UTC	Modified:	2021-06-13 04:22 UTC
From:	champetier dot etienne at gmail dot com	Assigned:	cmb (profile)
Status:	No Feedback	Package:	Unknown/Other Function
PHP Version:	5.4.31	OS:	rhel 6.5
Private report:	No	CVE-ID:	None

View Developer Edit

[2014-09-29 09:20 UTC] champetier dot etienne at gmail dot com

Description:
------------
Hi,

I'm using php-fpm 5.4.31 and i have 1 php-fpm process stuck at 100% in xbuf_format_converter.
I know it's not latest but it's not on a production server (yet) so i can keep it looping, and i've root acces on the machine to debug.

I only have php54-debuginfo-5.4.31-1.ius.el6.x86_64 installed, no other debuginfo rpm.

Please guide me if you need more info (i'm really no gdb expert)

Actual result:
--------------
# gdb php-fpm 44361
GNU gdb (GDB) Red Hat Enterprise Linux (7.2-60.el6_4.1)
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/php-fpm...Reading symbols from /usr/lib/debug/usr/sbin/php-fpm.debug...done.
done.
Attaching to program: /usr/sbin/php-fpm, process 44361
Reading symbols from /lib64/libcrypt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/libcrypt.so.1
....
....
xbuf_format_converter (xbuf=0x7ffff9dc0a30, fmt=0x6f9a7c "d to be %s, %s given", ap=0x7ffff9dc0ad0) at /usr/src/debug/php-5.4.31/main/spprintf.c:779
779				if (adjust_width && adjust == LEFT && min_width > s_len)
....

(gdb) bt

#0  xbuf_format_converter (xbuf=0x7ffff9dc0a30, fmt=0x6f9a7c "d to be %s, %s given", ap=0x7ffff9dc0ad0) at /usr/src/debug/php-5.4.31/main/spprintf.c:779
#1  0x00000000005867f4 in vspprintf (pbuf=0x2e44b40, max_len=0, format=<value optimized out>, ap=<value optimized out>) at /usr/src/debug/php-5.4.31/main/spprintf.c:799
#2  0x00000000005dd3c7 in zend_error (type=2, format=0x6f9a60 "%s%s%s() expects parameter %d to be %s, %s given") at /usr/src/debug/php-5.4.31/Zend/zend.c:1138
#3  0x00000000005e7a7b in zend_parse_arg (num_args=1, type_spec=0x6d9261 "rl", va=<value optimized out>, flags=0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:686
#4  zend_parse_va_args (num_args=1, type_spec=0x6d9261 "rl", va=<value optimized out>, flags=0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:844
#5  0x00000000005e8345 in zend_parse_parameters (num_args=2, type_spec=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:895
#6  0x000000000052a481 in zif_fread (ht=<value optimized out>, return_value=0x2e43558, return_value_ptr=<value optimized out>, this_ptr=<value optimized out>, 
    return_value_used=<value optimized out>) at /usr/src/debug/php-5.4.31/ext/standard/file.c:1747
#7  0x00000000006599ec in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:643
#8  0x0000000000647328 in execute (op_array=0x3f181d8) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:410
#9  0x00000000005d1fbc in zend_call_function (fci=0x7ffff9dc1150, fci_cache=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:956
#10 0x000000000051f03f in zif_call_user_func (ht=<value optimized out>, return_value=0x7f5437a24c88, return_value_ptr=<value optimized out>, this_ptr=<value optimized out>, 
    return_value_used=<value optimized out>) at /usr/src/debug/php-5.4.31/ext/standard/basic_functions.c:4724
#11 0x00000000006599ec in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:643
#12 0x0000000000647328 in execute (op_array=0x3f7bdf0) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:410
#13 0x00000000005dce60 in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /usr/src/debug/php-5.4.31/Zend/zend.c:1315
#14 0x000000000057f958 in php_execute_script (primary_file=0x7ffff9dc3930) at /usr/src/debug/php-5.4.31/main/main.c:2502
#15 0x00000000006915c2 in main (argc=<value optimized out>, argv=<value optimized out>) at /usr/src/debug/php-5.4.31/sapi/fpm/fpm/fpm_main.c:1933


strace -p 44361
....
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
....

Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports

[2014-09-29 09:22 UTC] champetier dot etienne at gmail dot com

forget to say that it's looping for maybe 6 hours, way more than max execution time

[2014-09-30 07:21 UTC] champetier dot etienne at gmail dot com

-Summary: php-fpm process stuck in a loop (xbuf_format_converter) +Summary: php-fpm process stuck in a loop (Zend/zend_vm_execute.h execute) -PHP Version: 5.4.33 +PHP Version: 5.4.31

[2014-09-30 07:21 UTC] champetier dot etienne at gmail dot com

i've improved my gdb skills a bit, php-fpm is stuck in Zend/zend_vm_execute.h execute function

i've crashed the php-fpm process so no more debugging ...

(gdb) bt
#0  zend_inline_hash_func (ht=0x2a1cc40, arKey=0x2e43e30 "download_exception_handler", nKeyLength=27, pData=0x7ffff9dc0998) at /usr/src/debug/php-5.4.31/Zend/zend_hash.h:271
#1  zend_hash_find (ht=0x2a1cc40, arKey=0x2e43e30 "download_exception_handler", nKeyLength=27, pData=0x7ffff9dc0998) at /usr/src/debug/php-5.4.31/Zend/zend_hash.c:921
#2  0x00000000005e25bb in zend_is_callable_check_func (check_flags=8, callable=0x31effd8, fcc=0x7ffff9dc0990, strict_class=0, error=0x7ffff9dc09c0)
    at /usr/src/debug/php-5.4.31/Zend/zend_API.c:2709
#3  0x00000000005e3033 in zend_is_callable_ex (callable=0x31effd8, object_ptr=<value optimized out>, check_flags=8, callable_name=0x7ffff9dc09c8, 
    callable_name_len=<value optimized out>, fcc=0x7ffff9dc0990, error=0x7ffff9dc09c0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:3079
#4  0x00000000005d1883 in zend_call_function (fci=0x7ffff9dc0a10, fci_cache=0x7ffff9dc0990) at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:807
#5  0x00000000005d2da0 in call_user_function_ex (function_table=<value optimized out>, object_pp=<value optimized out>, function_name=<value optimized out>, 
    retval_ptr_ptr=<value optimized out>, param_count=<value optimized out>, params=<value optimized out>, no_separation=1, symbol_table=0x0)
    at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:748
#6  0x00000000005dd62a in zend_error (type=2, format=0x6f9a60 "%s%s%s() expects parameter %d to be %s, %s given") at /usr/src/debug/php-5.4.31/Zend/zend.c:1197
#7  0x00000000005e7a7b in zend_parse_arg (num_args=1, type_spec=0x6d9261 "rl", va=<value optimized out>, flags=0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:686
#8  zend_parse_va_args (num_args=1, type_spec=0x6d9261 "rl", va=<value optimized out>, flags=0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:844
#9  0x00000000005e8345 in zend_parse_parameters (num_args=2, type_spec=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:895
#10 0x000000000052a481 in zif_fread (ht=<value optimized out>, return_value=0x2e44cc0, return_value_ptr=<value optimized out>, this_ptr=<value optimized out>, 
    return_value_used=<value optimized out>) at /usr/src/debug/php-5.4.31/ext/standard/file.c:1747
#11 0x00000000006599ec in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:643
#12 0x0000000000647328 in execute (op_array=0x3f181d8) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:410
#13 0x00000000005d1fbc in zend_call_function (fci=0x7ffff9dc1150, fci_cache=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:956
#14 0x000000000051f03f in zif_call_user_func (ht=<value optimized out>, return_value=0x7f5437a24c88, return_value_ptr=<value optimized out>, this_ptr=<value optimized out>, 
    return_value_used=<value optimized out>) at /usr/src/debug/php-5.4.31/ext/standard/basic_functions.c:4724
#15 0x00000000006599ec in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:643
#16 0x0000000000647328 in execute (op_array=0x3f7bdf0) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:410
#17 0x00000000005dce60 in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /usr/src/debug/php-5.4.31/Zend/zend.c:1315
#18 0x000000000057f958 in php_execute_script (primary_file=0x7ffff9dc3930) at /usr/src/debug/php-5.4.31/main/main.c:2502
#19 0x00000000006915c2 in main (argc=<value optimized out>, argv=<value optimized out>) at /usr/src/debug/php-5.4.31/sapi/fpm/fpm/fpm_main.c:1933
(gdb) fin
Run till exit from #0  zend_inline_hash_func (ht=0x2a1cc40, arKey=0x2e43e30 "download_exception_handler", nKeyLength=27, pData=0x7ffff9dc0998)
    at /usr/src/debug/php-5.4.31/Zend/zend_hash.h:271
924		p = ht->arBuckets[nIndex];
(gdb) 
Run till exit from #0  zend_hash_find (ht=0x2a1cc40, arKey=0x2e43e30 "download_exception_handler", nKeyLength=27, pData=0x7ffff9dc0998)
    at /usr/src/debug/php-5.4.31/Zend/zend_hash.c:924
0x00000000005e25bb in zend_is_callable_check_func (check_flags=8, callable=0x31effd8, fcc=0x7ffff9dc0990, strict_class=0, error=0x7ffff9dc09c0)
    at /usr/src/debug/php-5.4.31/Zend/zend_API.c:2709
2709			if (zend_hash_find(EG(function_table), lmname, mlen+1, (void**)&fcc->function_handler) == SUCCESS) {
Value returned is $1 = 0
(gdb) 
Run till exit from #0  0x00000000005e25bb in zend_is_callable_check_func (check_flags=8, callable=0x31effd8, fcc=0x7ffff9dc0990, strict_class=0, error=0x7ffff9dc09c0)
    at /usr/src/debug/php-5.4.31/Zend/zend_API.c:2709
zend_is_callable_ex (callable=0x31effd8, object_ptr=<value optimized out>, check_flags=8, callable_name=0x7ffff9dc09c8, callable_name_len=<value optimized out>, fcc=0x7ffff9dc0990, 
    error=0x7ffff9dc09c0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:3080
3080						if (fcc == &fcc_local &&
Value returned is $2 = 1
(gdb) 
Run till exit from #0  zend_is_callable_ex (callable=0x31effd8, object_ptr=<value optimized out>, check_flags=8, callable_name=0x7ffff9dc09c8, callable_name_len=<value optimized out>, 
    fcc=0x7ffff9dc0990, error=0x7ffff9dc09c0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:3080
0x00000000005d1883 in zend_call_function (fci=0x7ffff9dc0a10, fci_cache=0x7ffff9dc0990) at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:807
807			if (!zend_is_callable_ex(fci->function_name, fci->object_ptr, IS_CALLABLE_CHECK_SILENT, &callable_name, NULL, fci_cache, &error TSRMLS_CC)) {
Value returned is $3 = 1 '\001'
(gdb) 
Run till exit from #0  0x00000000005d1883 in zend_call_function (fci=0x7ffff9dc0a10, fci_cache=0x7ffff9dc0990) at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:807
call_user_function_ex (function_table=<value optimized out>, object_pp=<value optimized out>, function_name=<value optimized out>, retval_ptr_ptr=<value optimized out>, 
    param_count=<value optimized out>, params=<value optimized out>, no_separation=1, symbol_table=0x0) at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:749
749	}
Value returned is $4 = 0
(gdb) 
Run till exit from #0  call_user_function_ex (function_table=<value optimized out>, object_pp=<value optimized out>, function_name=<value optimized out>, 
    retval_ptr_ptr=<value optimized out>, param_count=<value optimized out>, params=<value optimized out>, no_separation=1, symbol_table=0x0)
    at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:749
0x00000000005dd62a in zend_error (type=2, format=0x6f9a60 "%s%s%s() expects parameter %d to be %s, %s given") at /usr/src/debug/php-5.4.31/Zend/zend.c:1197
1197				if (call_user_function_ex(CG(function_table), NULL, orig_user_error_handler, &retval, 5, params, 1, NULL TSRMLS_CC) == SUCCESS) {
Value returned is $5 = 0
(gdb) 
Run till exit from #0  0x00000000005dd62a in zend_error (type=2, format=0x6f9a60 "%s%s%s() expects parameter %d to be %s, %s given") at /usr/src/debug/php-5.4.31/Zend/zend.c:1197
0x00000000005e7a7b in zend_parse_arg (num_args=1, type_spec=0x6d9261 "rl", va=<value optimized out>, flags=0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:686
686					zend_error(severity, "%s%s%s() expects parameter %d to be %s, %s given",
(gdb) 
Run till exit from #0  0x00000000005e7a7b in zend_parse_arg (num_args=1, type_spec=0x6d9261 "rl", va=<value optimized out>, flags=0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:686
846				if (varargs && *varargs) {
(gdb) 
Run till exit from #0  zend_parse_va_args (num_args=1, type_spec=0x6d9261 "rl", va=<value optimized out>, flags=0) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:846
zend_parse_parameters (num_args=2, type_spec=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:899
899	}
Value returned is $6 = -1
(gdb) 
Run till exit from #0  zend_parse_parameters (num_args=2, type_spec=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_API.c:899
0x000000000052a481 in zif_fread (ht=<value optimized out>, return_value=0x2e44cc0, return_value_ptr=<value optimized out>, this_ptr=<value optimized out>, 
    return_value_used=<value optimized out>) at /usr/src/debug/php-5.4.31/ext/standard/file.c:1747
1747		if (zend_parse_parameters(ZEND_NUM_ARGS() TSRMLS_CC, "rl", &arg1, &len) == FAILURE) {
Value returned is $7 = -1
(gdb) 
Run till exit from #0  0x000000000052a481 in zif_fread (ht=<value optimized out>, return_value=0x2e44cc0, return_value_ptr=<value optimized out>, this_ptr=<value optimized out>, 
    return_value_used=<value optimized out>) at /usr/src/debug/php-5.4.31/ext/standard/file.c:1747
0x00000000006599ec in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:643
643					fbc->internal_function.handler(opline->extended_value, ret->var.ptr, (fbc->common.fn_flags & ZEND_ACC_RETURN_REFERENCE) ? &ret->var.ptr : NULL, EX(object), RETURN_VALUE_USED(opline) TSRMLS_CC);
(gdb) 
Run till exit from #0  0x00000000006599ec in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:643
0x0000000000647328 in execute (op_array=0x3f181d8) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:410
410			if ((ret = OPLINE->handler(execute_data TSRMLS_CC)) > 0) {
Value returned is $8 = 0
(gdb) bt
#0  0x0000000000647328 in execute (op_array=0x3f181d8) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:410
#1  0x00000000005d1fbc in zend_call_function (fci=0x7ffff9dc1150, fci_cache=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_execute_API.c:956
#2  0x000000000051f03f in zif_call_user_func (ht=<value optimized out>, return_value=0x7f5437a24c88, return_value_ptr=<value optimized out>, this_ptr=<value optimized out>, 
    return_value_used=<value optimized out>) at /usr/src/debug/php-5.4.31/ext/standard/basic_functions.c:4724
#3  0x00000000006599ec in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:643
#4  0x0000000000647328 in execute (op_array=0x3f7bdf0) at /usr/src/debug/php-5.4.31/Zend/zend_vm_execute.h:410
#5  0x00000000005dce60 in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /usr/src/debug/php-5.4.31/Zend/zend.c:1315
#6  0x000000000057f958 in php_execute_script (primary_file=0x7ffff9dc3930) at /usr/src/debug/php-5.4.31/main/main.c:2502
#7  0x00000000006915c2 in main (argc=<value optimized out>, argv=<value optimized out>) at /usr/src/debug/php-5.4.31/sapi/fpm/fpm/fpm_main.c:1933

[2021-06-02 10:31 UTC] cmb@php.net

-Status: Open +Status: Feedback -Assigned To: +Assigned To: cmb

[2021-06-02 10:31 UTC] cmb@php.net

Is this still an issue with any of the actively supported PHP
versions[1]?

[1] <https://www.php.net/supported-versions.php>

[2021-06-13 04:22 UTC] php-bugs at lists dot php dot net

No feedback was provided. The bug is being suspended because
we assume that you are no longer experiencing the problem.
If this is not the case and you are able to provide the
information that was requested earlier, please do so and
change the status of the bug back to "Re-Opened". Thank you.

	php.net \| support \| documentation \| report a bug \| advanced search \| search howto \| statistics \| random bug \| login
go to bug id or search bugs for


Copyright © 2001-2024 The PHP Group All rights reserved.	Last updated: Sun Dec 22 06:01:30 2024 UTC