Bug #113491
测试 Test-ST #113421: V4.0功能与专项测试
测试 Test-ST #113422: V4.0专项--AF专项--monkey测试
【AF】【EVT2】【Monkey】Monkey测试8小时，出现ANR：com.android.calendar
| Status: | CLOSED | Start date: | 2022-11-01 | |
|---|---|---|---|---|
| Priority: | Normal | Due date: | 2023-02-10 | |
| Assignee: | CD Test赵飞 | % Done: | 100% | |
| Category: | CD-APP | |||
| Target version: | - | |||
| Need_Info: | -- | Found Version: | FlatBuild_HH_VX1_MCE_FSE.M.D.user.01.00.X101.202210290232 | |
| Resolution: | -- | Degrated: | -- | |
| Severity: | Normal | Verified Version: | ||
| Reproducibility: | Frequently | Fixed Version: | ||
| Test Type: | Monkey Test | Root cause: |
Description
执行命令：
1. adb shell
2. monkey --ignore-crashes --ignore-timeouts --ignore-security-exceptions --monitor-native-crashes --ignore-native-crashes -s 20 --throttle 200 --pct-touch 30 --pct-motion 15 --pct-nav 15 --pct-majornav 15 --pct-syskeys 5 --pct-appswitch 5 --pct-anyevent 5 --ignore-crashes -v -v -v 180000 2>/sdcard/error.txt 1>/sdcard/info.txt
错误日志：
10-28 08:37:34.762 6173 22850 W Monkey : // NOT RESPONDING: com.android.calendar (pid 7595) 10-28 08:37:34.763 6173 22850 W Monkey : ANR in com.android.calendar (com.android.calendar/.AllInOneActivity) 10-28 08:37:34.763 6173 22850 W Monkey : PID: 7595 10-28 08:37:34.763 6173 22850 W Monkey : Reason: Input dispatching timed out (Application does not have a focused window) 10-28 08:37:34.763 6173 22850 W Monkey : Parent: com.android.calendar/.AllInOneActivity 10-28 08:37:34.763 6173 22850 W Monkey : ErrorId: bcb70b5b-0e2e-41ba-98ad-17996b5dddd7 10-28 08:37:34.763 6173 22850 W Monkey : Frozen: false 10-28 08:37:34.763 6173 22850 W Monkey : Load: 0.0 / 0.0 / 0.0 10-28 08:37:34.763 6173 22850 W Monkey : ----- Output from /proc/pressure/memory ----- 10-28 08:37:34.763 6173 22850 W Monkey : some avg10=0.00 avg60=0.00 avg300=0.00 total=37292 10-28 08:37:34.763 6173 22850 W Monkey : full avg10=0.00 avg60=0.00 avg300=0.00 total=12449 10-28 08:37:34.763 6173 22850 W Monkey : ----- End output from /proc/pressure/memory ----- 10-28 08:37:34.763 6173 22850 W Monkey : 10-28 08:37:34.763 6173 22850 W Monkey : CPU usage from 293464ms to 0ms ago (2022-10-28 08:32:40.962 to 2022-10-28 08:37:34.426): 10-28 08:37:34.763 6173 22850 W Monkey : 97% 1255/ept_uppertester_v2.0_fse: 85% user + 11% kernel 10-28 08:37:34.763 6173 22850 W Monkey : 55% 1240/tlog: 2.1% user + 52% kernel / faults: 33 minor 10-28 08:37:34.763 6173 22850 W Monkey : 41% 933/vendor.qti.hardware.display.composer-service: 12% user + 28% kernel / faults: 1285 minor 10-28 08:37:34.763 6173 22850 W Monkey : 38% 1135/system_server: 13% user + 24% kernel / faults: 789470 minor 10-28 08:37:34.763 6173 22850 W Monkey : 32% 1046/surfaceflinger: 13% user + 19% kernel / faults: 4111 minor 10-28 08:37:34.763 6173 22850 W Monkey : 24% 2097/com.android.systemui: 12% user + 12% kernel / faults: 108265 minor 10-28 08:37:34.763 6173 22850 W Monkey : 17% 31819/com.microsoft.emmx: 9.5% user + 8.3% kernel / faults: 150340 minor ...
History
#1 Updated by CD Test赵飞 over 2 years ago
日志见Bug #113456 附件
#2 Updated by CD FW 曹覃刚 over 2 years ago
- Category changed from CD-FW to CD-APP
- Assignee changed from CD FW 曹覃刚 to CD APP-王营
app的问题，请帮忙分析
#3 Updated by CD APP-王营 over 2 years ago
- Status changed from New to NEED_INFO
- Assignee changed from CD APP-王营 to CD Test赵飞
Monkey测试中出现的问题，请帮忙上传TLog，同时ANR问题需要将data目录下的anr文件夹一起抓出来，谢谢。
#4 Updated by CD Test赵飞 over 2 years ago
- File Tlog&ANR.zip.001 added
- File Tlog&ANR.zip.002 added
- File Tlog&ANR.zip.003 added
- File Tlog&ANR.zip.004 added
- File Tlog&ANR.zip.005 added
- File Tlog&ANR.zip.006 added
- File Tlog&ANR.zip.007 added
- Status changed from NEED_INFO to ASSIGNED
- Assignee changed from CD Test赵飞 to CD APP-王营
11月4号DB版本复现此问题，Tlog和ANR目录见附件
#5 Updated by CD Test赵飞 over 2 years ago
Log已传至FTP
ftp://cdiot@192.168.87.46/Pre_figure/Test_Log/Bug _113491/Tlog&ANR.zip
#6 Updated by CDTS-TEST 周婷 over 2 years ago
- Due date deleted (
2022-11-08) - Target version changed from VX1_MCE_FSE_V3.0_update_20221130 to VX1_MCE_FSE_V5.0_20221230
#7 Updated by CD APP-王营 over 2 years ago
- Due date set to 2022-12-15
#8 Updated by CDTS-TEST 周婷 over 2 years ago
- Target version changed from VX1_MCE_FSE_V5.0_20221230 to VX1_MCE_FSE_C sample_20230113
#9 Updated by CDTS-TEST 周婷 over 2 years ago
- Due date changed from 2022-12-15 to 2023-01-06
#10 Updated by CDTS-TEST 周婷 over 2 years ago
- Due date changed from 2023-01-06 to 2023-01-16
请更新bug 进展
#11 Updated by CD APP-王营 over 2 years ago
■ Current conclusion
从最新的log中没有找到直接引起ANR的原因，尝试另外方案。
■ My analysis
根据当前的Log可分析，在ANR发生时CPU占用率无异常，在正常范围内，排除CPU占用率过高导致，信息如下：
ANR in com.android.deskclock (com.android.deskclock/.DeskClock)
PID: 5486
Reason: Input dispatching timed out (Application does not have a focused window)
Parent: com.android.deskclock/.DeskClock
Frozen: false
Load: 0.0 / 0.0 / 0.0
----- Output from /proc/pressure/memory -----
some avg10=0.00 avg60=0.00 avg300=0.00 total=0
full avg10=0.00 avg60=0.00 avg300=0.00 total=0
----- End output from /proc/pressure/memory -----
CPU usage from 5440ms to 0ms ago (2023-01-08 01:52:31.837 to 2023-01-08 01:52:37.277):
13% 1516/system_server: 5.5% user + 7.9% kernel / faults: 3073 minor
4% 2353/com.android.systemui: 2.9% user + 1.1% kernel / faults: 1135 minor
3.4% 889/audioserver: 2% user + 1.4% kernel / faults: 23 minor
3.4% 1185/mediaserver: 2.3% user + 1.1% kernel / faults: 186 minor
2.7% 5486/com.android.deskclock: 2.3% user + 0.3% kernel / faults: 1227 minor
2.3% 798/android.hardware.audio.service: 0.5% user + 1.8% kernel / faults: 1 minor
2% 1240/media.swcodec: 1.6% user + 0.3% kernel / faults: 131 minor
1.6% 334/kworker/u16:13-ufs_pm_qos_0: 0% user + 1.6% kernel
1.2% 5036/adbd: 0.1% user + 1.1% kernel / faults: 319 minor
1.1% 330/kworker/u16:9-ufs_pm_qos_0: 0% user + 1.1% kernel
1.1% 499/logd: 0.3% user + 0.7% kernel / faults: 16 minor
1.1% 5344/kworker/u16:1-memlat_wq: 0% user + 1.1% kernel
0.9% 6035/com.android.systemui:screenshot: 0.9% user + 0% kernel / faults: 400 minor
0% 820/android.hardware.memtrack@1.0-service: 0% user + 0% kernel
0.5% 1163/tlog: 0.3% user + 0.1% kernel
0.3% 836/vendor.qti.hardware.iop@2.0-service: 0.1% user + 0.1% kernel
0.3% 898/surfaceflinger: 0.1% user + 0.1% kernel / faults: 2 minor
0.3% 2808/com.thundercomm.gamemode: 0.1% user + 0.1% kernel / faults: 35 minor
0.3% 5100/logcat: 0.3% user + 0% kernel
0.3% 5453/kworker/u17:1-kgsl-events: 0% user + 0.3% kernel
0.1% 1/init: 0% user + 0.1% kernel
0.1% 10/rcu_preempt: 0% user + 0.1% kernel
0% 21/ksoftirqd/1: 0% user + 0% kernel
0.1% 29/ksoftirqd/2: 0% user + 0.1% kernel
0% 37/ksoftirqd/3: 0% user + 0% kernel
0.1% 111/system: 0% user + 0.1% kernel
0.1% 646/vendor.ts.uart@1.0-service: 0% user + 0.1% kernel
0.1% 665/statsd: 0% user + 0.1% kernel / faults: 8 minor
0.1% 666/netd: 0.1% user + 0% kernel
0.1% 1183/media.extractor: 0.1% user + 0% kernel / faults: 8 minor
0.1% 1184/media.metrics: 0.1% user + 0% kernel / faults: 10 minor
0% 1357/imsdatadaemon: 0% user + 0% kernel
0.1% 1424/msm_irqbalance: 0.1% user + 0% kernel
0.1% 2595/com.thundercomm.tchttpserver: 0.1% user + 0% kernel / faults: 5 minor
0.1% 2714/com.thundercomm.remotecontrolservice: 0% user + 0.1% kernel / faults: 3 minor
0.1% 2832/com.android.launcher3: 0.1% user + 0% kernel / faults: 6 minor
0.1% 2920/com.thundercomm.gamemode.provider: 0.1% user + 0% kernel / faults: 10 minor
0.1% 3743/com.baidu.input: 0.1% user + 0% kernel / faults: 3 minor
0.1% 5435/kworker/1:1-sock_diag_events: 0% user + 0.1% kernel
0.1% 5452/kworker/0:1-events_freezable_power_: 0% user + 0.1% kernel
0.1% 6300/kworker/u17:3-dwc_wq: 0% user + 0.1% kernel
5.9% TOTAL: 2.9% user + 2.4% kernel + 0% iowait + 0.4% irq + 0% softirq
CPU usage from 1300218ms to 1300218ms ago (1970-01-01 08:00:00.000 to 1970-01-01 08:00:00.000) with 0% awake:
0% TOTAL: 0% user + 0% kernel
通过trace文件分析，未显示出ANR发生的具体页面，trace信息如下：
"main" prio=5 tid=1 Native
| group="main" sCount=1 ucsCount=0 flags=1 obj=0x7182cc18 self=0xb4000079ba857380
| sysTid=5486 nice=0 cgrp=default sched=0/0 handle=0x7b80c2b4f8
| state=S schedstat=( 23192377953 3631163267 31710 ) utm=1973 stm=345 core=0 HZ=100
| stack=0x7fd1623000-0x7fd1625000 stackSize=8188KB
| held mutexes=
native: #00 pc 00000000000a2c4c /apex/com.android.runtime/lib64/bionic/libc.so (__epoll_pwait+12)
native: #01 pc 0000000000017ea8 /system/lib64/libutils.so (android::Looper::pollInner(int)+184)
native: #02 pc 0000000000017d84 /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+116)
native: #03 pc 0000000000152d3c /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+48)
at android.os.MessageQueue.nativePollOnce(Native method)
at android.os.MessageQueue.next(MessageQueue.java:335)
at android.os.Looper.loopOnce(Looper.java:161)
at android.os.Looper.loop(Looper.java:288)
at android.app.ActivityThread.main(ActivityThread.java:7880)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1009)
■ Next action
目前怀疑是由于monkey启动app太快，导致当前focus window还没有切换，造成由于input事件导致app anr
同测试同事确认monkey测试是否有点击速度参数设置以及速度的标准范围。
#12 Updated by CD APP-王营 over 2 years ago
- % Done changed from 0 to 20
#13 Updated by CDTS-TEST 周婷 over 2 years ago
- Target version deleted (
VX1_MCE_FSE_C sample_20230113)
目前还在分析中，最晚下周一1/12 需fix
#14 Updated by CD APP-王营 over 2 years ago
- Due date changed from 2023-01-16 to 2023-02-10
■ Current conclusion
未找到问题点，分析中
■ My analysis
尝试log分析以及排除测试后未能定位问题产生的原因，目前还在排查是否是后期代码提交导致，使用2022-08-16版本测试，依然存在anr现象，数量较少。
■ Next action
需要协调system组的同事帮忙一起分析定位问题产生范围。
#15 Updated by CD APP-王营 over 2 years ago
- Status changed from ASSIGNED to NEED_INFO
- Assignee changed from CD APP-王营 to CD Test赵飞
■ Current conclusion
根据最新的monkey测试标准，最近两天的测试中未能复现此问题，需持续跟进，若后续几个版本无法复现可关闭此bug
■ My analysis
稳定性问题待确认，持续观察
■ Next action
请测试同事持续跟进测试，看此问题是否复现
#17 Updated by CD Test赵飞 over 2 years ago
2月3号DB版本未复现此问题
继续跟踪1个版本
#18 Updated by CD Test赵飞 over 2 years ago
- Status changed from NEED_INFO to RESOLVED
- % Done changed from 70 to 80
2月5号DB版本未复现此问题
暂时关闭此问题
#19 Updated by CD Test赵飞 over 2 years ago
- Status changed from RESOLVED to VERIFIED
- % Done changed from 80 to 100
#20 Updated by CD Test赵飞 over 2 years ago
- Status changed from VERIFIED to CLOSED