这几天看完了php的虚拟机和词法解析,写下这篇日志来将php的调试方法做一个总结,像一些最简单的var_dump,die这种入门级调试技巧就不说了,这种var_dump die的方法在fpm上还好说,但是如果是守护进程就需要破坏现场,重启服务。写日志有的时候也很难命中进程现场的运行情况。
如果我们运行了一个守护进程陷入了死循环或者阻塞希望知道这个程序的运行位置,或者希望知道程序里发生了什么我们应该怎么办呢?我们可以使用gdb和strace去调试程序
1、strace
strace 这个东西主要是用来观察进程的网络通讯方面的执行问题,好多次我都是通过strace排查出了问题所在!!!
strace -p 进程号
strace 可以观察进程的函数运行过程以及信号执行情况,好多次我都是使用strace去排查出程序出现的问题,比如curl没有设置timeout,当出现网络波动的时候,导致出现了大量的SIGPIPE信号我们就可以使用strace观察出来,包括子进程频繁挂掉的信号SIGCHILD信号我们也可以通过strace看出来,还有是否有收到数据啊等等。
2、gdbinit
我们使用gdb -p 进程号
进入之后 source + gdbinit的路径
使用zbacktrace 就可以看到php的调用栈了
3.使用gdb
如果从gdb上我们需要了解zend的虚拟机
主要从execute_data 这个数据结构上去查看运行过程
struct _zend_execute_data {
const zend_op *opline; /* executed opline */
zend_execute_data *call; /* current call */
zval *return_value;
zend_function *func; /* executed function */
zval This; /* this + call_info + num_args */
zend_execute_data *prev_execute_data;
zend_array *symbol_table;
#if ZEND_EX_USE_RUN_TIME_CACHE
void **run_time_cache; /* cache op_array->run_time_cache */
#endif
};
union _zend_function {
zend_uchar type; /* MUST be the first element of this struct! */
uint32_t quick_arg_flags;
struct {
zend_uchar type; /* never used */
zend_uchar arg_flags[3]; /* bitset of arg_info.pass_by_reference */
uint32_t fn_flags;
zend_string *function_name;
zend_class_entry *scope;
union _zend_function *prototype;
uint32_t num_args;
uint32_t required_num_args;
zend_arg_info *arg_info;
} common;
zend_op_array op_array;
zend_internal_function internal_function;
};
我们可以通过execute_data中的func这个成员里的common 成员中的function_name里去看到函数名字,filename可以看到文件敏子等等,当然如果我们想知道之前的调用过程可通过prev_execute_data 继续向上查看,当然我们可以通过
EG(current_execute_data)
去查看运行栈,里面也是有prev_execute_data的
如一个简单的gdb例子
(gdb) p *executor_globals.current_execute_data->func->common.function_name->val@10
$1 = {116 't', 114 'r', 97 'a', 99 'c', 107 'k', 101 'e', 114 'r', 95 '_', 116 't', 101 'e'}
(gdb) p *executor_globals.current_execute_data->prev_execute_data->func->common.function_name->val@10
$2 = {116 't', 101 'e', 115 's', 116 't', 0 '\000', 110 'n', 103 'g', 0 '\000', 1 '\001', 0 '\000'}
(gdb) p execute_data
$3 = (zend_execute_data *) 0x7fa8c0e1d150
(gdb) p *execute_data
$4 = {opline = 0x0, call = 0x0, return_value = 0x0, func = 0x563525130dc0, This = {value = {lval = 0, dval = 0, counted = 0x0, str = 0x0, arr = 0x0, obj = 0x0, res = 0x0, ref = 0x0, ast = 0x0, zv = 0x0, ptr = 0x0, ce = 0x0, func = 0x0, ww = {w1 = 0, w2 = 0}}, u1 = {v = {type = 0 '\000', type_flags = 0 '\000', u = {call_info = 0, extra = 0}}, type_info = 0}, u2 = {next = 1, cache_slot = 1, opline_num = 1, lineno = 1, num_args = 1, fe_pos = 1, fe_iter_idx = 1, access_flags = 1, property_guard = 1, constant_flags = 1, extra = 1}}, prev_execute_data = 0x7fa8c0e1d0b0, symbol_table = 0x0, run_time_cache = 0x0}
(gdb) p *execute_data.prev_execute_data
$5 = {opline = 0x7fa8c0ed0ee0, call = 0x0, return_value = 0x0, func = 0x7fa8c0e18d58, This = {value = {lval = 0, dval = 0, counted = 0x0, str = 0x0, arr = 0x0, obj = 0x0, res = 0x0, ref = 0x0, ast = 0x0, zv = 0x0, ptr = 0x0, ce = 0x0, func = 0x0, ww = {w1 = 0, w2 = 0}}, u1 = {v = {type = 0 '\000', type_flags = 0 '\000', u = {call_info = 0, extra = 0}}, type_info = 0}, u2 = {next = 0, cache_slot = 0, opline_num = 0, lineno = 0, num_args = 0, fe_pos = 0, fe_iter_idx = 0, access_flags = 0, property_guard = 0, constant_flags = 0, extra = 0}}, prev_execute_data = 0x7fa8c0e1d030, symbol_table = 0x300000000, run_time_cache = 0x7fa8c0e18e30}
(gdb) p *execute_data.prev_execute_data.common
There is no member named common.
(gdb) p *execute_data.prev_execute_data.func
$6 = {type = 2 '\002', quick_arg_flags = 2, common = {type = 2 '\002', arg_flags = {0 '\000', 0 '\000', 0 '\000'}, fn_flags = 134217728, function_name = 0x7fa8c0e80540, scope = 0x0, prototype = 0x0, num_args = 0, required_num_args = 0, arg_info = 0x0}, op_array = {type = 2 '\002', arg_flags = {0 '\000', 0 '\000', 0 '\000'}, fn_flags = 134217728, function_name = 0x7fa8c0e80540, scope = 0x0, prototype = 0x0, num_args = 0, required_num_args = 0, arg_info = 0x0, cache_size = 24, last_var = 1, T = 4, last = 11, opcodes = 0x7fa8c0ed0e00, run_time_cache = 0x7fa8c0e18e30, static_variables = 0x0, vars = 0x7fa8c0e79620, refcount = 0x7fa8c0e79618, last_live_range = 0, last_try_catch = 0, live_range = 0x0, try_catch_array = 0x0, filename = 0x7fa8c0e92600, line_start = 2, line_end = 7, doc_comment = 0x0, last_literal = 5, literals = 0x7fa8c0ed0f60, reserved = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0}}, internal_function = {type = 2 '\002', arg_flags = {0 '\000', 0 '\000', 0 '\000'}, fn_flags = 134217728, function_name = 0x7fa8c0e80540, scope = 0x0, prototype = 0x0, num_args = 0, required_num_args = 0, arg_info = 0x0, handler = 0x100000018, module = 0xb00000004, reserved = {0x7fa8c0ed0e00, 0x7fa8c0e18e30, 0x0, 0x7fa8c0e79620, 0x7fa8c0e79618, 0x0}}}
(gdb) p *execute_data.prev_execute_data.func.common
Structure has no component named operator*.
(gdb) p *execute_data.prev_execute_data.func
$7 = {type = 2 '\002', quick_arg_flags = 2, common = {type = 2 '\002', arg_flags = {0 '\000', 0 '\000', 0 '\000'}, fn_flags = 134217728, function_name = 0x7fa8c0e80540, scope = 0x0, prototype = 0x0, num_args = 0, required_num_args = 0, arg_info = 0x0}, op_array = {type = 2 '\002', arg_flags = {0 '\000', 0 '\000', 0 '\000'}, fn_flags = 134217728, function_name = 0x7fa8c0e80540, scope = 0x0, prototype = 0x0, num_args = 0, required_num_args = 0, arg_info = 0x0, cache_size = 24, last_var = 1, T = 4, last = 11, opcodes = 0x7fa8c0ed0e00, run_time_cache = 0x7fa8c0e18e30, static_variables = 0x0, vars = 0x7fa8c0e79620, refcount = 0x7fa8c0e79618, last_live_range = 0, last_try_catch = 0, live_range = 0x0, try_catch_array = 0x0, filename = 0x7fa8c0e92600, line_start = 2, line_end = 7, doc_comment = 0x0, last_literal = 5, literals = 0x7fa8c0ed0f60, reserved = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0}}, internal_function = {type = 2 '\002', arg_flags = {0 '\000', 0 '\000', 0 '\000'}, fn_flags = 134217728, function_name = 0x7fa8c0e80540, scope = 0x0, prototype = 0x0, num_args = 0, required_num_args = 0, arg_info = 0x0, handler = 0x100000018, module = 0xb00000004, reserved = {0x7fa8c0ed0e00, 0x7fa8c0e18e30, 0x0, 0x7fa8c0e79620, 0x7fa8c0e79618, 0x0}}}
(gdb) p *execute_data.prev_execute_data.func.common
Structure has no component named operator*.
(gdb) p *execute_data.prev_execute_data.func.common.function_name
$8 = {gc = {refcount = 1, u = {type_info = 6}}, h = 9223372043240499301, len = 4, val = {116 't'}}
(gdb) p *execute_data.prev_execute_data.func.common.function_name.val@10
$9 = {116 't', 101 'e', 115 's', 116 't', 0 '\000', 110 'n', 103 'g', 0 '\000', 1 '\001', 0 '\000'}
当然在条件允许可以直接var_dump的情况下可以不用gdb直接用debug_backtrace做这件事
贴出他的核心源码看到也是这么做的
ZEND_API void zend_fetch_debug_backtrace(zval *return_value, int skip_last, int options, int limit) /* {{{ */
{
zend_execute_data *ptr, *skip, *call = NULL;
zend_object *object;
int lineno, frameno = 0;
zend_function *func;
zend_string *function_name;
zend_string *filename;
zend_string *include_filename = NULL;
zval stack_frame, tmp;
array_init(return_value);
if (!(ptr = EG(current_execute_data))) {
return;
}
if (!ptr->func || !ZEND_USER_CODE(ptr->func->common.type)) {
call = ptr;
ptr = ptr->prev_execute_data;
}
if (ptr) {
if (skip_last) {
/* skip debug_backtrace() */
call = ptr;
ptr = ptr->prev_execute_data;
} else {
/* skip "new Exception()" */
if (ptr->func && ZEND_USER_CODE(ptr->func->common.type) && (ptr->opline->opcode == ZEND_NEW)) {
call = ptr;
ptr = ptr->prev_execute_data;
}
}
if (!call) {
call = ptr;
ptr = ptr->prev_execute_data;
}
}
while (ptr && (limit == 0 || frameno < limit)) {
frameno++;
array_init(&stack_frame);
ptr = zend_generator_check_placeholder_frame(ptr);
skip = ptr;
/* skip internal handler */
if ((!skip->func || !ZEND_USER_CODE(skip->func->common.type)) &&
skip->prev_execute_data &&
skip->prev_execute_data->func &&
ZEND_USER_CODE(skip->prev_execute_data->func->common.type) &&
skip->prev_execute_data->opline->opcode != ZEND_DO_FCALL &&
skip->prev_execute_data->opline->opcode != ZEND_DO_ICALL &&
skip->prev_execute_data->opline->opcode != ZEND_DO_UCALL &&
skip->prev_execute_data->opline->opcode != ZEND_DO_FCALL_BY_NAME &&
skip->prev_execute_data->opline->opcode != ZEND_INCLUDE_OR_EVAL) {
skip = skip->prev_execute_data;
}
if (skip->func && ZEND_USER_CODE(skip->func->common.type)) {
filename = skip->func->op_array.filename;
if (skip->opline->opcode == ZEND_HANDLE_EXCEPTION) {
if (EG(opline_before_exception)) {
lineno = EG(opline_before_exception)->lineno;
} else {
lineno = skip->func->op_array.line_end;
}
} else {
lineno = skip->opline->lineno;
}
ZVAL_STR_COPY(&tmp, filename);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_FILE), &tmp);
ZVAL_LONG(&tmp, lineno);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_LINE), &tmp);
/* try to fetch args only if an FCALL was just made - elsewise we're in the middle of a function
* and debug_baktrace() might have been called by the error_handler. in this case we don't
* want to pop anything of the argument-stack */
} else {
zend_execute_data *prev_call = skip;
zend_execute_data *prev = skip->prev_execute_data;
while (prev) {
if (prev_call &&
prev_call->func &&
!ZEND_USER_CODE(prev_call->func->common.type) &&
!(prev_call->func->common.fn_flags & ZEND_ACC_CALL_VIA_TRAMPOLINE)) {
break;
}
if (prev->func && ZEND_USER_CODE(prev->func->common.type)) {
ZVAL_STR_COPY(&tmp, prev->func->op_array.filename);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_FILE), &tmp);
ZVAL_LONG(&tmp, prev->opline->lineno);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_LINE), &tmp);
break;
}
prev_call = prev;
prev = prev->prev_execute_data;
}
filename = NULL;
}
/* $this may be passed into regular internal functions */
object = (call && (Z_TYPE(call->This) == IS_OBJECT)) ? Z_OBJ(call->This) : NULL;
if (call && call->func) {
func = call->func;
function_name = (func->common.scope &&
func->common.scope->trait_aliases) ?
zend_resolve_method_name(
(object ? object->ce : func->common.scope), func) :
func->common.function_name;
} else {
func = NULL;
function_name = NULL;
}
if (function_name) {
ZVAL_STR_COPY(&tmp, function_name);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_FUNCTION), &tmp);
if (object) {
if (func->common.scope) {
ZVAL_STR_COPY(&tmp, func->common.scope->name);
} else if (object->handlers->get_class_name == zend_std_get_class_name) {
ZVAL_STR_COPY(&tmp, object->ce->name);
} else {
ZVAL_STR(&tmp, object->handlers->get_class_name(object));
}
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_CLASS), &tmp);
if ((options & DEBUG_BACKTRACE_PROVIDE_OBJECT) != 0) {
ZVAL_OBJ(&tmp, object);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_OBJECT), &tmp);
Z_ADDREF(tmp);
}
ZVAL_INTERNED_STR(&tmp, ZSTR_KNOWN(ZEND_STR_OBJECT_OPERATOR));
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_TYPE), &tmp);
} else if (func->common.scope) {
ZVAL_STR_COPY(&tmp, func->common.scope->name);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_CLASS), &tmp);
ZVAL_INTERNED_STR(&tmp, ZSTR_KNOWN(ZEND_STR_PAAMAYIM_NEKUDOTAYIM));
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_TYPE), &tmp);
}
if ((options & DEBUG_BACKTRACE_IGNORE_ARGS) == 0 &&
func->type != ZEND_EVAL_CODE) {
debug_backtrace_get_args(call, &tmp);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_ARGS), &tmp);
}
} else {
/* i know this is kinda ugly, but i'm trying to avoid extra cycles in the main execution loop */
zend_bool build_filename_arg = 1;
zend_string *pseudo_function_name;
if (!ptr->func || !ZEND_USER_CODE(ptr->func->common.type) || ptr->opline->opcode != ZEND_INCLUDE_OR_EVAL) {
/* can happen when calling eval from a custom sapi */
pseudo_function_name = ZSTR_KNOWN(ZEND_STR_UNKNOWN);
build_filename_arg = 0;
} else
switch (ptr->opline->extended_value) {
case ZEND_EVAL:
pseudo_function_name = ZSTR_KNOWN(ZEND_STR_EVAL);
build_filename_arg = 0;
break;
case ZEND_INCLUDE:
pseudo_function_name = ZSTR_KNOWN(ZEND_STR_INCLUDE);
break;
case ZEND_REQUIRE:
pseudo_function_name = ZSTR_KNOWN(ZEND_STR_REQUIRE);
break;
case ZEND_INCLUDE_ONCE:
pseudo_function_name = ZSTR_KNOWN(ZEND_STR_INCLUDE_ONCE);
break;
case ZEND_REQUIRE_ONCE:
pseudo_function_name = ZSTR_KNOWN(ZEND_STR_REQUIRE_ONCE);
break;
default:
/* this can actually happen if you use debug_backtrace() in your error_handler and
* you're in the top-scope */
pseudo_function_name = ZSTR_KNOWN(ZEND_STR_UNKNOWN);
build_filename_arg = 0;
break;
}
if (build_filename_arg && include_filename) {
zval arg_array;
array_init(&arg_array);
/* include_filename always points to the last filename of the last last called-function.
if we have called include in the frame above - this is the file we have included.
*/
ZVAL_STR_COPY(&tmp, include_filename);
zend_hash_next_index_insert_new(Z_ARRVAL(arg_array), &tmp);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_ARGS), &arg_array);
}
ZVAL_INTERNED_STR(&tmp, pseudo_function_name);
zend_hash_add_new(Z_ARRVAL(stack_frame), ZSTR_KNOWN(ZEND_STR_FUNCTION), &tmp);
}
zend_hash_next_index_insert_new(Z_ARRVAL_P(return_value), &stack_frame);
include_filename = filename;
call = skip;
ptr = skip->prev_execute_data;
}
}