Figure

2月21日跑mtbf 16小时，出现卡在屏保的情况。可以下划打开状态栏，通知中心，但是没办法通过点击或者长按进入设置。tlog已经发给研发。

【】当前状态

根据测试提供的日志和现象截图，确认了问题

【】分析情况

1、测试反馈的现象是发生问题时，屏幕无响应。我怀疑可能存在ANR，查看了日志，并未找到有关的ANR信息，所以问题应该不是由ANR引起。

2、我怀疑是进程发生了奔溃，分析了tombstone文件，从tombstone中发现了类似这样的日志信息：
Build fingerprint: 'TC/figure_CN/figure:12/SKQ1.220201.001/2134:user/test-keys'
Revision: '0'
ABI: 'arm64'
Timestamp: 2023-02-21 07:52:11.627199597+0800
Process uptime: 0s
Cmdline: /system/bin/audioserver
pid: 898, tid: 1627, name: TimeCheckThread >>> /system/bin/audioserver <<<
uid: 1041
signal 6 (SIGABRT), code 1 (SI_QUEUE), fault addr -------
Abort message: 'TimeCheck timeout for IAudioFlinger command 38'
x0 0000000000000000 x1 000000000000065b x2 0000000000000006 x3 0000006e1e3d0530
x4 6d686b456e686374 x5 6d686b456e686374 x6 6d686b456e686374 x7 7f7f7f7f7f7f7f7f
x8 00000000000000f0 x9 117ed7971eb9a4ed x10 0000000000000000 x11 ffffff80ffffffdf
x12 0000000000000001 x13 000000000000002f x14 0000006e1e3d06c0 x15 0000000034155555
x16 0000007142246060 x17 0000007142222560 x18 0000006e1e1d0000 x19 0000000000000382
x20 000000000000065b x21 00000000ffffffff x22 b400006e5fbea010 x23 b400006e3fbe3c54
x24 b400006e3fbe3c54 x25 0000006e1e3d0cb0 x26 0000006e1e3d0ff8 x27 00000000000fc000
x28 0000006e1e2d8000 x29 0000006e1e3d05b0
lr 00000071421d295c sp 0000006e1e3d0510 pc 00000071421d2988 pst 0000000000001000

进行了堆栈分析，发现出现问题的代码位置是：
http://192.168.87.66:8006/source/xref/Pre_figure_turbox-c2130c-la1.1-qssi12-dev/LA.QSSI/LINUX/android/bionic/libc/bionic/abort.cpp#50
但是从代码来看与业务逻辑没有太大关系，从这个角度也没有发现有效的问题点。

3、从具体的日志文件出发寻找可疑的日志，发现有如下的日志

02-21 08:04:40.375 1521 1632 E SurfaceComposerClient: SurfaceComposerClient::createSurface error Out of memory
02-21 08:04:40.375 1521 1632 E WindowManager: Unhandled exception while laying out windows
02-21 08:04:40.375 1521 1632 E WindowManager: android.view.Surface$OutOfResourcesException
02-21 08:04:40.375 1521 1632 E WindowManager: at android.view.SurfaceControl.nativeCreate(Native Method)
02-21 08:04:40.375 1521 1632 E WindowManager: at android.view.SurfaceControl.<init>(SurfaceControl.java:1435)
02-21 08:04:40.375 1521 1632 E WindowManager: at android.view.SurfaceControl.<init>(SurfaceControl.java:87)
02-21 08:04:40.375 1521 1632 E WindowManager: at android.view.SurfaceControl$Builder.build(SurfaceControl.java:1108)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.SurfaceAnimator.createAnimationLeash(SurfaceAnimator.java:424)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.SurfaceAnimator.startAnimation(SurfaceAnimator.java:173)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.WindowContainer.startAnimation(WindowContainer.java:2526)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.WindowContainer.applyAnimationUnchecked(WindowContainer.java:2757)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.Task.applyAnimationUnchecked(Task.java:4062)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.WindowContainer.applyAnimation(WindowContainer.java:2628)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.AppTransitionController.applyAnimations(AppTransitionController.java:591)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.AppTransitionController.applyAnimations(AppTransitionController.java:723)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.AppTransitionController.handleAppTransitionReady(AppTransitionController.java:224)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.RootWindowContainer.checkAppTransitionReady(RootWindowContainer.java:1030)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.RootWindowContainer.performSurfacePlacementNoTrace(RootWindowContainer.java:869)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.RootWindowContainer.performSurfacePlacement(RootWindowContainer.java:805)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacementLoop(WindowSurfacePlacer.java:177)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacement(WindowSurfacePlacer.java:126)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.WindowSurfacePlacer.performSurfacePlacement(WindowSurfacePlacer.java:115)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.DisplayContent.layoutAndAssignWindowLayersIfNeeded(DisplayContent.java:3585)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.wm.WindowManagerService$H.handleMessage(WindowManagerService.java:5335)
02-21 08:04:40.375 1521 1632 E WindowManager: at android.os.Handler.dispatchMessage(Handler.java:106)
02-21 08:04:40.375 1521 1632 E WindowManager: at android.os.Looper.loopOnce(Looper.java:201)
02-21 08:04:40.375 1521 1632 E WindowManager: at android.os.Looper.loop(Looper.java:288)
02-21 08:04:40.375 1521 1632 E WindowManager: at android.os.HandlerThread.run(HandlerThread.java:67)
02-21 08:04:40.375 1521 1632 E WindowManager: at com.android.server.ServiceThread.run(ServiceThread.java:44)

从日志的信息来看是有surfaceflinger相关的日志错误，计划从这个角度进行一下追踪。

【】计划策略
1、目前在跟进monkey相关的bug，该问题暂时未继续跟进。

2、计划从surfaceflinger的错误日志进行一下追踪，看是否能找到一些突破点。

【】当前状态
从SurfaceComposerClient: SurfaceComposerClient::createSurface error Out of memory展开逻辑分析
触发日志点：

status_t SurfaceComposerClient::createSurfaceChecked(){
   err = mClient->createSurface(name, w, h, format, flags, parentHandle, std::move(metadata),
   &handle, &gbp, &id, &transformHint);
   if (outTransformHint) {
     *outTransformHint = transformHint;
   }
   ALOGE_IF(err, "SurfaceComposerClient::createSurface error %s", strerror(-err));
 }

status_t SurfaceFlinger::addClientLayer(){
  if (mNumLayers >= ISurfaceComposer::MAX_LAYERS) {
    ALOGE("AddClientLayer failed, mNumLayers (zu) >= MAX_LAYERS (%zu)", mNumLayers.load(),
               ISurfaceComposer::MAX_LAYERS);
        mCurrentState.traverseInZOrder([x%x](Layer* layer) {
               const auto& p = layer->getParent();
               ALOGE("layer (%s) ::  parent (%s).",
               layer->getName().c_str(),
               (p != nullptr) ? p->getName().c_str() : "no-parent");
        });
        return NO_MEMORY;
    }
 }

mNumLayers值的异常引发问题，而该值的调整逻辑与下面的方法有关系：
void SurfaceFlinger::onLayerFirstRef(Layer* layer) {}
void SurfaceFlinger::onLayerDestroyed(Layer* layer) {}

发生问题时：
通过脚本配合日志分析发现，在启动应用或者切换窗口时，添加的layer数与移除的layer数
并不是成正相关，随着脚本测试时间的持续，已经存在的layer数会越来越大最后超出阈值，报出异常信息。

【】后续策略
在正常启动应用和切花应用时，layer的数不会持续无限的增加，所以怀疑该问题的发生与测试所执行
测试脚本有强相关性，后续计划从系统逻辑层面结合测试的脚本细节展开，分析每一个测试点在逻辑层面的具体表现，
看能否定位出是什么具体的测试行为会触发问题或者引起问题的发生。

【】当前状态
根据之前的怀疑点：layer的慢慢增加最后超出了限制，与测试脚本的逻辑有强关系
一、我分析了测试的脚本源码：
1）我发现存在类似：time.sleep(1)、self.device.implicitly_wait(3)
从代码来看，应该是脚本在等在上一次事件或者操作的响应和执行，但是这个事件从设备的
层面也许时间可能并不能如预期，有时候逻辑层面的等待，并不是系统正常执行消耗的具体时间，所以在主动等待后
执行后续的逻辑也许并不能达到预期的效果。
疑问点：这个时间是否能达到预期，特别是长时间测试时？
2）是否完成了模块的单元测试
比如：小窗测试、游戏测试、音乐播放、视屏播放，是否可以做一个单元测试，单独的把每一个模块单独的跑一下脚本？

二、为了追踪问题，我在能反馈出layer数量变化的地方添加了日志信息，来监layer数量的变化
void SurfaceFlinger::onLayerFirstRef(Layer* layer) {}
void SurfaceFlinger::onLayerDestroyed(Layer* layer) {}
分析日志提交：
https://dev.thundercomm.com/gerrit/c/general/platform/frameworks/base/+/187456
https://dev.thundercomm.com/gerrit/c/general/platform/frameworks/native/+/187455
编译的Jenki版本：
//userdebug 版本
/Pre_figure/VerifyBuild/Pre_figure_turbox-c2130c-la1.1-qssi12-dev/20230314/202303141719-2928
//user版本
/Pre_figure/VerifyBuild/Pre_figure_turbox-c2130c-la1.1-qssi12-dev/20230314/202303141750-2929

请测试同事使用Jenkins的userdebug版本，帮忙做如下针对性测试：
1）不跑脚本，用手动的方式，执行脚本中的测试流程，测试轮数最好在10轮以上，记录日志；
2）将测试脚本进行拆分，最好能做单元的测试，如果不能完全的单元，可以把几个功能单独放在一起分别进行测试，
几个重要的模块：小窗相关的测试、音视频相关的测试、游戏网络相关的测试，记录日志；
3）直接用脚本跑测试，记录日志；
（Tisp：1、跑脚本测试时，执行时间不用很长，可以控制在30分钟到60分钟；2、记录下做每项测试的开始时间和结束时间）

已根据要求做针对性测试，log已发送

【】当前状态

小窗相关测试引起layer异常增加的调查

1）对比测试分析
a、不考虑高合特殊定制逻辑的情况下，针对纯粹的小窗功能做测试，layer同样异常增加；
b、使用同样搭载原生代码的其他设备进行相同的测试，问题表现一样，layer异常增加;
c、使用12版本的pixel进行同样的测试，未出现layer异常增加的表现
初步结论：在原生代码中开启小窗，依附原生的代码实现时，针对小窗的测试，都会存在layer异常增加；
而pixel虽然都是12的代码，但是pixel应该是进行了优化，所以未出现问题。

2）后续策略

a、先解决小窗基本功能不出现layer的异常增加，再检查包含高合定制功能是否会有layer异常增加；

b、解决小窗基本功能中出现的layer异常增加的两个方向：上层是否合理构建了正确的layer、底层是否正常的销毁了应该被销毁的layer

当前进度情况如下：
进行了首轮删除小窗模块后的mtbf跑测，正常运行的时间相对延长，三台设备，两台设备运行了39小时（仍正常运行），一台设备运行了42小时。
运行时间较长的设备（42小时）出现了黑屏卡住的情况，经分析是由于系统异常报错，造成layer过多。

目前mtbf出现的问题黑屏卡住等情况是layer过多造成的，经讨论，产生此情况的原因以及相对应的处理如下：
1、系统长时间进行mtbf测试时，响应时间会变长，此时脚本下发点击动作，会造成异常报错，从而产生过多layer。该报错没有固定出现的时间和地点，故需要考虑是否在脚本添加点击之前的判断或者延长的等待时间
2、小窗本身的逻辑问题，造成layer过多的情况。脚本将暂时去除掉小窗部分进行跑测，等待研发进行修改后再加入。

三台设备中，另外两台设备跑测到现在共44小时，未出现明显问题。

【】当前状态
唐军的调查进度：
1, 从问题单的log看, 看起来是Task没有销毁, 可能是system没有丢弃对BBinder的引用.
2, 从自测20次看, Offscreen Layers存在很多重复的Task Surface没有销毁. 看起来这是当前问题的另一种表现形式, Task的销毁没有完成.

下一步:
1, 确认"可能是system没有丢弃对BBinder的引用"和Task销毁逻辑.
2, 请测试帮忙在快要出现问题时, 抓取adb shell dumpsys activity activities > ams, adb shell dumpsys window windows > wms和adb shell dumpsys SurfaceFlinger > sf;

【】当前状态

唐军的调查进展：

1, 多次自测(20次),未释放的layer与Offscreen Layers基本一致.
主要是下面两种Layer未释放. Task数量基本是WallpaperWindowToken的两倍.
Surface(name=Task=19)/@0x3d1aa49 - animation-leash of recents_animation#0
Surface(name=WallpaperWindowToken{55f4d5e token=android.os.Binder@4047699})/@0x947c7ea - animation-leash of window_animation#0

2, 脚本跑15个小时左右时, Visible layers (count = 2603). 与自测20次的规律一致.

3, Google在12L上有发现max layer count问题,并且可能T也有,为了定位问题, 在T上有加入更多该问题的dump信息.
commit 26b98f4271095999a721fd85f17044eb8441cc97
Author: Robert Carr <racarr@google.com>
Date: Mon Apr 11 15:54:31 2022 -0700

SurfaceFlinger: Dump on layer leaks

Every so often some process will leak layer references and
    SurfaceFlinger will eventually crash (or refusing to create
    new layers because of the max layer count). We never have
    enough info to trace these down, and it becomes a horrible
    game of chasing repro steps. While we currently have no
    complaints about anything like this in T, a recent
    12L bug serves as a timely reminder that we should get
    this logging in BEFORE the next issue occurs, rather
    than after.

Bug: 227286456
    Test: Existing tests pass
    Change-Id: I2c8b834c93a27204225b482fea1e54837204c9cf

4, "animation-leash of recents_animation"与其它"animation-leash"的reset有差异.
5, 打入Android T的Leash相关patch验证无效.

下一步: 继续上面第4点以及其它尝试.

【】当前状态

唐军的调查进展：

1, 对比了T和S的surfaceflinger相关逻辑, 有6个patch待验证. 要么surfaceflinger崩溃, 要么验证没效果.
2, 在OnAnimationFinishedCallback中reset(false)时, Offscreen Layer不再增加, 但是mNumLayers仍然没减少,即Layer未释放.
Task的leash先挂到DefaultTaskDisplayArea, 接着Task从DefaultTaskDisplayArea之下移动到leash之下.
在RecentsAnimation.finishAnimation时,Task从leash之下移动到DefaultTaskDisplayArea之下.

注:在OnAnimationFinishedCallback中reset(true)时, Offscreen Layer会增加两种Layer.
Task的leash先挂到DefaultTaskDisplayArea, 接着Task从DefaultTaskDisplayArea之下移动到leash之下.
在RecentsAnimation.finishAnimation时,Task从leash之下移动到DefaultTaskDisplayArea之下.leash从DefaultTaskDisplayArea之下移除.

3, 如果对下面两种Layer不做动画, 可以规避问题. 但是效果不清楚.
Surface(name=Task=19)/@0x3d1aa49 - animation-leash of recents_animation#0
Surface(name=WallpaperWindowToken{55f4d5e token=android.os.Binder@4047699})/@0x947c7ea - animation-leash of window_animation#0

4, wms逻辑看着是正常的, 因为有销毁动作. 而该问题根源是Layer没有被销毁. 强制对Offscreen Layer的特定Layer销毁mNumLayers会减少.
看起来是系统进程一直持有Handle引用未释放导致了问题的发生.

下一步:
研究正常的leash销毁流程来找到规避方法或者找到差异点.

【】当前状态

唐军的调查进展：

1, 追踪surfaceflinger中的Layer存储和销毁流程.
Task Layer在重新挂载到DefaultDisplay时在leash中remove失败.
Layer有5种销毁流程. 与我们相关的销毁有两种, 我们的销毁缺少对BBinder的解引用.
正在确认正常销毁的相似的Layer流程, 然后根据wms信息或者Offscreen Layers信息给出规避方法.

【】当前状态

唐军的调查进展：

看起来是binder调用出了问题, surfaceflinger的Layer销毁流程看起来正确。
正在做规避patch。

Hi 诗雨
已优化patch内容，并重新编译了版本，请使用新版本验证，谢谢
/Pre_figure/VerifyBuild/Pre_figure_turbox-c2130c-la1.1-qssi12-dev/20230418/202304181109-3312

VB验证情况：
一台设备跑测一晚上15小时
出现一次黑屏，出现多次重启。

昨晚跑测DB版本带小窗，今晚用VB进行跑测

验证情况：
一台设备跑测了14小时
看截图出现了数次黑屏的情况，出现在由小窗切换成mini小窗的时候，未出现重启的情况。
日志比较大，已经私发

■ 当前的状态

看截图出现了数次黑屏的情况，出现在由小窗切换成mini小窗的时候，未出现重启的情况。

已定位问题原因，正在优化patch内容，预计今晚会再编译一个版本，应该是最终版本了

■ 下一步计划
版本编译完成后，跑MTBF验证

验证情况：
跑测14小时，出现一次重启，未出现黑屏卡住的情况，再跑测24小时查看情况

刷4.26DB进行新一轮的MTBF跑测中