Bug #115368

测试 Test-ST #113421: V4.0功能与专项测试

【BSP】【EVT2】【ST】【Boot】【偶现1次】断电重启开机过程中出现一次开机动画卡死

Added by 移动测试一组_CDTS 刘强 over 2 years ago. Updated about 2 years ago.

Status:CLOSEDStart date:2023-01-16
Priority:HighDue date:
Assignee:CDTS_TEST 王成% Done:

0%

Category:SYSTEM
Target version:-
Need_Info:TEST Found Version:01.00.X101_20230110
Resolution:FIXED Degrated:--
Severity:Major Verified Version:
Reproducibility:Occasionally Fixed Version:
Test Type:ST Root cause:无法复现，缺少日志

Description

【前提条件】
None

【测试步骤】
1. 设备正常开机
2. 进行断电重启测试
3. 查看设备情况

【预期结果】
3 设备正常工作

【实际结果】
3 偶现一次开机动画卡死，重启后恢复

开机动画卡死_01.00.X101_20230110.zip (5.65 MB) 移动测试一组_CDTS 刘强, 2023-01-16 19:15

中科创达软件股份有限公司20230116-165332.jpg (142 KB) 移动测试一组_CDTS 刘强, 2023-01-16 19:15

%e4%b8%ad%e7%a7%91%e5%88%9b%e8%be%be%e8%bd%af%e4%bb%b6%e8%82%a1%e4%bb%bd%e6%9c%89%e9%99%90%e5%85%ac%e5%8f%b820230116-165332

History

#1 Updated by CD BSP-杜磊 over 2 years ago

  • Status changed from New to ASSIGNED
  • Assignee changed from CD BSP-唐金泽 to CD BSP-杜磊

#2 Updated by CD SYSTEM-胡兵 over 2 years ago

  • Assignee changed from CD BSP-杜磊 to CD FW 曹覃刚

Hi 覃刚

分析下 systemui anr的问题呢
01-10 11:38:21.168 1482 1570 W ActivityManager: Timeout executing service: ServiceRecord{31deca6 u0 com.android.systemui/.dump.SystemUIAuxiliaryDumpService}
01-10 11:38:21.168 1482 2697 I am_anr : [0,2013,com.android.systemui,818462221,executing service com.android.systemui/.dump.SystemUIAuxiliaryDumpService]
01-10 11:38:21.170 1482 2697 I android_os_HwBinder: HwBinder: Starting thread pool for getting: ::IServiceManager/default
01-10 11:38:21.176 1482 2697 I ActivityManager: dumpStackTraces pids={1996=true, 2365=true, 2372=true, 2487=true, 2503=true, 2544=true} nativepids=[515, 905, 1161, 1996, 1230, 852, 661, 662, 919, 1176, 1181, 1185, 1315, 804, 1188, 875, 1196, 815, 818, 819, 563, 820, 564, 822, 824]
01-10 11:38:21.470 1482 2697 I ActivityManager: Skipping next CPU consuming process, not a java proc: 1540
01-10 11:38:21.470 1482 2697 I ActivityManager: Skipping next CPU consuming process, not a java proc: 1482
01-10 11:38:21.470 1482 2697 I ActivityManager: Skipping next CPU consuming process, not a java proc: 351
01-10 11:38:21.471 1482 2697 I ActivityManager: Dumping to /data/anr/anr_2023-01-10-11-38-21-470
01-10 11:38:21.471 1482 2697 I ActivityManager: Collecting stacks for pid 2013

01-10 11:39:34.951 1482 1561 E Watchdog: First set of traces taken from /data/anr/anr_2023-01-10-11-38-58-088
01-10 11:39:34.978 1482 1561 E Watchdog: Second set of traces taken from /data/anr/anr_2023-01-10-11-39-29-136
01-10 11:39:35.006 1482 3040 I DropBoxManagerService: add tag=system_server_watchdog isTagEnabled=true flags=0x6
01-10 11:39:35.009 1482 1561 W Watchdog: *** WATCHDOG KILLING SYSTEM PROCESS: Blocked in monitor com.android.server.am.ActivityManagerService on foreground thread (android.fg), Blocked in handler on ui thread (android.ui), Blocked in handler on display thread (android.display)
01-10 11:39:35.010 1482 1561 W Watchdog: android.fg annotated stack trace:

Thanks.

#3 Updated by CD FW 曹覃刚 over 2 years ago

  • Category changed from BSP to CD-FW

#4 Updated by CD FW 曹覃刚 over 2 years ago

  • Category changed from CD-FW to SYSTEM
  • Assignee changed from CD FW 曹覃刚 to CD SYSTEM-胡兵

Hi 胡兵

针对ANR本身的分析结果如下
----------------
01-10 11:38:22.563 1482 2697 I ActivityManager: Done dumping
01-10 11:38:22.564 1482 2697 E ActivityManager: ANR in com.android.systemui
01-10 11:38:22.564 1482 2697 E ActivityManager: PID: 2013
01-10 11:38:22.564 1482 2697 E ActivityManager: Reason: executing service com.android.systemui/.dump.SystemUIAuxiliaryDumpService
01-10 11:38:22.564 1482 2697 E ActivityManager: Frozen: false
01-10 11:38:22.564 1482 2697 E ActivityManager: Load: 2.61 / 0.66 / 0.22
01-10 11:38:22.564 1482 2697 E ActivityManager: ----- Output from /proc/pressure/memory -----
01-10 11:38:22.564 1482 2697 E ActivityManager: some avg10=0.00 avg60=0.00 avg300=0.00 total=0
01-10 11:38:22.564 1482 2697 E ActivityManager: full avg10=0.00 avg60=0.00 avg300=0.00 total=0
01-10 11:38:22.564 1482 2697 E ActivityManager: ----- End output from /proc/pressure/memory -----
01-10 11:38:22.564 1482 2697 E ActivityManager:
01-10 11:38:22.564 1482 2697 E ActivityManager: CPU usage from 9140ms to 636ms ago (2023-01-10 11:38:12.028 to 2023-01-10 11:38:20.532):
01-10 11:38:22.564 1482 2697 E ActivityManager: 16% 1540/irq/395-atmel_m: 0% user + 16% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 2.5% 351/kworker/0:3+events: 0% user + 2.5% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.4% 1174/cnss_diag: 0.2% user + 0.2% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.2% 1482/system_server: 0.1% user + 0.1% kernel / faults: 37 minor
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.1% 9/ksoftirqd/0: 0% user + 0.1% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0% 29/ksoftirqd/2: 0% user + 0% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0% 78/kworker/5:1-sock_diag_events: 0% user + 0% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.1% 336/kworker/u16:11-kverityd: 0% user + 0.1% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0% 345/kworker/0:2-pm: 0% user + 0% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.1% 467/kworker/u16:15-kverityd: 0% user + 0.1% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.1% 500/logd: 0% user + 0.1% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.1% 680/kworker/u17:12-pil_workqueue: 0% user + 0.1% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.1% 683/kworker/u17:15-kgsl-events: 0% user + 0.1% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.1% 829/: 0.1% user + 0% kernel / faults: 195 minor
01-10 11:38:22.564 1482 2697 E ActivityManager: 0% 1189/selfinstaller: 0% user + 0% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 0.1% 2072/com.android.networkstack.process: 0.1% user + 0% kernel / faults: 132 minor
01-10 11:38:22.564 1482 2697 E ActivityManager: 0% 2294/com.android.se: 0% user + 0% kernel / faults: 14 minor
01-10 11:38:22.564 1482 2697 E ActivityManager: 3.4% TOTAL: 0% user + 1.9% kernel + 1.3% irq + 0% softirq
01-10 11:38:22.564 1482 2697 E ActivityManager: CPU usage from 8ms to 293ms later (2023-01-10 11:38:21.176 to 2023-01-10 11:38:21.461):
01-10 11:38:22.564 1482 2697 E ActivityManager: 13% 1540/irq/395-atmel_m: 0% user + 13% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 8.9% 1482/system_server: 0% user + 8.9% kernel / faults: 132 minor
01-10 11:38:22.564 1482 2697 E ActivityManager: 8.9% 2697/AnrConsumer: 4.4% user + 4.4% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 3.8% 351/kworker/0:3+events: 0% user + 3.8% kernel
01-10 11:38:22.564 1482 2697 E ActivityManager: 8.3% TOTAL: 1.3% user + 5.7% kernel + 1.3% irq
01-10 11:38:22.565 1482 2697 D ActivityManager: Completed ANR of com.android.systemui in 1397ms, latency 0ms
-->ANR发生时间段，cpu占用良好

public class SystemUIAuxiliaryDumpService extends Service {
private final DumpHandler mDumpHandler;

@Inject
    public SystemUIAuxiliaryDumpService(DumpHandler dumpHandler) {
        mDumpHandler = dumpHandler;
    }
@Override
    public IBinder onBind(Intent intent) {
        return null;
    }
@Override
    protected void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
        // Simulate the NORMAL priority arg being passed to us
        mDumpHandler.dump(
                fd,
                pw,
                new String[] { DumpHandler.PRIORITY_ARG, DumpHandler.PRIORITY_ARG_NORMAL });
    }
}

-->SystemUIAuxiliaryDumpService服务本身，仅为dump信息服务，无额外操作
----------------
①ANR发生时间段，CPU占用率良好
②SystemUIAuxiliaryDumpService服务本身，仅为dump信息服务，无额外操作，本身设计不存在问题，不存在优化空间

结合上述观点
SystemUIAuxiliaryDumpService做dump操作时涉及到IO操作，怀疑此时IO阻塞，导致dump操作被block引起ANR
请帮助检查产生ANR(01-10 11:38:00 -> 01-10 11:38:21)时间段内的系统IO状态，非常感谢

#5 Updated by CD FW 曹覃刚 over 2 years ago

  • Status changed from ASSIGNED to NEED_INFO
  • Assignee changed from CD SYSTEM-胡兵 to 移动测试一组_CDTS 刘强
  • Need_Info changed from -- to TEST
  • Root cause set to 无法复现，缺少日志

Hi 强哥
如飞书沟通
当前研发无法复现此问题，且提供的日志，无有效发现
请帮助跟踪此问题，如再次复现，请帮忙关注复现条件，以及提供新的日志
非常感谢

#6 Updated by 移动测试一组_CDTS 刘强 over 2 years ago

验证版本：FlatBuild_HH_VX1_MCE_FSE.M.D.userdebug.01.00.X101.202302060240
验证结果：未复现，继续跟踪

#7 Updated by SZTS_TEST 邹涛 over 2 years ago

FlatBuild_HH_VX1_MCE_FSE.M.R.user.01.00.0077.X101

验证80次未复现

#8 Updated by SZTS_TEST 邹涛 over 2 years ago

FlatBuild_HH_MCE_FSE.M.R.user.01.00.0078.C101.zip

验证32次未复现

#9 Updated by CDTS_TEST 王成 over 2 years ago

  • Priority changed from Normal to High
  • Severity changed from Normal to Major

#10 Updated by 移动测试一组_CDTS 刘强 over 2 years ago

  • Status changed from NEED_INFO to RESOLVED

压测超过200次未复现，暂时关闭，等新的开机动画合入后，重新验证测试

#11 Updated by 移动测试一组_CDTS 刘强 over 2 years ago

  • Status changed from RESOLVED to VERIFIED

#12 Updated by 移动测试一组_CDTS 刘强 over 2 years ago

  • Status changed from VERIFIED to CLOSED

#13 Updated by CDTS_TEST 王成 about 2 years ago

  • Status changed from CLOSED to New
  • Assignee changed from 移动测试一组_CDTS 刘强 to CD TPM-王祥林

麻烦看看这个BUG是否需要再次跟踪处理

#14 Updated by CD TPM-王祥林 about 2 years ago

  • Status changed from New to RESOLVED
  • Assignee changed from CD TPM-王祥林 to CDTS_TEST 王成

新版本已经删除了原来的视频开机动画，问题出现的场景不存在了，可以关闭这个问题。后续发现新开机动画的问题另外提bug。

#15 Updated by CD TPM-王祥林 about 2 years ago

  • Resolution changed from -- to FIXED

#16 Updated by CDTS_TEST 王成 about 2 years ago

  • Status changed from RESOLVED to VERIFIED

开机动画需求已变更

#17 Updated by CDTS_TEST 王成 about 2 years ago

  • Status changed from VERIFIED to CLOSED

Also available in: Atom PDF