昨天同事帮忙review代码的时候,发现我代码里使用了一个非线程安全的函数localtime,并建议我使用线程安全的localtime_r。
于是我查了一下相关资料:
time 与 gettimeofday 两个函数得到的都是从Epoch开始(1970-1-1, 00:00:00)到当前的秒数(tt=tv.tv_sec),而后者还能得到更精细的微秒级结果,即tv_sec*(10^6)+tv_usec为从Epoch开始到当前的微秒数。
localtime函数:将时间数值变换成本地时间,考虑到本地时区和夏令时标志;
struct tm *localtime(const time_t *timep);
struct tm *localtime_r(const time_t *timep, struct tm *result);
localtime是直接返回strcut tm*指针(如果成功的话),这个指针是指向一个静态变量的;因此,返回的指针所指向的静态变量有可能被其他地方调用的localtime改掉,例如多线程使用的时候。
localtime_r则是由调用者在第二个参数传入一个struct tm result指针,该函数会把结果填充到这个传入的指针所指内存里面;成功的返回值指针也就是struct tm result。
其他的时间函数,如asctime,asctime_r;ctime,ctime_r;gmtime,gmtime_r都是类似的,所以,时间函数的 _r 版本都是线程安全的。
改这个实在太简单了,没想到在这里付出了沉重的代价。
原来的代码:
struct tm *p;
p = localtime(&timep);
修改后的代码:
struct tm *p = NULL;
localtime_r(&timep, p);
编译通过后,以为就万事大吉了,接下来发布测试,却得不到响应,查看服务器提示信息:
[alarm] zombie process,no keep alive msg for 60 seconds
竟然僵死了??
由于这次的代码里除了以上的修改,还改了其他地方,所以一开始我以为是其他地方出了问题,完全没有怀疑是localtime_r的问题,所以对其他地方进行了测试、代码review。
折腾了半个下午,毫无进展,于是决定分段测试,先只修改localtime_r,不改其他地方,以定位问题所在。结果发现只修改了localtime_r也发生了僵死,才把目标锁定在这里了。
真相只有一个——localtime_r死锁了。
这很新奇,localtime_r不就是专门服务于多线程的吗,为什么反而导致死锁?
百思不得其解,把这个问题抛给了同事,同事说,你看到的也许只是表象,建议你看一下堆栈,查一查死锁在哪里了。
这一下子击中了我的软肋——其实我一开始就应该这样做的。
而为什么说是软肋呢,因为我一开始当然也想用gdb来调试看一看问题所在,可是我完全没有试过调试多线程的程序,根本不知道怎么下手——然后就躲在自己的舒适圈里面,继续用“打印日志”、“裸眼debug”等以前在学校惯用的方法来调试。
走投无路,还是要走出舒适圈,google了几篇多线程调试的文章,发现其实也不是很难——并且这个方法很快就帮助我定位到了问题的根源。
方法如下:
1.运行服务程序,并向该服务发送请求,使其执行相应函数进入死锁的地方。
2.查找进程id
$ ps -aux| grep "PNGBusiOp"
得到pid为9883
3.启动gdb,attach进程
$ gdb PNGBusiOpServer 9883
(gdb) info threads //显示所有线程信息
33 Thread 0x7f5c1bee5700 (LWP 9884) 0x00007f5c1d2db98e in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
32 Thread 0x7f5c1b6e4700 (LWP 9885) 0x00007f5c1d2db98e in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
31 Thread 0x7f5c19edc700 (LWP 9886) 0x00007f5c1d2db98e in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
30 Thread 0x7f5c196db700 (LWP 9887) 0x00007f5c1d2db98e in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
29 Thread 0x7f5c18eda700 (LWP 9888) 0x00007f5c1d2db98e in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
28 Thread 0x7f5c13fff700 (LWP 9889) 0x00007f5c1c884ef3 in epoll_wait () from /lib64/libc.so.6
27 Thread 0x7f5c137fe700 (LWP 9890) 0x00007f5c1d2db98e in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
26 Thread 0x7f5c12ffd700 (LWP 9891) 0x00007f5c1c89405e in __lll_lock_wait_private () from /lib64/libc.so.6
25 Thread 0x7f5c127fc700 (LWP 9892)