xhprof源码分析
2015-06-04
源码位置：/path/xhprof/extension/xhprof.c
数据结构
两个重要的数据结构：
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 */
} hp_entry_t;
typedef struct hp_global_t {
/* ---------- Global attributes: ----------- */
/* Indicates if xhprof is currently enabled */
int enabled;
/* Indicates if xhprof was ever enabled during this request */
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. */
uint32 cpu_num;
/* The saved cpu affinity. */
cpu_set_t prev_mask;
/* The cpu id current process is bound to. (default 0) */
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;
第一个 hp_entry_t
name_hprof 为 函数名称
rlvl_hprof 为 递归调用深度
tsc_start 为 函数开始的时钟 通过rdtsc指令获得时钟周期
mu_start_hprof 为 函数内存使用量 通过 zend_memory_usage(0 TSRMLS_CC)获得
pmu_start_hprof 为 函数的内存峰值使用量 通过 zend_memory_peak_usage(0 TSRMLS_CC)获得
ru_start_hprof 通过 getrusage()获得CPU使用情况
prev_hprof 为 上一个hp_entry_t的指针
hash_code 为 函数名的哈希值
第二个 hp_global_t
enabled 为 xhprof现在是否启用
ever_enabled 为 xhprof在这次请求中是否被启用过，作用在于是否需要将hp_globals.entries设置为NULL
stats_count 为 存储统计信息的数组，key为函数名，val为统计信息
profiler_level 为 当前xhprof的模式(XHPROF_MODE_HIERARCHICAL/XHPROF_MODE_SAMPLED)
entries 为 分析堆栈的顶部
entry_free_list 用完的hp_entry_t不会被马上释放，而是放到这个列表中
mode_cb 为 不同xhprof模式设置的回调
last_sample_time 为 上一次采样时间点
last_sample_tsc 为 上一次采样时钟周期数
sampling_interval_tsc 为 采样的时钟周期间隔
cpu_frequencies 为 各个CPU和的时钟频率
cpu_num 为 机器拥有的逻辑CPU核数
prev_mask 为 保存的CPU亲和性
cur_cpu_id 为 当前绑定的CPU id
xhprof_flags 为 xhprof的标志，分为 XHPROF_FLAGS_NO_BUILTINS（跳过所有内置逻辑）、XHPROF_FLAGS_CPU（输出的性能数据中添加CPU的数据）、XHPROF_FLAGS_MEMORY（输出的性能数据中添加内存数据）
func_hash_counters 为 当前的分析堆栈中，函数的调用计算
ignored_function_names 为 忽略分析的函数名称数组
ignored_function_filter 为 用于快速判断一个函数是否应该被分析
模式
XHPROF_MODE_HIERARCHICAL模式，该模式是详细分析整个PHP代码的执行情况，对应xhprof_enable()和xhprof_disable()函数。其输出的分析数据如下：
<?php
array(7) {
["main()==>load::./inc.php"]=>
array(5) {
……
}
["main()==>run_init::Test/inc.php"]=>
array(5) {
……
}
["bar==>echoHello"]=>
array(5) {
……
}
["foo==>bar"]=>
array(5) {
……
}
["main()==>foo"]=>
array(5) {
……
}
["main()==>xhprof_disable"]=>
array(5) {
……
}
["main()"]=>
array(5) {
["ct"]=>
int(1)
["wt"]=>
int(390372)
["cpu"]=>
int(392000)
["mu"]=>
int(15040)
["pmu"]=>
int(10024)
}}
XHPROF_MODE_SAMPLED模式，该模式每隔0.1秒取样一次，记录当前执行的堆栈，对应xhprof_sample_enable()和xhprof_sample_disable()函数。其输出的分析数据如下：
<?php
array(5) {
["1460294938.300000"]=>
string(30)
"main()==>foo==>bar==>echoHello"
["1460294938.400000"]=>
string(30)
"main()==>foo==>bar==>echoHello"
["1460294938.500000"]=>
string(30)
"main()==>foo==>bar==>echoHello"
["1460294938.600000"]=>
string(30)
"main()==>foo==>bar==>echoHello"
["1460294938.700000"]=>
string(30)
"main()==>foo==>bar==>echoHello"
}
XHPROF_MODE_HIERARCHICAL模式分析
xhprof_enable([ int $flags = 0 [, array $options ]] )
$flags为分析添加额外信息的可选标记。例如，XHPROF_FLAGS_MEMORY可以开启内存的分析。
$options为array的可选选项，就是通过传递’ignored_functions’选项来忽略性能分析中的某些函数。
在 xhprof_enable() 中会先执行：
- hp_get_ignored_functions_from_arg(optional_array)，将要忽略的函数存储到char **hp_globals.ignored_function_names中。
- 接着执行hp_ignored_functions_filter_init()初始化hp_globals.ignored_function_filter[XHPROF_IGNORED_FUNCTION_FILTER_SIZE]。
打点采集性能数据的实现
在hp_begin(long level, long xhprof_flags TSRMLS_DC)中，替换掉了zend内核execute_data的执行函数以及一些编译代码的函数，相当于加了一层proxy，部分代码如下：
_zend_compile_file=zend_compile_file;
zend_compile_file=hp_compile_file;
_zend_compile_string=zend_compile_string;
zend_compile_string=hp_compile_string;
_zend_execute_ex=zend_execute_ex;
zend_execute_ex=hp_execute_ex;
_zend_execute_internal=zend_execute_internal;
zend_execute_internal=hp_execute_internal;
在每一层proxy中，都会调用BEGIN_PROFILING和END_PROFILING，以hp_execute_ex为例：
ZEND_DLEXPORT void hp_execute_ex (zend_execute_data *execute_data TSRMLS_DC) {
……
//函数执行前打点
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);
}
xhprof_disable输出数据中ct和wt的实现
ct是当前代码块被执行的次数，在END_PROFILING->hp_globals.mode_cb.end_fn_cb->hp_mode_hier_endfn_cb->hp_mode_shared_endfn_cb中：
hp_inc_count(counts, "ct", 1 TSRMLS_CC)
在每次代码块执行结束后就会对其对应的ct增1。
wt是当前代码块总的执行时间（wall clock time），在END_PROFILING->hp_globals.mode_cb.end_fn_cb->hp_mode_hier_endfn_cb->hp_mode_shared_endfn_cb中：
tsc_end = cycle_timer();
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);
top->tsc_start是在BEGIN_PROFILING->hp_globals.mode_cb.begin_fn_cb->hp_mode_hier_beginfn_cb()中通过cycle_timer()获得的，具体代码：
//通过rdtsc汇编指令获取CPU时钟周期
static inline uint64 cycle_timer() {
uint32 __a,__d;
uint64 val;
asm volatile("rdtsc":"=a" (__a),"=d" (__d));
(val)=((uint64)__a)|(((uint64)__d)<<32);
return val;
}
hp_globals.cpu_frequencies[hp_globals.cur_cpu_id]存储了各个CPU对应的时钟频率，时钟频率的获取是通过如下方式：
static double get_cpu_frequency() {
struct timeval start;
struct timeval end;
if (gettimeofday(&start, 0)) {
perror("gettimeofday");
return 0.0;
}
uint64 tsc_start = cycle_timer();
usleep(5000);
if (gettimeofday(&end, 0)) {
perror("gettimeofday");
return 0.0;
}
uint64 tsc_end = cycle_timer();
// 时钟周期数/时间 = 时钟频率
return (tsc_end - tsc_start) * 1.0 / (get_us_interval(&start, &end));
}
static void get_all_cpu_frequencies() {
int id;
double frequency;
hp_globals.cpu_frequencies = malloc(sizeof(double) * hp_globals.cpu_num);
if (hp_globals.cpu_frequencies == NULL) {
return;
}
/* Iterate over all cpus found on the machine. */
for (id = 0; id < hp_globals.cpu_num; ++id) {
/* Only get the previous cpu affinity mask for the first call. */
if (bind_to_cpu(id)) {
//为了测定每个CPU核的时钟频率，
//需要先绑定到指定的核上运行
clear_frequencies();
return;
}
/* Make sure the current process gets scheduled to the target cpu.
This might not be necessary though. */
usleep(0);
frequency = get_cpu_frequency();
if (frequency == 0.0) {
clear_frequencies();
return;
}
hp_globals.cpu_frequencies[id] = frequency;
}
}
在获取了每个核的CPU时钟频率后，会随机地绑定到某个核上继续执行。 最后在get_us_from_tsc()中，通过代码块执行花费的时钟周期数/当前CPU时钟频率得到代码块执行的时间wt。采用这种方式应该能更精确地获取wt。
xhprof_disable输出数据中cpu的实现
在END_PROFILING-> hp_globals.mode_cb.end_fn_cb -> hp_mode_hier_endfn_cb中：
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
);
}
top->ru_start_hprof是在hp_mode_hier_beginfn_cb()中通过getrusage()设置的。 ru_utime为user time，ru_stime为system time，两者加起来就得到cpu time了。
xhprof_disable输出数据中mu和pmu的实现
在END_PROFILING -> hp_globals.mode_cb.end_fn_cb -> hp_mode_hier_endfn_cb中：
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);}
top->mu_start_hprof和top->pmu_start_hprof已在BEGIN_PROFILING->hp_globals.mode_cb.begin_fn_cb->hp_mode_hier_beginfn_cb中通过zend_memory_usage和zend_memory_peak_usage赋值。这两个zend函数的实现：
ZEND_API size_t zend_memory_usage
(int real_usage TSRMLS_DC){
if (real_usage) {
return AG(mm_heap)->real_size;
//PHP实际占用了的系统内存
} else {
size_t usage = AG(mm_heap)->size;
#if ZEND_MM_CACHE
usage -= AG(mm_heap)->cached;
#endif
return usage;
}
}
ZEND_API size_t zend_memory_peak_usage
(int real_usage TSRMLS_DC){
if (real_usage) {
return AG(mm_heap)->real_peak;
} else {
return AG(mm_heap)->peak;
}
}
可见，这里获取的mu和pmu是当前使用到的内存，不包括已从系统申请的但未使用的。
XHPROF_MODE_SAMPLED模式分析
该模式不支持过滤掉不想被profile的函数。打点方式与XHPROF_MODE_HIERARCHICAL模式相同，不同点在于BEGIN_PROFILING调用的是hp_mode_sampled_beginfn_cb，END_PROFILING调用的是hp_mode_sampled_endfn_cb，而在这两个函数中都只调用了hp_sample_check()，其代码如下：
void hp_sample_check(hp_entry_t **entries TSRMLS_DC) {
/* Validate input */
if (!entries || !(*entries)) {
return;
}
while (
(cycle_timer() - hp_globals.last_sample_tsc) > hp_globals.sampling_interval_tsc) {
//如果当前时钟周期数 - 上一次的时钟周期数 > 采样的时钟周期间隔则继续采样
hp_globals.last_sample_tsc += hp_globals.sampling_interval_tsc;
//将上一次的时钟周期数加上采样的时钟周期数间隔
incr_us_interval(&hp_globals.last_sample_time,XHPROF_SAMPLING_INTERVAL);
//更新上一次的采样时间点
hp_sample_stack(entries TSRMLS_CC);
//采样数据
}
return;
}
在hp_sample_stack()中就是往hp_globals.stats_count中添加：函数调用栈 => 采样时间点。 在hp_begin->hp_init_profiler_state->hp_globals.mode_cb.init_cb->hp_mode_sampled_init_cb中做了一些初始化工作：
void hp_mode_sampled_init_cb(TSRMLS_D) {
struct timeval now;
uint64 truncated_us;
uint64 truncated_tsc;
double cpu_freq = hp_globals.cpu_frequencies[hp_globals.cur_cpu_id];
/* Init the last_sample in tsc */
hp_globals.last_sample_tsc = cycle_timer();
/* Find the microseconds that need to be truncated */
gettimeofday(&hp_globals.last_sample_time, 0);
//初始化开始采样的时钟周期数
now = hp_globals.last_sample_time;
//hp_trunc_time的作用是将hp_globals.last_sample_time更新为XHPROF_SAMPLING_INTERVAL的整数倍
hp_trunc_time(&hp_globals.last_sample_time, XHPROF_SAMPLING_INTERVAL);
/* Subtract truncated time from last_sample_tsc */
truncated_us = get_us_interval(&hp_globals.last_sample_time, &now);
truncated_tsc = get_tsc_from_us(truncated_us, cpu_freq);
if (hp_globals.last_sample_tsc > truncated_tsc) {
/* just to be safe while subtracting unsigned ints */
hp_globals.last_sample_tsc -= truncated_tsc;
}
/* Convert sampling interval to ticks */
//为了使last_sample_tsc和last_sample_time保持同步,对于hp_globals.last_sample_tsc<= truncated_tsc的情况，出现的可能性非常小，即使真的出现了也只是漏了第一次采样
hp_globals.sampling_interval_tsc =
get_tsc_from_us(XHPROF_SAMPLING_INTERVAL, cpu_freq);
}
函数调用堆栈的实现
对于每一个hp_entry_t（即分析点），都会有一个prev_hprof属性指向上一层的分析点，hp_get_function_stack(hp_entry_t *entry, int level, char *result_buf, size_t result_len)就是通过这个将函数调用堆栈的函数名串起来，在XHPROF_MODE_SAMPLED模式下level传参是INT_MAX，也就是说尽可能的将整个函数调用栈的函数名串起来返回，而在XHPROF_MODE_HIERARCHICAL模式下level传参是2，也就是说只取当前跟其上一级的函数名串起来返回，从两种模式的输出结果就可以看出来了。