ANR/Deadlock [134361006]

Fixed

Bug

Status Update

No update yet.

Description

d....@googlemail.com

created issue #1

Jun 3, 2019 10:37AM

Component used: WorkManager
Version used: 1.0.1
Devices/Android versions reproduced on: different Samsung Galaxy devices running Android 8 and 9

I have received deadlock reports like this:

"main" prio=5 tid=1 Blocked
| group="main" sCount=1 dsCount=0 flags=1 obj=0x76790a58 self=0x7d81014c00
| sysTid=27874 nice=0 cgrp=default sched=0/0 handle=0x7e07c1a560
| state=S schedstat=( 1835900780 7285545518 5958 ) utm=82 stm=100 core=1 HZ=100
| stack=0x7febcdd000-0x7febcdf000 stackSize=8MB
| held mutexes=
at androidx.work.impl.constraints.trackers.ConstraintTracker.removeListener (ConstraintTracker.java:77)
- waiting to lock <0x08a4f10d> (a java.lang.Object) held by thread 13 // ConstraintTracker.mLock
at androidx.work.impl.constraints.controllers.ConstraintController.replace (ConstraintController.java:98)
at androidx.work.impl.constraints.WorkConstraintsTracker.replace (WorkConstraintsTracker.java:99)
- locked <0x0cbac8c2> (a java.lang.Object) // WorkConstrainsTracker.mLock
at androidx.work.impl.background.greedy.GreedyScheduler.removeConstraintTrackingFor (GreedyScheduler.java:153)
- locked <0x0cbec6d3> (a java.lang.Object) // GreedyScheduler.mLock
at androidx.work.impl.background.greedy.GreedyScheduler.onExecuted (GreedyScheduler.java:141)
at androidx.work.impl.Processor.onExecuted (Processor.java:230)
- locked <0x08012210> (a java.lang.Object)
at androidx.work.impl.Processor$FutureListener.run (Processor.java:263)
at android.os.Handler.handleCallback (Handler.java:873)
at android.os.Handler.dispatchMessage (Handler.java:99)
at android.os.Looper.loop (Looper.java:214)
at android.app.ActivityThread.main (ActivityThread.java:7032)
at java.lang.reflect.Method.invoke (Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:494)
at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:965)
"ConnectivityThread" tid=13 Blocked
"ConnectivityThread" prio=5 tid=13 Blocked
| group="main" sCount=1 dsCount=0 flags=1 obj=0x12fc0770 self=0x7d7ab86800
| sysTid=27897 nice=0 cgrp=default sched=0/0 handle=0x7d684114f0
| state=S schedstat=( 247567475 11539483672 1368 ) utm=16 stm=7 core=2 HZ=100
| stack=0x7d6830e000-0x7d68310000 stackSize=1041KB
| held mutexes=
at androidx.work.impl.a.d.c (SourceFile:157) // synchronized (mLock)
- waiting to lock <0x0cbac8c2> (a java.lang.Object) held by thread 1 // trying to lock WorkConstraintsTracker.mLock
at androidx.work.impl.a.a.c.b (SourceFile:133) ConstraintController: mCallback.onConstraintNotMet(mMatchingWorkSpecIds);
at androidx.work.impl.a.a.c.a (SourceFile:142) ConstraintController: updateCallback();
at androidx.work.impl.a.b.d.a (SourceFile:103) listener.onConstraintChanged(mCurrentState);
- locked <0x08a4f10d> (a java.lang.Object) (ConstraintTracker.mLock)
at androidx.work.impl.a.b.e$b.onCapabilitiesChanged (SourceFile:149) (NetworkStateTracker)
at android.net.ConnectivityManager$CallbackHandler.handleMessage (ConnectivityManager.java:3331)
at android.os.Handler.dispatchMessage (Handler.java:106)
at android.os.Looper.loop (Looper.java:214)
at android.os.HandlerThread.run (HandlerThread.java:65)

I have written after the lines what is happening there.

The GreedyScheduler has finished executing and onExecuted is called. This tries to remove the workSpecId from the mConstrainedWorkSpecs list. After removing it it calls mWorkConstraintsTracker.replace to send the new list to the WorkContraintsTracker. This causes a lock of WorkConstraintsTracker.mLock and a call to ConstraintController.replace. This calls ConstraintController.removeListener which tries to lock ConstraintController.mLock but fails/deadlocks. So as you can see it has first locked WorkConstraintsTracker.mLock and then it tries to lock ConstraintController.mLock.

As you can see now the other thread does the opposite, which leads to the deadlock: The WorkManager receives a "onCapabilitiesChanges" message and locks ConstraintTracker.mLock. Then it tries to call onConstraintNotMet but it cannot lock WorkConstraintsTracker.mLock, because it is already locked by the upper thread.

So there is a deadlock because both functions are running at the same time and are locking the locks in opposite order. Can you please fix it? Or did I make a mistake somewhere?

(BTW I am only using WorkManager.getInstance, I am not calling "initialize").

Thank you very much!

Comments

ra...@google.com <ra...@google.com> #2Jun 3, 2019 04:57PM

Assigned to ra...@google.com.

Thank you for the report. We will try to fix this soon. In the meantime, could you please start the emulator from the console (see the commands below), open the camera app to crash it and attach the output, it might help to figure out what the problem is:

cd /Users/YOUR_USERNAME/Library/Android/sdk/emulator
./emulator -list-avds
./emulator -verbose -avd YOUR_AVD_FROM_PREVIOUS_STEP

if there is a crash report to send, please send it and attach the report id.

ra...@google.com <ra...@google.com> #3Jun 3, 2019 05:11PM

We got a crash report (thanks JP): 872e3b20bc34905b. It says EXC_BAD_INSTRUCTION / 0x00000001 and the console also says "Illegal hardware instruction". I suspect the new MacOS brought a new hypervizor which causes this behavior. Haitao, could you please take a look?

d....@googlemail.com <d....@googlemail.com> #4Jun 3, 2019 05:26PM

We have quite some crashes like this:

product_name="AndroidEmulator" AND crash.Reason="EXC_BAD_INSTRUCTION / 0x00000001" AND cpu.Architecture="arm64"

ra...@google.com <ra...@google.com> #5Jun 3, 2019 05:56PM

The most of crashes happen here:

vVertical_Scale_ARGB_8888_Accelerate
vImageVerticalShear_ARGB8888
vImageVerticalShear_ARGB8888
vImageScale_ARGB8888

vRotateClockwise270Degree_ARGB8888_Accelerate2
vRotate_90_ARGB_8888_270Degree_Accelerate2

d....@googlemail.com <d....@googlemail.com> #6Jun 3, 2019 09:38PM

I suspect EXC_BAD_INSTRUCTION happens in vImageRotate90_ARGB8888 and vImageScale_ARGB8888 which are used by webcam on MacOS.

ra...@google.com <ra...@google.com> #7Jun 5, 2019 05:31PM

With complete honesty, I have to say that I’m extremely disappointed by the handling of this issue by google and by the fact that it came out in the first place. I need to use android studio for work purposes and I am forced to switch to a different machine. Mac OS Sonoma has been in beta testing for months and google has had plenty of time to ensure the application would be properly running. I expect this issue to have the maximum priority and to be solved very soon.

ap...@google.com <ap...@google.com> #8Jun 5, 2019 06:15PM

Marked as fixed.

Hi rforzani22, I am sorry for this experience. This bug is my top priority. We expect a fix to be merged within a week. You should be able to download a build directly from our build server (https://ci.android.com/builds/branches/aosp-emu-master-dev/grid) once the fix is merged. The release process will take some additional time.