Bug #117780

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

测试 Test-ST #113422: V4.0专项--AF专项--monkey测试

【AF】【EVT3】【Monkey】Monkey测试12小时，出现ANR in com.android.gallery3d & com.android.music

Added by CD TEST-方永红 about 2 years ago. Updated about 2 years ago.

Status:CLOSEDStart date:2023-05-06
Priority:HighDue date:
Assignee:CD TEST-方永红% Done:

0%

Category:AUDIO-FW
Target version:-
Need_Info:-- Found Version:FlatBuild_HH_MCE_FSE.M.R.user.01.00.0095.C103(X103)
Resolution:-- Degrated:--
Severity:Critical Verified Version:
Reproducibility:Every time Fixed Version:
Test Type:ST Root cause:

Description

【执行命令】
adb shell
monkey --pkg-blacklist-file /sdcard/blacklist.txt --ignore-crashes --ignore-timeouts --ignore-security-exceptions --monitor-native-crashes --ignore-native-crashes -s 20 --throttle 500 --pct-touch 30 --pct-motion 15 --pct-nav 15 --pct-majornav 15 --pct-syskeys 5 --pct-appswitch 10 --pct-anyevent 10 --ignore-crashes -v -v -v 172800
2>/sdcard/error.txt 1>/sdcard/info.txt

【错误信息】

// NOT RESPONDING: com.android.gallery3d (pid 6361)
ANR in com.android.gallery3d (com.android.gallery3d/.app.MovieActivity)
PID: 6361
Reason: Input dispatching timed out (Application does not have a focused window)
Parent: com.android.gallery3d/.app.MovieActivity
Frozen: false
Load: 2.25 / 2.44 / 1.92
----- 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 83795ms to 0ms ago (2023-05-05 20:41:30.569 to 2023-05-05 20:42:54.364):
  9% 836/vendor.qti.hardware.display.composer-service: 5.6% user + 3.3% kernel / faults: 238 minor
  7.4% 5764/com.android.settings: 5.9% user + 1.4% kernel / faults: 45907 minor
  7.1% 1515/system_server: 4.9% user + 2.2% kernel / faults: 146582 minor
  5.9% 971/surfaceflinger: 3.9% user + 1.9% kernel / faults: 608 minor
  5.4% 1177/cnss_diag: 4.6% user + 0.7% kernel
  3.3% 1836/com.android.systemui: 2.5% user + 0.7% kernel / faults: 6215 minor
  2.9% 2686/com.hht.lebocast: 1.6% user + 1.3% kernel / faults: 3275 minor
  1.5% 8900/kworker/u16:14-memlat_wq: 0% user + 1.5% kernel
  1.1% 509/logd: 0.2% user + 0.9% kernel / faults: 14 minor
  0.9% 6361/com.android.gallery3d: 0.6% user + 0.2% kernel / faults: 13476 minor
  0.9% 826/android.hardware.wifi@1.0-service: 0.6% user + 0.3% kernel / faults: 1704 minor
  0.8% 8897/kworker/u16:7-devfreq_wq: 0% user + 0.8% kernel
  0.7% 8902/kworker/u16:16-devfreq_wq: 0% user + 0.7% kernel
  0.6% 389/crtc_commit:125: 0% user + 0.6% kernel
  0.5% 1225/tlog: 0.2% user + 0.2% kernel / faults: 10 minor
  0.4% 1200/mediaserver: 0.2% user + 0.2% kernel / faults: 2776 minor
  0.4% 2469/com.android.launcher3: 0.3% user + 0.1% kernel / faults: 1740 minor
  0.3% 6137/com.android.commands.monkey: 0.2% user + 0.1% kernel / faults: 134 minor
  0.3% 8898/kworker/u16:10-devfreq_wq: 0% user + 0.3% kernel
  0.3% 3556/logcat: 0.1% user + 0.2% kernel
  0.3% 287/kgsl_worker_thr: 0% user + 0.3% kernel
  0.3% 1188/installd: 0% user + 0.2% kernel / faults: 11 minor
  0.3% 2063/com.android.networkstack.process: 0.2% user + 0% kernel / faults: 993 minor
  0.2% 8904/kworker/u16:17-kgsl-mementry: 0% user + 0.2% kernel
  0.2% 1984/com.thundercomm.microservice: 0.1% user + 0.1% kernel / faults: 2066 minor
  0.2% 9/ksoftirqd/0: 0% user + 0.2% kernel
  0.2% 840/vendor.qti.hardware.perf@2.2-service: 0% user + 0.1% kernel / faults: 240 minor
  0.2% 1/init: 0% user + 0.1% kernel / faults: 124 minor
  0.2% 10/rcu_preempt: 0% user + 0.2% kernel
  0.2% 2010/com.thundercomm.microsettings: 0.1% user + 0% kernel / faults: 351 minor
  0.1% 3330/dp_rx_thread_0: 0% user + 0.1% kernel

error.txt Magnifier (95.4 KB) CD TEST-方永红, 2023-05-06 15:17

anr_2023-05-05-20-42-54-742 (1.4 MB) CD TEST-方永红, 2023-05-06 15:17

anr_2023-05-06-05-00-09-540 (1.62 MB) CD TEST-方永红, 2023-05-06 15:17

Related issues

Related to Figure - Bug #117793: 【IOVDEV-25910】【VC1】【0072】【台架】【EE环境】【副屏】副屏monkey测试异常结束，疑发生... CLOSED 2023-05-06

History

#1 Updated by Multimedia组-RD3_TSCD 梁卿山 about 2 years ago

  • Status changed from New to ASSIGNED

HI ALL,

当前未看出问题点，还需要细看，已经提高通case协助。

#2 Updated by Multimedia组-RD3_TSCD 梁卿山 about 2 years ago

HI ALL

已经将新的复现日志提供给高通；

#3 Updated by Multimedia组-RD3_TSCD 梁卿山 about 2 years ago

HI ALL

该问题在连接中控并连接输出设备后，经过测试不复现，将会进一步测试，看问题是否因为没有播放设备引起。

#4 Updated by Multimedia组-RD3_TSCD 梁卿山 about 2 years ago

HI ALL

5月11日Monkey测试结果：没有出现其他ANR。
测试环境：
1.和中控连接，网络良好
2.连接外放设备，音频输出的A2B线保持良好。

#5 Updated by Multimedia组-RD3_TSCD 梁卿山 about 2 years ago

HI ALL

根据之前复现的日志，进行分析，是audioflinger卡住了，该问题和是否连接外放设备有关系。
连接中控测试不复现也验证了上述结论，不连接中控才能复现。
我们将继续连接中控的情况下，进行测试，验证是否还会出现该问题。

#6 Updated by Multimedia组-RD3_TSCD 梁卿山 about 2 years ago

  • Status changed from ASSIGNED to NEED_INFO
  • Assignee changed from Multimedia组-RD3_TSCD 梁卿山 to CD TEST-方永红

HI 永红

该问题经过判断是未连接音频A2B导致了底层驱动阻塞，audio服务出现问题；
请在连接中控的情况下进行验证，谢谢！

#7 Updated by CD TEST-方永红 about 2 years ago

5.15
13日DB为复现，继续跟踪两个版本

#8 Updated by Multimedia组-RD3_TSCD 梁卿山 about 2 years ago

HI ALL

日志分析如下：
当前外接设备未连接，导致了audioflinger中写入数据时卡死，进而导致了各个audio相关的服务死了，出现了ANR。

365167:05-10 17:40:38.903 1022 1814 W AudioFlinger: write blocked for 10653 msecs, 205 delayed writes, thread 29
366389:05-10 17:40:43.165 1022 1805 W AudioFlinger: write blocked for 41747 msecs, 10 delayed writes, thread 13
367269:05-10 17:40:49.652 1022 1814 W AudioFlinger: write blocked for 10643 msecs, 206 delayed writes, thread 29
368973:05-10 17:40:53.699 1022 1805 W AudioFlinger: write blocked for 10531 msecs, 11 delayed writes, thread 13
371481:05-10 17:41:00.402 1022 1814 W AudioFlinger: write blocked for 10653 msecs, 207 delayed writes, thread 29
374104:05-10 17:41:11.157 1022 1814 W AudioFlinger: write blocked for 10653 msecs, 208 delayed writes, thread 29
375064:05-10 17:41:14.681 1022 1805 W AudioFlinger: write blocked for 20981 msecs, 12 delayed writes, thread 13
376589:05-10 17:41:21.909 1022 1814 W AudioFlinger: write blocked for 10652 msecs, 209 delayed writes, thread 29 ★★★写入数据卡死
376718:05-10 17:41:23.742 1022 1855 F TimeCheck: TimeCheck timeout for IAudioFlinger command 38
376779:05-10 17:41:24.595 11646 11646 F DEBUG : Abort message: 'TimeCheck timeout for IAudioFlinger command 38'
376832:05-10 17:41:24.837 11146 11177 W AudioSystem: AudioPolicyService server died! ★★★ 底层策略管理挂了
376833:05-10 17:41:24.838 18691 19131 W AudioSystem: AudioPolicyService server died!
376835:05-10 17:41:24.839 18624 27463 W AudioSystem: AudioFlinger server died! ★★★ audioflinger挂了
376837:05-10 17:41:24.839 5432 6303 W AudioSystem: AudioFlinger server died!
376838:05-10 17:41:24.839 1309 3364 W AudioSystem: AudioPolicyService server died!
484298:05-10 17:46:38.613 1086 1858 E AudioSystem-JNI: Command failed for android_media_AudioSystem_checkAudioFlinger: -32
484299:05-10 17:46:38.613 1086 1858 E AS.AudioService: Audioserver died. ★★★ audioserver挂了

#9 Updated by CD TEST-方永红 about 2 years ago

5.16
15日DB未复现，继续跟踪一个版本

#10 Updated by CD TEST-方永红 about 2 years ago

  • Status changed from NEED_INFO to RESOLVED

5.17
0100版本未复现
先关闭

#11 Updated by CD TEST-方永红 about 2 years ago

  • Status changed from RESOLVED to VERIFIED

#12 Updated by CD TEST-方永红 about 2 years ago

  • Status changed from VERIFIED to CLOSED

Also available in: Atom PDF