Open Bug 1848112 Opened 11 months ago Updated 9 months ago

Local mochitest run frequently fails with missing mochitest.log

Categories

(Testing :: Mochitest, defect, P2)

defect

Tracking

(Not tracked)

People

(Reporter: saschanaz, Unassigned)

Details

Attachments

(1 file, 2 obsolete files)

It either fails without even opening test runner at all, or after running test runner and mochitest main page but not the test itself.

 1:00.52 adb INFO Setting test_root to /data/local/tmp/test_root
 1:01.48 INFO Android sdk version '24'; will use this to filter manifests
 1:01.48 INFO These variables are available in the mozinfo environment and can be used to skip tests conditionally:
 1:01.48 INFO     a11y_checks: False
 1:01.48 INFO     android_min_sdk: 21
 1:01.48 INFO     android_version: 24
 1:01.48 INFO     apple_catalina: False
 1:01.48 INFO     apple_silicon: False
 1:01.48 INFO     appname: fennec
 1:01.48 INFO     artifact: False
 1:01.48 INFO     asan: False
 1:01.48 INFO     automation: False
 1:01.48 INFO     bin_suffix:
 1:01.48 INFO     bits: 64
 1:01.48 INFO     buildapp: mobile/android
 1:01.48 INFO     buildtype_guess: opt
 1:01.48 INFO     cc_type: clang
 1:01.48 INFO     ccov: False
 1:01.48 INFO     condprof: False
 1:01.48 INFO     crashreporter: False
 1:01.48 INFO     datareporting: True
 1:01.48 INFO     debug: False
 1:01.48 INFO     devedition: False
 1:01.48 INFO     display: None
 1:01.48 INFO     domstreams: True
 1:01.48 INFO     e10s: True
 1:01.48 INFO     early_beta_or_earlier: True
 1:01.48 INFO     fission: True
 1:01.48 INFO     has_sandbox: True
 1:01.48 INFO     headless: True
 1:01.48 INFO     healthreport: True
 1:01.48 INFO     http2: False
 1:01.48 INFO     http3: False
 1:01.48 INFO     is_emulator: True
 1:01.48 INFO     is_ubuntu: False
 1:01.48 INFO     isolated_process: False
 1:01.48 INFO     mozconfig: C:/Users/sasch/Documents/GitHub/gecko-dev/mozconfig-android-x86-64
 1:01.48 INFO     msix: False
 1:01.48 INFO     nightly_build: True
 1:01.48 INFO     normandy: False
 1:01.48 INFO     official: False
 1:01.48 INFO     os: android
 1:01.48 INFO     os_version: 10.0
 1:01.48 INFO     pgo: False
 1:01.48 INFO     platform_guess: android-x86_64
 1:01.48 INFO     processor: x86_64
 1:01.48 INFO     release_or_beta: False
 1:01.48 INFO     require_signing: False
 1:01.48 INFO     service_pack:
 1:01.48 INFO     serviceworker_e10s: True
 1:01.48 INFO     sessionHistoryInParent: True
 1:01.48 INFO     socketprocess_e10s: False
 1:01.48 INFO     socketprocess_networking: False
 1:01.48 INFO     stylo: True
 1:01.48 INFO     swgl: False
 1:01.48 INFO     sync: False
 1:01.48 INFO     telemetry: False
 1:01.48 INFO     tests_enabled: True
 1:01.48 INFO     toolkit: android
 1:01.48 INFO     topobjdir: C:/Users/sasch/Documents/GitHub/gecko-dev/obj-x86_64-unknown-linux-android
 1:01.49 INFO     topsrcdir: C:/Users/sasch/Documents/GitHub/gecko-dev
 1:01.49 INFO     tsan: False
 1:01.49 INFO     ubsan: False
 1:01.49 INFO     updater: False
 1:01.49 INFO     verify: False
 1:01.49 INFO     verify_fission: False
 1:01.49 INFO     version: 10.0.22621
 1:01.49 INFO     webgl_ipc: False
 1:01.49 INFO     win10_2004: False
 1:01.49 INFO     win10_2009: False
 1:01.49 INFO     win11_2009: True
 1:01.49 INFO     wmfme: 0
 1:01.49 INFO     xorigin: False
 1:01.49 INFO Checking for ssltunnel processes...
 1:01.91 INFO Checking for xpcshell processes...
 1:02.33 SUITE_START: mochitest-plain - running 5 tests
 1:02.33 INFO Running manifest: dom/notification/test/mochitest/mochitest.ini
 1:03.47 pid:11716 Full command: C:\Users\sasch\.mozbuild\android-device\host-utils-117.0a1.en-US.win32\pk12util -i C:/Users/sasch/Documents/GitHub/gecko-dev\build\pgo\certs\mochitest.client -w C:\Users\sasch\AppData\Local\Temp\tmprgc66vxw.mozrunner\.crtdbpw -d sql:C:\Users\sasch\AppData\Local\Temp\tmprgc66vxw.mozrunner
pid:11716 C:\Users\sasch\.mozbuild\android-device\host-utils-117.0a1.en-US.win32\pk12util: PKCS12 IMPORT SUCCESSFUL
 1:03.57 INFO MochitestServer : launching ['C:\\Users\\sasch\\.mozbuild\\android-device\\host-utils-117.0a1.en-US.win32\\xpcshell', '-g', 'C:\\Users\\sasch\\.mozbuild\\android-device\\host-utils-117.0a1.en-US.win32', '-e', "const _PROFILE_PATH = 'C:\\\\Users\\\\sasch\\\\AppData\\\\Local\\\\Temp\\\\tmprgc66vxw.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '10.238.24.20'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false; const _HTTPD_PATH = 'C:\\\\Users\\\\sasch\\\\.mozbuild\\\\android-device\\\\host-utils-117.0a1.en-US.win32\\\\components';", '-f', 'C:\\Users\\sasch\\Documents\\GitHub\\gecko-dev\\obj-x86_64-unknown-linux-android\\_tests\\testing\\mochitest\\server.js']
 1:03.57 INFO runtests.py | Server pid: 26080
 1:03.58 INFO runtests.py | Websocket server pid: 14380
 1:03.58 INFO runtests.py | SSL tunnel pid: 24452
 1:03.69 INFO use http3 server: 0
 1:04.24 INFO runtests.py | Running with scheme: http
 1:04.24 INFO runtests.py | Running with e10s: True
 1:04.24 INFO runtests.py | Running with fission: True
 1:04.24 INFO runtests.py | Running with cross-origin iframes: False
 1:04.24 INFO runtests.py | Running with serviceworker_e10s: True
 1:04.24 INFO runtests.py | Running with socketprocess_e10s: False
 1:04.24 INFO runtests.py | Running tests: start.

 1:04.31 adb INFO Granting important runtime permissions to org.mozilla.geckoview.test_runner
 1:05.21 adb INFO launch_application: am start -W -n org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity -a android.intent.action.MAIN --es env0 MOZ_CRASHREPORTER_NO_REPORT=1 --es env1 MOZ_CRASHREPORTER=1 --es env2 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env3 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env4 MOZ_IN_AUTOMATION=1 --es env5 R_LOG_LEVEL=6 --es env6 R_LOG_DESTINATION=stderr --es env7 R_LOG_VERBOSE=1 --es env8 MOZ_HEADLESS=1 --es env9 XPCOM_DEBUG_BREAK=stack --es env10 MOZ_UPLOAD_DIR=/data/local/tmp/test_root/mozlog --es env11 MOZ_HIDE_RESULTS_TABLE=1 --es arg0 -no-remote --es arg1 -profile --es arg2 /data/local/tmp/test_root/profile/ --ez use_multiprocess True -d 'http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&logFile=%2Fdata%2Flocal%2Ftmp%2Ftest_root%2Flogs%2Fmochitest.log&fileLevel=INFO&consoleLevel=INFO&hideResultsTable=1&manifestFile=tests.json&dumpOutputDirectory=%2Fdata%2Flocal%2Ftmp%2Ftest_root&ignorePrefsFile=ignorePrefs.json'
 1:05.70 INFO runtestsremote.py | Application pid: 5123
 1:26.16 WARNING Failed wait for remote log: /data/local/tmp/test_root/logs/mochitest.log missing?
 1:26.25 ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmp06cd8_ja, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist
 1:36.36 ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmp6og65n4t, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist
 1:36.36 INFO wait for org.mozilla.geckoview.test_runner complete; top activity=com.android.launcher3
 1:36.36 INFO runtestsremote.py | Application ran for: 0:00:32.093805
 1:36.86 INFO runtests.py | Running with scheme: https
 1:36.86 INFO runtests.py | Running with e10s: True
 1:36.86 INFO runtests.py | Running with fission: True
 1:36.86 INFO runtests.py | Running with cross-origin iframes: False
 1:36.86 INFO runtests.py | Running with serviceworker_e10s: True
 1:36.86 INFO runtests.py | Running with socketprocess_e10s: False
 1:36.86 INFO runtests.py | Running tests: start.

 1:36.95 adb INFO Granting important runtime permissions to org.mozilla.geckoview.test_runner
 1:37.81 adb INFO launch_application: am start -W -n org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity -a android.intent.action.MAIN --es env0 MOZ_CRASHREPORTER_NO_REPORT=1 --es env1 MOZ_CRASHREPORTER=1 --es env2 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env3 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env4 MOZ_IN_AUTOMATION=1 --es env5 R_LOG_LEVEL=6 --es env6 R_LOG_DESTINATION=stderr --es env7 R_LOG_VERBOSE=1 --es env8 MOZ_HEADLESS=1 --es env9 XPCOM_DEBUG_BREAK=stack --es env10 MOZ_UPLOAD_DIR=/data/local/tmp/test_root/mozlog --es env11 MOZ_HIDE_RESULTS_TABLE=1 --es arg0 -no-remote --es arg1 -profile --es arg2 /data/local/tmp/test_root/profile/ --ez use_multiprocess True -d 'https://example.com:443/tests?autorun=1&closeWhenDone=1&logFile=%2Fdata%2Flocal%2Ftmp%2Ftest_root%2Flogs%2Fmochitest.log&fileLevel=INFO&consoleLevel=INFO&hideResultsTable=1&manifestFile=tests.json&dumpOutputDirectory=%2Fdata%2Flocal%2Ftmp%2Ftest_root&ignorePrefsFile=ignorePrefs.json'
 1:38.31 INFO runtestsremote.py | Application pid: 5350
 1:58.78 WARNING Failed wait for remote log: /data/local/tmp/test_root/logs/mochitest.log missing?
 1:58.86 ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmphin9fd49, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist
 2:08.98 ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmppxajhhqp, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist
 2:08.98 INFO wait for org.mozilla.geckoview.test_runner complete; top activity=com.android.launcher3
 2:08.98 INFO runtestsremote.py | Application ran for: 0:00:32.097243
 2:09.00 INFO Stopping web server
 2:09.00 INFO Server shut down.
 2:09.01 INFO Web server killed.
 2:09.01 INFO Stopping web socket server
 2:09.04 INFO Stopping ssltunnel
 2:09.08 WARNING leakcheck | refcount logging is off, so leaks can't be detected!
 2:09.08 INFO runtests.py | Running tests: end.
 2:09.53 INFO Buffered messages finished
0 INFO TEST-START | Shutdown
1 INFO Passed:  0
2 INFO Failed:  0
3 INFO Todo:    0
4 INFO Mode:    e10s
5 INFO SimpleTest FINISHED
 2:09.77 INFO Buffered messages finished
 2:09.77 SUITE_END
 2:09.77
Overall Summary
===============

mochitest-plain
~~~~~~~~~~~~~~~
Ran 0 checks ()
Expected results: 0
Unexpected results: 0

Unexpected Results
------------------
ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmp06cd8_ja, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist
ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmp6og65n4t, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist
ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmphin9fd49, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist
ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmppxajhhqp, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist

Those errors usually mean that the test app crashed on startup, or failed to start. logcat usually provides more information.

Hey Nick, do you have any ideas on who might know more about this?

This seems to happen when people are using physical devices or testing on Windows

Flags: needinfo?(nalexander)

(In reply to Jeff Boek [:boek] from comment #2)

Hey Nick, do you have any ideas on who might know more about this?

This seems to happen when people are using physical devices or testing on Windows

I'm sorry, I really don't -- I've never done any Android development or testing on Windows. If I had to hazard a guess, I'd wonder if we were using os.path.join, which uses \\ on Windows, to produce Unix-y paths on Android, but the most obvious place does not see to do that -- note the %2F characters below.

 1:37.81 adb INFO launch_application: am start -W -n org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity -a android.intent.action.MAIN --es env0 MOZ_CRASHREPORTER_NO_REPORT=1 --es env1 MOZ_CRASHREPORTER=1 --es env2 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env3 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env4 MOZ_IN_AUTOMATION=1 --es env5 R_LOG_LEVEL=6 --es env6 R_LOG_DESTINATION=stderr --es env7 R_LOG_VERBOSE=1 --es env8 MOZ_HEADLESS=1 --es env9 XPCOM_DEBUG_BREAK=stack --es env10 MOZ_UPLOAD_DIR=/data/local/tmp/test_root/mozlog --es env11 MOZ_HIDE_RESULTS_TABLE=1 --es arg0 -no-remote --es arg1 -profile --es arg2 /data/local/tmp/test_root/profile/ --ez use_multiprocess True -d 'https://example.com:443/tests?autorun=1&closeWhenDone=1&logFile=%2Fdata%2Flocal%2Ftmp%2Ftest_root%2Flogs%2Fmochitest.log&fileLevel=INFO&consoleLevel=INFO&hideResultsTable=1&manifestFile=tests.json&dumpOutputDirectory=%2Fdata%2Flocal%2Ftmp%2Ftest_root&ignorePrefsFile=ignorePrefs.json'

Like :gbrown suggests, the next step is adb logcat output.

Flags: needinfo?(nalexander) → needinfo?(krosylight)

logcat says:

--------- beginning of main
--------- beginning of system
---------------------------- PROCESS STARTED (3342) for package org.mozilla.geckoview.test_runner ----------------------------
2023-08-11 14:30:36.658  3342-3342  MultiDex                org.mozilla.geckoview.test_runner    I  VM with version 2.1.0 has multidex support
2023-08-11 14:30:36.658  3342-3342  MultiDex                org.mozilla.geckoview.test_runner    I  Installing application
2023-08-11 14:30:36.658  3342-3342  MultiDex                org.mozilla.geckoview.test_runner    I  VM has multidex support, MultiDex support library is disabled.
2023-08-11 14:30:36.693  3342-3342  GeckoThread             org.mozilla.geckoview.test_runner    D  State changed to LAUNCHED
2023-08-11 14:30:36.695  3342-3357  GeckoThread             org.mozilla.geckoview.test_runner    I  preparing to run Gecko
2023-08-11 14:30:36.711  3342-3342  GeckoRuntime            org.mozilla.geckoview.test_runner    D  Lifecycle: onCreate
2023-08-11 14:30:36.712  3342-3357  GeckoThread             org.mozilla.geckoview.test_runner    D  State changed to MOZGLUE_READY
2023-08-11 14:30:36.719  3342-3357  GeckoLoader             org.mozilla.geckoview.test_runner    I  Library base=/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64
2023-08-11 14:30:36.720  3342-3357  Settings                org.mozilla.geckoview.test_runner    W  Setting animator_duration_scale has moved from android.provider.Settings.System to android.provider.Settings.Global, returning read-only global URI.
2023-08-11 14:30:36.721  3342-3357  GeckoLoader             org.mozilla.geckoview.test_runner    I  Library base=/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64
2023-08-11 14:30:36.722  3342-3357  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Load sqlite start
2023-08-11 14:30:36.732  3342-3357  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Load sqlite done
2023-08-11 14:30:36.732  3342-3357  GeckoLoader             org.mozilla.geckoview.test_runner    I  Library base=/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64
2023-08-11 14:30:36.732  3342-3357  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Load nss start
2023-08-11 14:30:36.732  3342-3357  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Load nss done
2023-08-11 14:30:36.733  3342-3357  GeckoLoader             org.mozilla.geckoview.test_runner    I  Library base=/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64
2023-08-11 14:30:36.786  3342-3357  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Loaded libs in 52.986800ms total, 10ms(30ms) user, 20ms(30ms) system, 0(0) faults
2023-08-11 14:30:36.786  3342-3357  GeckoThread             org.mozilla.geckoview.test_runner    D  State changed to LIBS_READY
2023-08-11 14:30:36.787  3342-3357  GeckoThread             org.mozilla.geckoview.test_runner    W  zerdatime 110905 - runGecko
2023-08-11 14:30:36.787  3342-3357  GeckoRuntime            org.mozilla.geckoview.test_runner    E  Error: headless mode is not currently supported on this platform.
2023-08-11 14:30:36.792  3342-3357  fennec                  org.mozilla.geckoview.test_runner    I  XRE_main returned 1
2023-08-11 14:30:36.792  3342-3357  GeckoThread             org.mozilla.geckoview.test_runner    D  State changed to EXITED
2023-08-11 14:30:36.796  3342-3342  GeckoRuntime            org.mozilla.geckoview.test_runner    D  Lifecycle: onStart
2023-08-11 14:30:36.797  3342-3342  GeckoRuntime            org.mozilla.geckoview.test_runner    D  Lifecycle: onResume
2023-08-11 14:30:36.800  3342-3342  GeckoNetworkManager     org.mozilla.geckoview.test_runner    D  Incoming event start for state OffNoListeners -> OnNoListeners
2023-08-11 14:30:36.802  3342-3342  GeckoNetworkManager     org.mozilla.geckoview.test_runner    D  New network state: UP, WIFI, WIFI
2023-08-11 14:30:36.806  3342-3342  <no-tag>                org.mozilla.geckoview.test_runner    D  HostConnection::get() New Host Connection established 0x71e975e1f220, tid 3342
2023-08-11 14:30:36.839  3342-3342  GeckoNetworkManager     org.mozilla.geckoview.test_runner    D  Incoming event receivedUpdate for state OnNoListeners -> OnNoListeners
2023-08-11 14:30:36.840  3342-3342  GeckoNetworkManager     org.mozilla.geckoview.test_runner    D  New network state: UP, WIFI, WIFI
2023-08-11 14:30:36.841  3342-3360  <no-tag>                org.mozilla.geckoview.test_runner    D  HostConnection::get() New Host Connection established 0x71e987a1f640, tid 3360
2023-08-11 14:30:36.843  3342-3360  OpenGLRenderer          org.mozilla.geckoview.test_runner    I  Initialized EGL, version 1.4
2023-08-11 14:30:36.843  3342-3360  OpenGLRenderer          org.mozilla.geckoview.test_runner    D  Swap behavior 1
2023-08-11 14:30:36.843  3342-3360  OpenGLRenderer          org.mozilla.geckoview.test_runner    W  Failed to choose config with EGL_SWAP_BEHAVIOR_PRESERVED, retrying without...
2023-08-11 14:30:36.843  3342-3360  OpenGLRenderer          org.mozilla.geckoview.test_runner    D  Swap behavior 0
2023-08-11 14:30:36.857  3342-3360  EGL_emulation           org.mozilla.geckoview.test_runner    D  eglCreateContext: 0x71e987ab56c0: maj 3 min 1 rcv 4
2023-08-11 14:30:36.859  3342-3360  EGL_emulation           org.mozilla.geckoview.test_runner    D  eglMakeCurrent: 0x71e987ab56c0: ver 3 1 (tinfo 0x71e987ac87a0)
2023-08-11 14:30:36.859  3342-3360  eglCodecCommon          org.mozilla.geckoview.test_runner    E  glUtilsParamSize: unknow param 0x000082da
2023-08-11 14:30:36.859  3342-3360  eglCodecCommon          org.mozilla.geckoview.test_runner    E  glUtilsParamSize: unknow param 0x00008cdf
2023-08-11 14:30:36.859  3342-3360  eglCodecCommon          org.mozilla.geckoview.test_runner    E  glUtilsParamSize: unknow param 0x00008824
2023-08-11 14:30:36.890  3342-3360  EGL_emulation           org.mozilla.geckoview.test_runner    D  eglMakeCurrent: 0x71e987ab56c0: ver 3 1 (tinfo 0x71e987ac87a0)
2023-08-11 14:30:37.002  3342-3360  EGL_emulation           org.mozilla.geckoview.test_runner    D  eglMakeCurrent: 0x71e987ab56c0: ver 3 1 (tinfo 0x71e987ac87a0)
2023-08-11 14:30:37.218  3342-3342  MemoryController        org.mozilla.geckoview.test_runner    I  onTrimMemory(20)
2023-08-11 14:30:37.220  3342-3342  Process                 org.mozilla.geckoview.test_runner    I  Sending signal. PID: 3342 SIG: 9
2023-08-11 14:30:37.224  1672-1715  InputDispatcher         system_process                       E  channel 'f82d9d5 org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
---------------------------- PROCESS ENDED (3342) for package org.mozilla.geckoview.test_runner ----------------------------
2023-08-11 14:31:09.659  3601-3601  MultiDex                org.mozilla.geckoview.test_runner    I  VM with version 2.1.0 has multidex support
2023-08-11 14:31:09.659  3601-3601  MultiDex                org.mozilla.geckoview.test_runner    I  Installing application
2023-08-11 14:31:09.659  3601-3601  MultiDex                org.mozilla.geckoview.test_runner    I  VM has multidex support, MultiDex support library is disabled.
2023-08-11 14:31:09.690  3601-3601  GeckoThread             org.mozilla.geckoview.test_runner    D  State changed to LAUNCHED
2023-08-11 14:31:09.694  3601-3616  GeckoThread             org.mozilla.geckoview.test_runner    I  preparing to run Gecko
2023-08-11 14:31:09.711  3601-3601  GeckoRuntime            org.mozilla.geckoview.test_runner    D  Lifecycle: onCreate
2023-08-11 14:31:09.718  3601-3616  GeckoThread             org.mozilla.geckoview.test_runner    D  State changed to MOZGLUE_READY
2023-08-11 14:31:09.722  3601-3616  GeckoLoader             org.mozilla.geckoview.test_runner    I  Library base=/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64
2023-08-11 14:31:09.723  3601-3616  Settings                org.mozilla.geckoview.test_runner    W  Setting animator_duration_scale has moved from android.provider.Settings.System to android.provider.Settings.Global, returning read-only global URI.
2023-08-11 14:31:09.724  3601-3616  GeckoLoader             org.mozilla.geckoview.test_runner    I  Library base=/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64
2023-08-11 14:31:09.726  3601-3616  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Load sqlite start
2023-08-11 14:31:09.745  3601-3616  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Load sqlite done
2023-08-11 14:31:09.745  3601-3616  GeckoLoader             org.mozilla.geckoview.test_runner    I  Library base=/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64
2023-08-11 14:31:09.745  3601-3616  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Load nss start
2023-08-11 14:31:09.745  3601-3616  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Load nss done
2023-08-11 14:31:09.745  3601-3616  GeckoLoader             org.mozilla.geckoview.test_runner    I  Library base=/data/app/org.mozilla.geckoview.test_runner-1/lib/x86_64
2023-08-11 14:31:09.899  3601-3616  GeckoLibLoad            org.mozilla.geckoview.test_runner    E  Loaded libs in 153.759100ms total, 20ms(20ms) user, 60ms(110ms) system, 0(0) faults
---------------------------- PROCESS STARTED (3601) for package org.mozilla.geckoview.test_runner ----------------------------
---------------------------- PROCESS ENDED (3601) for package org.mozilla.geckoview.test_runner ----------------------------
2023-08-11 14:31:09.899  3601-3616  GeckoThread             org.mozilla.geckoview.test_runner    D  State changed to LIBS_READY
2023-08-11 14:31:09.902  3601-3601  GeckoRuntime            org.mozilla.geckoview.test_runner    D  Lifecycle: onStart
2023-08-11 14:31:09.902  3601-3616  GeckoThread             org.mozilla.geckoview.test_runner    W  zerdatime 144020 - runGecko
2023-08-11 14:31:09.903  3601-3601  GeckoRuntime            org.mozilla.geckoview.test_runner    D  Lifecycle: onResume
2023-08-11 14:31:09.904  3601-3616  GeckoRuntime            org.mozilla.geckoview.test_runner    E  Error: headless mode is not currently supported on this platform.
2023-08-11 14:31:09.907  3601-3601  GeckoNetworkManager     org.mozilla.geckoview.test_runner    D  Incoming event start for state OffNoListeners -> OnNoListeners
2023-08-11 14:31:09.907  3601-3616  fennec                  org.mozilla.geckoview.test_runner    I  XRE_main returned 1
2023-08-11 14:31:09.908  3601-3616  GeckoThread             org.mozilla.geckoview.test_runner    D  State changed to EXITED
2023-08-11 14:31:09.908  3601-3601  GeckoNetworkManager     org.mozilla.geckoview.test_runner    D  New network state: UP, WIFI, WIFI
2023-08-11 14:31:09.913  3601-3601  <no-tag>                org.mozilla.geckoview.test_runner    D  HostConnection::get() New Host Connection established 0x71e975e1f280, tid 3601
2023-08-11 14:31:09.954  3601-3619  <no-tag>                org.mozilla.geckoview.test_runner    D  HostConnection::get() New Host Connection established 0x71e987a1f640, tid 3619
2023-08-11 14:31:09.955  3601-3601  GeckoNetworkManager     org.mozilla.geckoview.test_runner    D  Incoming event receivedUpdate for state OnNoListeners -> OnNoListeners
2023-08-11 14:31:09.956  3601-3601  GeckoNetworkManager     org.mozilla.geckoview.test_runner    D  New network state: UP, WIFI, WIFI
2023-08-11 14:31:09.956  3601-3619  OpenGLRenderer          org.mozilla.geckoview.test_runner    I  Initialized EGL, version 1.4
2023-08-11 14:31:09.956  3601-3619  OpenGLRenderer          org.mozilla.geckoview.test_runner    D  Swap behavior 1
2023-08-11 14:31:09.956  3601-3619  OpenGLRenderer          org.mozilla.geckoview.test_runner    W  Failed to choose config with EGL_SWAP_BEHAVIOR_PRESERVED, retrying without...
2023-08-11 14:31:09.956  3601-3619  OpenGLRenderer          org.mozilla.geckoview.test_runner    D  Swap behavior 0
2023-08-11 14:31:09.968  3601-3619  EGL_emulation           org.mozilla.geckoview.test_runner    D  eglCreateContext: 0x71e987ab4bc0: maj 3 min 1 rcv 4
2023-08-11 14:31:09.969  3601-3619  EGL_emulation           org.mozilla.geckoview.test_runner    D  eglMakeCurrent: 0x71e987ab4bc0: ver 3 1 (tinfo 0x71e987ac87e0)
2023-08-11 14:31:09.970  3601-3619  eglCodecCommon          org.mozilla.geckoview.test_runner    E  glUtilsParamSize: unknow param 0x000082da
2023-08-11 14:31:09.970  3601-3619  eglCodecCommon          org.mozilla.geckoview.test_runner    E  glUtilsParamSize: unknow param 0x00008cdf
2023-08-11 14:31:09.970  3601-3619  eglCodecCommon          org.mozilla.geckoview.test_runner    E  glUtilsParamSize: unknow param 0x00008824
2023-08-11 14:31:09.980  3601-3619  EGL_emulation           org.mozilla.geckoview.test_runner    D  eglMakeCurrent: 0x71e987ab4bc0: ver 3 1 (tinfo 0x71e987ac87e0)
2023-08-11 14:31:10.136  3601-3619  EGL_emulation           org.mozilla.geckoview.test_runner    D  eglMakeCurrent: 0x71e987ab4bc0: ver 3 1 (tinfo 0x71e987ac87e0)
2023-08-11 14:31:10.353  3601-3601  MemoryController        org.mozilla.geckoview.test_runner    I  onTrimMemory(20)
2023-08-11 14:31:10.354  3601-3601  Process                 org.mozilla.geckoview.test_runner    I  Sending signal. PID: 3601 SIG: 9
2023-08-11 14:31:10.358  1672-1715  InputDispatcher         system_process                       E  channel '8b073ee org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity (server)' ~ Channel is unrecoverably broken and will be disposed!

Edit: Oh, that one was because of --headless. I'll get another log without headless parameter. (But it should throw early)

Flags: needinfo?(krosylight)
Attached file logcat-headful3.txt

Huh, TIL Bugzilla implicitly clips the text when copypasted directly to Bugzilla. This time I'm creating and attaching a file (without --headless)

Attachment #9348542 - Attachment is obsolete: true

The severity field is not set for this bug.
:rsainani, could you have a look please?

For more information, please visit BugBot documentation.

Flags: needinfo?(rsainani)

This doesn't look like it is related to Android Studio or Gradle but Mach looking for a file path on Windows that doesn't exist

Component: Android Studio and Gradle Integration → Mach Core
Flags: needinfo?(rsainani)

I'm having trouble reproducing this, but I also don't think it's a mach issue, it seems more like test issue. I think the filepath not being found is a red herring, and something in runtestsremote.py caused a failure before the log file could be created.

As per this section of comment #1:

1:38.31 INFO runtestsremote.py | Application pid: 5350
 1:58.78 WARNING Failed wait for remote log: /data/local/tmp/test_root/logs/mochitest.log missing?
 1:58.86 ERROR RemoteProcessMonitor | exception reading log: args: C:/Users/sasch/.mozbuild/android-sdk-windows/platform-tools/adb.exe wait-for-device pull /data/local/tmp/test_root/logs/mochitest.log C:\Users\sasch\AppData\Local\Temp\tmphin9fd49, exitcode: 1, stdout: adb: error: remote object '/data/local/tmp/test_root/logs/mochitest.log' does not exist
Component: Mach Core → Mochitest
Product: Firefox Build System → Testing

The severity field is not set for this bug.
:jmaher, could you have a look please?

For more information, please visit BugBot documentation.

Flags: needinfo?(jmaher)
Severity: -- → S4
Flags: needinfo?(jmaher)
Priority: -- → P2
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: