记一次 .NET游戏站程序的 CPU 爆高分析

C# 小时候可胖了 26℃ 0评论

一:背景

1. 讲故事

上个月有个老朋友找到我,说他的站点晚高峰 CPU 会突然爆高,发了两份 dump 文件过来,如下图:

又是经典的 CPU 爆高问题,到目前为止,对这种我还是有一些经验可循的。

  • 抓 2-3 个 dump

第一个:有利于算两份 dump 中的线程时间差,从而推算最耗时线程。

第二个:有时候你抓的dump刚好线程都处理完了,cpu 还未真实回落,所以分析这种dump意义不大,我是吃了不少亏????????????。

  • 优先推测是否为 GC 捣鬼

现在的码农都精怪精怪的,基本不会傻傻的写出个死循环,绝大部分都是遇到某种

1
资源密集型

1
计算密集型

场景下导致非托管的 GC 出了问题。

好了,有了这个先入为主的思路,接下来就可以用 windbg 去占卜了。

二: windbg 分析

1. GC 捣鬼分析

GC 捣鬼的本质是 GC 出现了回收压力,尤其是对

1
大对象堆

的分配和释放,大家应该知道

1
大对象堆

采用的是链式管理法,不到万不得已 GC 都不敢回收它,所以在它上面的分配和释放都是一种

1
CPU密集型

操作,不信你可以去

1
StackOverflow

上搜搜 LOH 和 HighCPU 的关联关系????????????。

2. 使用 x 命令搜索

在 windbg 中有一个快捷命令

1
x

,可用于在非托管堆上检索指定关键词,检索之前先看看这个 dump 是什么

1
Framework

版本,决定用什么关键词。


1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
0:050> lmv
start    end        module name
00b80000 00b88000   w3wp       (pdb symbols)          c:mysymbolsw3wp.pdbCED8B2D5CB84AEB91307A0CE6BF528A1w3wp.pdb
    Loaded symbol image file: w3wp.exe
    Image path: C:WindowsSysWOW64inetsrvw3wp.exe
    Image name: w3wp.exe
71510000 71cc0000   clr        (pdb symbols)          c:mysymbolsclr.pdb9B2B2A02EC2D43899F87AC20F11B82DF2clr.pdb
    Loaded symbol image file: clr.dll
    Image path: C:WindowsMicrosoft.NETFrameworkv4.0.30319clr.dll
    Image name: clr.dll
    Browse all global symbols  functions  data
    Timestamp:        Thu Sep  3 03:30:58 2020 (5F4FF2F2)
    CheckSum:         007AC92B
    ImageSize:        007B0000
    File version:     4.8.4261.0
    Product version:  4.0.30319.0

1
File version

上可以看出当前是基于

1
Net Framework 4.8

的,好了,用

1
x clr!SVR::gc_heap::trigger*

看看有没有触发 gc 的操作。


1
2
3
4
0:050> x clr!SVR::gc_heap::trigger*
71930401          clr!SVR::gc_heap::trigger_ephemeral_gc (protected: int __thiscall SVR::gc_heap::trigger_ephemeral_gc(enum gc_reason))
71665cf9          clr!SVR::gc_heap::trigger_gc_for_alloc (protected: void __thiscall SVR::gc_heap::trigger_gc_for_alloc(int,enum gc_reason,struct SVR::GCDebugSpinLock *,bool,enum SVR::msl_take_state))
71930a08          clr!SVR::gc_heap::trigger_full_compact_gc (protected: int __thiscall SVR::gc_heap::trigger_full_compact_gc(enum gc_reason,enum oom_reason *,bool))

从输出信息看,gc 果然在高速运转,开心哈,接下来看一下是哪一个线程触发了gc,可以用

1
!eestack

把所有线程的托管和非托管堆栈打出来。

从图中可以看到当前 50 号线程的

1
GetUserLoginGameMapIds()

方法进行的大对象分配

1
try_allocate_more_space

触发了

1
clr!SVR::gc_heap::trigger_gc_for_alloc

GC回收操作,最后 GC 通过

1
clr!SVR::GCHeap::GarbageCollectGeneration

进行回收,既然在回收,必然有很多线程正在卡死。

接下来再看看有几个线程正在共同努力做多

1
GetUserLoginGameMapIds()

方法。

到这里基本就能确定是 gc 捣的鬼。接下来的兴趣点就是

1
GetUserLoginGameMapIds()

到底在干嘛?

3. 分析 GetUserLoginGameMapIds() 方法

接下来把方法的源码导出来,使用

1
!name2ee

找到其所属 module,然后通过

1
!savemodule

导出该 module 的源码。


1
2
3
4
5
6
7
8
9
10
11
12
0:050> !name2ee *!xxx.GetUserLoginGameMapIds
Module:      1c870580
Assembly:    xxx.dll
Token:       0600000b
MethodDesc:  1c877504
Name:        xxx.GetUserLoginGameMapIds(xxx.GetUserLoginGameMapIdsDomainInput)
JITTED Code Address: 1d5a2030
0:050> !savemodule  1c870580 E:dumps6.dll
3 sections in file
section 0 - VA=2000, VASize=112b8, FileAddr=200, FileSize=11400
section 1 - VA=14000, VASize=3c8, FileAddr=11600, FileSize=400
section 2 - VA=16000, VASize=c, FileAddr=11a00, FileSize=200

打开导出的

1
6.dll

,为了最大保护隐私,我就把字段名隐藏一下,

1
GetUserLoginGameMapIds()

大体逻辑如下。


1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
public GetUserLoginGameMapIdsDomainOutput GetUserLoginGameMapIds(GetUserLoginGameMapIdsDomainInput input)
{
    List<int> xxxQueryable = this._xxxRepository.Getxxx();
    List<UserLoginGameEntity> list = this._userLoginGameRepository.Where((UserLoginGameEntity u) => u.xxx == input.xxx, null, "").ToList<UserLoginGameEntity>();
    List<int> userLoginGameMapIds = (from u in list select u.xxx).ToList<int>();
    IEnumerable<GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput> source = (from mc in (from mc in this._mapCategoryRepository.AsQueryable().ToList<MapCategoryEntity>()
    where userLoginGameMapIds.Any((int mid) => mid == mc.xxx) && mapIdsQueryable.Any((int xxx) => xxx == mc.xxx)
    select mc).ToList<MapCategoryEntity>()
    join u in list on mc.xxx equals u.xxx
    select new GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput
    {
        xxx = mc.xxx,
        xxx = ((u != null)   new DateTime (u.xxx) : null).GetValueOrDefault(DateTime.Now)
    } into d
    group d by d.MapId).Select(delegate(IGrouping<int, GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput> g)
    {
        GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput getUserLoginGameMapIdsDataDomainOutput = new GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput();
        getUserLoginGameMapIdsDataDomainOutput.xxx = g.Key;
        getUserLoginGameMapIdsDataDomainOutput.xxx = g.Max((GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput v) => v.xxxx);
        return getUserLoginGameMapIdsDataDomainOutput;
    });
    return new GetUserLoginGameMapIdsDomainOutput
    {
        Data = source.ToList<GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput>()
    };
}

看的出来,这是一段EF读取DB的复杂写法,朋友说这段代码涉及到了多张表的关联操作,算是一个

1
资源密集型

的方法。

4. 到底持有什么大对象?

方法逻辑看完了,接下来看下

1
GetUserLoginGameMapIds()

方法到底分配了什么大对象触发了GC,可以探究下 50 线程的调用栈,使用

1
!clrstack -a

调出所有的

1
参数 + 局部

变量。


1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
0:050> !clrstack -a
OS Thread Id: 0x11a0 (50)
Child SP       IP Call Site
2501d350 7743c0bc [HelperMethodFrame: 2501d350]
2501d3dc 704fbab5 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].set_Capacity(Int32)
    PARAMETERS:
        this (<CLR reg>) = 0x08053f6c
        value = <no data>
    LOCALS:
        <no data>

2501d3ec 704fba62 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].EnsureCapacity(Int32)
    PARAMETERS:
        this = <no data>
        min = <no data>
    LOCALS:
        <no data>

2501d3f8 70516799 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].Add(System.__Canon)
    PARAMETERS:
        this (<CLR reg>) = 0x08053f6c
        item (<CLR reg>) = 0x2d7b07bc
    LOCALS:
        <no data>

从调用栈上看,由于 EF 的读取逻辑需要向

1
List

中添加一条记录刚好触发了List的扩容机制,就是因为这个扩容导致了GC大对象分配。

那怎么看呢 很简单,先把

1
this (<CLR reg>) = 0x08053f6c

中地址拿出来do一下

1
!do 0x08053f6c

调出 List。


1
2
3
4
5
6
7
8
9
10
11
12
13
0:050> !do 0x08053f6c
Name:        System.Collections.Generic.List`1[[xxx.MapCategoryEntity, xxx.Entities]]
MethodTable: 1e81eed0
EEClass:     70219c7c
Size:        24(0x18) bytes
File:        C:WindowsMicrosoft.NetassemblyGAC_32mscorlibv4.0_4.0.0.0__b77a5c561934e089mscorlib.dll
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
701546bc  40018a0        4     System.__Canon[]  0 instance 168792c0 _items
701142a8  40018a1        c         System.Int32  1 instance    32768 _size
701142a8  40018a2       10         System.Int32  1 instance    32768 _version
70112734  40018a3        8        System.Object  0 instance 00000000 _syncRoot
701546bc  40018a4        4     System.__Canon[]  0   static  <no information>

上面的

1
_size = 32768

看到了吗? 刚好是

1
2的15次方

,由于再次新增必须要扩容,List 在底层需分配一个

1
System.__Canon[65536]

的数组来存储老内容,这个数组肯定大于

1
85000byte

这个大对象的界定值啦。

如果有兴趣,你可以看下 List 的扩容机制。


1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
// System.Collections.Generic.List<T>
private void EnsureCapacity(int min)
{
    if (_items.Length < min)
    {
        int num = (_items.Length == 0)   4 : (_items.Length * 2);
        if ((uint)num > 2146435071u)
        {
            num = 2146435071;
        }
        if (num < min)
        {
            num = min;
        }
        Capacity = num;
    }
}

public int Capacity
{

    get
    {
        return _items.Length;
    }
    set
    {
        if (value < _size)
        {
            ThrowHelper.ThrowArgumentOutOfRangeException(ExceptionArgument.value, ExceptionResource.ArgumentOutOfRange_SmallCapacity);
        }
        if (value == _items.Length)
        {
            return;
        }
        if (value > 0)
        {
            T[] array = new T[value];   //这里申请了一个 65536 大小的数组
            if (_size > 0)
            {
                Array.Copy(_items, 0, array, 0, _size);
            }
            _items = array;
        }
        else
        {
            _items = _emptyArray;
        }
    }
}

三:总结

知道了前因后果之后,大概提三点优化建议。

  • 优化

    1
    GetUserLoginGameMapIds()

    方法中的逻辑,这是最好的办法。

  • 从 dump 上看也就

    1
    4核4G

    的小机器,提升下机器配置,或许有点用。


1
2
3
4
5
6
7
8
9
10
0:017> !cpuid
CP  F/M/S  Manufacturer     MHz
 0  6,63,2  GenuineIntel    2295
 1  6,63,2  GenuineIntel    2295
 2  6,63,2  GenuineIntel    2295
 3  6,63,2  GenuineIntel    2295

 0:017> !address -summary
--- Protect Summary (for commit) - RgnCount ----------- Total Size -------- %ofBusy %ofTotal
PAGE_READWRITE                          878          1eccd000 ( 492.801 MB)  29.61%   12.03%
  • 没有特殊原因的话,用 64bit 来跑程序,打破 32bit 的 4G 空间限制,这样也可以让gc拥有更大的堆分配空间。

参考网址:https://docs.microsoft.com/zh-cn/dotnet/standard/garbage-collection/fundamentals

更多高质量干货:参见我的 GitHub: dotnetfly

图片名称

转载请注明:九层楼 » 记一次 .NET游戏站程序的 CPU 爆高分析

喜欢 (0)
发表我的评论
取消评论
表情

Hi,您需要填写昵称和邮箱!

  • 昵称 (必填)
  • 邮箱 (必填)
  • 网址