感谢
感谢【一级码农】 的帮助,之前也读了大佬的好多文章,一直在学习中,也没有实际操作过。
这次的过程也是在大佬的指点下完成的。
现象描述
从周六上午开始,陆续收到服务器CPU高的报警短信,到下午已经累计三十多条报警了,看来确实得分析一下原因了。
打开云监控,与实际情况一致,CPU居高不下
通过进程,很快锁定是哪个应用,是一个car系统造成的
car系统的版本是.net 4.0
分析过程
通过以下命令,抓包,命令解释,当CPU超过50%时,持续三秒,抓两个包。进程ID是6100。进程ID在任务管理器中可以看到。
procdump -ma -c 50 -s 3 -n 2 6100
遇到如下错误
出现以上错误是因为没有用管理员运行CMD,重新用管理员打开即可。
很快抓包完成。从服务器down到本地。
# 加载sos和clr文件
0:016> .load C:\Windows\Microsoft.NET\Framework\v4.0.30319\sos.dll
0:016> .load C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
0:062> !runaway
User Mode Time
Thread Time
16:dc4 0 days 0:13:12.593
15:2be4 0 days 0:13:06.390
17:2404 0 days 0:13:06.328
18:bb4 0 days 0:12:45.953
39:3294 0 days 0:04:10.500
44:320 0 days 0:04:07.281
38:3b24 0 days 0:04:06.156
43:176c 0 days 0:04:00.218
46:1118 0 days 0:03:55.359
50:2a3c 0 days 0:03:54.921
40:1aac 0 days 0:03:50.531
51:2fb4 0 days 0:03:49.421
47:2508 0 days 0:03:48.718
!runaway发现前几个线程时间很长,那么他们在干什么呢?
切到 16 号线程~16s
0:016> !clrstack
PDB symbol for clr.dll not loaded
Failed to load data access DLL, 0x80004005
Verify that 1) you have a recent build of the debugger (6.2.14 or newer)
2) the file mscordacwks.dll that matches your version of clr.dll is
in the version directory or on the symbol path
3) or, if you are debugging a dump file, verify that the file
mscordacwks_<arch>_<arch>_<version>.dll is on your symbol path.
4) you are debugging on supported cross platform architecture as
the dump file. For example, an ARM dump file must be debugged
on an X86 or an ARM machine; an AMD64 dump file must be
debugged on an AMD64 machine.
You can also run the debugger command .cordll to control the debugger's
load of mscordacwks.dll. .cordll -ve -u -l will do a verbose reload.
If that succeeds, the SOS command should work on retry.
If you are debugging a minidump, you need to make sure that your executable
path is pointing to clr.dll as well.
上面不是提示sos clr文件不对吗,在服务器上分析是没有报这个错的,所以我从服务器上弄了两个回来
.load D:\soft\WinDbg+procdump\procdump\car\sos.dll
.load D:\soft\WinDbg+procdump\procdump\car\clr.dll
0:018> .load D:\soft\WinDbg+procdump\procdump\car\sos.dll
0:018> .load D:\soft\WinDbg+procdump\procdump\car\clr.dll
0:018> !clrstack
PDB symbol for clr.dll not loaded
OS Thread Id: 0xbb4 (18)
Unable to walk the managed stack. The current thread is likely not a
managed thread. You can run !threads to get a list of managed threads in
the process
Failed to start stack walk: 80070057
OK,现在不提示配置问题了。继续分析
0:016> !clrstack
OS Thread Id: 0xdc4 (16)
Unable to walk the managed stack. The current thread is likely not a
managed thread. You can run !threads to get a list of managed threads in
the process
Failed to start stack walk: 80070057
0:016> ~15s
eax=00000000 ebx=00000000 ecx=00000000 edx=00000000 esi=00000000 edi=0000053c
eip=76f2c0bc esp=1af3fbfc ebp=1af3fc6c iopl=0 nv up ei pl nz na pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000206
ntdll!NtWaitForSingleObject+0xc:
76f2c0bc c20c00 ret 0Ch
前四个线程,都提示not a managed thread
请教了一下【一级码农】大佬,这个方向可能是错误的。那我们就只能换一个方向。
这里大佬已经告诉我是拖管线程的问题,如果是我们首次分析,可能还需要先判断是拖管还是非拖管的问题。这个后面再慢慢消化加上去。
我们这里走一个捷径,直接查拖管线程,有时候你也可以假装碰碰运气,说不定就能找到原因了呢。
~*e !clrstack 发现触发了GC回收
!dumpstack 显示当前调用栈上的所有托管对象的信息,
发现这个Volcker.Autotrader.ProductPropertieData.GetAll()方法出现多次,明显有多个线程卡在这里了。那这个方法是干啥的呢,
查看一下源码就知道了。
当然,如果有时候你手里没有源码,或者服务器运行的和本地代码差异比较大,那就导出源代码
0:053> !ip2md 1c15f4bd
MethodDesc: 1b9ec174
Method Name: Volcker.Autotrader.ProductPropertieData.GetAll()
Class: 1bd668a4
MethodTable: 1b9ec19c
mdToken: 06000088
Module: 1b9ebbd4
IsJitted: yes
CodeAddr: 1c15f420
Transparency: Critical
0:053> !savemodule 1b9ebbd4 D:\dumps\car-cpu\GetAll.dll
3 sections in file
section 0 - VA=2000, VASize=1714c, FileAddr=200, FileSize=17200
section 1 - VA=1a000, VASize=3e8, FileAddr=17400, FileSize=400
section 2 - VA=1c000, VASize=c, FileAddr=17800, FileSize=200
需要提前创建好目录 D:\dumps\car-cpu,找到上面的方法
这一行代码是干啥的呢,解释一下,其实是个通用的将数据库表转换为实体类的方法。
/// <summary>
/// 根据IDataReader对属性进行赋值
/// </summary>
/// <param name="reader">
new public void LoadDataReader(IDataReader reader)
{
LoadDataReader(MethodBase.GetCurrentMethod(), this, reader);
}
/// <summary>
/// 根据DataReader为对象属性赋值
/// </summary>
/// <param name="method">所属类MethodBase对象
/// <param name="obj">
/// <param name="reader">设置其属性 (Property) 值的对象
/// <returns></returns>
virtual public void LoadDataReader(MethodBase method, Object obj,IDataReader reader)
{
Hashtable cols = new Hashtable();
for (var i = 0; i < reader.FieldCount; i++)
{
cols.Add(reader.GetName(i).ToLower(), reader.GetValue(i)); //装入数据到hashtable中
}
Hashtable h = GetFieldProperties(method, FieldType.DBField); //获取属性的Hasttable
foreach (var o in h.Keys)
{
PropertyInfo p = (PropertyInfo)h[o];
Object v = null;
if (cols.Contains(o))
{
v = cols[o];
}
if (v != null)
{
SetPropertieValue(ref obj, ref p, ref v);
}
}
}
这里用了一个反射,通过上面的分析得到,问题出在这一行
Hashtable h = GetFieldProperties(method, FieldType.DBField);//获取属性的Hasttable
可能是这个类或者方法的属性太多吧,或者其他原因造成的。
可能一开始写这个反射方法用法没有错,但是防不住后面有人在类中或者方法中加了其他的东东,造成反射有问题了。
我以前也写过类似的方法,没有这个智能,但也从来没出过问题。
有时候,太智能了也没有啥必要,
最简单的代码效率最高,搞这么复杂有必要吗?
不说这个了,解决问题先
由于代码历史太悠久,相关细节完全不清楚,所以也不敢改动太大
目前的办法就是加缓存,这个其实是个字典表,理论上变化不会很大,所以加了24小时的缓存,24小时请求一次。
改一下代码,更新一下看看。
效果很明显啊,再观察几天看看。
总结
上面的分析过程基本上比较详细了,但有些步骤可能没有啥逻辑,原因就是靠经验,或者运气。经历的越多,可能猜一下就大概知道原因在哪
再次感谢【一线码农】的帮助,下面是大佬的总结