记录一次用户态踩内存问题

Posted DoubleLi

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了记录一次用户态踩内存问题相关的知识,希望对你有一定的参考价值。

这几天在做总结,把三年前写的一个定位案例,翻了出来。回想起定位这个问题时的场景,领导催得紧,自己对很多东西又不熟悉,所以当时面临的压力还是很大的。现在回想起来感慨还是很多的,我们在遇到任何一个问题,一定不要放弃。还记得在产品线做开发时,学到的一些项目知识,任何一个bug,他总有一天会爆发出来。任何一个问题,总有一天找到好的解决方案。当我们尝尽了所有可以尝试的方案,定位办法,解决思路后,往往这个问题也就迎刃而解了。

把工程上的事情放大看,其实生活中很多事情都是一样的,任何一个问题都有解决办法,但是这个办法不是摆在那里给我们用,他是藏在某个地方,等着我们去挖掘的。所以勤奋,努力,不气馁,找对方向都是很重要的。

好了,我们言归正传,说下我这个踩内存的问题。首先我们来看一下,公司常讲的编程规范:有一条是说,

结构体指针在使用前需要赋初值。

这是很简单的一条规则,很多时候,我们会觉着麻烦,或者我们在后面具体用到这个结构体时,我们再对结构体的成员赋值也可以,或者我们在使用时,仅对我们感兴趣的成员赋值就好了,其他的我们就不关心了。但是下面我来告诉大家,这是不行的,下面这个问题会告诉大家,编程规范都是用血的教训写出来的。遵守它,我们就可以避免很多不必要的debuging。

我们下面看下这种写法是否正确:

struct msghdr msg;
msg.msg_iov = &iov;
msg.msg_iovlen = iovlen;
ret = recvmsg(sockfd, &msg, int flags);

在函数中,我们定义了一个msg结构体,但是没有给这个结构体赋初值,仅对其中的两个我们关心的变量做了赋值。那么这样是否会带来问题呢?

 

在项目交付前,A同学需要完成对S系统的压力测试,上面会反复的重启虚拟机,反复的杀死大量服务进程,做cpu,内存加压。这样的压力测试大概执行一天到两天,就会出现异常,C服务出现了大量的coredump。

这个问题是怎么产生的,如何定位这个问题,下面请看具体的定位步骤:

1、coredump

应用程序由于各种异常或者bug导致在运行过程中异常退出或者中止,并且在满足一定条件下会产生一个叫做core的文件。通常情况下,core文件会包含了程序运行时的内存,寄存器状态,堆栈指针,内存管理信息还有各种函数调用堆栈信息等,我们可以理解为是程序工作当前状态存储生成第一个文件,许多的程序出错的时候都会产生一个core文件,通过分析这个文件,我们可以定位到程序异常退出的时候对应的堆栈调用等信息,找出问题所在并进行及时解决。

应用程序崩溃时能产生core文件,还需要做一些设置:

1) 修改ulimit –c

如下,ulimit  -c设置core文件大小,一般设置为unlimited,让core文件不受大小限制。如果在当前会话设置,那么仅对当前会话的应用程序有效,即只有当前会话的程序崩溃才会有core文件生成。如果要想系统均有效,需要设置/etc/profile文件,在文件中加入ulimit –c unlimited,然后source /etc/profile,让配置生效。如果还是生成不了core文件,可以在拉起进程的脚本里加入ulimit –c unlimited。

2) 配置core文件生成路径

core文件默认的存储位置与对应的可执行程序在同一目录下,文件名为core,很多时候程序崩溃了,我们找不到core文件存放在什么位置,按照如下方法可以指定core文件的存放位置。

echo "/home/xx/core-%e-%p-%u-%g-%t" > /proc/sys/kernel/core_pattern

参数含义:
%%:相当于%
%p:相当于<pid>
%u:相当于<uid>
%g:相当于<gid>
%s:相当于导致dump的信号的数字
%t:相当于dump的时间
%e:相当于执行文件的名称
%h:相当于hostname

coredump产生的几种可能情况:

1)内存访问越界
a) 由于使用错误的下标,导致数组访问越界。
b) 搜索字符串时,依靠字符串结束符来判断字符串是否结束,但是字符串没有正常的使用结束符。
c) 使用strcpy, strcat, sprintf, strcmp,strcasecmp等字符串操作函数,将目标字符串读/写爆。应该使用strncpy, strlcpy, strncat, strlcat, snprintf, strncmp, strncasecmp等函数防止读写越界。
2)多线程程序使用了线程不安全的函数。
3)多线程读写的数据未加锁保护。
对于会被多个线程同时访问的全局数据,应该注意加锁保护,否则很容易造成coredump
4)非法指针
  a) 使用空指针
  b) 随意使用指针转换。一个指向一段内存的指针,除非确定这段内存原先就分配为某种结构或类型,或者这种结构或类型的数组,否则不要将它转换为这种结构或类型的指针,而应该将这段内存拷贝到一个这种结构或类型中,再访问这个结构或类型。这是因为如果这段内存的开始地址不是按照这种结构或类型对齐的,那么访问它时就很容易因为bus error而core dump。
5)堆栈溢出
不要使用大的局部变量(因为局部变量都分配在栈上),这样容易造成堆栈溢出,破坏系统的栈和堆结构,导致出现莫名其妙的错误

2、Gdb进程coredump定位

 再来具体看看core文件,一般使用gdb的方式来查看,为了看到更多的信息,需要先编译当时的C服务的debug版本,可以取对应代码,加-g选项进行编译,或者从obs上取到对应的debuginfo的安装包。同时也需要安装了glibc的debuginfo包。

然后通过命令 gdb C(C为c服务的二进制可执行文件调试版本) core.C-pid打印出core信息。bt来查看调用栈。

program terminated with signal 11, Segmentation fault.
#0 strcmp () at ../sysdeps/x86_64/strcmp.s:135
135   cmpb [%rsi], %al
(gdb) bt
#0 strcmp () at ../sysdeps/x86_64/strcmp.s:135
#1 0x00007fc63177a345 in _dl_name_watch_p (name=0x400d56 "libc.so.6", map=0x7fc631909000) ad dl-misc.c:305
#2……

gdb常用命令:经常使用有l(list),b(break), p(print), r(run), c(continue), q(quit),i r(查看当时的寄存器信息),info local(查看当前变量信息),frame 4(切换),disassemble+地址(反汇编解析)

通过命令 p *(struct link_map *)+地址来查看出现问题时map的内容,如下:

(gdb) p *(struct link_map*)0x7fae515fe000
$1 = l_addr = 16, l_name = 0x7fab00000001<Address 0x7fab0000001 out of bonds>,……

可以看到结构体中l_name的地址是明显错误的,查看glibc的代码,代码如下,strcmp在比较name的时候出现了段错误。L_name的地址为0x7fab00000001,怀疑是低四字节的位置被踩。

int
internal_function
_dl_name_match_p (const char *name, const struct link_map *map)

  if (strcmp (name, map->l_name) == 0)
    return 1; 
  struct libname_list *runp = map->l_libname; 

  while (runp != NULL)
    if (strcmp (name, runp->name) == 0)
      return 1;
    else
      runp = runp->next;

  return 0;

另外通过map中的next指针,依次可以找到链表所有节点的l_name的值,如下所示:

link_map->l_name ""
link_map->l_name ""
link_map->l_name /usr/lib64/libsecurec.so
link_map->l_name 0x7fab00000001
link_map->l_name /usr/lib64/libalarm.so
link_map->l_name /usr/lib64/libc.so.6
link_map->l_name /usr/lib64//lib64/ld-linux-x86-64.so.2

查看C依赖的动态库:

:/home # ldd C

      linux-vdso.so.1 =>  (0x00007ffff27e3000)
      libsecurec.so => /usr/lib64/libsecurec.so (0x00007fea37fb2000)
      libpthread.so.0 => /usr/lib64/libpthread.so.0 (0x00007fea37d95000)
      libalarm.so => /usr/lib64/libalarm.so (0x00007fea37b92000)
      libc.so.6 => /usr/lib64/libc.so.6 (0x00007fea377d2000)
      /lib64/ld-linux-x86-64.so.2 (0x00007fea381c5000)

可以知道l_name对应的值应为/usr/lib64/libpthread.so。

这里我们插播一个小知识点:

3、动态库符号解析 

这个问题暂时也没有什么思路,就先从调用栈入手吧,这一族函数,_dl_runtime_resolve->_dl_fixup->_dl_lookup_symbol_x->do_lookup_x->_dl_name_match_p->strcmp是与函数的动态解析有关系,上网查看了相关资料,简单说涉及两个方面:

1、动态的加载,就是当这个运行的模块在需要的时候才被映射入运行模块的虚拟内存空间中,如一个模块在运行中要用到mylib.so中的myget函数,而在没有调用mylib.so这个模块中的其它函数之前,是不会把这个模块加载到你的程序中(也就是内存映射)。 

2、动态的解析,就是当要调用的函数被调用的时候,才会去把这个函数在虚拟内存空间的起始地址解析出来,再写到专门在调用模块中的储存地址内,如前面所说的你已经调用了myget,所以mylib.so模块肯定已经被映射到了程序虚拟内存之中,而如果你再调用 mylib.so中的myput函数,那它的函数地址就在调用的时候才会被解析出来。 

调用栈是地址解析相关的东西,那么说明调用的函数在之前是没有被解析过的,即在此进程中是第一次调用。segfault是在调用prctl时产生的,函数中会先fork出子进程,然后在子进程中调用prctl函数,而prctl这个函数恰恰就是只有在这个子进程中才会调用,至此这个问题的一些现象就可以解释清楚了:动态库相关的link_map结构的某个字段被踩,fork出的子进程,虽然会从父进程那里得到所有信息的副本,但是父进程没有调用过prctl这个函数,也就不会有这个函数的解析地址信息,那么在子进程中调用prctl函数时,就会走入动态解析的流程,在进行strcmp比较时出现段错误。因为父进程没有segfault,父进程还在继续运行,还会再继续fork子进程,因此core文件中会产生多个相同大小,但是进程id,时间戳不同的core文件。 

4、踩内存问题的定位手段

1)gdb watch

排查代码,找到了存储link_map的全局变量_rtld_global,在C模块的main函数中,守护进程拉起后,加入了延时(这样我们有时间可以根据全局变量找到总是被踩的内存的地址),重新编译代码,替换bin文件,然后ps –aux | grep C,查看守护进程的id,再gdb –p PID,进入守护进程的gdb调试,先p _rtld_global,然后找到这个全局变量的第一个变量,p *(struct link_map*) 这个地址,这个就是link_map链表的第一个成员的地址,然后按照next的地址依次找到存放pthread.so信息的link_map结构的地址,然后watch *(int*)这个地址。如果有应用程序在改写这个地址,那么当被写的时候,gdb就会断住,并且会打印调用栈信息。  

但是不幸的是,已经发生了segfault,但并没有调用栈信息记录。在gdb中,如果watch不到,很有可能是内核改写了内存。

2)将被踩内存设置为只读

将这个地址设置为只读,那么当有程序去改写这个内存时,就会生成对应的core文件,通过core,我们就可以知道调用栈,可以清楚是谁改写内存了。

void set_page_ro(void)

        char *p = NULL;
        p = find_link_map("/usr/lib64/libpthread.so.0");  
        mprotect((void*)((unsigned long)p & 0xfffffffffffff000UL), 4096, PROT_READ);

代码中,先找到libpthread.so对应的地址,然后设置这个地址所在的页为只读的。但是实践后,发现这个办法不行,因为只能对4k的页设置只读,那么很多在4k范围内的正常写入也会产生core文件。

那么既然怀疑是内核在改写这个内存,那么我们就开始从内核入手吧。

3)通过系统调用来获取内核踩内存的调用栈

需要先编译出一个ko,然后ismod这个ko,再在C模块的main函数中,加入syscall(SYS_afs_syscall, p); p为获取到的那个pthread.so对应的地址。然后编译可执行文件,替换bin,启动C服务,当p这个地址被改写时,通过dmesg就可以看到调用栈了。

[ 6322.163418] Call Trace:
[ 6322.166046]  <#DB>  [<ffffffff816379e4>] dump_stack+0x19/0x1b
[ 6322.171993]  [<ffffffffa049402a>] sample_hbp_handler+0x2a/0x30 [a]
[ 6322.178361]  [<ffffffff81160d31>] __perf_event_overflow+0xa1/0x250
[ 6322.184733]  [<ffffffff81161081>] perf_swevent_overflow+0x51/0xe0
[ 6322.191013]  [<ffffffff8116117f>] perf_swevent_event+0x6f/0x90
[ 6322.197031]  [<ffffffff81161b49>] perf_bp_event+0x99/0xc0
[ 6322.202618]  [<ffffffff816412b0>] hw_breakpoint_exceptions_notify+0x120/0x150
[ 6322.209944]  [<ffffffff81643a1c>] notifier_call_chain+0x4c/0x70
[ 6322.216025]  [<ffffffff81643ac5>] notify_die+0x45/0x60
[ 6322.221351]  [<ffffffff816404ef>] do_debug+0xaf/0x230
[ 6322.226589]  [<ffffffff8163f92b>] debug+0x2b/0x40
[ 6322.231484]  [<ffffffff8151b2c7>] ? kfree_skbmem+0x37/0x90
[ 6322.237163]  [<ffffffff8130323b>] ? copy_user_enhanced_fast_string+0xb/0x20
[ 6322.244278]  <<EOE>>  [<ffffffff81513062>] ? move_addr_to_user+0xb2/0xd0
[ 6322.251210]  [<ffffffff81514c9d>] ___sys_recvmsg+0x14d/0x2b0
[ 6322.257052]  [<ffffffff8163cfb9>] ? schedule+0x29/0x70
[ 6322.262383]  [<ffffffff8119912c>] ? handle_mm_fault+0x65c/0xf50
[ 6322.268493]  [<ffffffff81515821>] __sys_recvmsg+0x51/0x90
[ 6322.274052]  [<ffffffff81515872>] SyS_recvmsg+0x12/0x20
[ 6322.279465]  [<ffffffff81648049>] system_call_fastpath+0x16/0x1b
[ 6322.285796] --- 14678, 00007f73450a3000 value is changed

使用这个方法,需要解释的内容比较多,请看我的另外一个博客https://www.cnblogs.com/xingmuxin/p/11289138.html

后来通过代码排查,找出所有recvmsg调用的地方,再结合出现问题的模块,最后发现是与msg结构体没有初始化有关系。下面我们把这个问题,从原因开始再分析一遍。

5、问题原因

1)C服务刚启动时,进程空间是新分配的,所以内存的值应该都是清零的。拉起一个线程,msg为该线程申请的一个局部变量,虽然没有对其初始化,但此时的整片内存的值都是0。

[2016-08-09:10:23:04]C[690]: C starting up
[2016-08-09:10:23:04]C[690]: --- nlh[0x23750e0]: typ[32676] seq[677353752]; msg[0x7fa424236d10]: name[(nil)] len[(nil)] control[(nil)] clen[0] flags[0]

2)开始执行长稳测试用例,看C的日志,发现大概1s中有40条监控的记录,然后会recvmsg出错,错误码为105,意思是No buffer space available。

[2016-08-10:07:59:59]C[690]: recvmsg from NETLINK_SIGNO socket failed [105]

3)  之后信号监控线程会退出,守护进程会再拉起信号监控的线程,那么此时的LWP进程空间已经不是全新的了,就不会是全0的了。可以看到msg,name的值已经不是0了。

[2016-08-10:07:59:59]C[690]: C starting up
[2016-08-10:07:59:59]C[690]: --- nlh[0x2376fd0]: typ[32676] seq[677353560]; msg[0x7fa424236d10]: name[0x7fa428e50000] len[0x7fa428c3ae6f] control[0x5] clen[0] flags[1]

可以看到那么中的地址0x7fa428e50000,那么这个地址就是对应的该进程空间中的链接库的地址。

 

导致出现这个问题,其实是开发人员编程习惯和规范的问题,我们在调用recvmsg函数时,传入的参数中有几个变量没有赋初值。

再回来说到recvmsg,函数原型如下:

ssize_t recvmsg(int sockfd, struct msghdr *msg, int flags);

这里msghdr定义如下:

struct msghdr 
    void          *msg_name;            /* protocol address */
    socklen_t     msg_namelen;          /* sieze of protocol address */
    struct iovec  *msg_iov;             /* scatter/gather array */
    int           msg_iovlen;           /* # elements in msg_iov */
    void          *msg_control;         /* ancillary data ( cmsghdr struct) */
    socklen_t     msg_conntrollen;      /* length of ancillary data */
    int           msg_flags;            /* flags returned by recvmsg() */

我们在使用这个函数时,对msghdr这个结构的msg_iov,msg_iovlen做了赋值,其他变量都没有处理,也没有赋初值。当C服务启动后,C服务的进程空间是新分配的,这块空间都会被初始化为0(因为这块空间是内核分配的一块物理内存,分配给用户态,一定要清零,不然用户就会读到内核内容),C服务的进程在创建线程后,线程是共享进程空间的,所以线程的空间也是清零,我们在这个线程中定义一个struct msghdr类型的变量时,这块内存也是全零的,即使我们没有赋初值,在正常情况下,不会出现问题。

但异常情况,比如我们现在的压力测试,cpu,内存加压的情况下,什么异常都有可能会出现。当出现异常后,这个线程出现了异常退出,C服务的守护进程会再拉起该线程,那么这个重新拉起来的线程,就不会那么巧合,分配到一个为0的空间。在使用msg值,代码里只对两个成员赋值,其他的值未知,刚好存储msg这个变量的地址曾经被动态库访问过,里面还残留着之前使用这个地址的局部变量,而这个值刚好就是pthread.so的link_map结构l_name的地址。这样,我们在调用recvmsg时,就把这些参数传给了内核,内核以为我们把msg_name的地址传给了它,于是它给我们返回了socket name,即内核往这个错误的地址上写了数据。那么,再往后就导致了segfault的问题的发生。

现在来回顾下公司的编程规范,是不是这么一个简单的要求就可以避免后面我们做了那么多的debugging工作呢。

记录一次很有意思的bug

情景是这样的:

 log 一直在狂打不止,直到打满了磁盘, 在上传文件的时候发现只要是超过了1m就传不上去。

解决策略 

  首先肯定是清除磁盘 干掉无用的log,清除了之后发现问题并没有解决,于是使用top命令查看内存使用情况 发现内存使用并不高,于是这个问题就很有意思了。

有如下几种猜测:

1.程序内存泄漏 导致内存无法有效回收 

  经过重启,仔细查看每个进程的内存情况发现 并非这种情况。

2.依稀记得linux文件目录有大小限制  翻阅大量文档发现大小制约的其实是Inode ,只有在大量的小文件的写入时候才会出现限制。

  参考连接:http://www.ruanyifeng.com/blog/2011/12/inode.html

 

在经过1.2两步试错之后 发现自己可能走偏了。首先只有大小超过一定的限制之后才会无法写入,其次 程序刚开始运行没问题的。这些特征更像是触发了某种内存保护机制。

是虚拟机的参数的设置吗?

一连串的碰壁之后 幡然醒悟。 如果是虚拟机参数的设置,那么应该是在刚开始就有限制,在momery和磁盘都还未满的情况下,虚拟机应该有自动扩容的功能,不至于限制1m左右文件大小的读写。

那么就是linux本身了。

3.经过排查分析,发现linux经过内存满的时候会触发读写保护机制,当内存恢复的时候,保护机制并不会撤销。因此问题得解。

哈哈哈,这可能不算linux的bug 算是featrue 。

参考连接:http://www.it1352.com/764980.html

 

以上是关于记录一次用户态踩内存问题的主要内容,如果未能解决你的问题,请参考以下文章

记录一次DialogFragment 内存泄漏

记录一次很有意思的bug

再记录一次delete出错的经历

记录一次生产环境中Redis内存增长异常排查全流程!

记录一次idea崩溃问题

粗糙记录网站加载过慢的一次排查经历