WPF应用熄屏后内存暴涨问题解决记录

1.背景

最近在负责开发和测试一个读取外部ZMQ数据并解包出图显示在界面上的.Net Framework 4.6.2 WPF应用,通过ZMQ接收上游数据,使用WriteableBitmap实现同一时刻多个图像的绘制和双击原图的展示功能。

应用运行在一台物理4CPU、300G+内存(不是硬盘空间)的某品牌服务器上,外部为一台4K显示器,经由DP线与服务器连接。

在前期优化测试确认已经消灭可见的性能问题后,因需要等待上游环节配合,因此自己平常会使用自制高速数据模拟器对应用进行性能压测。

2.问题暴露过程

2.1 一顿让人迷糊的午饭

在一天中午吃饭前,我照例挂上了模拟器和应用,准备进行长时间的压测。

压测场景中,应用会由一个主窗口A开启一个包含12个方形卡片的窗口B,每个方形卡片内上方为WriteableBitmap,下方为根据数据项数进行双列排布的ItemsControl;另外还会双击一个卡片中的图片部分,开启一个全屏窗口C,内部为一个WriteableBitmap,方便使用者查看图片细节。

一个多小时后,待下午上班点亮屏幕查看情况时,资源管理器内显示我的应用进程已经占用了160G+。

而且可能是下午刚上班,人还有些迷糊,以为是占用了16G,使用任务管理器进行了内存转储,待看到转储文件才发现是160G。

2.2 啃不动的“巨无霸”

因为前期有在设备上排查内存问题的经历,我在设备上安装了DotMemory,想着等软件加载并分析出结果后进行可视化查看。

然而在我打开DotMemory并使用Import Process Dump选项加载这个转储文件等了几分钟后,才发现DotMemory的进度条移动缓慢。

再等了几分钟无果,只好取消了这次加载。

2.3 令人茅塞顿开的晚饭

下午我在设备前跑了一次长时间的性能压测,并且会时不时查看内存占用情况,但是内存依然只在400-800MB上波动。

没有突破点但离饭点没多久了,为了排除下午性能压测的干扰,于是我重新启动了模拟器和应用并挂上了Procdump , 执行了性能压测流程。

procdump64.exe -accepteula -ma -m 2048 LoadDisplayFourChannel.exe D:\dumps

待我吃完晚饭回来,点亮屏幕的时候发现内存也出现了暴涨的问题,并暴涨到了16G,而Procdump 也已经在内存2G的时候成功将内存文件进行转储。

发现问题后,我思考了一下共性和区别,发现内存暴涨疑似都发生在熄屏后,并有随着时间延长占用量上涨的趋势。

于是我找到了系统的电源选项,将显示器熄屏设置为3分钟(当时设备上的最小值),然后启动了性能压测流程。

待屏幕熄灭一分钟后,我操作鼠标唤醒了屏幕,查看内存果然有上涨迹象,基本可以确定在屏幕熄灭时软件的内存出现了一些堆积问题。

3. 排故过程

3.1 与AI的问题探讨

在今年AI编码排故能力提升之前,我会使用DotMemory导入dump文件并进行可视化的分析;平常也会看一些.NET排故分析的文章,但是苦于没有系统化学习过,所以总是浅尝辄止。

在今年AI能力提升之后,我也尝试在进行软件性能自测试的过程中,使用AI集成对Dump的分析,体感是在没有系统性知识体系的情况下,可以通过AI的分析对Dump调试建立一些初步的认识。

本次排故也让AI参与了分析,但本文不会直接贴出大段的AI对话过程与大段结论,会在自己后续手动复现的情况下,用自己的理解还原这次问题的定位和解决过程,但受限于知识储备,可能会有一些错误,还请大佬们批评指正。

3.2 第一回合:无人消费的数据

首先找到这个dump文件,使用dotnet-dump对dump文件进行加载分析

dotnet-dump analyze D:\dumps\LoadDisplayFourChannel.exe_261021_170628.dmp

如果没有安装过dotnet-dump,可以通过以下命令进行安装

dotnet tool install --global dotnet-dump

这里使用dotnet-dump主要是为了方便分析托管堆;另外由于主程序基于.Net Framework开发的,无法使用dotnet-dump进行转储(而且这个场合需要在内存涨上去之后再做转储,所以选择的procdump进行满足条件后的转储操作)

进入分析视图后,使用dumpheap -stat分析托管堆中是否有内存堆积(由于结果太多,仅列出10行堆栈)

> dumpheap -stat
Statistics:
          MT  Count     TotalSize Class Name
.....
7ff8be15c6e0  6,090       828,464 System.Runtime.CompilerServices.ConditionalWeakTable<System.Object, System.Object>+Entry[]
7ff8be0e5dd8 43,658     1,047,792 System.Object
7ff8bc48fdc8  6,154     1,057,616 System.Windows.EffectiveValueEntry[]
7ff8be0ec408  9,590     1,074,080 System.Reflection.RuntimeMethodInfo
7ff861932868 12,600     1,108,800 LoadDisplayFourChannel.Share.ParseData.AuxiliaryDataInfo
7ff8be0e59c0 28,938     1,708,736 System.String
0255987684a0  5,177     5,903,716 Free
7ff861c6ebe0     63     6,490,216 ScottPlot.Coordinates[]
7ff8be0eaaa0  9,846 1,435,845,922 System.Byte[]
Total 377,428 objects, 1,473,378,414 bytes

从堆栈中看到很多字节数组占用了超出其他类型一个数量级的,使用dumpheap -mt 7ff8be0eaaa0 -live对字节数组在堆上的占用分布进行分析,由于数据较多仅展示10行,中间做省略处理

> dumpheap -mt 7ff8be0eaaa0 -live
Calculating live objects, this may take a while...
Caching GC roots, this may take a while.
Subsequent runs of this command will be faster.

Calculating live objects complete: 229,211 objects from 952 roots
         Address               MT           Size
    02559a74c7c8     7ff8be0eaaa0             40
    02559a74d5a8     7ff8be0eaaa0             88
    02559a750930     7ff8be0eaaa0             69
    02559a774aa8     7ff8be0eaaa0             32
    02559a774ce0     7ff8be0eaaa0             32
    ......
    02562e067a28     7ff8be0eaaa0      1,125,024
    02562e2a5000     7ff8be0eaaa0      1,125,024
    02562e4e25d8     7ff8be0eaaa0      1,125,024
    02562e71fbb0     7ff8be0eaaa0      1,125,024
    02562e95d188     7ff8be0eaaa0      1,125,024

这里一定要携带-live参数,否则会列出很多实际不可达等待GC(垃圾回收)的对象

从结果中可以看出,有很多被实际持有的大对象,如果想要统计大对象的规模但输出内容太多,可以使用以下指令将内存占用分析结果输出重定向到文件内,方便使用外部指令/工具/甚至是EXCEL进行分析统计

dotnet-dump analyze D:\dumps\LoadDisplayFourChannel.exe_261021_170628.dmp -c "dumpheap -mt 7ff8be0eaaa0 -live" -c "exit" < nul > dumpheap_stat.txt

其中 -c 参数后跟上的双引号内容代表在加载dump后输入的指令,可以接多个起到重定向需要的输出结果并在执行完毕后自行退出,让操作者能直观确认到已经重定向完毕。

经过(AI的)对重定向结果文件的统计聚合后,大小和出现次数最高的两条分别是

次数  大小
1049 32
740 1,125,024

可以看到有740个大对象被实际持有,接下来需要使用 gcroot address 命令查看单个大对象的应用根,如本次使用 gcroot 02562e95d188 查看;由于实际应用根结果较多,下面仅展示一个典型应用根的路径和底部的汇总结果

由于应用根路径较长,进行折叠处理,请点击查看
> gcroot 02562e95d188
HandleTable:
......
    00000255986912a8 (strong handle)
          -> 02559ae81470     System.Threading.Timer 
          -> 02559ae81540     System.Threading.TimerHolder 
          -> 02559ae81490     System.Threading.TimerQueueTimer 
          -> 02559ae82950     System.Threading.TimerQueueTimer 
          -> 02559ae83e10     System.Threading.TimerQueueTimer 
          -> 02559ae852d0     System.Threading.TimerQueueTimer 
          -> 02559ae86790     System.Threading.TimerQueueTimer 
          -> 02559ae87c50     System.Threading.TimerQueueTimer 
          -> 02559ae89110     System.Threading.TimerQueueTimer 
          -> 02559ae8a5d0     System.Threading.TimerQueueTimer 
          -> 02559ae8ba90     System.Threading.TimerQueueTimer 
          -> 02559ae8cf50     System.Threading.TimerQueueTimer 
          -> 02559ae8e410     System.Threading.TimerQueueTimer 
          -> 02559ae8f8d0     System.Threading.TimerQueueTimer 
          -> 02559ae90d90     System.Threading.TimerQueueTimer 
          -> 02559ae928c0     System.Threading.TimerQueueTimer 
          -> 02559c0c0700     System.Threading.TimerQueueTimer 
          -> 02559c36dd70     System.Threading.TimerQueueTimer 
          -> 02559c36dcd8     System.Threading.Tasks.Task+DelayPromise 
          -> 02559c36deb0     System.Action 
          -> 02559c36de90     System.Runtime.CompilerServices.AsyncMethodBuilderCore+MoveNextRunner 
          -> 02559b013ff8     LoadDisplayFourChannel.Share.ParseData.AuxiliaryDataController+<>c__DisplayClass24_0+<<-ctor>b__2>d 
          -> 02559b245bd8     LoadDisplayFourChannel.Share.ParseData.AuxiliaryDataController+<>c__DisplayClass24_0 
          -> 02559a8acde0     LoadDisplayFourChannel.Share.ParseData.AuxiliaryDataController 
          -> 02559a8abae0     Prism.Events.EventAggregator 
          -> 02559a7c5c68     System.Windows.Threading.DispatcherSynchronizationContext 
          -> 02559a750b58     System.Windows.Threading.Dispatcher 
          -> 02559a750c58     System.Collections.Generic.List<System.Windows.Threading.DispatcherTimer> 
          -> 02559ad49ed8     System.Windows.Threading.DispatcherTimer[] 
          -> 02559af74f30     System.Windows.Threading.DispatcherTimer 
          -> 02559af74f98     System.EventHandler 
          -> 02559af4db68     LoadDisplayFourChannel.Share.Chart.ViewChart 
          -> 02559af659e0     ScottPlot.WPF.WpfPlot 
          -> 02559af65790     System.Windows.Controls.Grid 
          -> 02559b107040     System.Windows.Controls.ContentPresenter 
          -> 02559b1949c0     System.Windows.EffectiveValueEntry[] 
          -> 02559ae30d40     LoadDisplayFourChannel.Views.Win.ViewWinSecond 
          -> 02559af6fa80     System.Windows.Controls.Primitives.ResizeGrip 
          -> 02559b109430     System.Windows.Controls.Grid 
          -> 02559b19fdc0     System.Windows.EffectiveValueEntry[] 
          -> 02559ae945d0     LoadDisplayFourChannel.ViewModels.Win.ViewWinSecondViewModel 
          -> 02559ae957e0     Prism.Commands.DelegateCommand 
          -> 02559ae234e8     System.EventHandler 
          -> 02559ae23488     System.Windows.Input.CanExecuteChangedEventManager+HandlerSink 
          -> 02559b06f8d8     System.Windows.Input.CanExecuteChangedEventManager 
          -> 02559ace8f28     MS.Internal.WeakEventTable 
          -> 02559ace9028     System.Collections.Hashtable 
          -> 02559ba51318     System.Collections.Hashtable+bucket[] 
          -> 02559b106380     System.Collections.Specialized.HybridDictionary 
          -> 02559b106858     System.Collections.Specialized.ListDictionary 
          -> 02559b106888     System.Collections.Specialized.ListDictionary+DictionaryNode 
          -> 02559b102e68     System.ComponentModel.ReflectPropertyDescriptor 
          -> 02559b1067a8     System.Collections.Hashtable 
          -> 02559b1067f8     System.Collections.Hashtable+bucket[] 
          -> 02559af8d3b0     System.Collections.Generic.KeyValuePair<System.String, LoadDisplayFourChannel.Share.Chart.ChartBase> 
          -> 02559af75a90     LoadDisplayFourChannel.Share.Chart.ViewChart 
          -> 02559b107c78     System.Windows.Controls.ContentControl 
          -> 02559b1020d0     System.Windows.Controls.ContentPresenter 
          -> 02559b194be0     System.Windows.EffectiveValueEntry[] 
          -> 02559b107ba0     System.Collections.Specialized.HybridDictionary[] 
          -> 02559b107bc0     System.Collections.Specialized.HybridDictionary 
          -> 02559b107df0     System.Collections.Specialized.ListDictionary 
          -> 02559b107e20     System.Collections.Specialized.ListDictionary+DictionaryNode 
          -> 02559b107e48     System.Windows.Data.BindingExpression 
          -> 02559acd4c50     MS.Internal.Data.DataBindEngine 
          -> 02559c1dcd70     System.Windows.Threading.DispatcherOperation 
          -> 02559c1dcef8     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c227f68     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c2281a8     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c2af458     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c30a308     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c357ef0     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c358110     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c35dc88     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c36c2e8     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c3a6250     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c3a6470     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c3a8960     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c3e5b78     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c3e36f8     System.Windows.Threading.PriorityItem<System.Windows.Threading.DispatcherOperation> 
          -> 02559c3e3570     System.Windows.Threading.DispatcherOperation 
          -> 02559c3e2fd8     Slice_Image_data 
          -> 02559c3e3108     Google.Protobuf.ByteString 
          -> 02562e95d188     System.Byte[] 
......
Found 95 unique roots.

从针对应用根底部的观察来看,可以发现以下现象

  1. 应用根由 System.Byte[] ->Google.Protobuf.ByteString-> Slice_Image_data 作为根部向上延伸,说明转储时刻有很多由System.Byte[] 被解析成 Slice_Image_data 的对象

Slice_Image_data来源于接收到ZMQ数据后,将符合条件的数据解析后生成的图像格式,之后通过Prism的事件发布将实体发送出去,供订阅方接收,由于涉及到在WriteableBitmap上进行图像绘制,所以订阅方需要将订阅方法跑在UI线程

  1. 有很多Threading.DispatcherOperation在堆栈上

后续查阅了一下Dispatcher的知识,了解到Dispatcher在接收到涉及UI线程的委托之后会先创建DispatcherOperation对象并设定优先级放入优先队列,Dispatcher再根据优先级从队列内取出DispatcherOperation并执行

针对第二点,首先使用dumpobj命令拆了一下离Slice_Image_data最近的DispatcherOperation对象,具体过程和结果如下所示(最后的类中省略部分与本文无关的字段)

> dumpobj 02559c3e3570
Name:        System.Windows.Threading.DispatcherOperation
MethodTable: 00007ff8bc493f98
EEClass:     00007ff8bc4ca818
Size:        112(0x70) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_MSIL\WindowsBase\v4.0_4.0.0.0__31bf3856ad364e35\WindowsBase.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ff8bc48e468  40012a1        8 ...gExecutionContext  0 instance 000002559c3e35f8 _executionContext
00007ff8bc493e30  40012a3       10 ...eading.Dispatcher  0 instance 000002559a750b58 _dispatcher
00007ff8bc48c4f0  40012a4       58         System.Int32  1 instance               10 _priority
00007ff8be0e80f0  40012a5       18      System.Delegate  0 instance 000002559c3e3530 _method
00007ff8be0e5dd8  40012a6       20        System.Object  0 instance 000002559c3e2fd8 _args
00007ff8be0e85a0  40012a7       5c         System.Int32  1 instance                1 _numArgs
00007ff8bc8b8d20  40012a8       60         System.Int32  1 instance                0 _status
00007ff8be0e5dd8  40012a9       28        System.Object  0 instance 0000000000000000 _result
00007ff8be0e5b70  40012aa       30     System.Exception  0 instance 0000000000000000 _exception
00007ff8bc48e5e0  40012ab       38 ...on, WindowsBase]]  0 instance 000002559c3e36f8 _item
00007ff8be160e30  40012ac       40  System.EventHandler  0 instance 0000000000000000 _aborted
00007ff8be160e30  40012ad       48  System.EventHandler  0 instance 0000000000000000 _completed
00007ff8bc4825e0  40012ae       50 ...erationTaskSource  0 instance 000002559c3e35e0 _taskSource
00007ff8be0eb698  40012af       64       System.Boolean  1 instance                0 _useAsyncSemantics
00007ff8be1647d0  40012a2      8d8 ...g.ContextCallback  0   static 000002559a7736c0 _invokeInSecurityContext
> dumpobj 000002559c3e3530
Name:        System.Threading.SendOrPostCallback
MethodTable: 00007ff8be166880
EEClass:     00007ff8be0c64d8
Size:        64(0x40) 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
00007ff8be0e5dd8  40002f3        8        System.Object  0 instance 000002559c3e3518 _target
00007ff8be0e5dd8  40002f4       10        System.Object  0 instance 0000000000000000 _methodBase
00007ff8be1631f8  40002f5       18        System.IntPtr  1 instance 00007FF861D5DBF0 _methodPtr
00007ff8be1631f8  40002f6       20        System.IntPtr  1 instance 0000000000000000 _methodPtrAux
00007ff8be0e5dd8  4000300       28        System.Object  0 instance 0000000000000000 _invocationList
00007ff8be1631f8  4000301       30        System.IntPtr  1 instance 0000000000000000 _invocationCount
> dumpobj 000002559c3e3518
Name:        Prism.Events.DispatcherEventSubscription`1+<>c__DisplayClass2_0[[Slice_Image_data, LoadDisplayFourChannel]]
MethodTable: 00007ff861f04688
EEClass:     00007ff861de8e48
Size:        24(0x18) bytes
File:        C:\Users\Administrator\Downloads\share\Release\Prism.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ff8be15ddd0  4000072        8 ...Canon, mscorlib]]  0 instance 000002559c3e3278 action
> dumpobj 000002559c3e3278
Name:        System.Action`1[[Slice_Image_data, LoadDisplayFourChannel]]
MethodTable: 00007ff861df1798
EEClass:     00007ff8be0c5e78
Size:        64(0x40) 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
00007ff8be0e5dd8  40002f3        8        System.Object  0 instance 000002559b1cca30 _target
00007ff8be0e5dd8  40002f4       10        System.Object  0 instance 0000000000000000 _methodBase
00007ff8be1631f8  40002f5       18        System.IntPtr  1 instance 00007FF861DAD310 _methodPtr
00007ff8be1631f8  40002f6       20        System.IntPtr  1 instance 0000000000000000 _methodPtrAux
00007ff8be0e5dd8  4000300       28        System.Object  0 instance 0000000000000000 _invocationList
00007ff8be1631f8  4000301       30        System.IntPtr  1 instance 0000000000000000 _invocationCount
> dumpobj 000002559b1cca30
Name:        LoadDisplayFourChannel.ViewModels.Win.ViewClipImageViewModel
MethodTable: 00007ff861d3f7d8
EEClass:     00007ff861de2470
Size:        168(0xa8) bytes
File:        C:\Users\Administrator\Downloads\share\Release\LoadDisplayFourChannel.exe
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ff8bd4c5208  4000003        8 ...angedEventHandler  0 instance 000002559b1d20e8 PropertyChanged
...
00007ff8be0eb698  4000203       9d       System.Boolean  1 instance                1 _fullImageWindowOpened
...
00007ff8be0eb698  4000207       9e       System.Boolean  1 instance                1 _sliceWriteInFlight
00007ff861df0848  4000208       48 ...playFourChannel]]  0 instance 000002559b1ccad8 _pendingSlices
...

前面提到了DispatcherOperation是由Dispatcher接收到委托后创建出来的,所以第一步dump了02559c3e3570对象后可以去找对应的委托,而代表委托类型System.Delegate的字段就是_method。

dump了委托后,就可以去找委托内包裹的实际对象了,于是执行dumpobj 000002559c3e3518命令,发现被dump出来的类型名称带有Prism.Events.DispatcherEventSubscription,因为程序本身使用的是Prism框架,所以容易知道它是用于发布订阅事件的类型,再根据内部包裹的类型,可以推出和订阅了该Event(后称事件A)的方法有关联

再根据包裹的action查持有action包裹方法的对象,发现是ViewClipImageViewModel,也就是最开始提到的包含12个方形卡片的窗口B;从源码可知该VM有订阅事件A,而订阅时调用的方法大致是将收到的Slice_Image_data放到名称为_pendingSlices的队列内。

考虑到原有的代码逻辑里,订阅了事件A的两处方法中,另外一处仅会访问Slice_Image_data中的某个值类型属性,所以优先关注这个队列的情况,再对队列进行dump,结果如下

> dumpobj 000002559b1ccad8
Name:        System.Collections.Generic.Queue`1[[Slice_Image_data, LoadDisplayFourChannel]]
MethodTable: 00007ff861df0848
EEClass:     00007ff8bd522b28
Size:        48(0x30) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_MSIL\System\v4.0_4.0.0.0__b77a5c561934e089\System.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ff8be0fe250  4001ff1        8     System.__Canon[]  0 instance 000002559b9458a8 _array
00007ff8be0e85a0  4001ff2       18         System.Int32  1 instance               82 _head
00007ff8be0e85a0  4001ff3       1c         System.Int32  1 instance              807 _tail
00007ff8be0e85a0  4001ff4       20         System.Int32  1 instance              725 _size
00007ff8be0e85a0  4001ff5       24         System.Int32  1 instance             1504 _version
00007ff8be0e5dd8  4001ff6       10        System.Object  0 instance 0000000000000000 _syncRoot
00007ff8be0fe250  4001ffb        8     System.__Canon[]  0   static dynamic statics NYI <no information>

可以看到队列里持有了725个Slice_Image_data对象;第四节提到过,下午做过的性能测试里,内存占用只会在400-800M范围内变化,目前看来可能是熄屏之后出现了什么状况,让持续入队的队列无法被正常消费。

3.3 第二回合:无尽的等待

使用clrstack查看UI线程(因为我从加载dump文件开始没有主动切换过线程)转储时刻的堆栈,结果如下所示

> clrstack
OS Thread Id: 0x1774 (0)
        Child SP               IP Call Site
000000F2D93FD028 00007ff8e9689904 [HelperMethodFrame_1OBJ: 000000f2d93fd028] System.Threading.SynchronizationContext.WaitHelper(IntPtr[], Boolean, Int32)
000000F2D93FD370 00007FF8BC5D1ECA System.Windows.Threading.DispatcherSynchronizationContext.Wait(IntPtr[], Boolean, Int32)
000000F2D93FD708 00007ff8c0b16913 [GCFrame: 000000f2d93fd708]
000000F2D93FD918 00007ff8c0b16913 [HelperMethodFrame_1OBJ: 000000f2d93fd918] System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
000000F2D93FDA40 00007FF8BE689CCC System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean)
000000F2D93FDA70 00007FF8BEF1AF1B System.Threading.WaitHandle.WaitOne(System.TimeSpan, Boolean)
000000F2D93FDAB0 00007FF8BBD8367A System.Windows.Media.Imaging.WriteableBitmap.AcquireBackBuffer(System.TimeSpan, Boolean)
000000F2D93FDB00 00007FF8BBD8221E System.Windows.Media.Imaging.WriteableBitmap.TryLock(System.Windows.Duration)
000000F2D93FDB90 00007FF861F479DD LoadDisplayFourChannel.Share.WriteableBitmapHelper.LockForWrite(System.Windows.Media.Imaging.WriteableBitmap, Int32 ByRef)
000000F2D93FDBE0 00007FF861F5361F LoadDisplayFourChannel.ViewModels.Win.ViewFullImageViewModel.StartWriteFrame(LoadDisplayFourChannel.Event.BitmapInfo)
000000F2D93FDCD0 00007FF8BC5D3DED System.Windows.Threading.ExceptionWrapper.InternalRealCall(System.Delegate, System.Object, Int32)
000000F2D93FDD40 00007FF8BC5D3C56 System.Windows.Threading.ExceptionWrapper.TryCatchWhen(System.Object, System.Delegate, System.Object, Int32, System.Delegate)
000000F2D93FDD90 00007FF8BC5D673C System.Windows.Threading.DispatcherOperation.InvokeImpl()
000000F2D93FDE10 00007FF8BC5EA7FD MS.Internal.CulturePreservingExecutionContext.CallbackWrapper(System.Object)
000000F2D93FDE50 00007FF8BE64DF12 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000F2D93FDF20 00007FF8BE64DD95 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000F2D93FDF50 00007FF8BE64DD65 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
000000F2D93FDFA0 00007FF8BC5D6531 MS.Internal.CulturePreservingExecutionContext.Run(MS.Internal.CulturePreservingExecutionContext, System.Threading.ContextCallback, System.Object)
000000F2D93FE000 00007FF8BC5D6332 System.Windows.Threading.DispatcherOperation.Invoke()
000000F2D93FE060 00007FF8BC5D18CD System.Windows.Threading.Dispatcher.ProcessQueue()
000000F2D93FE0F0 00007FF8BC5D044F System.Windows.Threading.Dispatcher.WndProcHook(IntPtr, Int32, IntPtr, IntPtr, Boolean ByRef)
000000F2D93FE170 00007FF8BC5D3314 MS.Win32.HwndWrapper.WndProc(IntPtr, Int32, IntPtr, IntPtr, Boolean ByRef)
000000F2D93FE200 00007FF8BC5D3714 MS.Win32.HwndSubclass.DispatcherCallbackOperation(System.Object)
000000F2D93FE250 00007FF8BC5D3D58 System.Windows.Threading.ExceptionWrapper.InternalRealCall(System.Delegate, System.Object, Int32)
000000F2D93FE2C0 00007FF8BC5D3C56 System.Windows.Threading.ExceptionWrapper.TryCatchWhen(System.Object, System.Delegate, System.Object, Int32, System.Delegate)
000000F2D93FE310 00007FF8BC5D1262 System.Windows.Threading.Dispatcher.LegacyInvokeImpl(System.Windows.Threading.DispatcherPriority, System.TimeSpan, System.Delegate, System.Object, Int32)
000000F2D93FE3B0 00007FF8BC5D3082 MS.Win32.HwndSubclass.SubclassWndProc(IntPtr, Int32, IntPtr, IntPtr)
000000F2D93FE4B0 00007FF8BC793B82 DomainBoundILStubClass.IL_STUB_ReversePInvoke(Int64, Int32, Int64, Int64)
000000F2D93FE7E0 00007ff8c0b1222e [InlinedCallFrame: 000000f2d93fe7e0] MS.Win32.UnsafeNativeMethods.DispatchMessage(System.Windows.Interop.MSG ByRef)
000000F2D93FE7E0 00007ff8bc5f4479 [InlinedCallFrame: 000000f2d93fe7e0] MS.Win32.UnsafeNativeMethods.DispatchMessage(System.Windows.Interop.MSG ByRef)
000000F2D93FE7B0 00007FF8BC5F4479 DomainBoundILStubClass.IL_STUB_PInvoke(System.Windows.Interop.MSG ByRef)
000000F2D93FE870 00007FF8BC5CEDF5 System.Windows.Threading.Dispatcher.PushFrameImpl(System.Windows.Threading.DispatcherFrame)
000000F2D93FE910 00007FF8BA056421 System.Windows.Application.RunDispatcher(System.Object)
000000F2D93FE950 00007FF8BA055E5C System.Windows.Application.RunInternal(System.Windows.Window)
000000F2D93FE9B0 00007FF8615D08D2 LoadDisplayFourChannel.App.Main()
000000F2D93FEBC8 00007ff8c0b16913 [GCFrame: 000000f2d93febc8]

从堆栈顶部向下找包含程序命名空间的调用方法,发现定位到LoadDisplayFourChannel.Share.WriteableBitmapHelper.LockForWrite方法,这个方法用于锁定传入的WriteableBitmap,并返回传入对象的BackBuffer地址,具体代码如下

public static IntPtr LockForWrite(WriteableBitmap bitmap, out int stride)
{
    bitmap.Lock();
    stride = bitmap.BackBufferStride;
    return bitmap.BackBuffer;
}

从方法层向上一层发现是System.Windows.Media.Imaging.WriteableBitmap.TryLock(System.Windows.Duration)方法,那么在源码中反编译LockForWrite方法第一行,得到的代码如下

public void Lock() => this.TryLock(Duration.Forever);

也就是说,调用了WriteableBitmap.Lock方法,会给内部的TryLock方法传入一个永久的等待时间,那么再反编译一层下去,看传到WriteableBitmap.AcquireBackBuffer方法时,会给这个方法什么参数(省略AcquireBackBuffer后的语句。

public bool TryLock(Duration timeout)
{
  this.WritePreamble();
  if (timeout == Duration.Automatic)
    throw new ArgumentOutOfRangeException(nameof (timeout));
  TimeSpan timeout1 = !(timeout == Duration.Forever) ? timeout.TimeSpan : TimeSpan.FromMilliseconds(-1.0);
  if (this._lockCount == uint.MaxValue)
    throw new InvalidOperationException(MS.Internal.PresentationCore.SR.Get("Image_LockCountLimit"));
  if (this._lockCount == 0U)
  {
    if (!this.AcquireBackBuffer(timeout1, true))
      return false;
    ...
  }
  ++this._lockCount;
  return true;
}

从反编译出来的代码并结合堆栈汇总可知,当调用WriteableBitmap.Lock方法后,语句会一直等待直至完成锁定过程。具体在等什么,单从托管侧已经看不出来了。

虽然托管侧已经止步于此,但是可以分析出这个dump现场出现内存暴涨的过程及原因了。

  1. ZMQ持续接收外部的Slice_Image_data并通过发布订阅传递给订阅方
  2. 窗口B订阅了上述数据,执行入队操作,并在队列内将收到的数据通过操作渲染至WriteableBitmap内
  3. 渲染WriteableBitmap前需要执行WriteableBitmap.Lock操作以在改写内部BackBuffer的过程中不被渲染
  4. 执行Lock操作后,该方法因非托管堆原因陷入无限等待状态
  5. ZMQ仍在持续发布订阅,窗口B队列内会一直添加新到的数据;但由于第四点中提到的无限等待,会出现无法消费的问题,进而导致内存暴涨。

修复思路也显而易见了,将调用WriteableBitmap.Lock的部分调整为WriteableBitmap.TryLock并传入适合的等待时间即可在超时后快速完成对当前对象的消费,规避持续入队而没有消费的问题。

3.3 第三回合:等待的源头

虽然问题得以修复,但是问题的源头还不能说完全找到了,因此让我们请出WinDbg,从包含非托管堆栈的视角看一下这个堆栈发生了什么事。

首先打开老版本的WinDbg并加载Dump,由于我是这方面的新手,对一些操作(包括但不限于加载源、加载SOS)不是很熟悉,我就以最为原生的步骤去还原涉及到非托管堆的环境。

当然我的设备上因为以前的一些原因,歪打正着安装上了新版的WinDbg,里面会在加载Dump的时候尝试自动下载符号,比老版体验确实好很多,堆栈中甚至能看到托管堆里的完全限定方法名。

首先从3.3查看UI线程时已经知道了UI线程在1774,那么就先输入~~[1774]s;和 k 100两个命令查看线程调用点和线程的堆栈,结果如下所示

上述指令的含义为切换到ID为1774的线程与打印至多100层当前堆栈信息,具体拆解可以向搜索引擎或者AI了解。

0:000>  ~~[1774]s;
win32u!NtUserMsgWaitForMultipleObjectsEx+0x14:
00007ff8`e9689904 c3              ret
0:000> k 100
 # Child-SP          RetAddr           Call Site
00 000000f2`d93fcb68 00007ff8`ebd3ffbd win32u!NtUserMsgWaitForMultipleObjectsEx+0x14
01 000000f2`d93fcb70 00007ff8`ea3d1e0c user32!RealMsgWaitForMultipleObjectsEx+0x1d
02 000000f2`d93fcbb0 00007ff8`ea3d188e combase!CCliModalLoop::BlockFn+0x14c [onecore\com\combase\dcomrem\callctrl.cxx @ 2257] 
03 000000f2`d93fcc30 00007ff8`ea392df6 combase!ClassicSTAThreadWaitForHandles+0xce [onecore\com\combase\dcomrem\classicsta.cpp @ 51] 
04 000000f2`d93fcd60 00007ff8`c0c640ad combase!CoWaitForMultipleHandles+0x76 [onecore\com\combase\dcomrem\sync.cxx @ 124] 
05 000000f2`d93fcda0 00007ff8`c0c64110 clr!MsgWaitHelper+0x8e
06 000000f2`d93fce10 00007ff8`c0cd329d clr!Thread::DoAppropriateWaitWorker+0x2e6
07 000000f2`d93fcf10 00007ff8`c102ef11 clr!Thread::DoAppropriateWait+0x7d
08 000000f2`d93fcf90 00007ff8`bc5d1eca clr!SynchronizationContextNative::WaitHelper+0x181
09 000000f2`d93fd370 00007ff8`c0b16913 WindowsBase_ni+0x161eca
0a 000000f2`d93fd3b0 00007ff8`c0b16818 clr!CallDescrWorkerInternal+0x83
0b 000000f2`d93fd3f0 00007ff8`c0b170d8 clr!CallDescrWorkerWithHandler+0x4e
0c 000000f2`d93fd430 00007ff8`c0f75ca0 clr!MethodDescCallSite::CallTargetWorker+0x102
0d 000000f2`d93fd530 00007ff8`c0eaab21 clr!Thread::DoSyncContextWait+0xc0
0e 000000f2`d93fd690 00007ff8`c0cd329d clr!Thread::DoAppropriateWaitWorker+0x1d7861
0f 000000f2`d93fd790 00007ff8`c0cce911 clr!Thread::DoAppropriateWait+0x7d
10 000000f2`d93fd810 00007ff8`be689ccc clr!WaitHandleNative::CorWaitOneNative+0x161
11 000000f2`d93fda40 00007ff8`bef1af1b mscorlib_ni+0x5c9ccc
12 000000f2`d93fda70 00007ff8`bbd8367a mscorlib_ni+0xe5af1b
13 000000f2`d93fdab0 00007ff8`bbd8221e PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0xa8367a)
14 000000f2`d93fdb00 00007ff8`61f479dd PresentationCore_ni!`string' <PERF> (PresentationCore_ni+0xa8221e)
15 000000f2`d93fdb90 00007ff8`61f5361f 0x00007ff8`61f479dd
16 000000f2`d93fdbe0 00007ff8`bc5d3ded 0x00007ff8`61f5361f
17 000000f2`d93fdcd0 00007ff8`bc5d3c56 WindowsBase_ni+0x163ded
18 000000f2`d93fdd40 00007ff8`bc5d673c WindowsBase_ni+0x163c56
19 000000f2`d93fdd90 00007ff8`bc5ea7fd WindowsBase_ni+0x16673c
1a 000000f2`d93fde10 00007ff8`be64df12 WindowsBase_ni+0x17a7fd
1b 000000f2`d93fde50 00007ff8`be64dd95 mscorlib_ni+0x58df12
1c 000000f2`d93fdf20 00007ff8`be64dd65 mscorlib_ni+0x58dd95
1d 000000f2`d93fdf50 00007ff8`bc5d6531 mscorlib_ni+0x58dd65
1e 000000f2`d93fdfa0 00007ff8`bc5d6332 WindowsBase_ni+0x166531
1f 000000f2`d93fe000 00007ff8`bc5d18cd WindowsBase_ni+0x166332
20 000000f2`d93fe060 00007ff8`bc5d044f WindowsBase_ni+0x1618cd
21 000000f2`d93fe0f0 00007ff8`bc5d3314 WindowsBase_ni+0x16044f
22 000000f2`d93fe170 00007ff8`bc5d3714 WindowsBase_ni+0x163314
23 000000f2`d93fe200 00007ff8`bc5d3d58 WindowsBase_ni+0x163714
24 000000f2`d93fe250 00007ff8`bc5d3c56 WindowsBase_ni+0x163d58
25 000000f2`d93fe2c0 00007ff8`bc5d1262 WindowsBase_ni+0x163c56
26 000000f2`d93fe310 00007ff8`bc5d3082 WindowsBase_ni+0x161262
27 000000f2`d93fe3b0 00007ff8`bc793b82 WindowsBase_ni+0x163082
28 000000f2`d93fe4b0 00007ff8`c0b1222e WindowsBase_ni+0x323b82
29 000000f2`d93fe520 00007ff8`ebd37446 clr!UMThunkStub+0x6e
2a 000000f2`d93fe5b0 00007ff8`ebd36f62 user32!UserCallWinProcCheckWow+0x266
2b 000000f2`d93fe730 00007ff8`bc5f4479 user32!DispatchMessageWorker+0x1b2
2c 000000f2`d93fe7b0 00007ff8`bc5cedf5 WindowsBase_ni+0x184479
2d 000000f2`d93fe870 00007ff8`ba056421 WindowsBase_ni+0x15edf5
2e 000000f2`d93fe910 00007ff8`ba055e5c PresentationFramework_ni+0x486421
2f 000000f2`d93fe950 00007ff8`615d08d2 PresentationFramework_ni+0x485e5c
30 000000f2`d93fe9b0 00007ff8`c0b16913 0x00007ff8`615d08d2
31 000000f2`d93fe9e0 00007ff8`c0b16818 clr!CallDescrWorkerInternal+0x83
32 000000f2`d93fea20 00007ff8`c0b170d8 clr!CallDescrWorkerWithHandler+0x4e
33 000000f2`d93fea60 00007ff8`c0c51330 clr!MethodDescCallSite::CallTargetWorker+0x102
34 000000f2`d93feb60 00007ff8`c0c51bd7 clr!RunMain+0x25f
35 000000f2`d93fed40 00007ff8`c0c51a8b clr!Assembly::ExecuteMainMethod+0xb7
36 000000f2`d93ff030 00007ff8`c0c513d4 clr!SystemDomain::ExecuteMainMethod+0x643
37 000000f2`d93ff630 00007ff8`c0c5112d clr!ExecuteEXE+0x3f
38 000000f2`d93ff6a0 00007ff8`c0c52314 clr!_CorExeMainInternal+0xb2
39 000000f2`d93ff730 00007ff8`c15d8c01 clr!CorExeMain+0x14
3a 000000f2`d93ff770 00007ff8`d508a57c mscoreei!CorExeMain+0x112
3b 000000f2`d93ff7d0 00007ff8`ec627974 mscoree!CorExeMain_Exported+0x6c
3c 000000f2`d93ff800 00007ff8`ed12a271 kernel32!BaseThreadInitThunk+0x14
3d 000000f2`d93ff830 00000000`00000000 ntdll!RtlUserThreadStart+0x21

从上方可以看到,UI线程在转储时刻执行方法停留在了win32u!NtUserMsgWaitForMultipleObjectsEx方法上,对应的地址为00007ff8e9689904,而回到之前的托管堆栈内,堆栈顶部的方法System.Threading.SynchronizationContext.WaitHelper(IntPtr[], Boolean, Int32)的来源IP正好就是00007ff8e9689904

在微软官网中查询NtUserMsgWaitForMultipleObjectsEx方法作用描述如下

Waits until one or all of the specified objects are in the signaled state or the time-out interval elapses

等待直到一个或所有指定对象处于有信号状态,或者超时时间间隔结束。

由此可以推断,WriteableBitmap在调用Lock方法之后,上层也已经陷入了等待状态;至于要等待什么,可以尝试看看wpf渲染线程的现有状态。由于我们目前还不知道wpf渲染线程在哪里,就先使用!findstack wpfgfx获取线程信息,如下所示

0:004> !findstack wpfgfx
Thread 004, 13 frame(s) match
        * 02 00000255b724ff50 00007ff8b979d5d8 wpfgfx_v0400!CD3DDeviceLevel1::PresentWithD3D+0xd2
        * 03 000000f2dbbff9e0 00007ff8b979d50a wpfgfx_v0400!CD3DDeviceLevel1::Present+0x14a
        * 04 00000255b47e1f50 00007ff8b979d462 wpfgfx_v0400!CHwDisplayRenderTarget::PresentInternal+0x46
        * 05 00000255b47e1f50 00007ff8b979d38b wpfgfx_v0400!CHwDisplayRenderTarget::Present+0xd7
        * 06 0000000000000000 00007ff8b9770590 wpfgfx_v0400!CHwHWNDRenderTarget::Present+0xb
        * 07 0000000000000000 00007ff8b9770467 wpfgfx_v0400!CDesktopRenderTarget::Present+0xdc
        * 08 0000000000000002 00007ff8b975c4cc wpfgfx_v0400!CDesktopHWNDRenderTarget::Present+0x17
        * 09 0000000000000002 00007ff8b975c710 wpfgfx_v0400!CSlaveHWndRenderTarget::Present+0x4c
        * 10 0000000000000002 00007ff8b975c5c2 wpfgfx_v0400!CRenderTargetManager::Present+0xd6
        * 11 000000f2dbbffbb0 00007ff8b975c2d2 wpfgfx_v0400!CComposition::Present+0xe2
        * 12 0000000000000000 00007ff8b97586db wpfgfx_v0400!CPartitionThread::PresentPartition+0x2e
        * 13 0000000000000000 00007ff8b97557ab wpfgfx_v0400!CPartitionThread::Run+0x55
        * 14 0000000000000000 00007ff8ec627974 wpfgfx_v0400!CPartitionThread::ThreadMain+0x2b

由于我们只需要确定所在线程,关注“Thread 004”字样即可,注意这里的004不是线程ID,而是调试器序号;确定线程对应调试器序号后,使用~4s;k 100切换到线程并查看线程堆栈,如下所示:

0:000> ~4s;k 100
ntdll!NtDelayExecution+0x14:
00007ff8`ed15fde4 c3              ret
 # Child-SP          RetAddr               Call Site
00 000000f2`dbbff7b8 00007ff8`e93996f1     ntdll!NtDelayExecution+0x14
01 000000f2`dbbff7c0 00007ff8`b97cc236     KERNELBASE!SleepEx+0xa1
02 000000f2`dbbff860 00007ff8`b979d5d8     wpfgfx_v0400!CD3DDeviceLevel1::PresentWithD3D+0xd2
03 000000f2`dbbff8d0 00007ff8`b979d50a     wpfgfx_v0400!CD3DDeviceLevel1::Present+0x14a
04 000000f2`dbbff940 00007ff8`b979d462     wpfgfx_v0400!CHwDisplayRenderTarget::PresentInternal+0x46
05 000000f2`dbbff990 00007ff8`b979d38b     wpfgfx_v0400!CHwDisplayRenderTarget::Present+0xd7
06 000000f2`dbbffa20 00007ff8`b9770590     wpfgfx_v0400!CHwHWNDRenderTarget::Present+0xb
07 000000f2`dbbffa50 00007ff8`b9770467     wpfgfx_v0400!CDesktopRenderTarget::Present+0xdc
08 000000f2`dbbffad0 00007ff8`b975c4cc     wpfgfx_v0400!CDesktopHWNDRenderTarget::Present+0x17
09 000000f2`dbbffb00 00007ff8`b975c710     wpfgfx_v0400!CSlaveHWndRenderTarget::Present+0x4c
0a 000000f2`dbbffb30 00007ff8`b975c5c2     wpfgfx_v0400!CRenderTargetManager::Present+0xd6
0b 000000f2`dbbffb80 00007ff8`b975c2d2     wpfgfx_v0400!CComposition::Present+0xe2
0c 000000f2`dbbffbd0 00007ff8`b97586db     wpfgfx_v0400!CPartitionThread::PresentPartition+0x2e
0d 000000f2`dbbffc00 00007ff8`b97557ab     wpfgfx_v0400!CPartitionThread::Run+0x55
0e 000000f2`dbbffc30 00007ff8`ec627974     wpfgfx_v0400!CPartitionThread::ThreadMain+0x2b
0f 000000f2`dbbffc60 00007ff8`ed12a271     kernel32!BaseThreadInitThunk+0x14
10 000000f2`dbbffc90 00000000`00000000     ntdll!RtlUserThreadStart+0x21

可以看到WPF渲染所在线程的顶部也在执行底层函数NtDelayExecution,经过搜索了解到这个函数的作用也是使当前线程进入等待状态。从堆栈能推测出,WPF在尝试进行渲染时,在等待NtDelayExecution执行完毕并返回,不过由于黑屏的原因一直没有被返回。

至于为什么黑屏的时候WPF渲染会被阻塞,目前就不得而知了。

我在没有修复前,尝试过在自己开发的笔记本上复现这个问题,但是同样的操作路径却无法复现;考虑到目标设备是用DP线连接到显示器上的,也许会跟DP输出有一些关系。不过这只能算个人推断了。

写到这里的时候,我在好奇如果是正常的运行状态下,WPF渲染线程会在干什么,于是我重新模拟了测试场景,让三个窗口打开并接收数据显示图片,然后我使用procdump采集了dump,并在WinDbg中打开,查找WPF渲染线程所在位置和堆栈,堆栈结果如下。

0:005> k 100
 # Child-SP          RetAddr           Call Site
00 00000044`c6bfc870 00007ffc`f803ba28 nvd3dumx!QueryOglResource+0x329dbc
01 00000044`c6bfc8c0 00007ffc`f8032fd4 nvd3dumx+0xa7ba28
02 00000044`c6bfcf50 00007ffc`f80331b1 nvd3dumx+0xa72fd4
03 00000044`c6bfcff0 00007ffc`f80d4a1a nvd3dumx+0xa731b1
04 00000044`c6bfd050 00007ffc`fd69dda4 nvd3dumx+0xb14a1a
05 00000044`c6bfd5b0 00007ffc`fd782701 d3d9!CD3DDDIDX10::Blt+0x84
06 00000044`c6bfd660 00007ffc`fd76155e d3d9!CD3DDDIDX10::SurfaceBlt+0x61
07 00000044`c6bfd6e0 00007ffc`fd71c164 d3d9!CD3DBase::SurfaceBlt+0x72
08 00000044`c6bfd770 00007ffd`027b7dee d3d9!CBaseDevice::UpdateSurface+0x5d4
09 00000044`c6bfd8c0 00007ffd`027ab46d wpfgfx_v0400!CD3DDeviceLevel1::UpdateSurface+0x56
0a 00000044`c6bfd910 00007ffd`027abc88 wpfgfx_v0400!CHwBitmapColorSource::PushTheSourceBitsToVideoMemory+0x3cd
0b 00000044`c6bfda10 00007ffd`027ab9e9 wpfgfx_v0400!CHwBitmapColorSource::FillTextureWithTransformedSource+0x310
0c 00000044`c6bfdd10 00007ffd`027ab755 wpfgfx_v0400!CHwBitmapColorSource::FillTexture+0x30a
0d 00000044`c6bfdde0 00007ffd`027b4354 wpfgfx_v0400!CHwBitmapColorSource::Realize+0x11f
0e 00000044`c6bfde10 00007ffd`027b427a wpfgfx_v0400!CHwPipeline::RealizeColorSources+0xc2
0f 00000044`c6bfde50 00007ffd`027b41bd wpfgfx_v0400!CHwPipeline::RealizeColorSourcesAndSendState+0x1a
10 00000044`c6bfde80 00007ffd`027b6800 wpfgfx_v0400!CHwTVertexBuffer<CD3DVertexXYZDUV2>::Builder::FlushInternal+0x2d
11 00000044`c6bfdec0 00007ffd`027b6748 wpfgfx_v0400!CHwPipeline::Execute+0x11c
12 00000044`c6bfdef0 00007ffd`027b4959 wpfgfx_v0400!CHwShaderPipeline::Execute+0x14
13 00000044`c6bfdf20 00007ffd`027b487f wpfgfx_v0400!CHwSurfaceRenderTarget::ShaderAcceleratedFillPath+0xc8
14 00000044`c6bfe410 00007ffd`027b476f wpfgfx_v0400!CHwSurfaceRenderTarget::AcceleratedFillPath+0x37
15 00000044`c6bfe460 00007ffd`027b3f3d wpfgfx_v0400!CHwSurfaceRenderTarget::FillPathWithBrush+0x370
16 00000044`c6bfe8f0 00007ffd`027b3d67 wpfgfx_v0400!CHwSurfaceRenderTarget::FillPath+0x190
17 00000044`c6bfeb10 00007ffd`027b3bf7 wpfgfx_v0400!CHwSurfaceRenderTarget::DrawPathInternal+0x173
18 00000044`c6bfebf0 00007ffd`027b3b96 wpfgfx_v0400!CHwSurfaceRenderTarget::DrawPath+0x3b
19 00000044`c6bfec40 00007ffd`027865db wpfgfx_v0400!CHwDisplayRenderTarget::DrawPath+0x36
1a 00000044`c6bfec90 00007ffd`0279a7f6 wpfgfx_v0400!CMetaRenderTarget::DrawPath+0x12a
1b 00000044`c6bfee30 00007ffd`0279a626 wpfgfx_v0400!CDrawingContext::FillShapeWithBitmap+0x16e
1c 00000044`c6bfef30 00007ffd`0279a3fe wpfgfx_v0400!CDrawingContext::DrawBitmap+0x264
1d 00000044`c6bff0e0 00007ffd`0279a0d9 wpfgfx_v0400!CDrawingContext::DrawImage+0x11f
1e 00000044`c6bff1a0 00007ffd`02785719 wpfgfx_v0400!CMilSlaveRenderData::Draw+0x547
1f 00000044`c6bff2f0 00007ffd`02783e3e wpfgfx_v0400!CMilVisual::RenderContent+0x5c
20 00000044`c6bff320 00007ffd`02784e7e wpfgfx_v0400!CDrawingContext::PreSubgraph+0x7ce
21 00000044`c6bff440 00007ffd`02784da1 wpfgfx_v0400!CGraphIterator::Walk+0x5a
22 00000044`c6bff4a0 00007ffd`02784ba2 wpfgfx_v0400!CDrawingContext::DrawVisualTree+0x1d2
23 00000044`c6bff5a0 00007ffd`0277aa92 wpfgfx_v0400!CDrawingContext::Render+0x2cf
24 00000044`c6bff690 00007ffd`02773224 wpfgfx_v0400!CSlaveHWndRenderTarget::Render+0x24b
25 00000044`c6bff750 00007ffd`027731b0 wpfgfx_v0400!CRenderTargetManager::Render+0x5c
26 00000044`c6bff7a0 00007ffd`02773119 wpfgfx_v0400!CComposition::Render+0x28
27 00000044`c6bff7d0 00007ffd`02772ff8 wpfgfx_v0400!CComposition::ProcessComposition+0x182
28 00000044`c6bff860 00007ffd`02772f54 wpfgfx_v0400!CComposition::Compose+0x4e
29 00000044`c6bff8a0 00007ffd`02772f0d wpfgfx_v0400!CPartitionThread::RenderPartition+0x34
2a 00000044`c6bff8d0 00007ffd`027757ab wpfgfx_v0400!CPartitionThread::Run+0x64
2b 00000044`c6bff900 00007ffd`35c97974 wpfgfx_v0400!CPartitionThread::ThreadMain+0x2b
2c 00000044`c6bff930 00007ffd`378ba271 kernel32!BaseThreadInitThunk+0x14
2d 00000044`c6bff960 00000000`00000000 ntdll!RtlUserThreadStart+0x21

从WPF渲染线程的一些方法名称看,渲染进程在执行常规的界面渲染流程,并调用了DirectX的渲染方法。与上文熄屏时的等待对比差距巨大。

4.还有新的问题吗

4.1 起因

AI在分析完我上面提到的dump后,我应用了修复代码去做了二次测试。为了证明修复有效,我首先重新模拟了测试场景,然后执行了命令start "" cmd /c "timeout /t 210 /nobreak >nul && procdump64 -ma LoadDisplayFourChannel D:\dumps\"用于在熄屏后采集dump文件,在熄屏前资源管理器显示的程序进程占用为500M左右,熄屏后且采集出来的dump显示为890M;
AI对此作了分析,发现托管堆内存没有明显增长趋势,结合原生堆栈内的信息,认为是熄屏时WriteableBitmap尝试绘制但因熄屏导致所谓“为持续置脏的内容提供内存”,然后给出建议是使用user32.dll内的RegisterPowerSettingNotification函数,订阅并更新屏幕点亮状态,让涉及到图像渲染的部分在渲染前进行检测并确定是否需要渲染。
我乍看觉得有道理,然后根据AI的建议做了修复。

4.2 疑惑

后面在编写这篇文章的过程中,我会时不时查看原有的对话记录和归纳总结的文档,当看到第二个dump排查过程中的一段描述时,心里开始生起疑惑。
这段描述大概的含义是,dump采集时程序运行了3分钟38秒,且根据我现场熄屏前查看的内存为500M,因此推出内存增长速率约为110M每分钟。
单按照计算值来说其实没有多大问题,但我想起当时在等dump的时候,我一直在观察资源管理器里显示的应用进程内存,基本是在500M上下波动,到熄屏时的三分钟基本没有太大的变化,也就是说,是在熄屏后半分钟内存涨了400M。
根据我代码里的逻辑,渲染WriteableBitmap时会先调用WriteableBitmap.TryLock让WriteableBitmap处于锁定状态,再去执行后续的渲染流程;但在黑屏的情况下,TryLock方法超时后会返回false,就会执行锁定失败分支,结束这次渲染尝试。
再加之前面修复之后,锁定超时而渲染失败的对象也不会阻塞队列,而是快速消费完成让后续对象被消费。第二次采集的dump中针对托管堆的分析可以证明这一点。
也就是说AI针对第二个dump给出的推断结论有问题,但怎么证伪呢?

4.3 解谜

有一天测试的时候,我想起了这个问题,想着用procdump先拿个dump,看看正常渲染的时候堆栈占用情况,当时占用内存在400M左右。
执行指令后发现dump文件的大小翻倍不说,程序占用内存也显著提高了。这下提醒了我,之前内存的升高,会不会和采集方式有关系?
考虑到我目前只是为了确认在不应用AI针对第二个dump修复方案的前提下,在熄屏时内存是否还会继续暴涨,于是我在吃饭前使用了DotMemory启动应用进程并模拟测试场景,对软件内存占用情况进行记录。

我使用DotMemory的原因有二

  1. 它能采集非托管堆内存占用量且可以采集时查看趋势
  2. 我每年都会付费在JetBrains的全家桶许可证上,不用太可惜了(笑)

等到吃完饭回来,点亮屏幕,发现内存曲线非常平稳,遂问题与结论均被证伪。

5.后记

到这里总算已经把这次问题的排查过程梳理完了,因为是工作之余抽空做的,针对AI已有过程步骤和结论的合理性审查花了挺多功夫,而且在写上去的时候需要考虑是否经得起推敲,所以这篇文章写到这里已经差不多花了十多天。
本来是觉得AI能够通过dump分析出问题,而且问题原因是自己没见过的,因此想要分享一下;但考虑到读文章的是人,所以不能直接把AI生成的技术文档一股脑发出来。而且自己也想着借这个机会一窥究竟,了解.NET的dump分析思路,为以后可能会遇到的性能问题做知识储备。
手动复现的过程中,也逐渐熟悉了dotnet-dump和WinDbg工具的一些常见用法,到后面我甚至可以自行做一些额外的分析;而且为了了解问题中涉及到诸如DispatcherOperation的细节,还去专门了解了Dispatcher的运行机制;甚至意外地推翻了AI针对“第二个问题”的分析与结论。
不得不感慨,AI在dump分析的基础知识层面,已经能提供部分准确的知识和思路了;但是就和以前的搜索引擎一样,面对AI给出的结果,尤其是疑难杂症方面的结果,还是需要谨慎推断和定夺。
本文到此即将结束,如文章内有问题或者遗漏的地方,希望各位大佬不吝指导。

6.参考链接

在编写这篇文章的过程中,为了了解更多的的知识细节,参考了很多介绍知识内容的文章,在此列出主要阅读的链接以表感谢!
(排名不分先后)
周永恒_深入WPF -- Dispatcher(补)
广州大雄_dotnet-dump工具使用
吕毅_深入了解 WPF Dispatcher 的工作原理(Invoke/InvokeAsync 部分)
DotNet菜园_WPF入门教程系列四——Dispatcher介绍

posted on 2026-11-04 16:47  dellbeat  阅读(30)  评论(0)    收藏  举报