低级bug耗费12小时Fix

lzwml

低级bug耗费12小时Fix [复制链接]

 

调试某程序非常简单的程序，简单到认为不可能存在缺陷，但该BUG处理时间超过12小时：

• 程序属于后台进程，监控系统每隔15秒检查外设IO状态，IO异常后发出报警或复位外设，外设都在linux下有/sys/class等文件节点。
  

程序有规律性4-5小时后崩溃




程序崩溃原因也非常简单：

• 某文件反复打开未释放，打开文件数超过linux单进程最大打开文件数。
• 未对文件打开成功检查，持无效文件描述符写文件导致Segmentation fault
  

下面是排除过程
下面是程序运行打印信息，可看到文件在调用ti_ck_mutil函数第266行时崩溃
TickStatusIO():124
ti_ck_mutil():266
ti_ck_mutil():272
ti_ck_mutil():276
TickStatusIO():105
ti_ck_mutil():266
Segmentation fault (core dumped)

gdb打开coredump查看栈状态
(gdb) bt
#0  0x401b28e0 in vfwprintf () from /lib/libc.so.6
#1  0xe92d47f0 in ?? ()
#2  0x00009d10 in ti_ck_mutil (ptiem=0xbebffa4c, len=1) at src/ckself.c:268
#3  0x00008e2c in TickStatusIO () at src/initgpio.c:106
#4  0x00009238 in main (argc=1, argv=0xbebffbf4) at src/initgpio.c:304

最终显示在c库函数vfwprintf里崩溃，并在在二行的栈地址以及崩溃了，显示" in ?? ()"，他的调用者正是ti_ck_mutil，并且更进一步显示崩溃点在268行而不是266行。

如下是ti_ck_mutil的主要代码

1. int ti_ck_mutil(struct ck_self *ptiem, int len)
   
2. {
   
3.         FILE *stream;
   
4.         char strout[256];
   
5.         int ret;
   
6.         int failcount = 0;
   
7. 
   
8.         for (int i = 0; i < len; i++) {
   
9.                 printf("%s()%d\n", __FUNCTION__, __LINE__);          //226行
   
10.                 stream = popen(ptiem[i].dir, "r");                                //未检查文件是否成功
    
11.                 ret = fread( strout, sizeof(char), sizeof(strout), stream);        
    
12.                 strout[ret] = '\0';
    
13.                 pclose(stream);
    
14.                 // ...
    
15. 
    
16.         }
    
17.         return failcount;
    
18. }

复制代码

fread输入参数只有4个，可能存在的错误无非是3点：

• 被编译器优化后strout的缓存不是256（纯属胡乱猜测，可以通过查看map文件看到具体大小）
• fread写入最后一个字符时溢出（实际我读写的文件不超过64byte，不应该超过256）
• stream文件描述符无效
  

于是首先对fread修改，保证最后一个字符不被fread填写。
ret = fread( strout, sizeof(char), sizeof(strout) - 1, stream);        
测试依旧崩溃

接着对stream检查，代码如下

1. int ti_ck_mutil(struct ck_self *ptiem, int len)
   
2. {
   
3.         FILE *stream;
   
4.         char strout[256];
   
5.         int ret;
   
6.         int failcount = 0;
   
7. 
   
8.         for (int i = 0; i < len; i++) {
   
9.                 printf("%s()%d\n", __FUNCTION__, __LINE__);  //226行
   
10.                 stream = popen(ptiem[i].dir, "r");                  //未检查文件是否成功
    
11.                 if (NULL == stream) {
    
12.                         continue;
    
13.                 }
    
14.                 // 读出内容，并在末尾添加字符串终结符号
    
15.                 //存在溢出，应该用 sizeof(strout) - 1
    
16.                 ret = fread( strout, sizeof(char), sizeof(strout) - 1, stream);        
    
17.                 strout[ret] = '\0';
    
18.                 pclose(stream);
    
19.                 // ...
    
20. 
    
21.         }
    
22.         return failcount;
    
23. }

复制代码

测试4小时后程序不崩溃，但当IO异常后也既不报警也不复位，相当于程序不工作了，由上面代码可知必定是popen失败导致，函数内部一直continue。

查看man popen

RETURN VALUE        The popen() function returns NULL if the fork(2) or pipe(2) calls fail, or if it cannot allocate memory.

man fork

RETURN VALUE        On  success,  the  PID of the child process is returned in the parent, and 0 is returned in the child.  On failure, -1 is        returned in the parent, no child process is created, and errno is set appropriately.

问题很明显popen的失败是由于fork函数失败或内存不足，而这两个失败的原因是不能创建子进程。
该程序运行内存极小，不可能引发内存不足。
根据经验linux对每个用户默认打开文件数做了限制，也预示着代码里有未释放的文件描述符

为了证明再次运行应用程序，接着每秒查看程序打开的文件个数
watch -n 1 ls /proc//fd
果不其然文件个数每15s递增一个。当达到最大限制1024后文件打开失败，ti_ck_mutil只能continue，也就是原始程序在大约4小时崩溃的原因（15s打开新文件，大约4.2小时达到1024上限）

全工程搜索open关键词，看各调用后是否存在close，果然有个opendir后忘记closedir。
加上后bug解决

soso

解决问题的过程真心不容易

bobde163

学习楼主的经验

chenzhufly

这个调试的过程 值得学习

QingjinZheng

学习一下，好东西

白丁

复现时间太长，搞三遍十二小时就没了，真心伤不起

wateras1

能重复性复现问题还好，就担心有些问题概率性出现，那就很麻烦了

lzwml

也是运气好，如果最初的程序没有崩溃，而是无限continue，定位就更加难，都不清楚为什么程序在跑着而不工作

胡迪

原来如此!!

lyfly_away

感谢分享经验

Charlottechang

感谢分享经验

Charlottechang

感谢分享经验