网站开发者收入来源,网站优化的价值,wordpress编辑器移植,竞价网站移动端一#xff1a;背景 1. 讲故事上个月底#xff0c;有位朋友微信找到我#xff0c;说他的程序 多线程处理 RabbitMQ 时过慢#xff0c;帮忙分析下什么原因#xff0c;截图如下#xff1a;这问题抛出来#xff0c;有点懵逼#xff0c;没说CPU爆高#xff0c;也没说内存泄… 一背景 1. 讲故事上个月底有位朋友微信找到我说他的程序 多线程处理 RabbitMQ 时过慢帮忙分析下什么原因截图如下这问题抛出来有点懵逼没说CPU爆高也没说内存泄漏也没说程序卡死。。。鬼知道为啥 Rabbitmq 处理过慢哈 。既然没有一个缘由那就往 freeze 这个方向去找吧上 windbg 说话。二Windbg 分析 1. 寻找 freeze 原因处理过慢原因有很多可能是干活的人少了也可能这些人摸鱼去了总之工作不饱和接下来看看这帮人有没有摸鱼从 线程池 看起。0:000 !tp
CPU utilization: 81%
Worker Thread: Total: 187 Running: 172 Idle: 0 MaxLimit: 32767 MinLimit: 8
Work Request in Queue: 0
--------------------------------------
Number of Timers: 0
--------------------------------------
Completion Port Thread:Total: 1 Free: 1 MaxFree: 16 CurrentLimit: 1 MaxLimit: 1000 MinLimit: 8从输出中看当前的 CPU81% 大概率是这个程序引起的既然 CPU 过高可能是某些计算密集型操作可能是大量锁导致的上下文切换也可能是 GC 频繁触发所致。2. 是 GC 触发吗本系列到这里我相信有很多朋友应该知道如何从线程栈上看是否为 GC 触发所致用命令 ~*e !dumpstack 经过一通寻找发现是 214 号线程触发了 GC如下图所示用 !dumpstack 输出的信息太多为了让信息更加简化改用 !clrstack。0:214 !clrstack
OS Thread Id: 0x290c (214)Child SP IP Call Site
000000bb2983c7d0 00007ffed8c3e335 System.Text.UTF8Encoding.GetString(Byte[], Int32, Int32)
000000bb2983c810 00007ffe7aaecee9 StackExchange.Redis.RedisValue.op_Implicit(StackExchange.Redis.RedisValue)
000000bb2983c860 00007ffe7aaecd92 xxxx.Util.Helper.RedisHelper.ConvertObj[[System.__Canon, mscorlib]](StackExchange.Redis.RedisValue)
000000bb2983c8f0 00007ffe7abc3997 xxxx.Util.Helper.RedisHelperc__DisplayClass29_01[[System.__Canon, mscorlib]].b__0(StackExchange.Redis.IDatabase)
000000bb2983ca20 00007ffe7aaeaca0 xxxx.Util.Helper.RedisHelper.Do[[System.__Canon, mscorlib]](System.Func2StackExchange.Redis.IDatabase,System.__Canon)
000000bb2983caa0 00007ffe7abc3762 xxxx.Util.Helper.RedisHelper.HashGet[[System.__Canon, mscorlib]](System.String, System.String)
000000bb2983cb40 00007ffe7abc2f3d xxxx.Implementation.xxx.GetCompany(System.String)
...
000000bb2983e170 00007ffe7ad2fadf xxx.xxx.MQ.xxxc__DisplayClass21_01[[System.__Canon, mscorlib]].b__1()
000000bb2983e1c0 00007ffed8c11862 System.Threading.Tasks.Task1[[System.__Canon, mscorlib]].InnerInvoke()
000000bb2983e220 00007ffed8c10937 System.Threading.Tasks.Task.Execute()
000000bb2983e260 00007ffed8bc674e System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000bb2983e330 00007ffed8bc65e7 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000bb2983e360 00007ffed8c10bdd System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef)
000000bb2983e410 00007ffed8c10303 System.Threading.Tasks.Task.ExecuteEntry(Boolean)
000000bb2983e450 00007ffed8bcfa10 System.Threading.ThreadPoolWorkQueue.Dispatch()
000000bb2983e8e8 00007ffed9d465d3 [DebuggerU2MCatchHandlerFrame: 000000bb2983e8e8]从卦中信息看程序在 RedisHelper.HashGet 操作的过程中触发了 GC我去难道是从 redis 中读了什么大数据接下来用 !clrstack -a 看看到底从redis中读了个啥0:214 !clrstack -a
OS Thread Id: 0x290c (214)Child SP IP Call Site
000000bb2983c860 00007ffe7aaecd92 xxx.Util.Helper.RedisHelper.ConvertObj[[System.__Canon, mscorlib]](StackExchange.Redis.RedisValue)PARAMETERS:this (0x000000bb2983c8f0) 0x000000bb182da3d0value (0x000000bb2983c960) 0x000000bb18440778LOCALS:0x000000bb2983c8c4 0x00000000000000000x000000bb2983c8a0 0x00000000000000000x000000bb2983c898 0x00000000000000000:214 !do 0x000000bb18440778
Name: System.Byte[]
MethodTable: 00007ffed8db93d0
EEClass: 00007ffed87f4dc8
Size: 6679(0x1a17) bytes
Array: Rank 1, Number of elements 6655, Type Byte (Print Array)
Content: {ID:104x,Code:130x,xxx:1304,xxx:8888,Name:...............,xxx:...............,MqConnStr可以看到redis 读了大概 6.6 k 的数据才这么点数据我还以为 几十M 呢 要说这点东西就能触发GC我是不相信的 。3. 到底是什么诱使了 GC 触发 那这个 罪魁祸首 到底是谁呢其实仔细想一想GC触发无非就是将对象从 gen0 推到 gen1然后由 gen1 推到 gen2那朋友的这个 RabbitMQ 处理慢肯定是触发了多次GC才有了这个肉眼可见的处理慢。这里就有一个突破点既然触发多次GC那gen2上肯定有很多带根的对象所以从这里入手比较好用 !dumpgen 命令查看。0:214 !dumpgen 2 -statCount Total Size Type
-------------------------------------------------87,738 24,925,316 System.Int32[]509,643 56,399,716 System.String83,077 65,760,888 System.Reflection.Emit.__FixupData[]2,158,346 69,067,072 System.Reflection.Emit.GenericMethodInfo92,388 172,765,392 System.Object[]796,870 179,587,796 **** FREE ****14,030,441 336,730,584 System.RuntimeMethodHandle428,376 348,743,274 System.Byte[]我去gen2 上居然有 1.4 kw 的对象这太让人好奇了接下来随便抽几个 address 看看它的引用根是个啥0:214 !dumpgen 2 -type System.RuntimeMethodHandle
Object MT Size Name
-------------------------------------------------------------------
000000bac9f8fe68 00007FFED8DB9978 24 System.RuntimeMethodHandle
000000bac9f8fe80 00007FFED8DB9978 24 System.RuntimeMethodHandle
000000bac9f8fe98 00007FFED8DB9978 24 System.RuntimeMethodHandle
000000bac9f8feb0 00007FFED8DB9978 24 System.RuntimeMethodHandle
000000bac9f8fec8 00007FFED8DB9978 24 System.RuntimeMethodHandle
...
000000baca1af510 00007FFED8DB9978 24 System.RuntimeMethodHandle
000000baca1af548 00007FFED8DB9978 24 System.RuntimeMethodHandle
000000baca1af560 00007FFED8DB9978 24 System.RuntimeMethodHandle
000000baca1afd90 00007FFED8DB9978 24 System.RuntimeMethodHandle
000000baca1afde0 00007FFED8DB9978 24 System.RuntimeMethodHandle0:214 !gcroot 000000baca1afde0
Thread 187c0:000000baeeb5cb30 00007ffed8ba9c60 System.Collections.Generic.Dictionary2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].FindEntry(System.__Canon)rsi: - 000000baca4c6ef0 System.Collections.Generic.Dictionary2[[System.Tuple4[[System.String, mscorlib],[System.String, mscorlib],[System.Int32, mscorlib],[System.Int32, mscorlib]], mscorlib],[System.Delegate, mscorlib]]- 000000badab3b8a0 System.Collections.Generic.Dictionary2Entry[[System.Tuple4[[System.String, mscorlib],[System.String, mscorlib],[System.Int32, mscorlib],[System.Int32, mscorlib]], mscorlib],[System.Delegate, mscorlib]][]- 000000baca1b5210 System.Func2[[System.Data.IDataReader, System.Data],[xxx.BAR_AccountDC, xxxx]]- 000000baca1ae8b0 System.Reflection.Emit.DynamicMethodRTDynamicMethod- 000000baca1ae7f8 System.Reflection.Emit.DynamicMethod- 000000baca1b51b0 System.RuntimeMethodInfoStub- 000000baca1b4a18 System.Reflection.Emit.DynamicResolver- 000000baca1aea60 System.Reflection.Emit.DynamicScope- 000000baca1aea78 System.Collections.Generic.List1[[System.Object, mscorlib]]- 000000baca1b3b20 System.Object[]- 000000baca1afde0 System.RuntimeMethodHandle从引用链看它是被 Dictionary 所持有那我们就 dump 一下这个 dictionary看看是个啥。0:214 !do 000000baca4c6ef0
Name: System.Collections.Generic.Dictionary2[[System.Tuple4[[System.String, mscorlib],[System.String, mscorlib],[System.Int32, mscorlib],[System.Int32, mscorlib]], mscorlib],[System.Delegate, mscorlib]]
MethodTable: 00007ffe7a937f18
EEClass: 00007ffed87f7cb8
Size: 80(0x50) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:MT Field Offset Type VT Attr Value Name
00007ffed8dc3e30 400182a 8 System.Int32[] 0 instance 000000badaaa2c10 buckets
00007ffed9874d38 400182b 10 ...non, mscorlib]][] 0 instance 000000badab3b8a0 entries
00007ffed8dc3e98 400182c 38 System.Int32 1 instance 83000 count
00007ffed8dc3e98 400182d 3c System.Int32 1 instance 83000 version
00007ffed8dc3e98 400182e 40 System.Int32 1 instance -1 freeList
00007ffed8dc3e98 400182f 44 System.Int32 1 instance 0 freeCount
00007ffed8d9a430 4001830 18 ...Canon, mscorlib]] 0 instance 000000baca2ec958 comparer
00007ffed8d9c550 4001831 20 ...Canon, mscorlib]] 0 instance 0000000000000000 keys
00007ffed8dcef28 4001832 28 ...Canon, mscorlib]] 0 instance 0000000000000000 values
00007ffed8dc1c98 4001833 30 System.Object 0 instance 0000000000000000 _syncRoot0:214 !objsize 000000baca4c6ef0
sizeof(000000baca4c6ef0) 1116325152 (0x4289c520) bytes (System.Collections.Generic.Dictionary2[[System.Tuple4[[System.String, mscorlib],[System.String, mscorlib],[System.Int32, mscorlib],[System.Int32, mscorlib]], mscorlib],[System.Delegate, mscorlib]])可以看到当前dict 的 size 8.3w总大小为 1.1G, 然后用 !mdt 抽查一下字典内容。可以看出字典中的item大概都是 key select * from xxx where AccountNo xxxx value Func 4. 查看源码从 !gcroot 中知道当前根在 187c0 号线程然后我们通过线程栈去寻找下源码。0:089 ~~[187c0]s
ntdll!NtWaitForSingleObject0xa:
00007ffee9ea06fa c3 ret
0:089 !clrstack
OS Thread Id: 0x187c0 (89)Child SP IP Call Site
000000baeeb5caa0 00007ffed9718dfe System.Tuple4[[System.__Canon, mscorlib],[System.__Canon, mscorlib],[System.Int32, mscorlib],[System.Int32, mscorlib]].System.Collections.IStructuralEquatable.GetHashCode(System.Collections.IEqualityComparer)
000000baeeb5cb00 00007ffed8ba90a7 System.Collections.Generic.ObjectEqualityComparer1[[System.__Canon, mscorlib]].GetHashCode(System.__Canon)
000000baeeb5cb30 00007ffed8ba9c60 System.Collections.Generic.Dictionary2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].FindEntry(System.__Canon)
000000baeeb5cba0 00007ffed8bc53a4 System.Collections.Generic.Dictionary2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].TryGetValue(System.__Canon, System.__Canon ByRef)
000000baeeb5cbe0 00007ffe7abd8069 xxx.Internal.Cache2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].Get(System.__Canon, System.Func1System.__Canon)
000000baeeb5cc50 00007ffe7abd6d52 xxx.Databased__491[[System.__Canon, mscorlib]].MoveNext()
000000baeeb5ccd0 00007ffed733768e System.Linq.Enumerable.FirstOrDefault[[System.__Canon, mscorlib]](System.Collections.Generic.IEnumerable1System.__Canon)
000000baeeb5cd40 00007ffe7af5489e xxx.xxx.ParsePapPayDebitRecord(xxx, xxx.BAR_AccountDC ByRef, System.String ByRef, xxx ByRef, Boolean, xxx, Boolean)
...从线程栈看,程序做了一个 db 查询的操作源码大概如下public static InvalidTxnCode ParsePapPayDebitRecord(xxx)
{sql select * FROM [dbo].[xxx] where AccountNO transRecord.AccountNO ;IEnumerableBAR_AccountDC enumerable3 new YiBllBAR_AccountDC(transRecord.AccountNO).QuerySql(sql);
}问题就出现在这个 sql 拼接上底层的框架为了提高 mapping 速度将 sql 和与之对应的 FuncDataReader,Data 做了缓存处理由于每次sql都不一样这就导致底层的 dict越来越大直到目前的 1.1 G。三总结 总的来说本次事故是由于不断增长的 dict 在不断的挤压小对象堆加之程序多线程火力全开分配对象导致gc在小对象堆上的频繁回收造成的 rabbitmq 处理过慢。修改办法就是将 sql 参数化。sql select * FROM [dbo].[xxx] where AccountNO transRecord.AccountNO ;改成sql select * FROM [dbo].[xxx] where AccountNO AccountNO;最后提一下这个dump有一定的迷惑性因为触发GC的线程并不是罪魁祸首它只不过是压死骆驼的那最后一根稻草罢了。END工作中的你是否已遇到 ... 1. CPU爆高2. 内存暴涨3. 资源泄漏4. 崩溃死锁5. 程序呆滞等紧急事件全公司都指望着你能解决... 危难时刻才能展现你的技术价值作为专注于.NET高级调试的技术博主欢迎微信搜索: 一线码农聊技术免费协助你分析Dump文件希望我能将你的踩坑经验分享给更多的人。
