Repository: beeware/briefcase
Pull request #799 (2022-07-23 17:45:31)

Print Android Emulator Output if Startup Errors/Fails
## Summary
Inspired by #764, this PR simply prints the warning and error logs from the Android emulator if something goes wrong during start up. Currently, Briefcase only instructs users to attempt to run the emulator themselves to see potential issues; this leaves that instruction in place but allows the user to immediately see those logs as well.

For example, here is the new experience when users try to use the emulator without hardware acceleration:
```
❯ briefcase run android -d @beePhone

[helloworld] Starting emulator beePhone...
Starting emulator...
WARNING | unexpected system image feature string, emulator might not function correctly, please try updating the emulator.
ERROR   | x86_64 emulation currently requires hardware acceleration!
CPU acceleration status: KVM requires a CPU that supports vmx or svm
More info on configuring VM acceleration on Linux:
https://developer.android.com/studio/run/emulator-acceleration#vm-linux
General information on acceleration: https://developer.android.com/studio/run/emulator-acceleration.


Android emulator was unable to start!

Try starting the emulator manually by running:

    $ /home/user/.cache/briefcase/tools/android_sdk/emulator/emulator @beePhone -dns-server 8.8.8.8

Resolve any problems you discover, then try running your app again. You may
find this page helpful in diagnosing emulator problems.

    https://developer.android.com/studio/run/emulator-acceleration#accel-vm

Log saved to /home/user/tmp/beeware/helloworld/briefcase.2022_07_23-13_28_41.run.log
```

## Opinion
Probably the most controversial aspect of this is only printing `stderr` from the Android emulator. The emulator sends normal logs like `INFO` to `stdout` while `WARNING` and `ERROR` logs are sent to `stderr`. I choose to only print the warnings and errors since I thought it might help remove some clutter and allow users to zero in on the problem themselves. I could be convinced otherwise.

CC: @mhsmith

## PR Checklist:
<!--- Go over all the following points, and put an `x` in all the boxes that apply. -->
- [x] All new features have been tested
- [x] All new features have been documented
- [x] I have read the **CONTRIBUTING.md** file
- [x] I will abide by the code of conduct


rmartin16: I've gotta run for today. I'll get tests working tomorrow or monday. Feedback welcome in the interim.
codecov[bot]: # [Codecov](https://codecov.io/gh/beeware/briefcase/pull/799?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=beeware) Report
> Merging [#799](https://codecov.io/gh/beeware/briefcase/pull/799?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=beeware) (f9d1d2d) into [main](https://codecov.io/gh/beeware/briefcase/commit/8d4057f31a7bf48ee77c8e78bd895b5d9b4c190b?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=beeware) (8d4057f) will **increase** coverage by `0.00%`.
> The diff coverage is `100.00%`.

| [Impacted Files](https://codecov.io/gh/beeware/briefcase/pull/799?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=beeware) | Coverage Δ | |
|---|---|---|
| [src/briefcase/integrations/android\_sdk.py](https://codecov.io/gh/beeware/briefcase/pull/799/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=beeware#diff-c3JjL2JyaWVmY2FzZS9pbnRlZ3JhdGlvbnMvYW5kcm9pZF9zZGsucHk=) | `99.09% <100.00%> (+0.01%)` | :arrow_up: |

mhsmith: Thanks, this will be very useful. I've tested it on Windows and it works fine.

> Probably the most controversial aspect of this is only printing `stderr` from the Android emulator. The emulator sends normal logs like `INFO` to `stdout` while `WARNING` and `ERROR` logs are sent to `stderr`. I choose to only print the warnings and errors since I thought it might help remove some clutter and allow users to zero in on the problem themselves. I could be convinced otherwise.

When the emulator fails to start I think we should include the stdout, because it may give some important context without which the stderr can't be understood. For the same reason, I think stdout and stderr should be captured together rather than separately. This can be done using `stdout=subprocess.PIPE, stderr=subprocess.STDOUT`, after which both stdout and stderr can be retrieved from `emulator_popen.communicate(...)[0]`.

Patch:
diff --git a/changes/799.feature.rst b/changes/799.feature.rst
new file mode 100644
index 00000000..42badd76
--- /dev/null
+++ b/changes/799.feature.rst
@@ -0,0 +1,1 @@
+Android emulator output is printed to the console if it fails to start properly.
diff --git a/src/briefcase/integrations/android_sdk.py b/src/briefcase/integrations/android_sdk.py
index 8c0a76ee..c858e303 100644
--- a/src/briefcase/integrations/android_sdk.py
+++ b/src/briefcase/integrations/android_sdk.py
@@ -3,6 +3,7 @@ import re
 import shutil
 import subprocess
 import time
+from contextlib import suppress
 from pathlib import Path
 
 from requests import exceptions as requests_exceptions
@@ -1004,7 +1005,8 @@ In future, you can specify this device by running:
             ],
             env=self.env,
             stdout=subprocess.PIPE,
-            stderr=subprocess.PIPE,
+            stderr=subprocess.STDOUT,
+            bufsize=1,
             start_new_session=True,
         )
 
@@ -1013,15 +1015,16 @@ In future, you can specify this device by running:
         # not ready until the boot process has finished. To determine
         # the boot status, we need the device ID, and an ADB connection.
 
-        # Step 1: Wait for the device to appear so we can get an
+        # Phase 1: Wait for the device to appear so we can get an
         # ADB instance for the new device.
-        with self.command.input.wait_bar("Starting emulator..."):
-            adb = None
-            known_devices = set()
-            while adb is None:
-                if emulator_popen.poll() is not None:
-                    raise BriefcaseCommandError(
-                        f"""\
+        try:
+            with self.command.input.wait_bar("Starting emulator..."):
+                adb = None
+                known_devices = set()
+                while adb is None:
+                    if emulator_popen.poll() is not None:
+                        raise BriefcaseCommandError(
+                            f"""\
 Android emulator was unable to start!
 
 Try starting the emulator manually by running:
@@ -1033,34 +1036,34 @@ find this page helpful in diagnosing emulator problems.
 
     https://developer.android.com/studio/run/emulator-acceleration#accel-vm
 """
-                    )
-
-                for device, details in sorted(self.devices().items()):
-                    # Only process authorized devices that we haven't seen.
-                    if details["authorized"] and device not in known_devices:
-                        adb = self.adb(device)
-                        device_avd = adb.avd_name()
-
-                        if device_avd == avd:
-                            # Found an active device that matches
-                            # the AVD we are starting.
-                            full_name = f"@{avd} (running emulator)"
-                            break
-                        else:
-                            # Not the one. Zathras knows.
-                            adb = None
-                            known_devices.add(device)
-
-                # Try again in 2 seconds...
-                self.sleep(2)
-
-        # Phase 2: Wait for the boot process to complete
-        if not adb.has_booted():
-            with self.command.input.wait_bar("Booting emulator..."):
-                while not adb.has_booted():
-                    if emulator_popen.poll() is not None:
-                        raise BriefcaseCommandError(
-                            f"""\
+                        )
+
+                    for device, details in sorted(self.devices().items()):
+                        # Only process authorized devices that we haven't seen.
+                        if details["authorized"] and device not in known_devices:
+                            adb = self.adb(device)
+                            device_avd = adb.avd_name()
+
+                            if device_avd == avd:
+                                # Found an active device that matches
+                                # the AVD we are starting.
+                                full_name = f"@{avd} (running emulator)"
+                                break
+                            else:
+                                # Not the one. Zathras knows.
+                                adb = None
+                                known_devices.add(device)
+
+                    # Try again in 2 seconds...
+                    self.sleep(2)
+
+            # Phase 2: Wait for the boot process to complete
+            if not adb.has_booted():
+                with self.command.input.wait_bar("Booting emulator..."):
+                    while not adb.has_booted():
+                        if emulator_popen.poll() is not None:
+                            raise BriefcaseCommandError(
+                                f"""\
 Android emulator was unable to boot!
 
 Try starting the emulator manually by running:
@@ -1072,10 +1075,16 @@ find this page helpful in diagnosing emulator problems.
 
     https://developer.android.com/studio/run/emulator-acceleration#accel-vm
 """
-                        )
-
-                    # Try again in 2 seconds...
-                    self.sleep(2)
+                            )
+
+                        # Try again in 2 seconds...
+                        self.sleep(2)
+        except Exception:
+            # if the emulator exited, this should return its output immediately;
+            # if it is still running, this will quickly time out and print nothing.
+            with suppress(subprocess.TimeoutExpired):
+                self.command.logger.info(emulator_popen.communicate(timeout=1)[0])
+            raise
 
         # Return the device ID and full name.
         return device, full_name


Test patch:
diff --git a/tests/integrations/android_sdk/AndroidSDK/test_start_emulator.py b/tests/integrations/android_sdk/AndroidSDK/test_start_emulator.py
index 631210b9..bd9627d1 100644
--- a/tests/integrations/android_sdk/AndroidSDK/test_start_emulator.py
+++ b/tests/integrations/android_sdk/AndroidSDK/test_start_emulator.py
@@ -119,7 +119,8 @@ def test_start_emulator(mock_sdk):
         ],
         env=mock_sdk.env,
         stdout=subprocess.PIPE,
-        stderr=subprocess.PIPE,
+        stderr=subprocess.STDOUT,
+        bufsize=1,
         start_new_session=True,
     )
 
@@ -215,7 +216,8 @@ def test_emulator_fail_to_start(mock_sdk):
         ],
         env=mock_sdk.env,
         stdout=subprocess.PIPE,
-        stderr=subprocess.PIPE,
+        stderr=subprocess.STDOUT,
+        bufsize=1,
         start_new_session=True,
     )
 
@@ -314,7 +316,8 @@ def test_emulator_fail_to_boot(mock_sdk):
         ],
         env=mock_sdk.env,
         stdout=subprocess.PIPE,
-        stderr=subprocess.PIPE,
+        stderr=subprocess.STDOUT,
+        bufsize=1,
         start_new_session=True,
     )