由于之后的工作需要对nginx进行开发,所以又要开始去再深入了解一下它的实现。借此机会也记录一下自己在代码分析过程中的使用的一些技巧和方法。
网络上流传的nginx的代码分析很多,大多都是给代码打打注释和分析一下原因,以及概括的说下整个系统的结构。这样就会带来一些缺点,当有人想去深入学习的时候跟着大神们总结出来的代码分析去一点一点的浏览代码时,看了很久依然是雾蒙蒙的一片,不晓得当前这一行代码之后会发生什么,这样就很难弄明白这行代码为什么会写成这个样子。至少我是这个样子的 :) 。特别是在nginx中大量使用的回调函数绝对会让你最初在做代码阅读时有种崩溃到想死的感觉。
授之以鱼不如授之以渔,对于我来说更倾向于去了解前辈们面对未知的思维过程,而不是思考出的结果。由于我也不是大神,之下的分析或者方法难免有偏差或幼稚的地方,还请大家指出以及提出更好的方法。:)
为了能更加迅速的了解一个项目、服务器或者是一个简单的小应用的结构以及执行过程,我们十分渴望了解到其在执行的过程中的函数调用顺序。当这些完全摆在你面前的时候一切都清晰可见了。
也有一些工具提供了针对源码生成函数调用树导出成图片的工具,但是由于种类繁多并且实现的质量不一,这里我使用的是mac下自带的dtruss,是对dtrace的一个脚本封装,对应用进行的分析。在linux下也有相应的strace。但是也有一个缺点,只能跟踪到执行系统调用的函数。-_-!!,不过好在nginx的日志做得非常到位,在开启debug的情况下,基本每个函数都能跟踪到,日志是要调用系统调用输出的嘛。
先看个例子:
/* hello.c */
#include <unistd.h>
void print()
{
write(STDOUT_FILENO,"hello\n",6);
}
void test()
{
print();
}
int main(int argc,char*argv[])
{
while(1){
test();
sleep(1);
}
return 0;
}
gcc hello.c -o hello
我们通过dtruss直接执行hello
sudo dtruss -s /$path/hello
dtruss必须以root身份执行,"-s"则是打印应用执行的函数调用堆栈
mprotect(0x100A32000, 0x88, 0x1) = 0 0
libsystem_kernel.dylib`__mprotect+0xa
libsystem_c.dylib`unsetenv+0x42
libdtrace_dyld.dylib`_GLOBAL__I_dtrace_dyld.cpp+0x15
dyld`ImageLoaderMachO::doModInitFunctions(ImageLoader::LinkContext const&)+0xda
dyld`ImageLoaderMachO::doInitialization(ImageLoader::LinkContext const&)+0x2e
dyld`ImageLoader::recursiveInitialization(ImageLoader::LinkContext const&, unsigned int, ImageLoader::InitializerTimingList&)+0x104
dyld`ImageLoader::runInitializers(ImageLoader::LinkContext const&, ImageLoader::InitializerTimingList&)+0x3b
dyld`dyld::initializeMainExecutable()+0xa9
dyld`dyld::_main(macho_header const*, unsigned long, int, char const**, char const**, char const**)+0x73c
dyld`_dyld_start+0x31
hello`0x1009f7000
write(0x1, "hello\n\0", 0x6) = 6 0
libsystem_kernel.dylib`write+0xa
hello`test+0x9
hello`main+0x14
hello`start+0x34
hello`0x1
hello
__semwait_signal(0x1003, 0x0, 0x1) = -1 Err#60
libsystem_kernel.dylib`__semwait_signal+0xa
libsystem_c.dylib`sleep+0x3d
hello`main+0x20
hello`start+0x34
hello`0x1
将会得到了很长很长的这样的信息,mprotect getpid ioctl 等之类的就是当前的系统调用函数了,而下面有缩进的就是系统的函数调用栈了。 对于一个简单的hello程序来讲,只有最后两段才是程序执行时的系统调用,对比源码,一次系统调用是sleep,一次是write,这里没有使用printf也是由于c库中的printf中也含有大量的系统调用。会让情况看起来更加复杂一些。
而在之前的以dyld开头的一些函数调用是操作系统的动态库加载器在程序执行之前加载动态库时的一些系统调用. :)
函数调用堆栈能非常清楚直观的表现出你当前所执行的这个函数是在哪里被调用的,如这段:
write(0x1, "hello\n\0", 0x6) = 6 0
libsystem_kernel.dylib`write+0xa
hello`test+0x9
hello`main+0x14
hello`start+0x34
hello`0x1
在write被执行时,函数调用堆栈中已经存在了test,这里跟踪不到print,也就是调用系统调用的那个函数,当然,这个也不会给我们跟踪代码带来太多阻碍,因为在系统调用的上一层一般都是会有包装函数的。:)
另外呢,对于nginx它用得是多进程的模型,并且是daemon进程,所以如果直接使用sudo dtruss nginx的话程序启动后,初始化完毕就结束啦。就跟踪不到服务器执行响应时的函数调用了。所以如果要想跟踪到一条请求的处理过程,就要先看下nignx worker process的id,直接让dtruss hook进子进程:
ps aux | grep nginx
yuen 12193 0.0 0.0 2435776 996 ?? S 7:04上午 0:00.01 nginx: worker process
yuen 12192 0.0 0.0 2435600 296 ?? Ss 7:04上午 0:00.00 nginx: master process ./nginx
sudo dtruss -s -p 12193
这时候从浏览器向nginx请求一个最简单的index.html的页面,将会在终端得到这样的输出:
SYSCALL(args) = return
kevent(0x9, 0x7FAF98808200, 0x0) = 1 0
libsystem_kernel.dylib`kevent+0xa
nginx`ngx_process_events_and_timers+0xb9
nginx`ngx_worker_process_cycle+0x114
nginx`ngx_spawn_process+0x32b
nginx`ngx_start_worker_processes+0x7e
nginx`ngx_master_process_cycle+0x15a
nginx`main+0xb21
nginx`start+0x34
nginx`0x1
write(0x4, "2011/09/25 07:10:24 [debug] 12193#0: kevent events: 1\n\0", 0x36) = 54 0
libsystem_kernel.dylib`write+0xa
nginx`ngx_kqueue_process_events+0x138
nginx`ngx_process_events_and_timers+0xb9
nginx`ngx_worker_process_cycle+0x114
nginx`ngx_spawn_process+0x32b
nginx`ngx_start_worker_processes+0x7e
nginx`ngx_master_process_cycle+0x15a
nginx`main+0xb21
nginx`start+0x34
nginx`0x1
write(0x4, "2011/09/25 07:10:24 [debug] 12193#0: kevent: 3: ft:-1 fl:0025 ff:00000000 d:336 ud:00007FAF9882B750\n\0", 0x64) = 100 0
libsystem_kernel.dylib`write+0xa
nginx`ngx_kqueue_process_events+0x263
nginx`ngx_process_events_and_timers+0xb9
nginx`ngx_worker_process_cycle+0x114
nginx`ngx_spawn_process+0x32b
nginx`ngx_start_worker_processes+0x7e
nginx`ngx_master_process_cycle+0x15a
nginx`main+0xb21
nginx`start+0x34
nginx`0x1
当然了,这只是其中的一小丢丢的部分,已经可以非常确定的知道一条请求是从nginx`ngx_process_events_and_timers这个函数开始蔓延的了。一直顺着这个思路就可以一直找到输出丢给浏览器的结果了。:)
并且nginx的debug输出信息也会直接在系统调用时作为参数在这里输出出来,从debug信息中也可以知道大量的执行过程中的信息,也是一件让人开心的事情。
上面的方法可以快速的看到函数调用堆栈,分析出执行流程,但是输出冗余太多,不能很好的一眼看出全局结构。这时候自己可能需要一些可以定制的方式去查看结构输出了。
gcc提供了这样的支持,添加编译参数"-finstrument-functions",它能在每个函数执行前后调用两个自定义函数,方便做代码跟踪和分析的时候使用。这里还有一点需要说明的是如果你是在mac机器上使用的是默认xcode自带的gcc的话,可能会遇到"Undefined symbols"的错误。虽然在其man gcc手册里说是兼容的,但是事实情况好似不是这样子的。所以可能需要下载编译一个新的gcc。
在用gcc编译跟踪的项目时添加-finstrument-functions参数后,编译器会在每个函数的入口和出口处调用这两个函数。
void __cyg_profile_func_enter(void *this_fn,void* call_site)
void __cyg_profile_func_exit(void *this_fn,void* call_site)
我们只需要实现这两个函数就可以,函数的参数,this_fn是被调用的函数,call_site是调用this_fn的函数。
另外一点需要说明的就是给这两个函数添加上了"attribute((no_instrument_function))"声明,即在进行函数调用跟踪的时候不对这两个函数进行跟踪,否则就要一直递归下去直到栈溢出了。
还是让我们从一个小例子开始:
/* hello.c */
#include <stdio.h>
void __attribute__((__no_instrument_function__))
__cyg_profile_func_enter(void *this_fn,void* call_site)
{
printf("in >> %x\n",this_fn);
}
void __attribute__((__no_instrument_function__))
__cyg_profile_func_exit(void *this_fn,void* call_site)
{
printf("out << %x\n",this_fn);
}
void test()
{
}
void print()
{
test();
}
int main()
{
print();
return 0;
}
gcc -g -finstrument-functions -Wall -o hello hello.c
./hello
in >> d93edb2
in >> d93ed7c
in >> d93ed50
out<< d93ed50
out<< d93ed7c
out<< d93edb2
但是只有函数的地址并没有函数名称,这个是我们不能满意的。所以对代码做一下修整,使用backtrace输出函数调用栈,但我们只取当前函数的调用:
#include <execinfo.h>
//我们假设函数调用深度不会超过128
static void* callstack[128];
static unsigned int offset = 0;
void __attribute__((__no_instrument_function__))
print_stack()
{
int frames = backtrace(callstack, 128);
char** strs = backtrace_symbols(callstack, frames);
char* target;
int i;
//取堆栈中的第三条记录,即是调用__cyg_profile_func_enter的那个函数
//并使用c库中的分割字符串找到函数名输出
//原本strs[2] = "2 hello 0x000000010ae40df1 print + 23"
/* 注意:不同的操作系统可能strs返回的字符串格式不一样 */
//分割后就只剩下 print 了
target = strtok(strs[2]," ");
for (i=0;i<3;i++)
target = strtok(NULL," ");
for(i=0;i<offset;i++)
printf("| ");
puts(target);
free(strs);
}
void __attribute__((__no_instrument_function__))
__cyg_profile_func_enter(void *this_fn,void* call_site)
{
printf("in >> ");
print_stack();
}
void __attribute__((__no_instrument_function__))
__cyg_profile_func_exit(void *this_fn,void* call_site)
{
printf("out<< ");
print_stack();
}
编译后再执行就得到如下结果了:
in >> main
in >> | print
in >> | | test
out<< | | test
out<< | print
out<< main
有了上面的经验,我们再回到一个工程中怎么去使用它,依然拿nginx举例:
在执行configure之后,我们需要修改一下makefile,把自己的跟踪代码和调试参数加进去。
打开objs下的makefile,将CFLAGS修改为:
CFLAGS = -pipe -W -Wall -Wpointer-arith -Wno-unused-parameter -Wunused-function -Wunused-variable -Wunused-value -Werror -g -Wno-deprecated-declarations -finstrument-functions
这里添加了 -finstrument-functions,并去掉了原有的gcc编译优化参数。 在链接这项加入我们的跟踪函数的文件,
$(LINK) -o objs/nginx \
objs/src/core/nginx.o \
objs/src/core/ngx_log.o \
objs/src/core/ngx_palloc.o \
。。。 。。。 \
src/gcctrace.c
执行make就可以编译啦
下面是我的gcctrace.c文件,懒得自己写的同学可以直接copy.并且不仅仅可以用于nginx的调试。:)一劳永逸嘛。
#include <stdio.h>
#include <string.h>
#include <execinfo.h>
static void* callstack[128];
static unsigned int offset = 0;
void __attribute__((__no_instrument_function__))
print_stack()
{
int frames = backtrace(callstack, 128);
char** strs = backtrace_symbols(callstack, frames);
char* target;
int i;
target = strtok(strs[2]," ");
for (i=0;i<3;i++)
target = strtok(NULL," ");
for(i=0;i<offset;i++)
printf("| ");
printf("%d ",i);
puts(target);
free(strs);
}
void __attribute__((__no_instrument_function__))
__cyg_profile_func_enter(void *this_fn,void* call_site)
{
printf("in >> ");
print_stack();
offset++;
}
void __attribute__((__no_instrument_function__))
__cyg_profile_func_exit(void *this_fn,void* call_site)
{
printf("out<< ");
offset--;
print_stack();
}
这里我加入了缩进的个数显示,方便自己看嘛。并且可以通过grep来只输出自己关心的深度,防止大量无用的输出干扰思路。:)
另外一点需要注意的就是需要改写一下nginx.conf文件,加入这这个选项:"daemon off;",并设置为单进程模式。
让nginx不要跑在后台进程里,那样的话输出就看不到了。
这里最后我们得到的输出结构就时这个样子的了:
in >> | | 2 ngx_signal_handler
in >> | | | 3 ngx_time_sigsafe_update
out<< | | | 3 ngx_time_sigsafe_update
in >> | | | 3 ngx_process_get_status
out<< | | | 3 ngx_process_get_status
out<< | | 2 ngx_signal_handler
in >> | | 2 ngx_time_update
out<< | | 2 ngx_time_update
in >> | | 2 ngx_reap_children
in >> | | | 3 ngx_close_channel
out<< | | | 3 ngx_close_channel
out<< | | 2 ngx_reap_children
in >> | | 2 ngx_master_process_exit
in >> | | | 3 ngx_delete_pidfile
out<< | | | 3 ngx_delete_pidfile
in >> | | | 3 ngx_close_listening_sockets
out<< | | | 3 ngx_close_listening_sockets
in >> | | | 3 ngx_destroy_pool
in >> | | | | 4 ngx_resolver_cleanup
in >> | | | | | 5 ngx_resolver_cleanup_tree
out<< | | | | | 5 ngx_resolver_cleanup_tree
in >> | | | | | 5 ngx_resolver_cleanup_tree
out<< | | | | | 5 ngx_resolver_cleanup_tree
out<< | | | | 4 ngx_resolver_cleanup
out<< | | | 3 ngx_destroy_pool
毕竟是需要阅读源代码的,只看看执行过程也没什么意义。但是这里我就没有什么太多的技巧了。
我使用的是emacs + etags + grep-find + gdb-mode 做的代码查找和阅读。
etags可以比较方便的直接跳转的函数,变量的定义处,grep-find比较容易查找出一个函数都被谁调用了。gdb-mode是在要深入代码,跟踪参数变化时用的。
总体来说使用grep-find比较多,可以直接查找整个工程,也是相当方便的。
关于emacs的一些配置也可以在我之前的blog中找到。
我知道的,了解的也就这么多啦。不足之处还请大家指教。
hava fun :)
EOF