Recently, when I was helping my colleague solve the problem of Swoole Server, I found that one worker process has been in R state and the CPU time is very high. It is initially concluded that a dead loop occurred in PHP code.
The following is a piece of code to show how to solve the PHP dead loop problem.
#dead_loop.php
$array = array();
for($i = 0; $i < 10000; $i++)
{
$array[] = $i;
}
include __DIR__."/";
#
while(1)
{
usleep(10);
$keys = array_flip($array);
$index = array_search(rand(1500, 9999), $array);
$str = str_repeat('A', $index);
$strb = test($index, $str);
}
function test($index, $str)
{
return str_replace('A', 'B', $str);
}
The process ID and status are obtained through ps aux as follows. Use gdb -p process ptrace trace and get the call stack through the bt command
htf 3834 2.6 0.2 166676 22060 pts/12 R+ 10:50 0:12 php dead_loop.php
gdb -p 3834
(gdb) bt
#0 0x00000000008cc03f in zend_mm_check_ptr (heap=0x1eaa2c0, ptr=0x2584910, silent=1, __zend_filename=0xee3d40 "/home/htf/workspace/php-5.4.27/Zend/zend_variables.c",
__zend_lineno=182, __zend_orig_filename=0xee1888 "/home/htf/workspace/php-5.4.27/Zend/zend_execute_API.c", __zend_orig_lineno=437)
at /home/htf/workspace/php-5.4.27/Zend/zend_alloc.c:1485
#1 0x00000000008cd643 in _zend_mm_free_int (heap=0x1eaa2c0, p=0x2584910, __zend_filename=0xee3d40 "/home/htf/workspace/php-5.4.27/Zend/zend_variables.c", __zend_lineno=182,
__zend_orig_filename=0xee1888 "/home/htf/workspace/php-5.4.27/Zend/zend_execute_API.c", __zend_orig_lineno=437) at /home/htf/workspace/php-5.4.27/Zend/zend_alloc.c:2064
#2 0x00000000008cebf7 in _efree (ptr=0x2584910, __zend_filename=0xee3d40 "/home/htf/workspace/php-5.4.27/Zend/zend_variables.c", __zend_lineno=182,
__zend_orig_filename=0xee1888 "/home/htf/workspace/php-5.4.27/Zend/zend_execute_API.c", __zend_orig_lineno=437) at /home/htf/workspace/php-5.4.27/Zend/zend_alloc.c:2436
#3 0x00000000008eda0a in _zval_ptr_dtor (zval_ptr=0x25849a0, __zend_filename=0xee3d40 "/home/htf/workspace/php-5.4.27/Zend/zend_variables.c", __zend_lineno=182)
at /home/htf/workspace/php-5.4.27/Zend/zend_execute_API.c:437
#4 0x00000000008fe687 in _zval_ptr_dtor_wrapper (zval_ptr=0x25849a0) at /home/htf/workspace/php-5.4.27/Zend/zend_variables.c:182
#5 0x000000000091259f in zend_hash_destroy (ht=0x7f7263f6e380) at /home/htf/workspace/php-5.4.27/Zend/zend_hash.c:560
#6 0x00000000008fe2c5 in _zval_dtor_func (zvalue=0x7f726426fe50, __zend_filename=0xeea290 "/home/htf/workspace/php-5.4.27/Zend/zend_execute.c", __zend_lineno=901)
at /home/htf/workspace/php-5.4.27/Zend/zend_variables.c:45
#7 0x0000000000936656 in _zval_dtor (zvalue=0x7f726426fe50, __zend_filename=0xeea290 "/home/htf/workspace/php-5.4.27/Zend/zend_execute.c", __zend_lineno=901)
at /home/htf/workspace/php-5.4.27/Zend/zend_variables.h:35
#8 0x0000000000939747 in zend_assign_to_variable (variable_ptr_ptr=0x7f7263f8e738, value=0x7f726426f6a8) at /home/htf/workspace/php-5.4.27/Zend/zend_execute.c:901
#9 0x0000000000997ee5 in ZEND_ASSIGN_SPEC_CV_VAR_HANDLER (execute_data=0x7f726d04b2a8) at /home/htf/workspace/php-5.4.27/Zend/zend_vm_execute.h:33168
#10 0x000000000093b5fd in execute (op_array=0x21d58b0) at /home/htf/workspace/php-5.4.27/Zend/zend_vm_execute.h:410
#11 0x0000000000901692 in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /home/htf/workspace/php-5.4.27/Zend/:1315
#12 0x000000000087926a in php_execute_script (primary_file=0x7ffffe0038d0) at /home/htf/workspace/php-5.4.27/main/:2502
#13 0x00000000009a32e3 in do_cli (argc=2, argv=0x7ffffe004d18) at /home/htf/workspace/php-5.4.27/sapi/cli/php_cli.c:989
#14 0x00000000009a4491 in main (argc=2, argv=0x7ffffe004d18) at /home/htf/workspace/php-5.4.27/sapi/cli/php_cli.c:1365
After executing gdb, the process of the dead loop will become T, indicating that it is being traced. This is exclusive, so you can no longer use strace/gdb or other ptrace tools to debug this process. In addition, this process will interrupt execution. After gdb enters c, the program continues to run downward. Then press ctrl + c again to interrupt the program. View the process's call stack through the bt command.
(gdb) bt
#0 _zend_mm_alloc_int (heap=0x1eaa2c0, size=72, __zend_filename=0xe43410 "/home/htf/workspace/php-5.4.27/ext/standard/", __zend_lineno=2719,
__zend_orig_filename=0xee5a38 "/home/htf/workspace/php-5.4.27/Zend/zend_hash.c", __zend_orig_lineno=412) at /home/htf/workspace/php-5.4.27/Zend/zend_alloc.c:1895
#1 0x00000000008ceb86 in _emalloc (size=72, __zend_filename=0xe43410 "/home/htf/workspace/php-5.4.27/ext/standard/", __zend_lineno=2719,
__zend_orig_filename=0xee5a38 "/home/htf/workspace/php-5.4.27/Zend/zend_hash.c", __zend_orig_lineno=412) at /home/htf/workspace/php-5.4.27/Zend/zend_alloc.c:2425
#2 0x0000000000911d85 in _zend_hash_index_update_or_next_insert (ht=0x2257a10, h=3972, pData=0x7ffffe0012b0, nDataSize=8, pDest=0x0, flag=1,
__zend_filename=0xe43410 "/home/htf/workspace/php-5.4.27/ext/standard/", __zend_lineno=2719) at /home/htf/workspace/php-5.4.27/Zend/zend_hash.c:412
#3 0x00000000007767e1 in zif_array_flip (ht=1, return_value=0x7f726424ea68, return_value_ptr=0x0, this_ptr=0x0, return_value_used=1)
at /home/htf/workspace/php-5.4.27/ext/standard/:2719
#4 0x000000000093c03e in zend_do_fcall_common_helper_SPEC (execute_data=0x7f726d04b2a8) at /home/htf/workspace/php-5.4.27/Zend/zend_vm_execute.h:643
#5 0x00000000009400e6 in ZEND_DO_FCALL_SPEC_CONST_HANDLER (execute_data=0x7f726d04b2a8) at /home/htf/workspace/php-5.4.27/Zend/zend_vm_execute.h:2233
#6 0x000000000093b5fd in execute (op_array=0x21d58b0) at /home/htf/workspace/php-5.4.27/Zend/zend_vm_execute.h:410
The BT information was different the two times, because the program was interrupted at different locations. When you see the line execute (oparray=0x21d58b0), here is the entry for PHP to execute oparray. Enter f 6 in gdb (you can get it by calling stack number).
(gdb) f 6
#6 0x000000000093b5fd in execute (op_array=0x21d58b0) at /home/htf/workspace/php-5.4.27/Zend/zend_vm_execute.h:410
410 if ((ret = OPLINE->handler(execute_data TSRMLS_CC)) > 0) {
(gdb) p *op_array
$2 = {type = 2 '\002', function_name = 0x7f726d086540 "test", scope = 0x0, fn_flags = 134217728, prototype = 0x0, num_args = 2, required_num_args = 2, arg_info = 0x7f726d086bd8,
refcount = 0x7f726d0870f0, opcodes = 0x7f726424d600, last = 8, vars = 0x7f726424e890, last_var = 2, T = 1, brk_cont_array = 0x0, last_brk_cont = 0, try_catch_array = 0x0,
last_try_catch = 0, static_variables = 0x0, this_var = 4294967295, filename = 0x7f726424ba38 "/home/htf/wwwroot/", line_start = 12, line_end = 15, doc_comment = 0x0,
doc_comment_len = 0, early_binding = 4294967295, literals = 0x7f726424eae0, last_literal = 4, run_time_cache = 0x7f726450bfb0, last_cache_slot = 1, reserved = {0x0, 0x0, 0x0, 0x0}}
You can see which PHP file op_array is from the filename. Then enter f0 to enter the current position.
(gdb) p **executor_globals.opline_ptr
$4 = {handler = 0x93ff9c , op1 = {constant = 1680133296, var = 1680133296, num = 1680133296, hash = 140129283132592, opline_num = 1680133296,
jmp_addr = 0x7f726424ccb0, zv = 0x7f726424ccb0, literal = 0x7f726424ccb0, ptr = 0x7f726424ccb0}, op2 = {constant = 0, var = 0, num = 0, hash = 0, opline_num = 0, jmp_addr = 0x0,
zv = 0x0, literal = 0x0, ptr = 0x0}, result = {constant = 32, var = 32, num = 32, hash = 32, opline_num = 32, jmp_addr = 0x20, zv = 0x20, literal = 0x20, ptr = 0x20},
extended_value = 1, lineno = 5, opcode = 60 '
The lineno here represents the number of lines of code where OPCODE is located. You can go to the corresponding file to see which line of code is. You can see more information using GDB, so I won’t introduce it one by one here. If you are interested, you can try it yourself.
Use of zbacktrace
Zend official provides a gdb script that encapsulates the instructions and can directly see the calling relationship of the php function. There is a .gdbinit in the root directory of the php source package. use
source your_php_src_path/.gdbinit
zbacktrace
You can directly see the call stack of PHP functions.
The above is the entire content of this article, I hope you like it.