Android Studio connects to target VM on device but won't debug it - most of the time

Question

I'm using Android Studio 1.0.2 in ubuntu 14.04 on an app project migrated from Eclipse. I'm new to both Studio/IntelliJ and Gradle. When I go to debug the app by clicking on the debug icon in Studio:

• the app is built by Gradle
• the Choose Device dialog pops up and I can select my phone
• the Debug pane says under Variables: "Connected to the target VM, address: 'localhost:8601',transport: 'socket'

but none of the debugger icons for stepping into or over the code, etc, are enabled and the debugger won't stop at any breakpoints.

I haven't set android:debuggable="true" in my manifest as that seems to be deprecated now.

I've tried removing all but one JDK as suggested here but I still have this problem.

The weird thing is that sometimes the debugger does behave as expected but, 8 or 9 times out of 10, it just won't work. This is immensely frustrating! I get the same behaviour with the same code and version of Studio on another machine as well. Any ideas on how to get Studio's debugger to behave reliably please?

Update 23 Jan: The same instance of Studio is able to debug a newly created 'Hello World' app fine, so it's probably something to do with my app's project which is the problem, but I don't know what. Maybe it only occurs for some projects migrated from Eclipse - e.g., when manifests are merged; but this is a complete guess.

Update 7 Feb: If I set the debugger to suspend on any exception then I see this exception thrown first: libcore.io.ErrnoException: access failed: ENOENT (No such file or directory). The stacktrace for the main thread is:

<1> main@830017070344, prio=5, in group 'main', status: 'RUNNING'
  at libcore.io.ForwardingOs.access(ForwardingOs.java:38)
  at java.io.File.doAccess(File.java:283)
  at java.io.File.exists(File.java:363)
  at dalvik.system.DexPathList.splitAndAdd(DexPathList.java:168)
  at dalvik.system.DexPathList.splitPaths(DexPathList.java:149)
  at dalvik.system.DexPathList.splitLibraryPath(DexPathList.java:130)
  at dalvik.system.DexPathList.<init>(DexPathList.java:98)
  at dalvik.system.BaseDexClassLoader.<init>(BaseDexClassLoader.java:52)
  at dalvik.system.PathClassLoader.<init>(PathClassLoader.java:65)
  at android.app.ApplicationLoaders.getClassLoader(ApplicationLoaders.java:57)
  at android.app.LoadedApk.getClassLoader(LoadedApk.java:317)
  at android.app.LoadedApk.makeApplication(LoadedApk.java:493)
  at android.app.ActivityThread.handleBindApplication(ActivityThread.java:4170)
  at android.app.ActivityThread.access$1400(ActivityThread.java:134)
  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1278)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at android.app.ActivityThread.main(ActivityThread.java:4867)
  at java.lang.reflect.Method.invokeNative(Method.java:-1)
  at java.lang.reflect.Method.invoke(Method.java:511)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1007)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:774)
  at dalvik.system.NativeStart.main(NativeStart.java:-1)

This is followed by loads of BootClassLoader exceptions as the classloader tries and fails to load the classes in my app, and Google's classes. On my device all I see is the action bar - nothing else:(. I saw someone else have a similar problem here. Interestingly they also migrated from Eclipse to IntelliJ but, unlike them, I didn't have the problem in Eclipse already AFAIK. They never seemed to get to the bottom of it. Any ideas please? I still don't understand what triggers this because sometimes the debugger does work as expected.

Answer 1

Short answer: there's a known bug in Google Play Services v6.5.87 which means that Google Analytics (GA) is highly likely to deadlock when GoogleAnalytics.getInstance() tries to load the XML tracker file defined in your manifest. You can work around it by configuring your GA tracker programatically, as I did, or by downgrading the version of Google Play Services you're using (or waiting for a fix in a later release!). See here, here and here for more info.

My 'Hello World' app worked because it didn't use GA. I noticed that the dependencies section of my app's build.gradle file in Android Studio had said this:

compile 'com.google.android.gms:play-services:+'

I'm guessing the original Eclipse version of my app was referencing an older version of Google Play Services that did not have this issue and that when the app was migrated to Android Studio it was coincidentally given v6.5.87 with this bug. Thanks a lot Google! I've since changed the above line to

compile 'com.google.android.gms:play-services:6.5.87'

so at least I know exactly what I'm getting and can decide myself when to upgrade!

As for the class-loading errors they appear to be unrelated (and harmless?) but I still don't know what's causing them.

Long answer: I branched my code and stripped the app right down to its bare essentials with only a single activity. It was still crashing on startup but this time I noticed this line in LogCat:

I/dalvikvm﹕ Wrote stack traces to '/data/anr/traces.txt'

I used this command in my filesystem to pull the trace dump from my phone to my computer:

~/android-sdks/platform-tools$ ./adb pull /data/anr/traces.txt

At the head of traces.txt I saw this (my app packages and names have been changed):

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)

"main" prio=5 tid=1 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x41606508 self=0x415f6660
  | sysTid=4925 nice=0 sched=0/0 cgrp=[no-cpu-subsys] handle=1074638640
  | schedstat=( 71380610 113708500 297 ) utm=3 stm=4 core=1
  at com.google.android.gms.analytics.ae.getLogger((null):~-1)
  - waiting to lock <0x420608a0>  held by tid=13 (client_id_fetcher)
  at com.google.android.gms.analytics.ae.V((null):-1)
  at com.google.android.gms.analytics.GoogleAnalytics.a((null):-1)
  at com.google.android.gms.analytics.GoogleAnalytics.eZ((null):-1)
  at com.google.android.gms.analytics.GoogleAnalytics.<init>((null):-1)
  at com.google.android.gms.analytics.GoogleAnalytics.<init>((null):-1)
  at com.google.android.gms.analytics.GoogleAnalytics.getInstance((null):-1)
  at com.mycompany.mypackage.MyApp.getTracker(MyApp.java:61)
  at com.mycompany.mypackage.MyActivity.onCreate(MyActivity.java:125)
  at android.app.Activity.performCreate(Activity.java:5047)
  at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1094)
  at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2056)
  at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2117)
  at android.app.ActivityThread.access$700(ActivityThread.java:134)
  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1218)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at android.app.ActivityThread.main(ActivityThread.java:4867)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:511)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1007)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:774)
  at dalvik.system.NativeStart.main(Native Method)

"client_id_fetcher" prio=5 tid=13 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x4205e778 self=0x5a51d948
  | sysTid=4941 nice=0 sched=0/0 cgrp=[no-cpu-subsys] handle=1515314584
  | schedstat=( 16052255 21850583 224 ) utm=1 stm=0 core=1
  at com.google.android.gms.analytics.GoogleAnalytics.eY((null):~-1)
  - waiting to lock <0x4205af48>  held by tid=1 (main)
  at com.google.android.gms.analytics.ae.getLogger((null):-1)
  at com.google.android.gms.analytics.ae.V((null):-1)
  at com.google.android.gms.analytics.k.eq((null):-1)
  at com.google.android.gms.analytics.k$1.run((null):-1)

"GAThread" prio=5 tid=12 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x4205b950 self=0x415e59c8
  | sysTid=4940 nice=10 sched=0/0 cgrp=[no-cpu-subsys] handle=1096703512
  | schedstat=( 15808103 21026609 173 ) utm=1 stm=0 core=1
  at com.google.android.gms.analytics.GoogleAnalytics.getInstance((null):~-1)
  - waiting to lock <0x4205af48>  held by tid=1 (main)
  at com.google.android.gms.analytics.w.<init>((null):-1)
  at com.google.android.gms.analytics.x.init((null):-1)
  at com.google.android.gms.analytics.x.run((null):-1)

You can see thread id (tid) 1, "main", is calling GoogleAnalytics.getInstance() but is blocked waiting for lock <0x420608a0> held by tid=13 (client_id_fetcher)

But thread 13, "client_id_fetcher", is blocked waiting for lock <0x4205af48> held by tid=1 (main). Deadlock! (Thread 12, "GAThread" is also blocked waiting for the same lock.) After seeing this I was able to Google for deadlock in GoogleAnalytics.getInstance() and that led me to the workarounds mentioned above. Hope this helps someone else because it took me a long time to track this one down!