1、问题现象描述
收到线上反馈,打开我们的app后通常会白屏几秒后才显示页面,如下图所示
2、采集trace信息
通过Windows Performance Recorder工具收集了trace信息,有关该工具的获取和介绍:https://docs.microsoft.com/en-us/windows-hardware/test/wpt/windows-performance-recorder,生成的trace文件如下:
3、分析trace
分析trace即使用Windows Performance Analyzer工具,有关该工具的获取和介绍:https://docs.microsoft.com/en-us/windows-hardware/test/wpt/windows-performance-analyzer
3.1、首先查看各个进程生命周期是否正常
通过wpa的进程生命周期可以看到,软件主进程(10256)在启动2s后,渲染进程(5112)也正常启动,且之后没有出现进程挂掉的情况,其它进程的生命周期也正常。
3.2、再查看系统cpu是否正常
只有刚启动1s左右的时间轻微上涨,正常。
3.3、因为是白屏问题,重点查看render进程是否有主线程被阻塞的情况
重点看渲染进程(5112)的主线程切入到运行态的时间点
发现异常的时间点,上一次在第5秒切入之后在第10s才被再次切入,切入和切出时间间隔都很短,也就是说应该是在wait什么东西导致了5-10s之间的阻塞
加载符号后可以查看到第10s切入时主进程在做啥
加载符号完成后,看到的调用栈如下,一条来自gpu的消息导致了该线程的wait,这里有个问题是为什么要看第10s的栈而不是第5s的栈,因为这个栈记录的是线程被唤醒的瞬间(wait中)的栈。
再去看看gpu进程(10016)的主线程在第5-10秒这段时间在干啥,可以看到有多次切入时间差1s的情况,且切出时间和切入时间的差值(线程占用cpu的时间)是正常的,所以应该也不是再执行耗时任务而是再等什么东西。
查看第1、2、3处的被唤醒时的函数调用栈,都是因为条件等待导致的wait,这里是在等某个线程处理完事情将它唤醒。
我们再看看它是被谁唤醒的,可以看到是14572号线程、2576号线程、9436号线程
再看看这三个线程这几个时间戳前后在做啥
首先看14572线程在第4s-第5s的有无异常间隔的切入时间点的栈,发现有,展开调用栈看到第三方函数库(MozartBreathCore)注入,并且最终是在第三方的dll中调进了wait
同样的,看2576线程在5-6、6-7、7-8、8-9左右的异常的switch in时间戳和switch out的时间戳,可以发现切出与切入时间差(占用cpu的时间)不高,但是上一次切入和这次切入出现多次间隔1s的情况,也是在wait什么东西。
展开这几次函数的调用栈,看到了基本上都有第三方函数库注入,并且最终是在第三方的dll(MozartBreathCore)中调进了wait。
通过在image模块看到了我们的app被注入的dll文件所在路径
上网搜索路径中的LVUAAgentInstBaseRoot这个文件夹即可知道Mozartxxxx库和第三方软件UniAccess:https://www.leagsoft.com/doc/article/1027.html相关
网上搜cwnep.sys,得到和软件Websense Data Endpoint有关:http://systemexplorer.net/file-database/file/cwnep-sys(本来以为这个文件也属于UniAccess,但是卸载掉UniAccess还是白屏)
UniAccess和Websense Data Endpoint都卸载后,恢复正常。