We are facing frequently (every second to third run) the issue that the actual logcat logs are missing in our captured log file. This issue only appears with an Android emulator employing a x86 image with API level 28. The following logs are captured in such a faulty case:
INFO | Your emulator is out of date, please update by launching Android Studio:
- Start Android Studio
- Select menu "Tools > Android > SDK Manager"
- Click "SDK Tools" tab
- Check "Android Emulator" checkbox
- Click "OK"
VERBOSE | onGuestSendCommand: [0x871dad0] Adb connected, start proxing data
VERBOSE | _hwFingerprint_connect: connect finger print listen is called
VERBOSE | got message from guest system fingerprint HAL
INFO | boot completed
INFO | boot time 24250 ms
INFO | Increasing screen off timeout, logcat buffer size to 2M.
INFO | Revoking microphone permissions for Google App.
VERBOSE | onGuestClose: [0x871da00] Adb closed by guest
VERBOSE | onGuestClose: [0x871dad0] Adb closed by guest
VERBOSE | onGuestSendCommand: [0x8eccf70] Adb connected, start proxing data
VERBOSE | Emulator killed by console kill command.
VERBOSE | Saving state on exit with session uptime 3729156 ms
INFO | Shutting down gRPC endpoint
INFO | Shutting down gRPC endpoint
VERBOSE | Done with QEMU main loop
VERBOSE | User configuration saved to /dev/shm/auermich/tmp02g33cw1/.android/avd/PixelXL_API_28.avd/emulator-user.ini
VERBOSE | Adb transition disconnected -> disconnected
While in a successful execution the logcat logs are captured after the 'out of date' info log, e.g.:
--------- beginning of main
01-10 22:42:01.020 1538 1538 W auditd : type=2000 audit(0.0:1): initialized
01-10 22:42:01.740 1538 1538 I auditd : type=1403 audit(0.0:2): policy loaded auid=4294967295 ses=4294967295
01-10 22:42:01.750 1538 1538 W auditd : type=1404 audit(0.0:3): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295
01-10 22:42:02.494 1539 1539 I SELinux : SELinux: Loaded service_contexts from:
01-10 22:42:02.496 1539 1539 I SELinux : /system/etc/selinux/plat_service_contexts
01-10 22:42:02.500 1 1 W init : type=1400 audit(0.0:4): avc: denied { setattr } for name="slabinfo" dev="proc" ino=4026532041 scontext=u:r:init:s0 tcontext=u:object_r:proc:s0 tclass=file permissive=0
01-10 22:42:02.500 1 1 W init : type=1400 audit(0.0:5): avc: denied { setattr } for name="slabinfo" dev="proc" ino=4026532041 scontext=u:r:init:s0 tcontext=u:object_r:proc:s0 tclass=file permissive=0 01-10 22:42:02.511 1541 1541 I SELinux : SELinux: Loaded service_contexts from:
01-10 22:42:02.512 1541 1541 I SELinux : /vendor/etc/selinux/vndservice_contexts
01-10 22:42:02.537 1540 1540 I hwservicemanager: hwservicemanager is ready now.
01-10 22:42:02.558 1547 1547 I android.hardware.keymaster@3.0-impl: Fetching keymaster device name default
01-10 22:42:02.558 1547 1547 I android.hardware.keymaster@3.0-impl: Could not find any keystore module, using software-only implementation.
01-10 22:42:02.559 1547 1547 I ServiceManagement: Removing namespace from process name android.hardware.keymaster@3.0-service to keymaster@3.0-service.
01-10 22:42:02.559 1547 1547 I android.hardware.keymaster@3.0-service: Registration complete for android.hardware.keymaster@3.0::IKeymasterDevice/default.
--------- beginning of system
We are typically conducting experiments (thousands of runs) with a x86 image with API level 25 and there this issue doesn't appear at all, but we would like to update to a more recent API level. We are facing the issue both on Windows and Linux. More details regarding the emulator:
- Android emulator version 31.2.9.0 (build_id 8316981) (CL:N/A
- system-images/android-28/default/x86/
- Nexus 5 or Pixel XL AVD
The capturing of the log files is handled by a little python script:
self.f = open(emu_conf["logfile"], "a")
self.f_err = open(emu_conf["logfile_err"], "a")
self.emu_proc = subprocess.Popen(self.emu_command, stdout=self.f, stderr=self.f_err)
where the emu command is actually the following:
Running command ['/dev/shm/auermich/tmp02g33cw1/Android/Sdk/emulator/emulator', '-avd', 'PixelXL_API_28', '-verbose', '-logcat', 'E,acc', '-wipe-data', '-no-window']
UPDATE: Even if we use the option -logcat-output to log directly to a file, the same fault appears. The adjusted command now is:
Running command ['/dev/shm/auermich/tmp6wr4semi/Android/Sdk/emulator/emulator', '-avd', 'Pixel_XL_API_28', '-verbose', '-logcat', 'E,acc', '-logcat-output', 'log/logcat.log', '-wipe-data', '-no-window']
The specified log file remains empty in such a case.
