dump日志怎么看(dump日志)
Java死锁示例及dump日志分析
死锁在java多线程添加同步的时候如果锁资源释放不当就会造成线程互相等待资源而进入死锁状态,从业务上讲表面现象会是服务不能正常运行,从程序角度来看可能无法一时定位信息,因此我们需要通过dump线程日志来定位问题所在,这里记录个人单元测试写一个死锁程序,同时dump线程信息进行简要分析。
package thread; /** * 死锁 */ public class DeadLock { private static String A = \"A\"; private static String B = \"B\"; public static void main(String[] args) { new DeadLock().testDeadLock(); } private void testDeadLock(){ Thread thread1 = new Thread(new Runnable() { public void run() { System.out.println(\"thread1\"); synchronized (A){ try { Thread.sleep(2000); } catch (InterruptedException e) { e.printStackTrace(); } synchronized (B){ //26 System.out.println(\"thread lock B\"); } } } }); Thread thread2 = new Thread(new Runnable() { public void run() { System.out.println(\"thread2\"); synchronized (B){ synchronized (A){ //38 System.out.println(\"thread lock A\"); } } } }); thread1.start(); thread2.start(); } }
以上代码运行之后,输入结果如下:
不会输出lock A或者lock B
输出以上结果是因为线程thread1没有正常释放对A的锁,然后thread2启动后对B加锁之后尝试获取A的锁获取不上就处于等待状态,同时thread1开始获取B的锁也获取不上也开始处于等待的状态,造成彼此等待的死局。
氮素啊氮素,这里没有打印报错日志,我们无法看到哪里出现了问题,因此我们需要进行dump线程日志进行分析,我的测试环境是在windows上,因此我们可以打开cmd命令窗口,使用jps命令看一下在运行中java进程有哪些,以便找到进程PID,如下:
DeadLock PID:5600
然后,我们用jstack -l 5600 >> 123.txt进行dump日志,然后在C:\Users\用户名文件夹下找到dump下来的123.txt,打开可以看到:
\"Thread-1\" #12 prio=5 os_prio=0 tid=0x000000000a0bb000 nid=0x22e0 waiting for monitor entry [0x000000000b2ff000] javang.Thread.State: BLOCKED (on object monitor)at thread.DeadLock$2(DeadLock.java:38)- waiting to lock <0x00000000d6f88040> (a javang.String)- locked <0x00000000d6f88070> (a javang.String)at javang.Thread(Thread.java:745) Locked ownable synchronizers:- None\"Thread-0\" #11 prio=5 os_prio=0 tid=0x000000000a0b3800 nid=0x6dc waiting for monitor entry [0x000000000b1ee000] javang.Thread.State: BLOCKED (on object monitor)at thread.DeadLock$1(DeadLock.java:26)- waiting to lock <0x00000000d6f88070> (a javang.String)- locked <0x00000000d6f88040> (a javang.String)at javang.Thread(Thread.java:745) Locked ownable synchronizers:- None
以上信息中,说明了在代码的26行、38行产生了线程BLOCKED 阻塞,造成了死锁,我们通过类似的信息能够快速定位到异常所在,然后就可以进行代码优化修改。
以上仅仅为了死锁写了一个死锁程序,实际业务中不会出现这样的代码,我们也可以通过类似的手段去诊断并解决问题。
使用Windbg静态分析dump文件(实战经验总结)
在日常分析C++软件异常的日常工作中,大多数情况下我们都是使用Windbg去静态分析dump文件去排查软件异常的,今天我们就来详细地讲一下如何使用Windbg去静态分析dump文件,以供参考。
image.png
1、概述基本大部分软件都内置了异常捕获模块,在软件发生闪退崩溃时,都会弹出相关的提示框,比如PC版的微信在崩溃时,其内置的异常捕获模块会捕获到并生成日志及dump文件,同时会弹出如下的发送错误报告的提示框:
image.png
提示框的下方会自动带上崩溃相关的文件,其中最后一个文件就是我们要讲的dump文件,点击确定则会将这些文件发送到腾讯远端的服务器上。腾讯后台的运维人员就会收到通知,然后到服务器上将dump等文件下载下去去分析。
有些软件可能没有上传崩溃日志到服务器的功能,捕捉到异常时会自动将dump文件保存到指定的路径中,事后可以到该路径中取到对应的dump文件。如果客户机器上遇到崩溃,可以和客户联系,让客户帮忙从对应的路径中取来dump文件。
下面就来详细讲一下拿到dump文件之后如何使用Windbg去静态分析dump文件。
2、静态分析dump文件的一般步骤用Windbg打开dump文件,先使用.ecxr命令切换到异常的上下文,然后根据切换成功后显示的异常类型(ExceptionCode值对应的含义,比如0xC0000005对应的就是AccessViolation内存访问违例)、发生崩溃的那条汇编指令及相关寄存器的值。通过查看汇编指令及各寄存器的值,可以初步判断当前发生的是什么异常,比如C++类空指针、内存访问违例。
image.png
接着,使用kn/kv/kp查看函数调用堆栈,看看是调用了什么函数触发的异常。调用堆栈中会显示函数所在模块信息,一般我们需要拿到这些模块的pdb文件,加载pdb文件后函数堆栈中才会显示具体的函数名和行号的。我们需要使用lm命令查看这些模块的时间戳,然后找来这些模块对应的pdb文件,然后将pdb文件的路径设置到windbg中。
然后,根据函数调用堆栈中显示的函数名及行号,对照着源代码去分析发生异常的原因。有时候为了搞清楚发生异常的本质,我们还需要使用IDA查看相关二进制文件的汇编代码,查看一下发生异常的那条汇编指令的上下文,对照着C++源码,看看那条汇编指令为啥会出现异常。
3、分析实例说明我们为了方便展开讲解,我们特意使用VisualStudio创建了一个基于MFC对话框的exe程序工程,对话框中有个名为button1的按钮,如下所示:
image.png
我们在此按钮的响应中添加了一段引发崩溃的测试代码,故意让程序产生崩溃,测试然后拿到崩溃时的dump文件。
具体的测试代码如下所示:
// 添加的一段测试代码SHELLEXECUTEINFO *pShExeInfo = NULL;int nVal = pShExeInfo->cbSize; // 通过空指针访问结构体成员,导致崩溃 CString strTip;strTip.Format( _T("nVal=%d."), nVal );AfxMessageBox( strTip );
代码中使用到的结构体SHELLEXECUTEINFO 定义如下:
typedef struct _SHELLEXECUTEINFOW{ DWORD cbSize; // in, required, sizeof of this structure ULONG fMask; // in, SEE_MASK_XXX values HWND hwnd; // in, optional LPCWSTR lpVerb; // in, optional when unspecified the default verb is choosen LPCWSTR lpFile; // in, either this value or lpIDList must be specified LPCWSTR lpParameters; // in, optional LPCWSTR lpDirectory; // in, optional int nShow; // in, required HINSTANCE hInstApp; // out when SEE_MASK_NOCLOSEPROCESS is specified void *lpIDList; // in, valid when SEE_MASK_IDLIST is specified, PCIDLIST_ABSOLUTE, for use with SEE_MASK_IDLIST & SEE_MASK_INVOKEIDLIST LPCWSTR lpClass; // in, valid when SEE_MASK_CLASSNAME is specified HKEY hkeyClass; // in, valid when SEE_MASK_CLASSKEY is specified DWORD dwHotKey; // in, valid when SEE_MASK_HOTKEY is specified union { HANDLE hIcon; // not used#if (NTDDI_VERSION >= NTDDI_WIN2K) HANDLE hMonitor; // in, valid when SEE_MASK_HMONITOR specified#endif // (NTDDI_VERSION >= NTDDI_WIN2K) } DUMMYUNIONNAME; HANDLE hProcess; // out, valid when SEE_MASK_NOCLOSEPROCESS specified} SHELLEXECUTEINFOW, *LPSHELLEXECUTEINFOW; #ifdef UNICODEtypedef SHELLEXECUTEINFOW SHELLEXECUTEINFO;typedef LPSHELLEXECUTEINFOW LPSHELLEXECUTEINFO;#elsetypedef SHELLEXECUTEINFOA SHELLEXECUTEINFO;typedef LPSHELLEXECUTEINFOA LPSHELLEXECUTEINFO;#endif // UNICODE
在测试代码中定义了SHELLEXECUTEINFO结构体指针pShExeInfo,并初始化为NULL,然后并没有给该指针赋一个有效的结构体对象地址,然后使用pShExeInfo访问结构体的cbSize成员的内存,因为pShExeInfo中的值为NULL,所以结构体cbSize成员的内存地址是结构体对象起始地址的偏移,因为结构体对象地址为NULL,cbSize成员位于结构体的首位,所以cbSize成员就是结构体对象的首地址,就是NULL,所以就访问64KB小地址内存块的异常,引发内存访问违例,导致程序发生崩溃闪退。
至于如何在程序中设置异常捕获模块去捕获异常、自动生成dump文件,可以尝试使用google开源的CrashRpt库,我们产品很早就有了,具体怎么获取目前还没有研究过,大家需要的话可以到网上搜一下。
4、用Windbg打开dump文件,初步分析使用Windbg打开dump文件(直接将dump文件拖入到Windbg),然后输入.ecxr命令,切换到异常的上下文,就可以发生的异常类型、发生了异常崩溃的那条汇编及崩溃时的各个寄存器的值。
首先,我们查看一下发生的异常类型,比如AccessViolation内存访问违例、StackOverflow线程栈溢出的异常,这样对异常有个初步的认知,如下:
image.png
接着就是查看发生异常的那条指令,查看指令的构成以及崩溃时的各个寄存器的值,可能能初步估计出发生异常的原因。如果指令中访问了一个很小的地址或者访问了一个很大的地址,都会触发内存访问违例。
1)访问64KB小地址内存区,引发访问违例在Windows系统中,64KB以内的内存地址是禁止访问的,如果程序访问这个范围内的内存,则会触发内存访问违例,系统会强行将进程终止掉。2)访问了内核态的大地址内存区,引发访问违例对于32位程序,系统会给进程分配4GB的虚拟内存,一般情况下用户态和内核态会各占一半,即各占2GB,我们编写的代码基本都是运行在用户态的,用户态的代码时不能访问内核态内存地址的(内核态地址是供系统内核模块使用的),如果崩溃指令中访问了一个很大的内存地址,超过用户态的地址范围0-2GB,内存地址大于0x8000000,则会触发内存违例,因为用户态的代码是禁止访问内核态内存地址的。
如果汇编指令中使用到了ecx寄存器进行地址计算,去访问计算出来的内存地址,如果访问了一个小内存地址并且ecx寄存器为0,那么这个崩溃可能是空指针引发的。在C++中,在调用C++类的成员函数时是通过ecx寄存器传递C++对象地址的,所以在通过C++类对象去调用虚函数(调用虚函数时的二次寻址)及通过C++对象去访问对象中的数据成员时,都会用到ecx寄存器的。
上面故意添加的会引发崩溃的测试代码,运行后产生dump文件,我们来分析一下这个dump文件。用Windbg打开dump文件后,输入.excr命令,接着输入kn命令,查看到如下的结果:
image.png
首先,这是Access Violation内存访问违例的异常。其次,从崩溃的这条汇编指令来看,是访问了小地址0x00000000地址,这是访问了小于64KB小地址内存区,这个范围的地址是禁止访问的,所以引发了内存访问违例。从汇编指令及寄存器的值来看,看不出来什么明显的线索。
所以接着输入了kn命令,将函数调用堆栈打印出来。函数调用堆栈是从下往上看的,最上面一行就是最后调用的一个函数,也是崩溃的那条汇编指令所在的函数。从函数调用堆栈的最后一帧调用的函数来看,程序的崩溃是发生在TestDlg.exe文件模块中,不是其他的dll模块。显示的函数地址是相对TestDlg.exe文件模块起始地址的偏移,为啥看不到模块中具体函数名称呢?那是因为Windbg找不到TestDlg.exe对应的pdb文件,pdb文件中包含对应的二进制文件中的函数名称及变量等信息,Windbg加载到pdb文件才能显示完整的函数名。
查看函数调用堆栈的命令,除了kn,还有kv和kp命令,其中kv还可以看到函数调用堆栈中调用函数时传递的参数,如下所示:
我们需要取来pdb符号库文件,去查看具体的函数名及行号的,这样才好找到直接的线索的。下面就来看看如何获取到TestDlg.exe模块的pdb文件。
5、找到pdb文件,设置到windbg中,查看完整的函数调用堆栈如何才能找到TestDlg.exe文件对应的dpb文件?我们可以通过查看TestDlg.exe文件的时间戳找到文件的编译时间,通过编译时间找到文件对应的pdb文件。在Windbg中输入lm vm TestDlg命令,可以查看到TestDlg.exe文件的详细信息,其中就包含文件的时间戳:(当前的lm命令中使用m通配符参数,所以在TestDlg后面加上了号)
image.png
可以看到文件是2022年6月25日8点26分23秒生成的,就可以找到对应时间点的pdb文件了。
一般在公司正式的项目中,通过自动化软件编译系统,每天都会自动编译软件版本,并将软件的安装包及相关模块的pdb文件保存到文件服务器中,如下所示:
这样我们就可以根据模块的编译时间找到对应版本的pdb文件了。
我们找到了TestDlg.exe对应的pdb文件TestDlg.pdb,将其所在的路径设置到Windbg中。点击Windbg菜单栏中的File->Symbol File Path...,打开设置pdb文件路径的窗口,将pdb文件的路径设置进去,如下所示:
image.png
点击OK按钮之前,最好勾选上Reload选项,这样Windbg就会去自动加载pdb文件了。但有时勾选了该选项,好像不会自动去加载,我们就需要使用.reload /f TestDlg.exe命令去让Windbg强制去加载pdb文件(命令中必须是包含文件后缀的文件全名)。
设置完成后,我们可以再次运行lm vm TestDlg*命令去看看pdb文件有没有加载进来:
image.png
如果已经加载进来,则会在上图中的位置显示出已经加载进来的pdb文件的完整路径。,如上所示。
加载到TestDlg.exe文件对应的pdb文件之后,我们再次执行kn命令就可以包含具体的函数名及及代码的行号信息了,如下:
image.png
我们看到了具体的函数名CTestDlgDlg::OnBnClickedButton1,还看到了对应的代码行号312。通过这些信息,我们就能到源代码中找到对应的位置了,如下所示:
image.png
是访问了空指针产生的异常。当然上面的代码是我们故意这样写的,目的是为了构造一个异常来详细讲解如何使用Windbg进行动态调试跟踪的。
6、将C++源代码路径设置到Windbg中,Windbg会自动跳转到源代码行号上为了方便查看,我们可以直接在Windbg中设置C++源码路径,这样Windbg会自动跳转到源码对应的位置。点击Windbg菜单栏的File->Source File Path...,将源码路径设置进去:
image.png
然后Windbg会自动跳转到对应的函数及行号上:
image.png
然后点击函数调用堆栈中每行最前面的数字超链接,就可以自动切换到对应的函数中。上图中的函数调用堆栈中很多模块是系统库中的,比如mfc100u、User32等,这些库是系统库,是没有源码的。我们可以点击最下面的第23个链接,其位于我们应用程序的模块中,会自动跳转到对应的代码中,如下:
image.png
7、有时需要查看函数调用堆栈中函数的局部变量或C++类对象中变量的值有时我们通过查看变量的值,找到排查问题的线索,比如变量中值为0或者很大的异常值。这点我们在多次问题排查中使用到,确实能找到一些线索。
可以查看函数中局部变量的值,也可以查看函数所在类对象的this指针指向的类对象中变量的值。我们要查看哪个函数,就点击函数调用堆栈中每一行前面的数字超链接,如下所示:
image.png
我们看到了局部变量pShExeInfo 的值:
struct _SHELLEXECUTEINFOW * pShExeInfo = 0x00000000
我们可以点击this对象的超链接:
image.png
就能查看当前函数对应的C++类对象中成员变量的值,如下:
image.png
但有时不一定能查看变量的值,因为当前通过异常捕获模块自动生成的dump文件一般是minidump文件,文件也就几MB左右,不可能包含所有变量的值。所以要在minidump文件中查看变量的值,要看运气的,有时能查看到,有时是看不到的。这里要讲一下dump文件的分类,主要分为minidump文件和全dump文件。
我们将windbg附加到进程上使用.dump命令导出的dump文件,是全dump文件,全dump文件中包含了所有的信息,可以查看到所有变量的信息。另外通过任务管理器导出的dump文件:
image.png
也是全dump文件。全dump文件因为包含了所有的信息,所以会比较大,会达到数百MB,甚至上GB的大小。但如果通过安装在程序的异常捕获模块CrashReport导出的dump文件就是非全dump文件,是mini dump文件,大概只有几MB左右,因为异常捕获模块捕获到异常后,会自动导出dump文件,保存到磁盘上,如果都导出体量很大的全dump文件,很大量消耗用户的磁盘空间,所以我们会设置生成mini dump文件。
在异常捕获模块中我们是通过调用系统API函数MiniDumpWriteDump导出dump文件的,我们通过设置不同的函数调用参数去控制生成mini dump文件的。
8、有时我们需要用IDA打开二进制文件去查看汇编代码上下文有时通过函数调用堆栈中函数及行号,我们很难搞清楚到底为什么会发生崩溃,这时候我们就需要回归本源了,就需要去查看发生异常崩溃的那条汇编指令的上下文了。
汇编指令最能直观地反映出问题的本质,通过阅读汇编代码,就能搞清楚为啥会触发崩溃了。一般我们在使用.ecxr命令切换到发生异常的汇编指令时,我们可以直接在该条汇编指令的上下文了,点击菜单栏的View->Disassembly,即可打开显示汇编代码的页面,如下所示:
image.png
但直接在Windbg中查看汇编代码,对于我们这些不精通汇编代码的人来说,是有很大困难的,我们是大概率看不懂的。
一般需要借助IDA工具打开二进制文件去查看汇编代码的,IDA在解析出汇编时会在汇编代码中加上一些注释,特别是在有pdb符号库文件时,会添加更多的注释,通过这些注释,我们就能对照了C++源代码,就能大概读懂汇编上下文了。如果能找到pdb符号库文件,则需要将pdb文件放在目标二进制文件的同级目录中,IDA打开二进制文件时会去自动加载pdb文件。
8.1、IDA工具介绍image.png
IDA是比利时Hex-Rays公司出品的一款交互式静态反汇编工具。它可以直接反汇编出二进制文件的汇编代码,是目前软件逆向与安全分析领域最好用、最强大的一个静态反汇编软件,已成为众多软件安全分析人员不可缺少的利器!它支持Windows、Linux等多个平台,支持Intel X84、X64、ARM、MIPS等数十种CPU指令集。
在实际工作中,我们一般使用反汇编工具IDA去打开二进制文件,查看二进制文件中的汇编代码。IDA既支持打开Windows下的.exe、.dll等二进制文件,也可以打开Linux下的.bin、等二进制文件。
8.2、使用IDA打开二进制文件IDA安装完成后,双击启动程序,会弹出如下的提示框:
image.png
点击“New”即新建一个对象。紧接着弹出让选择要打开的文件:
image.png
可以找到目标文件的路径,打开目标文件即可。也可以点击取消,然后直接将文件拖到IDA中。打开文件时会让选择加载文件的方式:
image.png
对于Windows库,选择PE方式即可。接下来,会弹出是否要加载pdb文件的提示框:
image.png
选择Yes即可。前面我们说过,需要将pdb文件放置到目标二进制文件的同一级目录中,这样IDA在打开二进制文件时就会搜索到对应的pdb文件,回去自动加载pdb文件。
打开后的效果如下:
image.png
默认是先是Grapg View图状关系视图,需要右键点击视图区域,在弹出的右键菜单中点击Text View菜单项,切换到Text View文字视图,这样就能看到具体的汇编代码了:
image.png
8.3、在有pdb文件时到IDA中定位到发生异常的汇编指令的位置Windbg中发生异常的那条汇编指令,我们需要到IDA中找到对应的位置,然后查看目标位置的汇编指令的上下文。在目标二进制文件有pdb的情况下,要在IDA中定位到发生异常的汇编指令的位置,会比较简单。
首先在Windbg中显示的函数调用堆栈中找到发生崩溃的那条汇编指令所在的函数名CTestDlgDlg::OnBnClickedButton1,如下:
image.png
然后到IDA中,点击菜单栏的Jump->Jumptofunction...,在打开的函数列表窗口中,点击下方的Search按钮,在搜索框中输入函数名后搜索:
image.png
在列表中找到函数,双击之久切换到该函数的汇编代码处:
image.png
这样就看到该函数的代码段地址,然后加上Windbg中显示的偏移值:
image.png
即:
CTestDlgDlg::OnBnClickedButton1+0x32 = 0x00401A30 + 0x32 = 0x00401A62
就得到发生崩溃的那条汇编指令在当前二进制中的地址,因为汇编指令就为在当前这个函数中,鼠标向下拉动找到地址即可,这样就能找到发生异常的那条汇编指令了。
其实还有个快捷操作,在计算出发生异常的那条汇编指令的地址后,按下快捷键G,在弹出窗口中输入刚才的地址0x00401A62,就可以直接go到发生异常的那条汇编指令的位置,如下:
image.png
8.4、在没有pdb文件时到IDA中定位到发生异常的汇编指令的位置在没有目标二进制文件的pdb文件的情况下,要在IDA中定位到发生异常的汇编指令的位置,会相对麻烦一点。
发生异常的汇编指令的地址,是程序实际运行时的代码段地址,需要在Windbg中计算出该条汇编指令的地址相对于所在模块起始地址的偏移值,然后加上IDA中该模块的的默认加载地址,就能得到当前汇编指令在IDA中的静态地址,然后直接go过去,就能看到产生异常的汇编指令的上下文了。在本例中,发生异常的汇编指令的地址就是0x00401a62,如下:(发生异常的这行汇编指令最前面的那个地址,就是当前汇编指令的地址)
image.png
从函数调用堆栈上看,当前这条发生异常的汇编指令所在的函数为:
TestDlg!CTestDlgDlg::OnBnClickedButton1+0x32
所以这条指令所属模块为TestDlg.exe,所以使用lm命令查看TestDlg.exe模块的起始地址:
image.png
TestDlg.exe模块其实地址为0x00400000(这是系统将TestDlg.exe模块加载到进程空间中的起始地址,代码段地址 ),所以发生异常的这条汇编指令相对于所在模块TestDlg.exe的偏移地址为:
0x00401a62 - 0x00400000 = 0x00001a62
然后再到打开TestDlg.exe二进制文件的IDA中,查看该TestDlg.exe模块默认的加载地址:(将滚轮滚动到最上面即可看到,注意此处是默认预加载地址,并不是加载起来后的真正的地址)
image.png
这样根据之前计算出来的偏移,加上TestDlg.exe模块的默认加载地址,就得到发生异常的那条汇编指令在IDA打开的静态文件中的位置:
0x00001a62 + 0x00400000 = 0x00401a62
然后到IDA中按下G快捷键,GO到0x00401a62地址处,即找到发生异常的那条汇编指令:
image.png
在IDA中找到发生异常的汇编指令的位置,就可以去查看其附近的汇编代码上下文了。
8.5、阅读汇编代码上下文我们在阅读汇编代码的上下文时,一般是对照着C++源码进行的,然后依托汇编代码上下文中的注释,找到汇编代码与C++源码的对应关系。在阅读汇编代码时,要了解一些常用的汇编指令及常用寄存器的使用(比如EAX用来存放函数的返回值,ECX用来传递C++对象地址的),熟悉函数调用时的参数入栈、栈分布及参数寻址,了解内存拷贝的汇编代码实现、了解虚函数调用的二次寻址的过程,去啃发生异常的那条汇编指令的上下文中的汇编代码。
汇编指令比较多,我们只需要了解一些常用的汇编指令即可,如果遇到不熟悉的汇编指令去搜索一下就可以了。此外,有一点需要注意的是,在Release下编译器会对C++源码会做优化,部分C++源码可能会被优化掉,C++源码有时不能完全和汇编代码对应起来的,但这基本不影响汇编代码上下文的阅读。
避雷心经 | Coredump排查入门
作者:garrycai,腾讯PCG后台开发工程师
| 导语 想必每一位 C++ 选手在工作中都难免会踩中 Coredump 地雷,而我作为 C++ 新手也与 Coredump 有过激烈的战斗,下文正是我在排查 Coredump 过程中总结的一些心得经验。
1. 概念Coredump(核心存储)是进程异常终止或崩溃时的内存快照,操作系统会在程序发生异常而异常在进程内部又没有被捕获的情况下,会把进程此刻内存、寄存器状态、堆栈指针、内存管理信息以及函数调用堆栈等信息转储保存在一个文件里(Corefile)。Coredump 对于开发者诊断和调试程序是非常有帮助的,因为对于有些程序错误很难重现,例如偶发的指针越界,而 Corefile 可以再现程序出错时的情景。
2. 工具2.1 Coredump 开启有时进程 Core 了却没有找到 Corefile,有可能是因为没有开启 Coredump,可通过 ulimit 命令开启:
# 查看当前 Corefile 大小,为0则表示禁止产生 Corefileulimit -c# 设置 Corefile 大小无限大ulimit -c unlimited# 设置 Corefile 大小1024kbulimit -c 1024
2.2 GDB 工具2.2.1 概念GDB(GNU Debugger)是 GNU 软件系统中的标准调试器,具备各种调试功能,包括但不限于打断点、单步执行、打印变量、查看寄存器、查看函数调用堆栈等,能够有效地针对函数的运行进行追踪,也常用于 Coredump 分析。
2.2.2 GDB 分析 Corefile1.运行 gdb [executable file] [corefile] 开始调试,执行 corefile 需要对应的可执行文件:
2.键入 bt (backtrace)打印函数调用栈,第一行即为发生 Core 的最后调用处。
3.键入 f {num} 可切换至指定的一帧,从而打印该阶段的相关信息。
4.其他常用命令
命令 | 作用 |
print {variable} | 打印当前函数的指定变量值 |
info args | 打印出当前函数的参数名及其值 |
info locals | 打印出当前函数中所有局部变量及其值 |
disas | 查看当前栈帧的汇编代码 |
更多GDB使用:GDB调试
2.3 AddressSanitizer 工具2.3.1 概念很多时候通过 GDB 调试 Corefile 看出的只是 Core 的表象原因,例如通过 GDB 看出 Core 的直接原因是 NULL 指针引用,但真正的问题是这些不应该为 NULL 的指针为何被赋值成 NULL。在如今异步和多线程编程的场景下,很难只从函数调用栈中分析出原因。而 AddressSanitizer 工具正是针对这类问题的一把利器,用来探测内存访问的 bug,包括了缓冲区溢出、重复使用已被释放的堆内存等。
2.3.2 使用1.安装依赖 sudo yum install libasan
2.在项目根目录添加“.bazelrc”文件
3.在“.bazelrc”文件中配置以下内容
build --copt=-gbuild --copt=-Og // 禁用gcc优化,方便排查问题build --copt=-ggdbbuild --strip=neverbuild --copt=-fno-omit-frame-pointerbuild --copt=-fsanitize-recover=address // 检测到错误后,不退出,继续执行(需要配合环境变量配置)build --copt=-fsanitize=address // 打开AddressSanitizer模块(LeakSanitizer、MemorySanitizer实际上也都整合到了这里)build --linkopt=-fsanitize=address
4.编译程序,并将程序上传到测试容器,测试容器安装依赖 sudo yum install libasan
5.因为通过123无常启动会一直重启,建议停止容器,避免干扰
6.测试容器中启动程序,观察 std out
export LD_PRELOAD=/lib64/libasan.4export ASAN_OPTIONS=halt_on_error=0 // 检测到错误后,不退出,继续执行(框架或者某些库可能会运行到我们的关注点之前就报错)3. 实践3.1 WebQO 下线老紧密度算子引起的 Coredump3.1.1 背景
WebQO 是搜狗搜索引擎依赖的 Query 理解系统模块,其主要提供切词、词权、紧密度、意图识别的功能。因为项目过于悠久,WebQO 上冗余了两个紧密度算子,据分析,老紧密度算子结果处于无人使用废弃状态,于是我便打算下线老紧密度算子,欲降低系统复杂度与提升性能。
3.1.2. Coredump 情景回顾因为主流程仅调用了老紧密度算子对外提供 run() 接口,所以我下意识地认为注释掉这行调用代码即完成了算子的下线。
但事情往往没那么简单,在我提交测试后,发现每次对服务请求都会 Coredump,无法获取响应结果。
3.1.3. 原因分析1.使用 GDB 对 Corefile 进行分析,键入 bt 显示 Coredump 时的堆栈。
2.堆栈的第一行即为发生 Coredump 时的最后调用处,咱们定位到其对应的代码,这个函数的作用是用新紧密度算子的结果替换掉老紧密度算子的结果。从代码可以看出这里很有可能是数组越界访问的问题,访问了非法地址。我们会产生一个疑问:ngram_nodes这个数组会不会压根不存在 或者 长度与 seginfo.termsCount 不一致?
3.带着上面的疑问,我们可以先通过 GDB 打印 ngram_nodes 的值,可以看到数组的长度为0,验证了我们的猜想。
4.再结合代码分析,我们直接搜索 ngram_nodes 被赋值的地方,果不其然,ngram_nodes 数组是在老紧密度算子里被赋值的。当我把老紧密度算子调用注释掉后,该数组无元素,而上图函数的 for 循环条件是依据 term 的个数,而非 ngram_nodes 的数组长度,从而导致的数组访问越界。
3.1.4. 解决思路3.1.4.1. 做好防御在原来代码中,for 循环对两个数组(seginfo.terms & ngram_nodes)都进行了遍历,因为在原逻辑中默认两个数组长度是一致的,所以原作者设置的循环条件只是 seginfo.terms 的长度。 但是这种做法不够安全,因为当 ngram_nodes 的长度小于 seginfo.terms 时会发生数组越界。因此这里的循环条件应该是 i < min(seginfo.terms长度, ngram_nodes数组长度)。
但是该方案并不足以满足业务需求,因为如此修改后会进入不了 for 循环,也就无法对 ngram_nodes.adjoin 进行赋值。
3.1.4.2. 预分配内存因为老紧密度结果的 adjoin 字段还在被下游服务使用,这里需要进入 for 循环将新紧密度值赋给 adjoin 字段。所以更合理的思路是对 ngram_nodes 数组预分配内存,使其与 seginfo.termsCount 保持一致长度。
3.1.5. 小结这类 Coredump 算是较简单的必现型 Coredump,其 Coredump 原因在于业务功能冗余的情况下又没做好细节防御,从而在 ngram_nodes 数组长度变动时导致了数组访问越界。
3.2. 修改 QU_Platform 业务配置引起的 Coredump3.2.1. 背景QU_Platform 是搜索中台下的 Query 理解系统平台,其下囊括了众多 QU 算子服务,如切词、同义词、意图等。
3.2.2. Coredump 情景回顾鹰眼日志上报在配置中是默认开启的,当我在线上修改了服务的业务配置后,便产生了 Coredump。这个 Coredump 是偶发性的,集群中并非所有节点都 Coredump。
3.2.3. 原因分析1.使用 GDB 对 Corefile 进行分析,键入 f 0 显示发生 Coredump 时的堆栈首行。
2.从堆栈信息可以看出,程序在调 atta_api 时发生 Coredump。结合我修改配置的操作,以及并非所有服务都 Coredump 的特点来看,这里有可能是我修改配置后触发某些逻辑,而与此同时服务正好在上报鹰眼日志,从而导致了多线程冲突问题。
3.结合代码进行分析,在我修改了鹰眼日志上报的配置后,触发了 AttaReporter::ReInit() 函数,此函数会对 atta_client_ 做 release() 操作。
而与此同时,一个检索请求触发了 AttaReporter::Report() 调用 atta_client_→send_string(),而因为 atta_client_ 在此时已经被被析构了,这便产生了 Coredump。
3.2.4. 解决思路3.2.4.1. 删除 ReInit 功能当前考虑到 atta_conf 的配置几乎不用变动,所以采取直接删除 ReInit 功能的做法,这样其他业务配置修改时就不会影响到 AttaReport 上报日志。此做法下,如果改动了 atta_conf 配置,需要重启服务才能生效。
3.2.4.2. 加互斥锁另一种方法就是给 atta_client_ 加互斥锁,在 ReInit() 和 Report() 时都去申请该互斥锁,避免冲突。但这导致:即使不是 atta_conf 的配置更新,也会判断该申请锁逻辑,带来一定的性能损耗。
3.2.5. 小结这类 Coredump 是稍复杂的偶现型 Coredump,其 Coredump 原因在于没有对存在多线程竞争的资源做保护,可通过对竞争资源加锁保护解决,或者放弃写功能,使该资源只可读。
4. 总结在经历了一些 Coredump 的折磨后,我也从中学习积累了一些常见的 Coredump 场景以及应对办法,以后再遇到 Coredump 可以参照历史经验并按照下述步骤进行排查。
4.1. 常见 Coredump 场景1.内存访问越界。
由于使用错误的下标,导致数组访问越界搜索字符串时,依靠字符串结束符来判断字符串是否结束,但是字符串没有正常的使用结束符使用 strcpy, strcat, sprintf 等字符串操作函数,将目标字符串读/写爆。应该使用 strncpy, strncat, snprintf 等函数防止读写越界。2.多线程问题
多线程读写的数据未加锁保护多线程程序使用了线程不安全的函数智能指针多重析构3.非法指针
空指针访问随意使用指针转换。一个指向一段内存的指针,除非确定这段内存原先就分配为某种结构或类型,或者这种结构或类型的数组,否则不要将它转换为这种结构或类型的指针,而应该将这段内存拷贝到一个这种结构或类型中,再访问这个结构或类型。这是因为如果这段内存的开始地址不是按照这种结构或类型对齐的,那么访问它时就很容易因为 bus error 而 Coredump。4.堆栈溢出
不要使用大的局部变量(因为局部变量都分配在栈上),这样容易造成堆栈溢出,破坏系统的栈和堆结构,导致出现莫名其妙的错误。5.格式化输出时数据类型错误
例如输出日志时,将整型数据用字符串输出4.2. Coredump 排查步骤先深呼吸一口,调整下心态,催眠自己的内心:“真好,又获得了一次学习的机会”。服务应急措施。如果 Coredump 影响了线上服务,服务该扩容扩容,该重启重启。保存 Coredump 现场。千万不要头脑一热就把原来 Coredump 的节点直接删掉,可停止 Coredump 的节点,便于事后分析修复。梳理记录发生 Coredump 前的行为,任何举动都可能成为有价值的排查信息。使用 GDB 对 Corefile 进行分析,定位 Coredump 的代码位置,缩小排查范围。并结合代码等信息进行分析。如果仅通过 Corefile 无法确认 Coredump 的时机,也可参照 3.2.3 单步调试网络程序。若 GDB 无法解决当前问题,尝试使用 AddressSanitizer 工具深入排查。以上便是我作为 C++ 新手在踩了 Coredump 地雷后收获的经验,希望能给读者带来一些帮助,避免重复踩坑。
bug现场谜之进程为什么消失了?
1. bug现场情况2021年11月,客户现场某业务系统挂掉,运维发现系统的进程没了,看日志也没有任何报错信息。
运维重启服务,系统运行正常,第二天或者隔几天又挂掉...
值得注意的现象:周五重启的服务,周末基本没人用服务,系统周末正常运行,周一上班,大家一用系统就又挂了。
2. 尝试破案因为没有任何错误日志输出,首先想到的是由于操作系统资源限制导致的,比如内存、CPU、socket连接数、打开文件数等。如果是这样,操作系统级别会杀死进程并记录相关日志。
1. 查看系统级别的日志
查看系统日志:cat /var/log/messages |grep -i 'kill'
查看内核级别的日志:dmesg |grep -i 'kill'
没有查到任何java、OOM、或者kill相关的系统级记录。
2. 查看JVM crash日志
系统级别的日志没有,可能是JVM本身bug造成的crash,这样JVM在crash的时候会生成hs_err_pid_%p.log,该文件默认生成在JVM运行的工作目录中,也可以在JVM启动的时候指定路径:-XX:ErrorFile=/var/log/hs_err_pid_%p.log
工作目录中没有找到JVM crash日志。
3. 查看OOM Heap Dump日志
系统启动的时候如果设定了JVM参数-XX:+HeapDumpOnOutOfMemoryError和-XX:HeapDumpPath=*/java.hprof并且是由OOM导致的crash,可以在对应的路径上找到heap dump文件,使用jvisualvm这种工具分析dump文件也可以定位问题。
该系统有设定对应的JVM参数,对应路径上没有dump日志输出。
什么日志都没有,会不会是什么问题导致日志没有生成呢?因为周一客户一旦使用就发生宕机,就怀疑是内存问题,监控一下内存吧:
4. 监控OS进程内存、JVM堆内存
使用top命令监控OS进程内存脚本:
#!/bin/bashwhile truedo datetime=$(date '+%Y-%m-%d %H:%M:%s') echo "$datetime" >> record_new3.txt 2>&1 top -d 1 -b -n1 |grep $PID >> record_new3.txt 2>&1 sleep 60done复制代码
使用jmap命令监控JVM堆内存:
#!/bin/bashwhile truedo datetime=$(date '+%Y-%m-%d %H:%M:%s') echo "$datetime" >> record_jmap_new3.txt 2>&1 /home/jdk8u282-b08/bin/jmap -heap $PID >> record_jmap_new3.txt 2>&1 sleep 120done复制代码
分析日志发现:
JVM堆内存(通过jmap命令脚本监控得出)从3G到接近14G(JVM设置的是最大堆内存16G),然后JVM会进行GC,内存就会降下来,如此往复。没有出现堆内存溢出情况。
JA进程的内存(通过top命令脚本监控得出)不断增大,最后维持在16G左右(系统内存是256G,还非常充裕)。
当JVM进行GC的时候JVM堆内存是回收了一部分,但是对于分配给操作系统JA进程的内存不会回收。在JVM堆中GC时,释放的内存只是标记内存空间可用,所以这也是为什么系统级别JA进程内存一直增大,最后维持一个较大的值不变(这种是堆外内存正常的情况,有另外一种情况堆外内存持续增加最终导致内存过大,进程被OS杀死,这样的情况应该会有一些其他原因造成堆外内存异常增长,就要想办法找出导致堆外内存异常增长的原因)。
本宕机系统的监控显示:内存确实没有问题:堆内存增加到一定程度后JVM进行GC,堆内存会降下来,系统进程内存最后处在一个稳定的值。
至此,笔者已经尽了最大的努力,没有找到实际的问题,只能写一个重启脚本,让宕机的系统在5分钟内重启:
宕机后,5分钟重启服务
#!/bin/bashwhile truedolog_date=$(date '+%Y-%m-%d')sync_date=$(date '+%Y-%m-%d %H:%M:%s')pid=`/usr/sbin/lsof -t -i tcp:7001`logfile="/home/TAS/TAS2810/logs/restart-$log_date.log"if [ ! -z "$pid" ];then echo "${sync_date}::PID为:$pid,XX系统服务启动中..." >> "$logfile"else echo "${sync_date}::XX系统服务不存在,重新启动..." >> "$logfile" cd /home/TAS/TAS2810/bin nohup bash /home/TAS/TAS2810/bin/StartTAS.sh & echo "${sync_date}::重新启动完成!" >> "$logfile"fisleep 300done复制代码3. 真相浮出水面
再总结下上面的情况:服务隔一段时间就挂一次,而且没有任何错误的业务日志和操作系统级别的crash日志,监控内存也很正常。
那到底是什么问题呢?进程肯定是死了,被谁杀了?他杀吗?操作系统日志显示没有杀死它,内存或者JVM层次crash自杀吗?也没有找到任何日志。
还能怎么排查呢?项目派来了一个该系统的架构师,稳了!
Linux有一个strack工具可以跟踪进程的信号,也就是说用这个工具,进程是怎么退出的能够监控出来:
#!/bin/shnohup strace -T -tt -e trace=all -p $(netstat -tnalp | grep 7001 | grep LISTEN | awk '{print $7}' | tr -d '/java') > trace.log &复制代码
第二天系统宕机,通过strack输出日志发现是系统自己退出的,确实没有任何他杀和自杀。
另外架构师说很可能是Linux X Server调用的问题,本地环境复现一下,果然是这个问题。
具体是:在系统中有流程相关的功能,该功能会使用java的awt库调出来gui图形化界面,而gui的绘制是调用服务端启动环境的X DISPLAY Server,当服务端启动shell窗口关闭后,客户再点击流程功能,服务端不能找到X DISPLAY Server环境,系统就自己退出了。
这里应该是程序日志处理上有一些问题,awt库找不到X DISPLAY Server环境应该会报错的,而日志上没有任何体现,这也是问题难以找到的原因。
需要了解X DISPLAY Server更多内容,可以参考文章:SSH终端怎们正确打开Linux gui程序-Window System
怎样修改呢?需要添加JVM参数:-Djava.awt.headless=true,该参数的含义是告诉JVM,该运行环境没有相关显示屏、鼠标、键盘等硬件,可以利用计算机后台的资源满足awt相关的调用(不是所有图形化的内容都需要显示服务的,比如在后台产生一些图片就不需要显示屏)。来看一下demo理解一下这个参数:
import javax.swing.*;import java.awt.*;import java.awt.event.*;public class Calculator { static double num; public static void main(String[] args) { //System.setProperty("java.awt.headless", "true"); System.setProperty("java.awt.headless", "false"); System.out.println("是否是headless环境:" + java.awt.GraphicsEnvironment.isHeadless()); System.out.println("java.awt.headless 默认值:" + System.getProperty("java.awt.headless")); // set up frame JFrame frame = new JFrame(); frame.setSize(500, 500); frame.setTitle("Simple Calculator"); frame.setLocationByPlatform(true); frame.setDefaultCloseOperation(JFrame.EXIT_ON_CLOSE); // set up panel JPanel panel = new JPanel(); // set layout to 5x2 grid layout panel.setLayout(new GridLayout(5, 2)); // set up answer label JLabel answer = new JLabel(); // set up number text fields JTextField num1 = new JTextField(); JTextField num2 = new JTextField(); // set up buttons JButton add = new JButton(); add.setText("+"); add.addActionListener(new ActionListener() { @Override public void actionPerformed(ActionEvent event) { try { num = Double.parseDouble(num1.getText()) + Double.parseDouble(num2.getText()); answer.setText(Double.toString(num)); } catch (Exception e) { answer.setText("Error!"); } } }); JButton sub = new JButton(); sub.setText("-"); sub.addActionListener(new ActionListener() { @Override public void actionPerformed(ActionEvent event) { try { num = Double.parseDouble(num1.getText()) - Double.parseDouble(num2.getText()); answer.setText(Double.toString(num)); } catch (Exception e) { answer.setText("Error!"); } } }); JButton mul = new JButton(); mul.setText("*"); mul.addActionListener(new ActionListener() { @Override public void actionPerformed(ActionEvent event) { try { num = Double.parseDouble(num1.getText()) * Double.parseDouble(num2.getText()); answer.setText(Double.toString(num)); } catch (Exception e) { answer.setText("Error!"); } } }); JButton div = new JButton(); div.setText("/"); div.addActionListener(new ActionListener() { @Override public void actionPerformed(ActionEvent event) { try { num = Double.parseDouble(num1.getText()) / Double.parseDouble(num2.getText()); answer.setText(Double.toString(num)); } catch (Exception e) { answer.setText("Error!"); } } }); // add components to panel panel.add(new JLabel("Number 1")); panel.add(new JLabel("Number 2")); panel.add(num1); panel.add(num2); panel.add(add); panel.add(sub); panel.add(mul); panel.add(div); panel.add(new JLabel("Answer")); panel.add(answer); // add panel to frame and make it visible frame.add(panel); frame.setVisible(true); }}复制代码
执行代码,如果是Oracle JDK1.8,默认是java.awt.headless是false,而openjdk默认值是true。上面的代码打开一个简单的gui的计算器,如果设置java.awt.headless=true,就是告诉JVM没有相关的显示服务,就会报错:
为什么报错呢?awt要调出来gui程序,JVM参数headless的true设置告诉JVM运行环境没有显示服务,不支持gui程序。
上面代码设置java.awt.headless=false,执行输出:
这里报错信息是不能连接到启动环境中的X DISPLAY Server,本地环境中有安装Microsoft VcXsrv X Server,设置的display port为3600,因此在JVM启动的shell环境中设置export DISPLAY=172.26.18.37:3600,重新执行:
那java.awt.headless=true什么场景时候用呢?比如,要生成图片,没有用到显示服务,但是用awt库,下面demo所示:
import java.awt.Graphics;import java.awt.image.BufferedImage;import java.io.File;import javax.imageio.ImageIO;public class TestCHSGraphic { public static void main (String[] args) throws Exception { // 设置Headless模式 //System.setProperty("java.awt.headless", "true"); //System.setProperty("java.awt.headless", "false"); System.out.println("是否是headless环境:" + java.awt.GraphicsEnvironment.isHeadless()); System.out.println("java.awt.headless 默认值:" + System.getProperty("java.awt.headless")); BufferedImage bi = new BufferedImage(200, 100, BufferedImage.TYPE_INT_RGB); Graphics g = bi.getGraphics(); g.drawString(new String("Headless Test".getBytes(), "utf-8"), 50, 50); ImageIO.write(bi, "jpeg", new File("test.jpg")); }}复制代码
这里如果java.awt.headless设置为false,并且在JVM的运行环境中没有X DISPLAY Server,就会出现和上面一样找不到X DISPLAY Server的报错。
4. 总结不要先入为主,认为程序一定是被自杀或者他杀的。事实表明程序是自己退出的。日志是解决问题的最佳突破口,如果有日志就从日志出发。没有日志也能说明一些问题,比如本例中要尽早排除掉内存或者JVM crash导致问题的排查方向。不能完全依赖日志,代码有时候处理不当会把日志吃掉。尝试复现问题能够找出突破口。有些问题找不出原因可能是知识的盲区,多了解相关支持能帮助排查问题。问题排查要一点点缩小排查范围,一定不能想当然,要像教孩子一样亲身实践,一点点排除。很多情况由于自己想当然,很小的点疏忽了,会浪费大量时间。原文链接:https://juejin/post/7050315664426270750
如果你觉的本文对你有帮助,麻烦点赞关注支持一下
声明:本文内容由互联网用户自发贡献,该文观点仅代表作者本人。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如发现本站有涉嫌抄袭侵权/违法违规的内容, 请发送至邮件举报,一经查实,本站将立刻删除。转载务必注明出处:http://www.hixs.net/article/20240324/169625539588983.html