记一次 .NET某游戏后端API服务 CPU爆高分析

血面纱

一：背景

1. 讲故事

前几天有位朋友找到我，说他们的API服务程序跑着跑着CPU满了降不下去，让我帮忙看下怎么回事，现在貌似民间只有我一个人专注dump分析，还是申明一下我dump分析是免费的，如果想学习.NET高级调试的分析技术，可以来我的训练营看看，话不多说，dump分析走起！
二：WinDbg分析

1. CPU 真的爆高吗

昨天录了一个小视频，大意就是作为分析师，不要过分的相信客户说的话，他们往往会把你带偏，你要有自己的分析思路和前进方向，所以需要以数据说话，首先用 !tp 观察下线程池。

1. 0:030> !tp
2. CPU utilization: 60%
3. Worker Thread: Total: 18 Running: 3 Idle: 15 MaxLimit: 32767 MinLimit: 4
4. Work Request in Queue: 0
5. --------------------------------------
6. Number of Timers: 3
7. --------------------------------------
8. Completion Port Thread:Total: 3 Free: 1 MaxFree: 8 CurrentLimit: 1 MaxLimit: 1000 MinLimit: 4

复制代码

从卦中可以看到当前的 CPU=60%，这个值说高也不高，说低也不低，接下来观察下这台机器的cpu核心数，可以用 !cpuid 观察。

1. 0:030> !cpuid
2. CP  F/M/S  Manufacturer     MHz
3. 0  6,63,2  <unavailable>   2295
4. 1  6,63,2  <unavailable>   2295
5. 2  6,63,2  <unavailable>   2295
6. 3  6,63,2  <unavailable>   2295

复制代码

真的是无语，做游戏的不都是有钱的主，难道都在降本增效吗？既然到了 60%，说明有两个线程估计脱轨了，接下来就需要观察下那2个托轨线程都在做什么？
2. 脱轨线程在干嘛

要想观察每个线程都在做什么，可以使用 ~*e !clrstack 命令即可。

1. 0:030> ~*e !clrstack
2. OS Thread Id: 0x3eec (30)
3.         Child SP               IP Call Site
4. 0000001f8fbad610 00007ffd958535c3 System.Collections.Generic.HashSet`1[[System.__Canon, mscorlib]].Contains(System.__Canon)
5. 0000001f8fbad680 00007ffd95372933 System.Web.HttpCookieCollection.EnsureKeyValidated(System.String, System.String)
6. 0000001f8fbad6c0 00007ffd9483fa8d System.Web.HttpCookieCollection.Get(System.String)
7. 0000001f8fbad700 00007ffd3d12b3da xxx.CookieHelper.Read(System.String)
8. ...
9. OS Thread Id: 0x5cf0 (31)
10.         Child SP               IP Call Site
11. 0000001f8d27d330 00007ffd958535b8 System.Collections.Generic.HashSet`1[[System.__Canon, mscorlib]].Contains(System.__Canon)
12. 0000001f8d27d3a0 00007ffd95372933 System.Web.HttpCookieCollection.EnsureKeyValidated(System.String, System.String)
13. 0000001f8d27d3e0 00007ffd9483fa8d System.Web.HttpCookieCollection.Get(System.String)
14. 0000001f8d27d420 00007ffd3e2ab6da xxx.CookieHelper.Read(System.String)
15. ...

复制代码

仔细琢磨了一下卦象后，发现有两个线程都停在 HashSet 上，而且这个集合还是来自于底层的 System.Web，对一般人来说这个是比较奇葩的现象，但对于我这种有300+分析经验的熟手来说，一眼就看出来了什么问题，对，就是多线程操控 HashSet 导致的死循环，接下来的问题是如何去验证呢？毕竟空口无凭。。。
3. 真的死循环了吗

要想了解有没有真的死循环，需要你对 HashSet 的底层有一个了解，比如说 HashSet 挂链的时候在内部是如何组织的，其实这个我在.NET高级训练营里面也做过讲解，也做过演示，接下来切到 31 号线程观察下它的 HashSet 结构。

1. 0:031> !mdso
2. Thread 31:
3. Location          Object            Type
4. ------------------------------------------------------------
5. RCX:              000000200054ffc0  System.Collections.Generic.HashSet`1+Slot[[System.String, mscorlib]][]
6. RSI:              000000200054ff58  System.Collections.Generic.HashSet`1[[System.String, mscorlib]]
7. ...
8. 0:031> !mdt 000000200054ff58
9. 000000200054ff58 (System.Collections.Generic.HashSet`1[[System.String, mscorlib]])
10.     m_buckets:000000200054ff98 (System.Int32[], Elements: 3)
11.     m_slots:000000200054ffc0 (System.Collections.Generic.HashSet`1+Slot[[System.String, mscorlib]][], Elements: 3, ElementMT=00007ffd95555230)
12.     m_count:0x0 (System.Int32)
13.     m_lastIndex:0x0 (System.Int32)
14.     m_freeList:0xffffffff (System.Int32)
15.     m_comparer:00000022003d3380 (System.OrdinalComparer)
16.     m_version:0x6 (System.Int32)
17.     m_siInfo:NULL (System.Runtime.Serialization.SerializationInfo)
18. ...
19. 0:031> !mdt -e:2 000000200054ffc0
20. 000000200054ffc0 (System.Collections.Generic.HashSet`1+Slot[[System.String, mscorlib]][], Elements: 3, ElementMT=00007ffd95555230)
21. [0] (System.Collections.Generic.HashSet`1+Slot[[System.String, mscorlib]]) VALTYPE (MT=00007ffd95555230, ADDR=000000200054ffd0)
22.     hashCode:0xffffffff (System.Int32)
23.     next:0x0 (System.Int32)
24.     value:NULL (System.__Canon)
25. [1] (System.Collections.Generic.HashSet`1+Slot[[System.String, mscorlib]]) VALTYPE (MT=00007ffd95555230, ADDR=000000200054ffe0)
26.     hashCode:0x3eb5808c (System.Int32)
27.     next:0xffffffff (System.Int32)
28.     value:000000200054f8f0 (System.String) Length=6, String="xxx"
29. [2] (System.Collections.Generic.HashSet`1+Slot[[System.String, mscorlib]]) VALTYPE (MT=00007ffd95555230, ADDR=000000200054fff0)
30.     hashCode:0x7e225883 (System.Int32)
31.     next:0x1 (System.Int32)
32.     value:000000200054fba0 (System.String) Length=12, String="xxx"

复制代码

熟悉 HashSet底层的朋友，从上面的卦信息一眼就能看出问题，对，就是这个 next:0x0，在hashset的挂链中，最后一个节点永远是 -1，如果是 0 的话就相当于指向数组的首元素，最后就是无情死循环了，知道了前因后果之后，接下来就要寻找下到底是什么圣神代码。
4. 到底是什么奇葩代码

这个比较简单，观察下线程栈的托管层代码，然后看源码即可，为了保护客户隐私，我就多注释一点，输出如下：

1. 0:031> !clrstack
2. OS Thread Id: 0x5cf0 (31)
3.         Child SP               IP Call Site
4. 0000001f8d27d330 00007ffd958535b8 System.Collections.Generic.HashSet`1[[System.__Canon, mscorlib]].Contains(System.__Canon)
5. 0000001f8d27d3a0 00007ffd95372933 System.Web.HttpCookieCollection.EnsureKeyValidated(System.String, System.String)
6. 0000001f8d27d3e0 00007ffd9483fa8d System.Web.HttpCookieCollection.Get(System.String)
7. 0000001f8d27d420 00007ffd3e2ab6da xxx.CookieHelper.Read(System.String)
8. ...

复制代码

虽然信息比较少，但卦还是很明朗的，客户写了一个 CookieHelper 封装了 Request.Cookies 操作，那到底怎么封装的呢？仔细阅读代码之后终于发现了，截图如下：

我去，这代码还是挺奇葩的，居然将 Cookies 给了静态变量，静态变量可是一个进程小缓存呢，水落石出之后改发也比较简单，把 static 去掉即可。
三：总结

这种将Request.Cookies赋给静态变量的奇葩操作其实蕴含着巨大的安全隐患，会导致多个用户之间串cookie，但以服务器自爆的方式来避免客户端串cookie，真的是不幸中的万幸，哈哈，同时用bug去抑制另一个bug的神操作也真的是大自然的鬼斧神工！

来源:https://www.cnblogs.com/huangxincheng/p/18087576
免责声明：由于采集信息均来自互联网，如果侵犯了您的权益，请联系我们【E-Mail:cb@itdo.tech】 我们会及时删除侵权内容，谢谢合作！