Repository: wix/Detox (js)

Issue:
Report thread-dump when ANR's are in effect
**Is your feature request related to a problem? Please describe.**
Detox needs to introduce a way to deal with [ANR's](https://developer.android.com/topic/performance/vitals/anr).

Though their coming-into-existence is _not_ a test-framework matter per se, their instantiation (i.e. when alerted by Android) evidently causes all tests to bulkly-fail and with no clear hint as to why they've appeared in the first place. The latter fact makes it very hard to trace back when running on CI agents, in particular. Detox needs to step up :-)

**Describe the solution you'd like**
Have some mechanism that would detect and log a thread-dump when ANR's are in-effect, perhaps even provide the [system's traces file](https://developer.android.com/topic/performance/vitals/anr#pull_a_traces_file) as an artifact.

**Describe alternatives you've considered**
N/A

**Additional context**
N/A


Pull request description:
(Android) Introduce ANR monitor to produce warn-logs
- [ ] This is a small change 
- [x] This change has been discussed in issue #1925 and the solution has been agreed upon with maintainers.

---

**Description:**

Resolves #1925. Introduces usage of the very interesting [ANR-WatchDog project](https://github.com/SalomonBrys/ANR-WatchDog) for the sake of ANR-state proximation. The ends result is a warning on the Detox (tester) side with a main-thread stacktrace, when main-thread blockage is detected, alongside a complete thread-dump on the device logs.

Integration of it all was pretty straightforward, but testing this (e2e) was a bit of a pain since logs are not easy to intercept.

Patch:
diff --git a/detox/android/detox/build.gradle b/detox/android/detox/build.gradle
index 6e95ff383..c7b17341b 100644
--- 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
new file mode 100644
index 000000000..ceb0f9670
--- /dev/null
+++ 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
index 5b2b5c981..7d354db72 100644
--- 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
index 6d9244019..cb18a90e2 100644
--- 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 android.os.Looper;
 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 @@ class DetoxManager implements WebSocketClient.ActionHandler {
                     initReactNativeIfNeeded();
                     initWSClient();
                     initCrashHandler();
+                    initANRListener();
                     initActionHandlers();
                 }
             });
@@ -138,6 +141,10 @@ class DetoxManager implements WebSocketClient.ActionHandler {
         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
index 5e91dc07a..a4ba4ac2a 100644
--- 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/client/Client.js b/detox/src/client/Client.js
index f69b69d57..97f2e2548 100644
--- 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/actions/actions.js b/detox/src/client/actions/actions.js
index 1d060cb46..3ba8621e1 100644
--- 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,
 };


Test patch:
diff --git a/detox/src/Detox.test.js b/detox/src/Detox.test.js
index b157119df..545d4fe83 100644
--- 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.test.js b/detox/src/client/Client.test.js
index d042ec7e7..86091b159 100644
--- 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/test/android/app/src/main/java/com/example/NativeModule.java b/detox/test/android/app/src/main/java/com/example/NativeModule.java
index b08b0498c..932d626a7 100644
--- a/detox/test/android/app/src/main/java/com/example/NativeModule.java
+++ b/detox/test/android/app/src/main/java/com/example/NativeModule.java
@@ -26,10 +26,11 @@ import java.util.Set;
 
 public class NativeModule extends ReactContextBaseJavaModule {
 
-    public static final String NAME = "NativeModule";
-    ReactApplicationContext reactContext;
+    private static final String NAME = "NativeModule";
 
-    public NativeModule(ReactApplicationContext reactContext) {
+    private ReactApplicationContext reactContext;
+
+    NativeModule(ReactApplicationContext reactContext) {
         super(reactContext);
         this.reactContext = reactContext;
     }
@@ -53,45 +54,31 @@ public class NativeModule extends ReactContextBaseJavaModule {
     public void nativeSetTimeout(int delay, final Callback callback) {
 //        HashMap paramsMap = ((ReadableNativeMap) params).toHashMap();
         Handler handler = new Handler(Looper.getMainLooper());
-
-        handler.postDelayed(new Runnable() {
-            @Override
-            public void run() {
-                callback.invoke();
-            }
-        }, delay);
+        handler.postDelayed(callback::invoke, delay);
     }
 
     @ReactMethod
     public void switchToNativeRoot() {
-        reactContext.getCurrentActivity().runOnUiThread(new Runnable() {
-            @Override
-            public void run() {
-                Activity currentActivity = getCurrentActivity();
-
-                LinearLayout layout = new LinearLayout(currentActivity);
-                layout.setGravity(Gravity.CENTER);
-                LinearLayout.LayoutParams llp = new LayoutParams(LayoutParams.MATCH_PARENT, LayoutParams.MATCH_PARENT);
-
-                TextView tv = new TextView(currentActivity);
-                tv.setText("this is a new native root");
-                LinearLayout.LayoutParams lp = new LayoutParams(LayoutParams.WRAP_CONTENT, LayoutParams.WRAP_CONTENT);
-                tv.setLayoutParams(lp);
-
-                layout.addView(tv);
-                currentActivity.setContentView(layout, llp);
-            }
+        reactContext.getCurrentActivity().runOnUiThread(() -> {
+            Activity currentActivity = getCurrentActivity();
+
+            LinearLayout layout = new LinearLayout(currentActivity);
+            layout.setGravity(Gravity.CENTER);
+            LayoutParams llp = new LayoutParams(LayoutParams.MATCH_PARENT, LayoutParams.MATCH_PARENT);
+
+            TextView tv = new TextView(currentActivity);
+            tv.setText("this is a new native root");
+            LayoutParams lp = new LayoutParams(LayoutParams.WRAP_CONTENT, LayoutParams.WRAP_CONTENT);
+            tv.setLayoutParams(lp);
+
+            layout.addView(tv);
+            currentActivity.setContentView(layout, llp);
         });
     }
 
     @ReactMethod
     public void switchToMultipleReactRoots() {
-        reactContext.getCurrentActivity().runOnUiThread(new Runnable() {
-            @Override
-            public void run() {
-
-            }
-        });
+        reactContext.getCurrentActivity().runOnUiThread(() -> {}); // TODO?
     }
 
     @ReactMethod
@@ -113,6 +100,18 @@ public class NativeModule extends ReactContextBaseJavaModule {
         new LongTapCrasher(testID).attach();
     }
 
+    @ReactMethod
+    public void chokeMainThread() {
+        reactContext.getCurrentActivity().runOnUiThread(() -> {
+            try {
+                Thread.sleep(10500);
+            } catch (InterruptedException e) {
+                e.printStackTrace();
+                throw new RuntimeException(e);
+            }
+        });
+    }
+
     /**
      * Implementation note: For this purpose, a simpler RN API exists in the same class -
      * {@link ReactFindViewUtil#addViewListener(ReactFindViewUtil.OnViewFoundListener)}.
diff --git a/detox/test/e2e/19.app-responsiveness.test.js b/detox/test/e2e/19.app-responsiveness.test.js
new file mode 100644
index 000000000..b4dec8fa8
--- /dev/null
+++ b/detox/test/e2e/19.app-responsiveness.test.js
@@ -0,0 +1,19 @@
+const LogInterceptor = require('./utils/log-interceptor');
+
+describe(':android: App responsiveness', () => {
+  it('should log ANR warning when app nonresponsive', async () => {
+    const logInterceptor = new LogInterceptor();
+
+    try {
+      logInterceptor.startStderr();
+      await element(by.text('ANR')).tap();
+    } finally {
+      logInterceptor.stopAll();
+    }
+
+    if (!logInterceptor.strerrData.includes('APP_NONRESPONSIVE')) {
+      console.error('APP_NONRESPONSIVE warning-log was expected, but got:\n'+logInterceptor.strerrData);
+      fail('APP_NONRESPONSIVE not found in intercepted log');
+    }
+  });
+});
diff --git a/detox/test/e2e/utils/log-interceptor.js b/detox/test/e2e/utils/log-interceptor.js
new file mode 100644
index 000000000..a68380199
--- /dev/null
+++ b/detox/test/e2e/utils/log-interceptor.js
@@ -0,0 +1,29 @@
+class LogInterceptor {
+  constructor() {
+    this._stderrWrite = null;
+    this._stderrData = [];
+  }
+
+  startStderr() {
+    this._stderrWrite = process.stderr.write.bind(process.stderr);
+    process.stderr.write = (...args) => {
+      const [data] = args;
+      this._stderrData.push(data);
+
+      this._stderrWrite(...args);
+    };
+  }
+
+  get strerrData() {
+    return this._stderrData.join('');
+  }
+
+  stopAll() {
+    if (this._stderrWrite) {
+      process.stderr.write = this._stderrWrite;
+      this._stderrWrite = null;
+    }
+  }
+}
+
+module.exports = LogInterceptor;
diff --git a/detox/test/src/app.js b/detox/test/src/app.js
index 2fe46c00c..406bd9ccf 100644
--- a/detox/test/src/app.js
+++ b/detox/test/src/app.js
@@ -5,12 +5,15 @@ import {
   TouchableOpacity,
   Linking,
   Platform,
+  NativeModules,
 } from 'react-native';
 
 import * as Screens from './Screens';
 
 const isAndroid = Platform.OS === 'android';
 
+const { NativeModule } = NativeModules;
+
 class example extends Component {
 
   constructor(props) {
@@ -107,9 +110,17 @@ class example extends Component {
           {this.renderScreenButton('Location', Screens.LocationScreen)}
           {!isAndroid && this.renderScreenButton('DatePicker', Screens.DatePickerScreen)}
           {!isAndroid && this.renderScreenButton('Picker', Screens.PickerViewScreen)}
-          {this.renderButton('Crash', () => {
-            throw new Error('Simulated Crash')
-          })}
+
+          <View style={{flexDirection: 'row', justifyContent: 'center'}}>
+            {this.renderButton('Crash', () => {
+              throw new Error('Simulated Crash')
+            })}
+            {isAndroid && <Text style={{width: 10}}> | </Text>}
+            {isAndroid && this.renderButton('ANR', () => {
+              NativeModule.chokeMainThread();
+            })}
+          </View>
+
           {this.renderScreenButton('Shake', Screens.ShakeScreen)}
           {isAndroid && this.renderScreenButton('Launch Args', Screens.LaunchArgsScreen)}
         </View>