Bug 1609198 - Print logcat on junit test failure. r=droeh,nalexander

This also adds a --verbose flag to |mach geckoview-junit| which always prints
the logcat for every test.

Differential Revision: https://phabricator.services.mozilla.com/D104769

mobile/android/geckoview/src/androidTest/java/org/mozilla/geckoview/test/rule/GeckoSessionTestRule.java

@@ -1279,6 +1279,10 @@ public class GeckoSessionTestRule implements TestRule {
         RuntimeCreator.setTelemetryDelegate(null);
     }
 
+    // These markers are used by runjunit.py to capture the logcat of a test
+    private static final String TEST_START_MARKER = "test_start 1f0befec-3ff2-40ff-89cf-b127eb38b1ec";
+    private static final String TEST_END_MARKER = "test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059";
+
     @Override
     public Statement apply(final Statement base, final Description description) {
         return new Statement() {
@@ -1291,7 +1295,7 @@ public class GeckoSessionTestRule implements TestRule {
                     RuntimeCreator.setPortDelegate(mPortDelegate);
                     getRuntime();
 
-                    Log.e(LOGTAG, "====");
+                    Log.e(LOGTAG, TEST_START_MARKER + " " + description);
                     Log.e(LOGTAG, "before prepareStatement " + description);
                     prepareStatement(description);
                     Log.e(LOGTAG, "after prepareStatement");
@@ -1314,9 +1318,8 @@ public class GeckoSessionTestRule implements TestRule {
                         Log.e(LOGTAG, "after evaluate");
                         performTestEndCheck();
                         Log.e(LOGTAG, "after performTestEndCheck");
-                        Log.e(LOGTAG, "====");
                     } catch (Throwable t) {
-                        Log.e(LOGTAG, "====", t);
+                        Log.e(LOGTAG, "Error", t);
                         exceptionRef.set(t);
                     } finally {
                         try {
@@ -1325,6 +1328,7 @@ public class GeckoSessionTestRule implements TestRule {
                         } catch (Throwable t) {
                             exceptionRef.compareAndSet(null, t);
                         }
+                        Log.e(LOGTAG, TEST_END_MARKER + " " + description);
                     }
                 });
 

testing/mochitest/runjunit.py

@@ -51,14 +51,18 @@ class JUnitTestRunner(MochitestDesktop):
 
     def __init__(self, log, options):
         self.log = log
-        verbose = False
+        self.verbose = False
-        if options.log_tbpl_level == "debug" or options.log_mach_level == "debug":
+        if (
-            verbose = True
+            options.log_tbpl_level == "debug"
+            or options.log_mach_level == "debug"
+            or options.verbose
+        ):
+            self.verbose = True
         self.device = ADBDeviceFactory(
             adb=options.adbPath or "adb",
             device=options.deviceSerial,
             test_root=options.remoteTestRoot,
-            verbose=verbose,
+            verbose=self.verbose,
             run_as_package=options.app,
         )
         self.options = options
@@ -89,6 +93,21 @@ class JUnitTestRunner(MochitestDesktop):
         self.startServers(self.options, debuggerInfo=None, public=True)
         self.log.debug("Servers started")
 
+    def collectLogcatForCurrentTest(self):
+        # These are unique start and end markers logged by GeckoSessionTestRule.java
+        START_MARKER = "1f0befec-3ff2-40ff-89cf-b127eb38b1ec"
+        END_MARKER = "c5ee677f-bc83-49bd-9e28-2d35f3d0f059"
+        logcat = self.device.get_logcat()
+        test_logcat = ""
+        started = False
+        for l in logcat:
+            if START_MARKER in l and self.test_name in l:
+                started = True
+            if started:
+                test_logcat += l + "\n"
+            if started and END_MARKER in l:
+                return test_logcat
+
     def needsWebsocketProcessBridge(self, options):
         """
         Overrides MochitestDesktop.needsWebsocketProcessBridge and always
@@ -307,6 +326,9 @@ class JUnitTestRunner(MochitestDesktop):
                         status = "PASS"
                         expected = "PASS"
                         self.pass_count += 1
+                        if self.verbose:
+                            self.log.info("Printing logcat for test:")
+                            print(self.collectLogcatForCurrentTest())
                     elif status == "-3":  # ignored (skipped)
                         message = ""
                         status = "SKIP"
@@ -325,6 +347,8 @@ class JUnitTestRunner(MochitestDesktop):
                         status = "FAIL"
                         expected = "PASS"
                         self.fail_count += 1
+                        self.log.info("Printing logcat for test:")
+                        print(self.collectLogcatForCurrentTest())
                     self.log.test_end(full_name, status, expected, message)
                     self.test_started = False
                 else:
@@ -506,6 +530,14 @@ class JunitArgumentParser(argparse.ArgumentParser):
             default=None,
             help="If running tests by chunks, the chunk number to run.",
         )
+        self.add_argument(
+            "--verbose",
+            "-v",
+            action="store_true",
+            dest="verbose",
+            default=False,
+            help="Verbose output - enable debug log messages",
+        )
         self.add_argument(
             "--enable-coverage",
             action="store_true",