Bug #116608

【AF】【EVT3】【ST】【OTA】【偶现一次】使用*#149# app进行FOTA升级过程，偶现跳转到开机动画界面

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

Status:CLOSEDStart date:2023-02-28
Priority:NormalDue date:
Assignee:移动测试一组_CDTS 刘强% Done:

100%

Category:CD-FW
Target version:-
Need_Info: Found Version:FlatBuild_HH_VX1_MCE_FSE.M.D.userdebug.01.00.X101.202302241209
Resolution:FIXED Degrated:No
Severity:Normal Verified Version:
Reproducibility:Occasionally Fixed Version:2023-03-09
Test Type:ST Root cause:原生通知声音已删除，不会发此死锁问题

Description

【前提条件】
None

【测试步骤】
1. 烧写0224 User版本
2. push 0225 fota包
3. *#149# 进入升级界面
4. 点击升级

【预期结果】
4. 可以正常升级

【实际结果】

4.出现Download进度后，马上跳转显示开机动画->开机引导流程

tlog_215aead3_002_0224134905.tar.gz (9.88 MB) 移动测试一组_CDTS 刘强, 2023-02-28 19:56

tlog_sts40x190142_002_0228115243.tar.gz - 复现日志 (5.09 MB) 移动测试一组_CDTS 刘强, 2023-03-23 10:38

History

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

Hi all
我在刷完user.01.00.0078.C101版本后，开机5分钟左右后，设备自动跳转到开机动画。
期间仅打开了USB调制。

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

第一份日志异常如下：
02-24 13:47:46.538 1136 1226 W Watchdog: * WATCHDOG KILLING SYSTEM PROCESS: Blocked in handler on main thread (main)
02-24 13:47:46.539 1136 1226 W Watchdog: main annotated stack trace:
02-24 13:47:46.539 1136 1226 W Watchdog: at com.android.server.audio.MediaFocusControl.getCurrentAudioFocus(MediaFocusControl.java:802)
02-24 13:47:46.539 1136 1226 W Watchdog: - waiting to lock <0x03499ede> (a java.lang.Object)
02-24 13:47:46.539 1136 1226 W Watchdog: at com.android.server.audio.AudioService.getCurrentAudioFocus(AudioService.java:8417)
02-24 13:47:46.539 1136 1226 W Watchdog: at android.media.AudioManager.isAudioFocusExclusive(AudioManager.java:3204)
02-24 13:47:46.539 1136 1226 W Watchdog: at com.android.server.notification.NotificationManagerService.playSound(NotificationManagerService.java:7676)
02-24 13:47:46.539 1445 1445 I update_engine: [libfs_mgr]GetFstabPath()fstab_path:/vendor/etc/fstab.qcom
02-24 13:47:46.539 1136 1226 W Watchdog: at com.android.server.notification.NotificationManagerService.buzzBeepBlinkLocked(NotificationManagerService.java:7463)
02-24 13:47:46.539 1136 1226 W Watchdog: at com.android.server.notification.NotificationManagerService$PostNotificationRunnable.run(NotificationManagerService.java:7097)
02-24 13:47:46.539 1136 1226 W Watchdog: - locked <0x0fa29df1> (a java.lang.Object)
02-24 13:47:46.539 1136 1226 W Watchdog: at android.os.Handler.handleCallback(Handler.java:938)
02-24 13:47:46.539 1136 1226 W Watchdog: at android.os.Handler.dispatchMessage(Handler.java:99)
02-24 13:47:46.539 1136 1226 W Watchdog: at android.os.Looper.loopOnce(Looper.java:201)
02-24 13:47:46.539 1136 1226 W Watchdog: at android.os.Looper.loop(Looper.java:288)
02-24 13:47:46.539 1136 1226 W Watchdog: at com.android.server.SystemServer.run(SystemServer.java:909)
02-24 13:47:46.539 1136 1226 W Watchdog: at com.android.server.SystemServer.main(SystemServer.java:616)
02-24 13:47:46.540 1136 1226 W Watchdog: at java.lang.reflect.Method.invoke(Native Method)
02-24 13:47:46.540 1136 1226 W Watchdog: at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
02-24 13:47:46.540 1136 1226 W Watchdog: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:987)
02-24 13:47:46.540 1136 1226 W Watchdog: * GOODBYE!
02-24 13:47:46.540 1136 1226 I Process : Sending signal. PID: 1136 SIG: 9

"main" prio=5 tid=1 Blocked | group="main" sCount=1 ucsCount=0 flags=1 obj=0x7216cbb8 self=0xb4000076b3849be0 | sysTid=1136 nice=-2 cgrp=default sched=0/0 handle=0x7881fc64f8 | state=S schedstat=( 4151259479 2623823968 6708 ) utm=154 stm=260 core=1 HZ=100 | stack=0x7fd818b000-0x7fd818d000 stackSize=8188KB | held mutexes=
at com.android.server.audio.MediaFocusControl.getCurrentAudioFocus(MediaFocusControl.java:802)
- waiting to lock <0x03499ede> (a java.lang.Object) held by thread 118
at com.android.server.audio.AudioService.getCurrentAudioFocus(AudioService.java:8417)
at android.media.AudioManager.isAudioFocusExclusive(AudioManager.java:3204)
at com.android.server.notification.NotificationManagerService.playSound(NotificationManagerService.java:7676)
at com.android.server.notification.NotificationManagerService.buzzBeepBlinkLocked(NotificationManagerService.java:7463)
at com.android.server.notification.NotificationManagerService$PostNotificationRunnable.run(NotificationManagerService.java:7097)
- locked <0x0fa29df1> (a java.lang.Object)
at android.os.Handler.handleCallback(Handler.java:938)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loopOnce(Looper.java:201)
at android.os.Looper.loop(Looper.java:288)
at com.android.server.SystemServer.run(SystemServer.java:909)
at com.android.server.SystemServer.main(SystemServer.java:616)
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:987)

"Binder:1136_4" prio=5 tid=118 Blocked | group="main" sCount=1 ucsCount=0 flags=1 obj=0x14344138 self=0xb4000076b39572d0 | sysTid=1920 nice=-10 cgrp=default sched=0/0 handle=0x743a67acb0 | state=S schedstat=( 703336650 650765444 1590 ) utm=25 stm=44 core=6 HZ=100 | stack=0x743a583000-0x743a585000 stackSize=991KB | held mutexes=
at com.android.server.audio.PlaybackActivityMonitor.restoreVShapedPlayers(PlaybackActivityMonitor.java:628)
- waiting to lock <0x0d2282d5> (a java.lang.Object) held by thread 129
at com.android.server.audio.MediaFocusControl.restoreVShapedPlayers(MediaFocusControl.java:134)
at com.android.server.audio.FocusRequester.handleFocusGainFromRequest(FocusRequester.java:364)
at com.android.server.audio.MediaFocusControl.requestAudioFocus(MediaFocusControl.java:1043)
- locked <0x03499ede> (a java.lang.Object)
at com.android.server.audio.AudioService.requestAudioFocus(AudioService.java:8346)
at android.media.IAudioService$Stub.onTransact(IAudioService.java:1878)
at android.os.Binder.execTransactInternal(Binder.java:1179)
at android.os.Binder.execTransact(Binder.java:1143)

#3 Updated by CD TPM-王祥林 over 2 years ago

第二份日志异常：
02-28 11:51:16.461 1499 1602 E Watchdog: First set of traces taken from /data/anr/anr_2023-02-28-11-50-36-008
02-28 11:51:16.505 1499 1602 E Watchdog: Second set of traces taken from /data/anr/anr_2023-02-28-11-51-08-866
02-28 11:51:16.552 1499 4790 I DropBoxManagerService: add tag=system_server_watchdog isTagEnabled=true flags=0x6
02-28 11:51:16.565 1499 1602 W Watchdog: * WATCHDOG KILLING SYSTEM PROCESS: Blocked in handler on main thread (main)
02-28 11:51:16.566 1499 1602 W Watchdog: main annotated stack trace:
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.server.audio.MediaFocusControl.getCurrentAudioFocus(MediaFocusControl.java:802)
02-28 11:51:16.566 1499 1602 W Watchdog: - waiting to lock <0x0bb40ef3> (a java.lang.Object)
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.server.audio.AudioService.getCurrentAudioFocus(AudioService.java:8417)
02-28 11:51:16.566 1499 1602 W Watchdog: at android.media.AudioManager.isAudioFocusExclusive(AudioManager.java:3204)
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.server.notification.NotificationManagerService.playSound(NotificationManagerService.java:7676)
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.server.notification.NotificationManagerService.buzzBeepBlinkLocked(NotificationManagerService.java:7463)
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.server.notification.NotificationManagerService$PostNotificationRunnable.run(NotificationManagerService.java:7097)
02-28 11:51:16.566 1499 1602 W Watchdog: - locked <0x01bedd30> (a java.lang.Object)
02-28 11:51:16.566 1499 1602 W Watchdog: at android.os.Handler.handleCallback(Handler.java:938)
02-28 11:51:16.566 1499 1602 W Watchdog: at android.os.Handler.dispatchMessage(Handler.java:99)
02-28 11:51:16.566 1499 1602 W Watchdog: at android.os.Looper.loopOnce(Looper.java:201)
02-28 11:51:16.566 1499 1602 W Watchdog: at android.os.Looper.loop(Looper.java:288)
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.server.SystemServer.run(SystemServer.java:909)
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.server.SystemServer.main(SystemServer.java:616)
02-28 11:51:16.566 1499 1602 W Watchdog: at java.lang.reflect.Method.invoke(Native Method)
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
02-28 11:51:16.566 1499 1602 W Watchdog: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:987)
02-28 11:51:16.566 1499 1602 W Watchdog: * GOODBYE!

"main" prio=5 tid=1 Blocked | group="main" sCount=1 ucsCount=0 flags=1 obj=0x7159efc8 self=0xb400007020e56010 | sysTid=1499 nice=-2 cgrp=default sched=0/0 handle=0x71e2e584f8 | state=S schedstat=( 1437516942 550747890 4507 ) utm=103 stm=40 core=3 HZ=100 | stack=0x7ff39b0000-0x7ff39b2000 stackSize=8188KB | held mutexes=
at com.android.server.audio.MediaFocusControl.getCurrentAudioFocus(MediaFocusControl.java:802)
- waiting to lock <0x0bb40ef3> (a java.lang.Object) held by thread 10
at com.android.server.audio.AudioService.getCurrentAudioFocus(AudioService.java:8417)
at android.media.AudioManager.isAudioFocusExclusive(AudioManager.java:3204)
at com.android.server.notification.NotificationManagerService.playSound(NotificationManagerService.java:7676)
at com.android.server.notification.NotificationManagerService.buzzBeepBlinkLocked(NotificationManagerService.java:7463)
at com.android.server.notification.NotificationManagerService$PostNotificationRunnable.run(NotificationManagerService.java:7097)
- locked <0x01bedd30> (a java.lang.Object)
at android.os.Handler.handleCallback(Handler.java:938)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loopOnce(Looper.java:201)
at android.os.Looper.loop(Looper.java:288)
at com.android.server.SystemServer.run(SystemServer.java:909)
at com.android.server.SystemServer.main(SystemServer.java:616)
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:987)

"ranker" prio=5 tid=90 Blocked | group="main" sCount=1 ucsCount=0 flags=1 obj=0x13b834f8 self=0xb400007020f2d8d0 | sysTid=1779 nice=10 cgrp=default sched=0/0 handle=0x6dd2a9dcb0 | state=S schedstat=( 8679267 18263908 48 ) utm=0 stm=0 core=3 HZ=100 | stack=0x6dd299a000-0x6dd299c000 stackSize=1039KB | held mutexes=
at com.android.server.notification.NotificationManagerService.handleRankingReconsideration(NotificationManagerService.java:8032)
- waiting to lock <0x01bedd30> (a java.lang.Object) held by thread 1
at com.android.server.notification.NotificationManagerService.access$10500(NotificationManagerService.java:335)
at com.android.server.notification.NotificationManagerService$RankingHandlerWorker.handleMessage(NotificationManagerService.java:8365)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loopOnce(Looper.java:201)
at android.os.Looper.loop(Looper.java:288)
at android.os.HandlerThread.run(HandlerThread.java:67)

#4 Updated by CD TPM-王祥林 over 2 years ago

  • Assignee changed from CD TPM-王祥林 to CD FW 曹覃刚

覃刚

两份日志看起来都是播通知音的时候发生了死锁。复现的版本是2.28之前的，删除通知音的提交在186166，3.8入库的。看看是否和这个有关。

frameworks/base/services/core/java/com/android/server/notification/NotificationManagerService.java

mRankingHelper.extractSignals(r); // 持锁0x0bb40ef3，等0x01bedd30。 （基于第二份日志）
mRankingHelper.sort(mNotificationList);
final int position = mRankingHelper.indexOf(mNotificationList, r);

int buzzBeepBlinkLoggingCode = 0;
if (!r.isHidden()) {
buzzBeepBlinkLoggingCode = buzzBeepBlinkLocked(r); //持锁0x01bedd30,等0x0bb40ef3 （基于第二份日志）
}

刘强

不连中控的情况下，压测一下反复弹通知会不会比较容易复现这个问题。

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

  • Status changed from New to NEED_INFO
  • Assignee changed from CD FW 曹覃刚 to 移动测试一组_CDTS 刘强
  • Need_Info changed from -- to TEST

Hi 强哥
对于此票中发生的死锁问题，应该在03/08之后的版本不会复现了
在下面的提交中已经移除了其中通知音播放的流程
https://dev.thundercomm.com/gerrit/c/general/platform/frameworks/base/+/186166
-------------------
"main" prio=5 tid=1 Blocked | group="main" sCount=1 ucsCount=0 flags=1 obj=0x7159efc8 self=0xb400007020e56010 | sysTid=1499 nice=-2 cgrp=default sched=0/0 handle=0x71e2e584f8 | state=S schedstat=( 1437516942 550747890 4507 ) utm=103 stm=40 core=3 HZ=100 | stack=0x7ff39b0000-0x7ff39b2000 stackSize=8188KB | held mutexes=
at com.android.server.audio.MediaFocusControl.getCurrentAudioFocus(MediaFocusControl.java:802)
- waiting to lock <0x0bb40ef3> (a java.lang.Object) held by thread 10
at com.android.server.audio.AudioService.getCurrentAudioFocus(AudioService.java:8417)
at android.media.AudioManager.isAudioFocusExclusive(AudioManager.java:3204) //这个之后的流程已经不会被调用了，因此该死锁问题不会存在
at com.android.server.notification.NotificationManagerService.playSound(NotificationManagerService.java:7676)
at com.android.server.notification.NotificationManagerService.buzzBeepBlinkLocked(NotificationManagerService.java:7463)
at com.android.server.notification.NotificationManagerService$PostNotificationRunnable.run(NotificationManagerService.java:7097)
- locked <0x01bedd30> (a java.lang.Object)
at android.os.Handler.handleCallback(Handler.java:938)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loopOnce(Looper.java:201)
at android.os.Looper.loop(Looper.java:288)
-------------------

请帮助使用03/08之后的版本验证此问题，如果验证OK，请关闭此票
谢谢

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

验证版本：Figure：0086
验证结果：未复现

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

  • Assignee changed from 移动测试一组_CDTS 刘强 to CD FW 曹覃刚

验证版本：Figure：01.00.0087.C102
验证结果：未复现

麻烦走下流程关闭问题

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

  • Status changed from NEED_INFO to RESOLVED
  • Assignee changed from CD FW 曹覃刚 to 移动测试一组_CDTS 刘强
  • % Done changed from 0 to 100
  • Need_Info deleted (TEST)
  • Resolution changed from -- to FIXED
  • Degrated changed from -- to No
  • Fixed Version set to 2023-03-09
  • Root cause set to 原生通知声音已删除，不会发此死锁问题

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

  • Status changed from RESOLVED to VERIFIED

连续三个新版本验证未复现，先关闭

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

  • Status changed from VERIFIED to CLOSED

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

  • Subject changed from 【BSP】【EVT3】【ST】【OTA】【偶现一次】使用*#149# app进行FOTA升级过程，偶现跳转到开机动画界面 to 【AF】【EVT3】【ST】【OTA】【偶现一次】使用*#149# app进行FOTA升级过程，偶现跳转到开机动画界面

Also available in: Atom PDF