Debugging espresso tests hangs at 'Instantiating tests...' with Object.wait error

1.8k Views Asked by At

Sorry for the super long question, i'm a bit lost.

I can run the test fine, however when debugging it gets stuck at the 'instantiating tests...' phase. In my console i see the below log output. The main error seems to be:

A/xxxx.xxxx.debu: instrumentation.cc:267] Check failed: m == frame.method_ (m=0x72c770c558, frame.method_=0x6feec140) Expected void java.lang.Object.wait(long, int), Found void java.lang.Object.wait(long, int)

I can find no reference to instrumentation.cc:267 in code or in google

Testing started at 16:29 ...

07/23 16:29:42: Launching 'showEmptyStateWhen...()' on OnePlus ONEPLUS A5010.
Running tests

$ adb shell am instrument -w -r  --no-window-animation  -e debug true -e class 'com.xxx.xxx.ui.LeaderboardTest#showEmptyStateWhenNoEntries' com.xxx.xxx.debug.test/com.xxx.xxx.test.TestAppJUnitRunner
Waiting for application to come online: com.xxx.xxx.debug | com.xxx.xxx.debug.test
Waiting for application to come online: com.xxx.xxx.debug | com.xxx.xxx.debug.test
Connecting to com.xxx.xxx.debug
Waiting for application to start debug server
Waiting for application to come online: com.xxx.xxx.debug | com.xxx.xxx.debug.test
Connected to process 17819 on device 'oneplus-oneplus_a5010-533ce755'.
Connecting to com.xxx.xxx.debug
Waiting for application to start debug server
Waiting for application to come online: com.xxx.xxx.debug | com.xxx.xxx.debug.test
Connecting to com.xxx.xxx.debug
Waiting for application to start debug server
Waiting for application to come online: com.xxx.xxx.debug | com.xxx.xxx.debug.test
Connecting to com.xxx.xxx.debug
Capturing and displaying logcat messages from application. This behavior can be disabled in the "Logcat output" section of the "Debugger" settings page.
I/rics.xxx.debu: Late-enabling -Xcheck:jni
I/rics.xxx.debu: The ClassLoaderContext is a special shared library.
I/rics.xxx.debu: The ClassLoaderContext is a special shared library.
I/chatty: uid=10132(com.xxx.xxx.debug) identical 1 line
I/rics.xxx.debu: The ClassLoaderContext is a special shared library.
I/Perf: Connecting to perf service.
I/rics.xxx.debu: The ClassLoaderContext is a special shared library.
I/rics.xxx.debu: The ClassLoaderContext is a special shared library.
W/rics.xxx.debu: Accessing hidden method Landroid/app/Instrumentation;->execStartActivity(Landroid/content/Context;Landroid/os/IBinder;Landroid/os/IBinder;Landroid/app/Activity;Landroid/content/Intent;ILandroid/os/Bundle;)Landroid/app/Instrumentation$ActivityResult; (light greylist, linking)
Accessing hidden method Landroid/app/Instrumentation;->execStartActivity(Landroid/content/Context;Landroid/os/IBinder;Landroid/os/IBinder;Ljava/lang/String;Landroid/content/Intent;ILandroid/os/Bundle;)Landroid/app/Instrumentation$ActivityResult; (light greylist, linking)
W/TestAppJUnitRunner: Opening Dex
W/TestAppJUnitRunner: Creating new application for Espresso Testing
V/FA: Registered activity lifecycle callback
I/FirebaseInitProvider: FirebaseApp initialization successful
I/CrashlyticsInitProvider: CrashlyticsInitProvider skipping initialization
D/NetworkSecurityConfig: No Network Security Config specified, using platform default
I/DpmTcmClient: RegisterTcmMonitor from: com.android.okhttp.TcmIdleTimerMonitor
V/FA: App measurement collection enabled
V/FA: App measurement enabled for app package, google app id: com.xxx.xxx.debug, 1:282636929683:android:47d41ff836b04659e81b66
I/FA: App measurement initialized, version: 22048
To enable debug logging run: adb shell setprop log.tag.FA VERBOSE
To enable faster debug mode event logging run:
adb shell setprop debug.firebase.analytics.app com.xxx.xxx.debug
D/FA: Debug-level message logging enabled
D/LeakCanary: Installing AppWatcher
I/AndroidJUnitRunner: Waiting for debugger to connect...
I/System.out: Sending WAIT chunk
V/FA: Connecting to remote service
V/FA: Connection attempt already in progress
I/System.out: Debugger has connected
I/System.out: waiting for debugger to settle...
Connected to the target VM, address: 'localhost:8601', transport: 'socket'
I/chatty: uid=10132(com.xxx.xxx.debug) identical 4 lines
I/System.out: waiting for debugger to settle...
I/System.out: waiting for debugger to settle...
I/chatty: uid=10132(com.xxx.xxx.debug) identical 1 line
I/System.out: waiting for debugger to settle...
I/System.out: debugger has settled (1338)
I/AndroidJUnitRunner: Debugger connected.
I/MonitoringInstr: Instrumentation started!
I/MonitoringInstr: Setting context classloader to 'dalvik.system.PathClassLoader[DexPathList[[zip file "/system/framework/android.test.mock.jar", zip file "/system/framework/android.test.runner.jar", zip file "/system/framework/org.apache.http.legacy.boot.jar", zip file "/data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/base.apk", zip file "/data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/base.apk"],nativeLibraryDirectories=[/data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/lib/arm64, /data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/lib/arm64, /data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/base.apk!/lib/arm64-v8a, /data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/base.apk!/lib/arm64-v8a, /system/lib64]]]', Original: 'dalvik.system.PathClassLoader[DexPathList[[zip file "/system/framework/android.test.mock.jar", zip file "/system/framework/android.test.runner.jar", zip file "/system/framework/org.apache.http.legacy.boot.jar", zip file "/data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/base.apk", zip file "/data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/base.apk"],nativeLibraryDirectories=[/data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/lib/arm64, /data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/lib/arm64, /data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/base.apk!/lib/arm64-v8a, /data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/base.apk!/lib/arm64-v8a, /system/lib64]]]'
I/[Koin]: [init] declare Android Context
I/[Koin]: bind type:'android.content.Context' ~ [type:Single,primary_type:'android.content.Context']
I/[Koin]: bind type:'android.app.Application' ~ [type:Single,primary_type:'android.app.Application']
I/[Koin]: bind type:'com.xxx.xxx.rust.App' ~ [type:Single,primary_type:'com.xxx.xxx.rust.App']
I/[Koin]: total 3 registered definitions
I/[Koin]: load modules in 0.852136 ms
W/rics.xxx.debu: Accessing hidden field Lsun/misc/Unsafe;->theUnsafe:Lsun/misc/Unsafe; (light greylist, reflection)
W/rics.xxx.debu: Current dex file has more than one class in it. Calling RetransformClasses on this class might fail if no transformations are applied to it!
W/rics.xxx.debu: Current dex file has more than one class in it. Calling RetransformClasses on this class might fail if no transformations are applied to it!
D/LeakCanary: org.junit.Test detected in classpath, app is running tests => disabling heap dumping & analysis
D/LeakCanary: Updated LeakCanary.config: Config(dumpHeap=false)
I/MonitoringInstr: No JSBridge.
D/FA: Connected to remote service
V/FA: Processing queued up service tasks: 2
I/MonitoringInstr: Setting context classloader to 'dalvik.system.PathClassLoader[DexPathList[[zip file "/system/framework/android.test.mock.jar", zip file "/system/framework/android.test.runner.jar", zip file "/system/framework/org.apache.http.legacy.boot.jar", zip file "/data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/base.apk", zip file "/data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/base.apk"],nativeLibraryDirectories=[/data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/lib/arm64, /data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/lib/arm64, /data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/base.apk!/lib/arm64-v8a, /data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/base.apk!/lib/arm64-v8a, /system/lib64]]]', Original: 'dalvik.system.PathClassLoader[DexPathList[[zip file "/system/framework/android.test.mock.jar", zip file "/system/framework/android.test.runner.jar", zip file "/system/framework/org.apache.http.legacy.boot.jar", zip file "/data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/base.apk", zip file "/data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/base.apk"],nativeLibraryDirectories=[/data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/lib/arm64, /data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/lib/arm64, /data/app/com.xxx.xxx.debug.test-wLTCT-KdJLBvnaz-MPHnsA==/base.apk!/lib/arm64-v8a, /data/app/com.xxx.xxx.debug-TMZta6Gwfny405iw5P3XHw==/base.apk!/lib/arm64-v8a, /system/lib64]]]'
I/UsageTrackerFacilitator: Usage tracking enabled
A/rics.xxx.debu: instrumentation.cc:267] Check failed: m == frame.method_ (m=0x72c770c558, frame.method_=0x6feec140) Expected void java.lang.Object.wait(long, int), Found void java.lang.Object.wait(long, int)

Here's the logs from a successful run of the test. Specifically, the section of logs where it fails when debugging.

I/MonitoringInstr: Setting context classloader to 'dalvik.system.PathClassLoader[DexPathList[[zip file "/system/framework/android.test.mock.jar", zip file "/system/framework/android.test.runner.jar", zip file "/system/framework/org.apache.http.legacy.boot.jar", zip file "/data/app/com.xxxx.xxxx.debug.test-zybM_FbDvAOU4iJ_hV3x9w==/base.apk", zip file "/data/app/com.xxxx.xxxx.debug-UCsb2m8du-jGof7-p5hIkQ==/base.apk"],nativeLibraryDirectories=[/data/app/com.xxxx.xxxx.debug.test-zybM_FbDvAOU4iJ_hV3x9w==/lib/arm64, /data/app/com.xxxx.xxxx.debug-UCsb2m8du-jGof7-p5hIkQ==/lib/arm64, /data/app/com.xxxx.xxxx.debug.test-zybM_FbDvAOU4iJ_hV3x9w==/base.apk!/lib/arm64-v8a, /data/app/com.xxxx.xxxx.debug-UCsb2m8du-jGof7-p5hIkQ==/base.apk!/lib/arm64-v8a, /system/lib64]]]', Original: 'dalvik.system.PathClassLoader[DexPathList[[zip file "/system/framework/android.test.mock.jar", zip file "/system/framework/android.test.runner.jar", zip file "/system/framework/org.apache.http.legacy.boot.jar", zip file "/data/app/com.xxxx.xxxx.debug.test-zybM_FbDvAOU4iJ_hV3x9w==/base.apk", zip file "/data/app/com.xxxx.xxxx.debug-UCsb2m8du-jGof7-p5hIkQ==/base.apk"],nativeLibraryDirectories=[/data/app/com.xxxx.xxxx.debug.test-zybM_FbDvAOU4iJ_hV3x9w==/lib/arm64, /data/app/com.xxxx.xxxx.debug-UCsb2m8du-jGof7-p5hIkQ==/lib/arm64, /data/app/com.xxxx.xxxx.debug.test-zybM_FbDvAOU4iJ_hV3x9w==/base.apk!/lib/arm64-v8a, /data/app/com.xxxx.xxxx.debug-UCsb2m8du-jGof7-p5hIkQ==/base.apk!/lib/arm64-v8a, /system/lib64]]]'
I/UsageTrackerFacilitator: Usage tracking enabled
D/TestExecutor: Adding listener androidx.test.internal.runner.listener.LogRunListener
D/TestExecutor: Adding listener androidx.test.internal.runner.listener.InstrumentationResultPrinter
D/TestExecutor: Adding listener androidx.test.internal.runner.listener.ActivityFinisherRunListener
I/TestRunner: run started: 1 tests

From this, it looks like its failing when adding those 3 listeners

The test itself is unimportant as its not even reaching the first line of the test.

The point at which it seems to fail is important. I'm trying to mock the following didStart() call in my App class which is called when my android Application class is created. This is part of a larger task to mock out the calls to my native android library.

class App constructor (val self: Long) {
    companion object {
        init {
            try {
                System.loadLibrary("android")
            } catch (e: UnsatisfiedLinkError) {
                System.err.println("Native code library failed to load when creating ${this.javaClass.name} ")
                e.printStackTrace()
                exitProcess(1)
            }
        }
        @JvmStatic private external fun _did_start(self: Long)
    }
    fun didStart() {
        App._did_start(self)
    }
}
abstract class MyApp: Application() {
    private val rustApp: RustApp by inject()

    fun setup() {
        rustApp.didStart()
        ...
    }
}

To do this, I've subclassed my app and added some custom koin loading to allow the didStart() call to be called successfully, before i get the chance to mock things within the test itself.

class MyAppEspresso : MyApp() {

    override fun onCreate() {
        super.onCreate()
        startKoin {
            androidLogger()
            androidContext(this@MyAppEspresso)
            modules(listOf(module {
                        single {
                            mockk<App>() {
                                every { didStart() } returns Unit
                            }
                        }
                    }))
        }
        super.setup()
    }
}

Here's my build info:

dependencies {
    ...
    androidTestImplementation "io.mockk:mockk-android:1.10.0"
    androidTestImplementation "androidx.test.espresso:espresso-core:3.2.0"
    androidTestImplementation "androidx.test:runner:1.2.0"
    androidTestImplementation "androidx.test:rules:1.2.0"
    androidTestImplementation 'androidx.test.ext:junit:1.1.1'
}

Android studio info if thats useful?

Android Studio 4.0
Build #AI-193.6911.18.40.6514223, built on May 20, 2020
Runtime version: 1.8.0_242-release-1644-b3-6222593 x86_64
VM: OpenJDK 64-Bit Server VM by JetBrains s.r.o
macOS 10.13.6
GC: ParNew, ConcurrentMarkSweep
Memory: 4029M
Cores: 8
Registry: ide.new.welcome.screen.force=true
Non-Bundled Plugins: org.jetbrains.kotlin, com.google.services.firebase, izhangzhihao.rainbow.brackets, org.toml.lang, org.rust.lang

I'm mainly sttruggling to debug this due to the lack of useful error message. Any suggestions welcome!

0

There are 0 best solutions below