1797132 - Android gtest crash may result in task retry

Status: RESOLVED FIXED

(Testing :: GTest, defect)

Description

[Geoff Brown [:gbrown]]

I called MOZ_CRASH during a gtest, to verify appropriate crash handling and reporting. All is well on desktop, but on Android, the task retried (probably because it reported an ADBTimeoutError).

https://treeherder.mozilla.org/jobs?repo=try&revision=20de5962cd389763a4e4ea6a96f9c00b1a1631a0

https://firefoxci.taskcluster-artifacts.net/Qu8H8N3NSsaeFUM-mvX2dg/0/public/logs/live_backing.log

[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -  gtest ERROR | args: adb wait-for-device shell am start -W -n org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity -a android.intent.action.MAIN --es env0 XPCOM_DEBUG_BREAK=stack-and-abort --es env1 MOZ_CRASHREPORTER_NO_REPORT=1 --es env2 MOZ_CRASHREPORTER=1 --es env3 MOZ_RUN_GTEST=1 --es env4 MOZ_TBPL_PARSER=1 --es env5 MOZ_GTEST_LOG_PATH=/data/local/tmp/test_root/gtest.log --es env6 MOZ_GTEST_CWD=/data/local/tmp/test_root/gtest-profile --es env7 MOZ_GTEST_MINIDUMPS_PATH=/data/local/tmp/test_root/gtest-minidumps --es env8 MOZ_IN_AUTOMATION=1 --es env9 MOZ_ANDROID_LIBDIR_OVERRIDE=/data/local/tmp/test_root/gtest/libxul.so --es env10 MOZ_WEBRENDER=1 --es arg0 -unittest --es arg1 --gtest_death_test_style=threadsafe --es arg2 '-profile /data/local/tmp/test_root/gtest-profile' --ez use_multiprocess False; echo adb_returncode=$?, exitcode: None, stdout: Starting: Intent { act=android.intent.action.MAIN cmp=org.mozilla.geckoview.test_runner/.TestRunnerActivity (has extras) }
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -  Traceback (most recent call last):
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -    File "/builds/worker/workspace/build/tests/gtest/remotegtests.py", line 463, in main
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -      options.symbols_path,
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -    File "/builds/worker/workspace/build/tests/gtest/remotegtests.py", line 135, in run_gtest
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -      extra_args=args,
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -    File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/mozdevice/adb.py", line 4346, in launch_activity
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -      timeout=timeout,
[task 2022-10-24T16:32:19.775Z] 16:32:19     INFO -    File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/mozdevice/adb.py", line 4150, in launch_application
[task 2022-10-24T16:32:19.775Z] 16:32:19     INFO -      cmd_output = self.shell_output(cmd, timeout=timeout)
[task 2022-10-24T16:32:19.775Z] 16:32:19     INFO -    File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/mozdevice/adb.py", line 2220, in shell_output
[task 2022-10-24T16:32:19.775Z] 16:32:19 CRITICAL -      raise ADBTimeoutError("%s" % adb_process)
[task 2022-10-24T16:32:19.776Z] 16:32:19 CRITICAL -  mozdevice.adb.ADBTimeoutError: args: adb wait-for-device shell am start -W -n org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity -a android.intent.action.MAIN --es env0 XPCOM_DEBUG_BREAK=stack-and-abort --es env1 MOZ_CRASHREPORTER_NO_REPORT=1 --es env2 MOZ_CRASHREPORTER=1 --es env3 MOZ_RUN_GTEST=1 --es env4 MOZ_TBPL_PARSER=1 --es env5 MOZ_GTEST_LOG_PATH=/data/local/tmp/test_root/gtest.log --es env6 MOZ_GTEST_CWD=/data/local/tmp/test_root/gtest-profile --es env7 MOZ_GTEST_MINIDUMPS_PATH=/data/local/tmp/test_root/gtest-minidumps --es env8 MOZ_IN_AUTOMATION=1 --es env9 MOZ_ANDROID_LIBDIR_OVERRIDE=/data/local/tmp/test_root/gtest/libxul.so --es env10 MOZ_WEBRENDER=1 --es arg0 -unittest --es arg1 --gtest_death_test_style=threadsafe --es arg2 '-profile /data/local/tmp/test_root/gtest-profile' --ez use_multiprocess False; echo adb_returncode=$?, exitcode: None, stdout: Starting: Intent { act=android.intent.action.MAIN cmp=org.mozilla.geckoview.test_runner/.TestRunnerActivity (has extras) }
[task 2022-10-24T16:32:19.787Z] 16:32:19    ERROR - Return code: 1
[task 2022-10-24T16:32:19.787Z] 16:32:19    ERROR - No tests run or test summary not found

(OTOH, I see no open bugs for this type of failure, and there are known intermittent gtest crashes -- maybe it only happens sometimes?).

Comment 1

[Geoff Brown [:gbrown]]

The tests ran for only a second, and the process went down quickly:
https://firefoxci.taskcluster-artifacts.net/Qu8H8N3NSsaeFUM-mvX2dg/0/public/test_info/logcat-emulator-5554.log

10-24 16:27:20.220  5840  5855 I gtest   : TEST-INFO | GTest unit test starting
10-24 16:27:20.220  5840  5855 I gtest   : TEST-START | IntlBidi.SimpleLTR
...
10-24 16:27:20.424  5840  5855 I gtest   : TEST-START | SpanTest.from_nullptr_constructor
10-24 16:27:20.432  5840  5855 W google-breakpad: ExceptionHandler::GenerateDump cloned child 
10-24 16:27:20.432  5840  5855 W google-breakpad: 5876
10-24 16:27:20.432  5876  5855 W google-breakpad: ExceptionHandler::WaitForContinueSignal waiting for continue signal...
10-24 16:27:20.432  5840  5855 W google-breakpad: 
10-24 16:27:20.433  5840  5855 W google-breakpad: ExceptionHandler::SendContinueSignalToChild sent continue signal to child
10-24 16:27:20.523  1660  1697 W InputDispatcher: channel 'a7d3fba org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity (server)' ~ Consumer closed input channel or an error occurred.  events=0x9
10-24 16:27:20.523  1660  1697 E InputDispatcher: channel 'a7d3fba org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
10-24 16:27:20.523  1660  1770 I WindowManager: WIN DEATH: Window{1451dc8 u0 SurfaceView - org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity}
10-24 16:27:20.523  1660  2064 D GraphicsStats: Buffer count: 3
10-24 16:27:20.523  1660  1770 I WindowManager: Destroying surface Surface(name=SurfaceView - org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity) called by com.android.server.wm.WindowStateAnimator.destroySurface:2014 com.android.server.wm.WindowStateAnimator.destroySurfaceLocked:881 com.android.server.wm.WindowState.removeLocked:1449 com.android.server.wm.WindowManagerService.removeWindowInnerLocked:2478 com.android.server.wm.WindowManagerService.removeWindowLocked:2436 com.android.server.wm.WindowState$DeathRecipient.binderDied:1780 android.os.BinderProxy.sendDeathNotice:688 <bottom of call stack> 
10-24 16:27:20.524  1660  2096 I ActivityManager: Process org.mozilla.geckoview.test_runner (pid 5840) has died
10-24 16:27:20.524  1660  2096 D ActivityManager: cleanUpApplicationRecord -- 5840
10-24 16:27:20.525  1660  2096 W ActivityManager: Force removing ActivityRecord{6ae0250 u0 org.mozilla.geckoview.test_runner/.TestRunnerActivity t2}: app died, no saved state
...
10-24 16:27:20.563  1344  1344 I Zygote  : Process 5840 exited due to signal (11)

but the test script was waiting around for 5 minutes:
https://firefoxci.taskcluster-artifacts.net/Qu8H8N3NSsaeFUM-mvX2dg/0/public/logs/live_backing.log

[task 2022-10-24T16:27:19.771Z] 16:27:19     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 XPCOM_DEBUG_BREAK=stack-and-abort --es env1 MOZ_CRASHREPORTER_NO_REPORT=1 --es env2 MOZ_CRASHREPORTER=1 --es env3 MOZ_RUN_GTEST=1 --es env4 MOZ_TBPL_PARSER=1 --es env5 MOZ_GTEST_LOG_PATH=/data/local/tmp/test_root/gtest.log --es env6 MOZ_GTEST_CWD=/data/local/tmp/test_root/gtest-profile --es env7 MOZ_GTEST_MINIDUMPS_PATH=/data/local/tmp/test_root/gtest-minidumps --es env8 MOZ_IN_AUTOMATION=1 --es env9 MOZ_ANDROID_LIBDIR_OVERRIDE=/data/local/tmp/test_root/gtest/libxul.so --es env10 MOZ_WEBRENDER=1 --es arg0 -unittest --es arg1 --gtest_death_test_style=threadsafe --es arg2 '-profile /data/local/tmp/test_root/gtest-profile' --ez use_multiprocess False
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -  gtest ERROR | args: adb wait-for-device shell am start -W -n org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity -a android.intent.action.MAIN --es env0 XPCOM_DEBUG_BREAK=stack-and-abort --es env1 MOZ_CRASHREPORTER_NO_REPORT=1 --es env2 MOZ_CRASHREPORTER=1 --es env3 MOZ_RUN_GTEST=1 --es env4 MOZ_TBPL_PARSER=1 --es env5 MOZ_GTEST_LOG_PATH=/data/local/tmp/test_root/gtest.log --es env6 MOZ_GTEST_CWD=/data/local/tmp/test_root/gtest-profile --es env7 MOZ_GTEST_MINIDUMPS_PATH=/data/local/tmp/test_root/gtest-minidumps --es env8 MOZ_IN_AUTOMATION=1 --es env9 MOZ_ANDROID_LIBDIR_OVERRIDE=/data/local/tmp/test_root/gtest/libxul.so --es env10 MOZ_WEBRENDER=1 --es arg0 -unittest --es arg1 --gtest_death_test_style=threadsafe --es arg2 '-profile /data/local/tmp/test_root/gtest-profile' --ez use_multiprocess False; echo adb_returncode=$?, exitcode: None, stdout: Starting: Intent { act=android.intent.action.MAIN cmp=org.mozilla.geckoview.test_runner/.TestRunnerActivity (has extras) }
[task 2022-10-24T16:32:19.774Z] 16:32:19     INFO -  Traceback (most recent call last):
...

Comment 2

[Geoff Brown [:gbrown]]

Attachment: Bug 1797132 - Improve Android gtest crash reporting; r=

Do not wait for gtest process completion in mozdevice; instead, rely
on existing gtest support for waiting for process completion.
The mozdevice no-wait code was broken; fixed here.

Comment 3

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/460e8620ad58
Improve Android gtest crash reporting; r=jmaher

Comment 4

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/460e8620ad58