XHProf 简要概念

• 重新封装zend的原生方法

• 如果要检测CPU的话，会有5ms的延迟，因为需要计算cpu频率

• 内部使用了链表

• 源码地址：/root/Downloads/xhprof/extension/xhprof.c

最重要的两个结构体

/* Xhprof's global state. * * This structure is instantiated once.  Initialize defaults for attributes in * 这个结构体只初始化一次 * hp_init_profiler_state() Cleanup/free attributes in * hp_clean_profiler_state() */typedef struct hp_global_t {  /*       ----------   Global attributes:  -----------       */  /* Indicates if xhprof is currently enabled 是否当前可用 */  int              enabled;  /* Indicates if xhprof was ever enabled during this request 在本次请求过程中是否其用过xhprof */  int              ever_enabled;  /* Holds all the xhprof statistics */  zval            *stats_count;  /* Indicates the current xhprof mode or level 当前的运行模式和等级*/  int              profiler_level;  /* Top of the profile stack 堆栈中的第一个*/  hp_entry_t      *entries;  /* freelist of hp_entry_t chunks for reuse... */  hp_entry_t      *entry_free_list;  /* Callbacks for various xhprof modes 代表不同模式的回调么？*/  hp_mode_cb       mode_cb;  /*       ----------   Mode specific attributes:  -----------       */  /* Global to track the time of the last sample in time and ticks */  struct timeval   last_sample_time;  uint64           last_sample_tsc;  /* XHPROF_SAMPLING_INTERVAL in ticks */  uint64           sampling_interval_tsc;  /* This array is used to store cpu frequencies for all available logical   * cpus.  For now, we assume the cpu frequencies will not change for power   * saving or other reasons. If we need to worry about that in the future, we   * can use a periodical timer to re-calculate this arrary every once in a   * while (for example, every 1 or 5 seconds). 处理器的执行频率？*/  double *cpu_frequencies;  /* The number of logical CPUs this machine has. 逻辑cpu的数量*/  uint32 cpu_num;  /* The saved cpu affinity. */  cpu_set_t prev_mask;  /* The cpu id current process is bound to. (default 0) 当前进程在的处理器的id*/  uint32 cur_cpu_id;  /* XHProf flags */  uint32 xhprof_flags;  /* counter table indexed by hash value of function names.  方法的调用次数的表*/  uint8  func_hash_counters[256];  /* Table of ignored function names and their filter 忽略统计的方法的表格*/  char  **ignored_function_names;  uint8   ignored_function_filter[XHPROF_IGNORED_FUNCTION_FILTER_SIZE];} hp_global_t;

typedef struct hp_entry_t {  char                   *name_hprof;                       /* function name 方法名称*/  int                     rlvl_hprof;        /* recursion level for function 方法的递归层级*/  uint64                  tsc_start;         /* start value for TSC counter  开始的时钟周期*/  long int                mu_start_hprof;                    /* memory usage 内存使用量*/  long int                pmu_start_hprof;              /* peak memory usage 内存使用峰值*/  struct rusage           ru_start_hprof;             /* user/sys time start */  struct hp_entry_t      *prev_hprof;    /* ptr to prev entry being profiled 指向上一个被分析的指针*/  uint8                   hash_code;     /* hash_code for the function name  每个方法名称对应的hash*/} hp_entry_t;

XHProf 在php中的使用

我们先看下XHProf的使用方法

    save_run($data,'test');// 我这里直接将可视化的链接地址打印了出来，方便调试echo "test";function test() {        $a = range(0,10000);        foreach($a as $item) {                // pass        }}

执行结果如下：（可以直接跳过结果，看下面，但是要记住有ct、wt这两个值）

array(7) {  ["test==>range"]=>  array(2) {    ["ct"]=>    int(2)    ["wt"]=>    int(4463)  }  ["main()==>test"]=>  array(2) {    ["ct"]=>    int(1)    ["wt"]=>    int(3069)  }  ["main()==>eval::/var/www/html/index2.php(9) : eval()'d code"]=>  array(2) {    ["ct"]=>    int(1)    ["wt"]=>    int(16)  }  ["eval==>test"]=>  array(2) {    ["ct"]=>    int(1)    ["wt"]=>    int(2614)  }  ["main()==>eval"]=>  array(2) {    ["ct"]=>    int(1)    ["wt"]=>    int(2617)  }  ["main()==>xhprof_disable"]=>  array(2) {    ["ct"]=>    int(1)    ["wt"]=>    int(0)  }  ["main()"]=>  array(2) {    ["ct"]=>    int(1)    ["wt"]=>    int(5716)  }}

XHProf 源码

xhprof_enable()

首先我们来看xhprof_enable()，这个方法定义了要接受的三个参数，并且将这三个参数分别传递给两个方法使用，其中最重要的是hp_begin()

/** * Start XHProf profiling in hierarchical mode. * * @param  long $flags  flags for hierarchical mode * @return void * @author kannan */PHP_FUNCTION(xhprof_enable) {  long  xhprof_flags = 0;                                    /* XHProf flags */  zval *optional_array = NULL;         /* optional array arg: for future use */  /*     获取参数并且允许传递一个l 和z的可选参数  分别代表xhprof_flags 和 optional_array    关于TSRMLS_CC 可以看http://www.laruence.com/2008/08/03/201.html    另外关于zend_parse_parameters的返回值failure 代表参数的处理是否成功   */  if (zend_parse_parameters(ZEND_NUM_ARGS() TSRMLS_CC,                            "|lz", &xhprof_flags, &optional_array) == FAILURE) {    return;  }  /*    从参数中获取需要被忽略的方法    参照手册参数的说明 http://php.net/manual/zh/function.xhprof-enable.php   */  hp_get_ignored_functions_from_arg(optional_array);  hp_begin(XHPROF_MODE_HIERARCHICAL, xhprof_flags TSRMLS_CC);}

hp_begin()

这个方法看起来很长，但是世界上逻辑很简单，主要是进行了一些初始化。

下面这四个重新替换封装非常重要，具体的方法作用已经在下面的代码注释中写明了。

1. zend_compile_file => hp_compile_file

2. zend_compile_string => hp_compile_string

3. zend_execute => hp_execute

4. zend_execute_internal => hp_execute_internal

/** * This function gets called once when xhprof gets enabled. * 这个方法在enable的时候调用一次 * It replaces all the functions like zend_execute, zend_execute_internal, * etc that needs to be instrumented with their corresponding proxies. * 他用来替换zend的一些需要被代理的方法意思就是xhprof劫持了原生方法 * hp_begin(XHPROF_MODE_HIERARCHICAL, xhprof_flags TSRMLS_CC); * * level 等级 * xhprof_flags 运行方式 */static void hp_begin(long level, long xhprof_flags TSRMLS_DC) {  /*    如果xhprof 没有开启，也就是没有调用enable方法，那么走这里买的逻辑，这个是通过hp_globals来判断的，   */  if (!hp_globals.enabled) {    int hp_profile_flag = 1;    hp_globals.enabled      = 1; /* 这里修改了enbale状态，保证enable在整个请求过程中只会被第一次调用触发 */    hp_globals.xhprof_flags = (uint32)xhprof_flags; /* 格式化为32位的无符号整数 */    /*      下面一共进行了四次replace，用来封装zend的方法      1. zend_compile_file => hp_compile_file      zend_compile_file负责将要执行的脚本文件编译成由ZE的基本指令序列构成的op codes , 然后将op codes交由zend_execute执行，从而得到我们脚本的结果。      http://www.laruence.com/2008/08/14/250.html      2. zend_compile_string => hp_compile_string      这个是把php代码编译成为opcode的过程      http://www.phpchina.com/portal.php?mod=view&aid=40347      3. zend_execute => hp_execute      zend_compile_file() zend_compile_file() is the wrapper for the lexer, parser, and code generator. It compiles a file and returns a zend_op_array.      zend_execute() After a file is compiled, its zend_op_array is executed by zend_execute().       http://php.find-info.ru/php/016/ch23lev1sec2.html      4. zend_execute_internal => hp_execute_internal      There is also a companion zend_execute_internal() function, which executes internal functions.     */    /* Replace zend_compile with our proxy 先对其进行了备份_，通过加入_下划线的方式，然后使用hp_compile_file来替换*/    _zend_compile_file = zend_compile_file;    zend_compile_file  = hp_compile_file;    /* Replace zend_compile_string with our proxy */    _zend_compile_string = zend_compile_string;    zend_compile_string = hp_compile_string;    /* Replace zend_execute with our proxy */#if PHP_VERSION_ID < 50500    _zend_execute = zend_execute;    zend_execute  = hp_execute;#else    _zend_execute_ex = zend_execute_ex;    zend_execute_ex  = hp_execute_ex;#endif    /* Replace zend_execute_internal with our proxy */    _zend_execute_internal = zend_execute_internal;    /*       XHPROF_FLAGS_NO_BUILTINGS 是用来标识，不需要统计内置函数性能       通过位运算&来判断是否用户传递的flags包含了NO_BUILTINGS      除此之外还包含一下三种flags      1. HPROF_FLAGS_NO_BUILTINS (integer) 使得跳过所有内置（内部）函数。      2. XHPROF_FLAGS_CPU (integer) 使输出的性能数据中添加 CPU 数据。      3. XHPROF_FLAGS_MEMORY (integer) 使输出的性能数据中添加内存数据。    */    if (!(hp_globals.xhprof_flags & XHPROF_FLAGS_NO_BUILTINS)) {      /* if NO_BUILTINS is not set (i.e. user wants to profile builtins),       * then we intercept internal (builtin) function calls.       * 如果没有设置的话，那么就代表用户想分析内置函数性能，并且我们就会拦截内置的方法请求       */      zend_execute_internal = hp_execute_internal;    }    /* Initialize with the dummy mode first Having these dummy callbacks saves     * us from checking if any of the callbacks are NULL everywhere.      * 首先来初始化一下这些方法，可以避免在回调方法为NULL的时候*/    hp_globals.mode_cb.init_cb     = hp_mode_dummy_init_cb;    hp_globals.mode_cb.exit_cb     = hp_mode_dummy_exit_cb;    hp_globals.mode_cb.begin_fn_cb = hp_mode_dummy_beginfn_cb;    hp_globals.mode_cb.end_fn_cb   = hp_mode_dummy_endfn_cb;    /* Register the appropriate callback functions Override just a subset of     * all the callbacks is OK. 根据不同的处理模式，简单还是详细*/    switch(level) {      /* 一般都是使用的这个模式，所以我们专注看这个mode */      case XHPROF_MODE_HIERARCHICAL:        hp_globals.mode_cb.begin_fn_cb = hp_mode_hier_beginfn_cb;        hp_globals.mode_cb.end_fn_cb   = hp_mode_hier_endfn_cb;        break;      case XHPROF_MODE_SAMPLED:        hp_globals.mode_cb.init_cb     = hp_mode_sampled_init_cb;        hp_globals.mode_cb.begin_fn_cb = hp_mode_sampled_beginfn_cb;        hp_globals.mode_cb.end_fn_cb   = hp_mode_sampled_endfn_cb;        break;    }    /* one time initializations 初始化分析器，内部搞定了cpu频率、initcb、可忽略的方法*/    hp_init_profiler_state(level TSRMLS_CC);    /* start profiling from fictitious main() */    BEGIN_PROFILING(&hp_globals.entries, ROOT_SYMBOL, hp_profile_flag);  }}

hp_init_profiler_state()

/** * Initialize profiler state * 初始化分析器状态 * * 这里最开始的时候传递进来的level是XHPROF_MODE_HIERARCHICAL *  * @author kannan, veeve */void hp_init_profiler_state(int level TSRMLS_DC) {  /* Setup globals */  if (!hp_globals.ever_enabled) {    /* 如果之前没有开启过xhprof，那么将这个值初始化为1，现在就算开启了 */    hp_globals.ever_enabled  = 1;    /* 堆栈的第一个设置空 */    hp_globals.entries = NULL;  }  /* 分析器的等级 */  hp_globals.profiler_level  = (int) level;  /* Init stats_count 初始化统计数量 */  if (hp_globals.stats_count) {    /* 释放这个内存 */    zval_dtor(hp_globals.stats_count);    /* 通知垃圾回收机制来回收这个内存 */    FREE_ZVAL(hp_globals.stats_count);  }  /* 创建一个zval变量，并且初始化为数组 参考 http://www.cunmou.com/phpbook/8.3.md */  MAKE_STD_ZVAL(hp_globals.stats_count);  array_init(hp_globals.stats_count);  /* NOTE(cjiang): some fields such as cpu_frequencies take relatively longer   * to initialize, (5 milisecond per logical cpu right now), therefore we   * calculate them lazily. 一些字段初始化起来要花费非常长的时间，那么我们要懒计算，就是放到后面计算*/  if (hp_globals.cpu_frequencies == NULL) {    get_all_cpu_frequencies();    restore_cpu_affinity(&hp_globals.prev_mask);  }  /* bind to a random cpu so that we can use rdtsc instruction. 这里竟然是随机绑定一个cpu*/  bind_to_cpu((int) (rand() % hp_globals.cpu_num));  /* Call current mode's init cb  根据不同的模式，调用初始方法，看line:1933*/  hp_globals.mode_cb.init_cb(TSRMLS_C);  /* Set up filter of functions which may be ignored during profiling 设置被过滤的方法*/  hp_ignored_functions_filter_init();}

get_cpu_frequency()

在上面的方法中调用了一个get_all_cpu_frequencies(),这个方法内部调用了一个get_cpu_frequency很有意思，因为这个方法将导致如果开启CPU的检测，那么会有5ms的延迟

/** * This is a microbenchmark to get cpu frequency the process is running on. The * returned value is used to convert TSC counter values to microseconds. * * @return double. * @author cjiang */static double get_cpu_frequency() {  struct timeval start;  struct timeval end;  /* gettimeofday 获取当前的时间，并且放到start中 */  if (gettimeofday(&start, 0)) {    perror("gettimeofday");    return 0.0;  }  uint64 tsc_start = cycle_timer();  /* Sleep for 5 miliseconds. Comparaing with gettimeofday's  few microseconds   * execution time, this should be enough.    * 这个是为了获取CPU的执行频率，用5000微秒的时间中cpu的执行次数，来得到每秒cpu能执行的频率   * TSC 自从启动CPU开始记录的时钟周期   * */  usleep(5000);  if (gettimeofday(&end, 0)) {    perror("gettimeofday");    return 0.0;  }  uint64 tsc_end = cycle_timer();  /* 时钟周期的数量除以微秒时间间隔的数量得到cpu频率 */  return (tsc_end - tsc_start) * 1.0 / (get_us_interval(&start, &end));}

BEGIN_PROFILING 重要！

这个就是分析的逻辑，他的要点在于生成了一个单项链表。

/* * Start profiling - called just before calling the actual function * 开始分析，只在正式方法调用之前要调用 * NOTE:  PLEASE MAKE SURE TSRMLS_CC IS AVAILABLE IN THE CONTEXT *        OF THE FUNCTION WHERE THIS MACRO IS CALLED. *        TSRMLS_CC CAN BE MADE AVAILABLE VIA TSRMLS_DC IN THE *        CALLING FUNCTION OR BY CALLING TSRMLS_FETCH() *        TSRMLS_FETCH() IS RELATIVELY EXPENSIVE. * entries 这里传递进来的是hp_entry_t的一个指向指针的地址 * 这个地方实际上生成的是一个单链表，都是用prev_hprof 来进行关联 * * 这里do while(0) 是用来封装宏的 *  */#define BEGIN_PROFILING(entries, symbol, profile_curr)                  \  do {                                                                  \    /* Use a hash code to filter most of the string comparisons. */     \    uint8 hash_code  = hp_inline_hash(symbol);                          \    /* 判断这个方法是否是需要忽略的方法，如果不是需要被忽略的，那么进行分析 */     \    profile_curr = !hp_ignore_entry(hash_code, symbol);                 \    if (profile_curr) {                                                 \      /* 返回一个指针（地址），开辟了一个内存空间给cur_entry,包括了hash_code、方法名称、堆栈指针 */     \      hp_entry_t *cur_entry = hp_fast_alloc_hprof_entry();              \      (cur_entry)->hash_code = hash_code;                               \      (cur_entry)->name_hprof = symbol;                                 \      /* 这里的*entries 指向的是指针hp_global_t.entires 堆栈的首地址  */     \      (cur_entry)->prev_hprof = (*(entries));                           \      /* Call the universal callback*/                                 \      hp_mode_common_beginfn((entries), (cur_entry) TSRMLS_CC);         \      /* Call the mode's beginfn callback 这个方法除却cpu和mem 只是设置了tsc_Start */                            \      hp_globals.mode_cb.begin_fn_cb((entries), (cur_entry) TSRMLS_CC); \      /* Update entries linked list */                                  \      (*(entries)) = (cur_entry);                                       \    }                                                                   \  } while (0)

我们可以看上面的链表在生成的过程中，调用了 hp_globals.mode_cb.begin_fn_cb方法。我们这里不考虑CPU和内存，那么发现给每隔current设置了一个tsc的起始时钟周期。

/** * XHPROF_MODE_HIERARCHICAL's begin function callback * * @author kannan */void hp_mode_hier_beginfn_cb(hp_entry_t **entries,                             hp_entry_t  *current  TSRMLS_DC) {  /* Get start tsc counter */  current->tsc_start = cycle_timer();  /* Get CPU usage 如果要计算cpu的话*/  if (hp_globals.xhprof_flags & XHPROF_FLAGS_CPU) {    getrusage(RUSAGE_SELF, &(current->ru_start_hprof));  }  /* Get memory usage 如果要计算内存的话*/  if (hp_globals.xhprof_flags & XHPROF_FLAGS_MEMORY) {    current->mu_start_hprof  = zend_memory_usage(0 TSRMLS_CC);    current->pmu_start_hprof = zend_memory_peak_usage(0 TSRMLS_CC);  }}

hp_execute 代码执行部分

每次有代码执行的时候，都会走这个地方，这段代码主要是在执行zend_execute的前后，粉分别调用了BEGIN_PROFILING 和END_PROFILING

#if PHP_VERSION_ID < 50500ZEND_DLEXPORT void hp_execute (zend_op_array *ops TSRMLS_DC) {#elseZEND_DLEXPORT void hp_execute_ex (zend_execute_data *execute_data TSRMLS_DC) {  zend_op_array *ops = execute_data->op_array;#endif  char          *func = NULL;  int hp_profile_flag = 1;  func = hp_get_function_name(ops TSRMLS_CC);  if (!func) {#if PHP_VERSION_ID < 50500    _zend_execute(ops TSRMLS_CC);#else    _zend_execute_ex(execute_data TSRMLS_CC);#endif    return;  }  BEGIN_PROFILING(&hp_globals.entries, func, hp_profile_flag);#if PHP_VERSION_ID < 50500  _zend_execute(ops TSRMLS_CC);#else  _zend_execute_ex(execute_data TSRMLS_CC);#endif  if (hp_globals.entries) {    END_PROFILING(&hp_globals.entries, hp_profile_flag);  }  efree(func);}

END_PROFILING

hp_globals.mode_cb.end_fn_cb((entries) TSRMLS_CC);

这段代码最终指向了hp_mode_hier_endfn_cb，这段代码中主要构成了一个'==>'数据格式，并且计算了每个方法的调用次数。

void hp_mode_hier_endfn_cb(hp_entry_t **entries  TSRMLS_DC) {  /* 整个堆栈的最后一个调用 */  hp_entry_t   *top = (*entries);  zval            *counts;  struct rusage    ru_end;  char             symbol[SCRATCH_BUF_LEN];  long int         mu_end;  long int         pmu_end;  /* Get the stat array */  hp_get_function_stack(top, 2, symbol, sizeof(symbol));  if (!(counts = hp_mode_shared_endfn_cb(top,                                         symbol  TSRMLS_CC))) {    return;  }  if (hp_globals.xhprof_flags & XHPROF_FLAGS_CPU) {    /* Get CPU usage */    getrusage(RUSAGE_SELF, &ru_end);    /* Bump CPU stats in the counts hashtable */    hp_inc_count(counts, "cpu", (get_us_interval(&(top->ru_start_hprof.ru_utime),                                              &(ru_end.ru_utime)) +                              get_us_interval(&(top->ru_start_hprof.ru_stime),                                              &(ru_end.ru_stime)))              TSRMLS_CC);  }  if (hp_globals.xhprof_flags & XHPROF_FLAGS_MEMORY) {    /* Get Memory usage */    mu_end  = zend_memory_usage(0 TSRMLS_CC);    pmu_end = zend_memory_peak_usage(0 TSRMLS_CC);    /* Bump Memory stats in the counts hashtable */    hp_inc_count(counts, "mu",  mu_end - top->mu_start_hprof    TSRMLS_CC);    hp_inc_count(counts, "pmu", pmu_end - top->pmu_start_hprof  TSRMLS_CC);  }}

hp_mode_shared_endfn_cb

这个方法统计了调用次数和消耗时间，实际上最终所有的数据都存储在hp_entry_t所构造的链表中

zval * hp_mode_shared_endfn_cb(hp_entry_t *top,                               char          *symbol  TSRMLS_DC) {  zval    *counts;  uint64   tsc_end;  /* Get end tsc counter */  tsc_end = cycle_timer();  /* Get the stat array */  if (!(counts = hp_hash_lookup(symbol TSRMLS_CC))) {    return (zval *) 0;  }  /* Bump stats in the counts hashtable */  hp_inc_count(counts, "ct", 1  TSRMLS_CC);  hp_inc_count(counts, "wt", get_us_from_tsc(tsc_end - top->tsc_start,        hp_globals.cpu_frequencies[hp_globals.cur_cpu_id]) TSRMLS_CC);  return counts;}