Watchdog killing system_server because of deadlock in Android JB-MR1-DEV

[Lalit Kansara]

Hi,

Description: We are facing framework reboot issue in Monkey test. Watchdog killing system_server because of three threads are in a deadlock condition due to holding locks and waiting to other locks. Traces are pasted here, do let me know if any other info is required. Info regarding locks are mentioned in bold text. Please help me to know if any fix is available to this issue.
Android OS: JB-MR1-DEV

"android.server.ServerThread" prio=5 tid=12 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x4145c598 self=0x5acca5e8
  | sysTid=775 nice=-2 sched=0/0 cgrp=apps handle=1523358712
  | state=S schedstat=( 0 0 0 ) utm=40001 stm=15027 core=0
  at com.android.server.am.ActivityManagerService.broadcastIntent(ActivityManagerService.java:~12060) --> waiting to lock: ActivityManagerService.this
  - waiting to lock <0x41467120> (a com.android.server.am.ActivityManagerService) held by tid=15 (ActivityManager)
  at android.app.ContextImpl.sendBroadcastAsUser(ContextImpl.java:1137)
  at com.android.server.DropBoxManagerService$3.handleMessage(DropBoxManagerService.java:161)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at com.android.server.ServerThread.run(SystemServer.java:1061)

"ActivityManager" prio=5 tid=15 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x41466f20 self=0x594951e0
  | sysTid=778 nice=-2 sched=0/0 cgrp=apps handle=1490778896
  | state=S schedstat=( 0 0 0 ) utm=30621 stm=39448 core=0
  at android.view.inputmethod.InputMethodManager.isActive(InputMethodManager.java:~687) --> waiting to lock: mH
  - waiting to lock <0x414a2738> (a android.view.inputmethod.InputMethodManager$H) held by tid=94 (Binder_D)
  at android.widget.TextView.setEnabled(TextView.java:1332)
  at com.android.server.am.BaseErrorDialog.setEnabled(BaseErrorDialog.java:60)
  at com.android.server.am.BaseErrorDialog.onStart(BaseErrorDialog.java:44)
  at android.app.Dialog.show(Dialog.java:263)
  at com.android.server.am.ActivityManagerService$2.handleMessage(ActivityManagerService.java:981) --> lock held: ActivityManagerService.this
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at com.android.server.am.ActivityManagerService$AThread.run(ActivityManagerService.java:1486)
   
  "Binder_D" prio=5 tid=94 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x417840d0 self=0x4104b818
  | sysTid=11230 nice=0 sched=0/0 cgrp=apps handle=1489350032
  | state=S schedstat=( 0 0 0 ) utm=22207 stm=17572 core=0
  at com.android.server.InputMethodManagerService.getCurrentInputMethodSubtype(InputMethodManagerService.java:~3201) --> waiting to lock: mMethodMap
  - waiting to lock <0x4177cf10> (a java.util.HashMap) held by tid=75 (Binder_8)
  at android.view.inputmethod.InputMethodManager.getCurrentInputMethodSubtype(InputMethodManager.java:1773) --> lock held: mH
  at com.android.server.TextServicesManagerService.getCurrentSpellCheckerSubtype(TextServicesManagerService.java:341)
  at com.android.internal.textservice.ITextServicesManager$Stub.onTransact(ITextServicesManager.java:72)
  at android.os.Binder.execTransact(Binder.java:351)
  at dalvik.system.NativeStart.run(Native Method)
   
  "Binder_8" prio=5 tid=75 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x41879558 self=0x585f8330
  | sysTid=1046 nice=0 sched=0/0 cgrp=apps handle=1482437864
  | state=S schedstat=( 0 0 0 ) utm=22925 stm=17307 core=0
  at com.android.server.am.ActivityManagerService.getCurrentUser(ActivityManagerService.java:~14672) --> waiting to lock: ActivityManagerService.this
  - waiting to lock <0x41467120> (a com.android.server.am.ActivityManagerService) held by tid=15 (ActivityManager)
  at android.app.ActivityManager.getCurrentUser(ActivityManager.java:1936)
  at com.android.server.NotificationManagerService.enqueueNotificationInternal(NotificationManagerService.java:1032)
  at com.android.server.NotificationManagerService.enqueueNotificationWithTag(NotificationManagerService.java:904)
  at android.app.NotificationManager.notifyAsUser(NotificationManager.java:154)
  at com.android.server.InputMethodManagerService.setImeWindowStatus(InputMethodManagerService.java:1518) --> lock held: mMethodMap
  at com.android.internal.view.IInputMethodManager$Stub.onTransact(IInputMethodManager.java:328)
  at com.android.server.InputMethodManagerService.onTransact(InputMethodManagerService.java:825)
  at android.os.Binder.execTransact(Binder.java:351)
  at dalvik.system.NativeStart.run(Native Method)

Thanks & Regards.

[Lalit Kansara]

"ActivityManager" ----------------------------------------------	"Binder_D" -----------------------------	"Binder_8" ------------------------------------
mH                                               |	mMethodMap      |	ActivityManagerService.this
ActivityManagerService.this     |	mH                        |	mMethodMap

[Lalit Kansara]

Can someone from Google team please help on this issue?

[Glenn Kasten]

Do you know the locks held by each thread at time the stack trace was taken?

Do you have reproduction steps (for example the monkey seed values),

and how quickly does the monkey fail after it starts.

[Lalit Kansara]

Thanks Glenn for replying.
Unfortunately I don't have monkey seed values to reproduce the issue. Monkey ran for 26.5 hrs before watchdog happening, only one instance has been seen as yet. Threads with locks (holding/waiting) are depicted in bold text in main post. The system_server traces file is also attached with this post.

[Glenn Kasten]

Sorry I saw the "waiting to lock" but not "lock held". Thanks for reporting.

I'll forward to right people, but this will likely be a hard one.

[Lalit Kansara]

Hi Glenn, any update on this issue from Google?