記錄一次用戶態踩內存問題
這幾天在做總結,把三年前寫的一個定位案例,翻了出來。回想起定位這個問題時的場景,領導催得緊,自己對很多東西又不熟悉,所以當時面臨的壓力還是很大的。現在回想起來感慨還是很多的,我們在遇到任何一個問題,一定不要放棄。還記得在產品線做開發時,學到的一些項目知識,任何一個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工作呢。