(Android) Introduce ANR monitor to produce warn-logs

wix · Feb 23, 2020 · a83af02 · a83af02
1 parent 396b1d4
commit a83af02
Show file tree

Hide file tree

Showing 13 changed files with 255 additions and 58 deletions.
diff --git a/detox/android/detox/build.gradle b/detox/android/detox/build.gradle
@@ -75,6 +75,7 @@ dependencies {
     api 'androidx.test:rules:1.2.0'
     api 'androidx.test.ext:junit:1.1.1'
     api 'androidx.annotation:annotation:1.1.0'
+    api 'com.github.anrwatchdog:anrwatchdog:1.4.0'
 
     // Version is the latest; Cannot sync with the Github repo (e.g. android/android-test) because the androidx
     // packaging version of associated classes is simply not there...

diff --git a/detox/android/detox/src/main/java/com/wix/detox/DetoxANRHandler.kt b/detox/android/detox/src/main/java/com/wix/detox/DetoxANRHandler.kt
@@ -0,0 +1,24 @@
+package com.wix.detox
+
+import android.util.Log
+import com.github.anrwatchdog.ANRWatchDog
+
+class DetoxANRHandler(private val wsClient: WebSocketClient) {
+    fun attach() {
+        ANRWatchDog().setReportMainThreadOnly().setANRListener {
+            val info = mapOf("threadDump" to Log.getStackTraceString(it))
+            wsClient.sendAction(ACTION_NAME, info, MESSAGE_ID)
+        }.start()
+
+        ANRWatchDog().setANRListener {
+            Log.e(LOG_TAG, "App nonresnponsive detection!", it)
+        }.start()
+    }
+
+    companion object {
+        val LOG_TAG: String = DetoxANRHandler::class.java.simpleName
+
+        private const val ACTION_NAME = "AppNonresponsiveDetected"
+        private const val MESSAGE_ID = -10001L
+    }
+}
diff --git a/detox/android/detox/src/main/java/com/wix/detox/DetoxCrashHandler.kt b/detox/android/detox/src/main/java/com/wix/detox/DetoxCrashHandler.kt
@@ -1,22 +1,21 @@
 package com.wix.detox
 
 import android.util.Log
-import org.apache.commons.lang3.exception.ExceptionUtils
 
 class DetoxCrashHandler(private val wsClient: WebSocketClient) {
     fun attach() {
         Thread.setDefaultUncaughtExceptionHandler { thread, exception ->
             Log.e(LOG_TAG, "Crash detected!!! thread=${thread.name} (${thread.id})")
 
-            val crashInfo = mapOf("errorDetails" to "@Thread ${thread.name}(${thread.id}):\n${ExceptionUtils.getStackTrace(exception)}")
-            wsClient.sendAction(APP_CRASH_ACTION_NAME, crashInfo, APP_CRASH_MESSAGE_ID)
+            val crashInfo = mapOf("errorDetails" to "@Thread ${thread.name}(${thread.id}):\n${Log.getStackTraceString(exception)}")
+            wsClient.sendAction(ACTION_NAME, crashInfo, MESSAGE_ID)
         }
     }
 
     companion object {
         val LOG_TAG: String = DetoxCrashHandler::class.java.simpleName
 
-        const val APP_CRASH_ACTION_NAME = "AppWillTerminateWithError"
-        const val APP_CRASH_MESSAGE_ID = -10000L
+        private const val ACTION_NAME = "AppWillTerminateWithError"
+        private const val MESSAGE_ID = -10000L
     }
 }
diff --git a/detox/android/detox/src/main/java/com/wix/detox/DetoxManager.java b/detox/android/detox/src/main/java/com/wix/detox/DetoxManager.java
@@ -7,6 +7,8 @@
 import androidx.annotation.NonNull;
 import android.util.Log;
 
+import com.github.anrwatchdog.ANRError;
+import com.github.anrwatchdog.ANRWatchDog;
 import com.wix.detox.instruments.DetoxInstrumentsManager;
 import com.wix.detox.reactnative.ReactNativeExtension;
 import com.wix.detox.systeminfo.Environment;
@@ -72,6 +74,7 @@ public void run() {
                     initReactNativeIfNeeded();
                     initWSClient();
                     initCrashHandler();
+                    initANRListener();
                     initActionHandlers();
                 }
             });
@@ -138,6 +141,10 @@ private void initCrashHandler() {
         new DetoxCrashHandler(wsClient).attach();
     }
 
+    private void initANRListener() {
+        new DetoxANRHandler(wsClient).attach();
+    }
+
     private void initActionHandlers() {
         readyActionHandler = new ReadyActionHandler(wsClient, testEngineFacade);
         actionHandlers.clear();

diff --git a/detox/src/Detox.js b/detox/src/Detox.js
@@ -1,7 +1,7 @@
 const _ = require('lodash');
 const util = require('util');
 const logger = require('./utils/logger');
-const log = require('./utils/logger').child({ __filename });
+const log = logger.child({ __filename });
 const Device = require('./devices/Device');
 const IosDriver = require('./devices/drivers/IosDriver');
 const SimulatorDriver = require('./devices/drivers/SimulatorDriver');
@@ -57,6 +57,7 @@ class Detox {
     }
 
     this._client = new Client(sessionConfig);
+    this._client.setNonresponsivenessListener(this._onNonresnponsivenessEvent.bind(this));
     await this._client.connect();
 
     const DeviceDriverClass = DEVICE_CLASSES[this._deviceConfig.type];
@@ -173,6 +174,18 @@ class Detox {
     }
   }
 
+  _onNonresnponsivenessEvent(params) {
+    const message = [
+      'Application nonresponsiveness detected!',
+      'On Android, this could imply an ANR alert, which evidently causes tests to fail.',
+      'Here\'s the native main-thread stacktrace from the device, to help you out (refer to device logs for the complete thread dump):',
+      params.threadDump,
+      'Refer to https://developer.android.com/training/articles/perf-anr for further details.'
+    ].join('\n');
+
+    log.warn({ event: 'APP_NONRESPONSIVE' }, message);
+  }
+
   async _dumpUnhandledErrorsIfAny({ testName, pendingRequests }) {
     if (pendingRequests) {
       this._client.dumpPendingRequests({testName});

diff --git a/detox/src/Detox.test.js b/detox/src/Detox.test.js
@@ -14,6 +14,8 @@ const defaultPlatformEnv = {
 };
 
 describe('Detox', () => {
+  let client;
+  let mockLogger;
   let fs;
   let Detox;
   let detox;
@@ -27,12 +29,16 @@ describe('Detox', () => {
   const deviceMockData = {lastConstructorArguments: null};
 
   beforeEach(async () => {
-    function setCustomMock(modulePath, dataObject) {
+    function setCustomClassMock(modulePath, dataObject, mockObject = {}) {
       const JestMock = jest.genMockFromModule(modulePath);
       class FinalMock extends JestMock {
         constructor(...rest) {
           super(rest);
           dataObject.lastConstructorArguments = rest;
+
+          Object.keys(mockObject).forEach((key) => {
+            this[key] = mockObject[key].bind(this);
+          });
         }
         on(event, callback) {
           if (event === 'launchApp') {
@@ -43,13 +49,23 @@ describe('Detox', () => {
       jest.setMock(modulePath, FinalMock);
     }
 
-    jest.mock('./utils/logger');
     jest.mock('fs');
     jest.mock('fs-extra');
     fs = require('fs');
     jest.mock('./ios/expect');
-    setCustomMock('./client/Client', clientMockData);
-    setCustomMock('./devices/Device', deviceMockData);
+
+    mockLogger = jest.genMockFromModule('./utils/logger');
+    mockLogger.child.mockReturnValue(mockLogger);
+    jest.mock('./utils/logger', () => mockLogger);
+
+    setCustomClassMock('./devices/Device', deviceMockData);
+
+    client = {
+      setNonresponsivenessListener: jest.fn(),
+      getPendingCrashAndReset: jest.fn(),
+      dumpPendingRequests: jest.fn(),
+    };
+    setCustomClassMock('./client/Client', clientMockData, client);
 
     process.env = Object.assign({}, defaultPlatformEnv[process.platform]);
 
@@ -59,8 +75,6 @@ describe('Detox', () => {
     jest.mock('./devices/drivers/SimulatorDriver');
     jest.mock('./devices/Device');
     jest.mock('./server/DetoxServer');
-    jest.mock('./client/Client');
-    jest.mock('./utils/logger');
   });
 
   it(`Passing --cleanup should shutdown the currently running device`, async () => {
@@ -158,10 +172,11 @@ describe('Detox', () => {
   });
 
   it(`handleAppCrash if client has a pending crash`, async () => {
+    client.getPendingCrashAndReset.mockReturnValueOnce('crash');
+
     Detox = require('./Detox');
     detox = new Detox({deviceConfig: validDeviceConfigWithSession});
     await detox.init();
-    detox._client.getPendingCrashAndReset.mockReturnValueOnce('crash'); // TODO: rewrite to avoid accessing private fields
     await detox.afterEach({ title: 'a', fullName: 'b', status: 'failed' });
     expect(device.launchApp).toHaveBeenCalledTimes(1);
   });
@@ -174,7 +189,7 @@ describe('Detox', () => {
     await detox.init();
     await detox.afterEach(testSummary);
 
-    expect(detox._client.dumpPendingRequests).not.toHaveBeenCalled();
+    expect(client.dumpPendingRequests).not.toHaveBeenCalled();
   });
 
   it(`handleAppCrash should dump pending requests if testSummary has timeout flag`, async () => {
@@ -184,7 +199,42 @@ describe('Detox', () => {
 
     await detox.init();
     await detox.afterEach(testSummary);
-    expect(detox._client.dumpPendingRequests).toHaveBeenCalled();
+    expect(client.dumpPendingRequests).toHaveBeenCalled();
+  });
+
+  it(`should register an async nonresponsiveness listener`, async () => {
+    Detox = require('./Detox');
+    detox = new Detox({deviceConfig: validDeviceConfigWithSession});
+
+    await detox.init();
+
+    expect(client.setNonresponsivenessListener).toHaveBeenCalled();
+  });
+
+  it(`should log thread-dump provided by a nonresponsiveness event`, async () => {
+    const callbackParams = {
+      threadDump: 'mockThreadDump',
+    };
+    const expectedMessage = [
+      'Application nonresponsiveness detected!',
+      'On Android, this could imply an ANR alert, which evidently causes tests to fail.',
+      'Here\'s the native main-thread stacktrace from the device, to help you out (refer to device logs for the complete thread dump):',
+      callbackParams.threadDump,
+      'Refer to https://developer.android.com/training/articles/perf-anr for further details.'
+    ].join('\n');
+
+    Detox = require('./Detox');
+    detox = new Detox({deviceConfig: validDeviceConfigWithSession});
+
+    await detox.init();
+    await invokeDetoxCallback();
+
+    expect(mockLogger.warn).toHaveBeenCalledWith({ event: 'APP_NONRESPONSIVE' }, expectedMessage);
+
+    async function invokeDetoxCallback() {
+      const callback = client.setNonresponsivenessListener.mock.calls[0][0];
+      await callback(callbackParams);
+    }
   });
 
   describe('.artifactsManager', () => {

diff --git a/detox/src/client/Client.js b/detox/src/client/Client.js
@@ -110,6 +110,10 @@ class Client {
     return crash;
   }
 
+  setNonresponsivenessListener(clientCallback) {
+    this.setActionListener(new actions.AppNonresponsive(), (event) => clientCallback(event.params));
+  }
+
   setActionListener(action, clientCallback) {
     this.ws.setEventCallback(action.messageId, (response) => {
       const parsedResponse = JSON.parse(response);

diff --git a/detox/src/client/Client.test.js b/detox/src/client/Client.test.js
@@ -328,13 +328,31 @@ describe('Client', () => {
     expect(client.getPendingCrashAndReset()).toBeDefined();
 
     function triggerAppWillTerminateWithError() {
-      const event = JSON.stringify({
-        type: "AppWillTerminateWithError",
-        params: {errorDetails: "someDetails"},
-        messageId: -10000
-      });
+      const event = createAppWillTerminateEvent();
+      client.ws.setEventCallback.mock.calls[0][1](JSON.stringify(event));
+    }
+  });
+
+  it(`should allow for a nonresponsiveness listener`, async () => {
+    client.ws.setEventCallback = jest.fn();
+    await connect();
+
+    const callback = setNonresponsiveEventCallbackMock();
+    const event = triggerAppNonresponsiveEvent();
+
+    expect(callback).toHaveBeenCalledWith(event.params);
 
-      client.ws.setEventCallback.mock.calls[0][1](event);
+    function setNonresponsiveEventCallbackMock() {
+      const callback = jest.fn();
+      client.ws.setEventCallback.mockReset();
+      client.setNonresponsivenessListener(callback);
+      return callback;
+    }
+
+    function triggerAppNonresponsiveEvent() {
+      const event = createAppNonresponsiveEvent();
+      client.ws.setEventCallback.mock.calls[0][1](JSON.stringify(event));
+      return event;
     }
   });
 
@@ -353,4 +371,16 @@ describe('Client', () => {
         messageId: messageId
       }));
   }
+
+  const createAppNonresponsiveEvent = () => ({
+    type: "AppNonresponsiveDetected",
+    params: {threadDump: "someThreadStacks"},
+    messageId: -10001
+  });
+
+  const createAppWillTerminateEvent = () => ({
+    type: "AppWillTerminateWithError",
+    params: {errorDetails: "someDetails"},
+    messageId: -10000
+  });
 });
diff --git a/detox/src/client/actions/actions.js b/detox/src/client/actions/actions.js
@@ -161,6 +161,17 @@ class AppWillTerminateWithError extends Action {
   }
 }
 
+class AppNonresponsive extends Action {
+  constructor(params) {
+    super(params);
+    this.messageId = -10001;
+  }
+
+  handle(response) {
+    this.expectResponseOfType(response, 'AppNonresponsiveDetected');
+  }
+}
+
 module.exports = {
   Login,
   WaitForBackground,
@@ -173,5 +184,6 @@ module.exports = {
   CurrentStatus,
   Shake,
   SetInstrumentsRecordingState,
-  AppWillTerminateWithError
+  AppWillTerminateWithError,
+  AppNonresponsive,
 };