Open
Bug 1916019
Opened 3 months ago
Updated 3 months ago
Intermittent | runjunit.py | The previous test failed because of an error in the test harness | org.mozilla.geckoview.test.rule.TestHarnessException: org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
Categories
(GeckoView Graveyard :: Sandboxing, defect, P5)
Tracking
(Not tracked)
NEW
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: sstanca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=472413283&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/cDqo-da-TluIOjm8e8_y-A/runs/1/artifacts/public/logs/live_backing.log
[task 2024-08-31T00:02:41.212Z] 00:02:41 INFO - TEST-PASS | org.mozilla.geckoview.test.SelectionActionDelegateTest#compareClientRect[#x-input] | took 6355ms
[task 2024-08-31T00:02:41.691Z] 00:02:41 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=1162
[task 2024-08-31T00:02:41.691Z] 00:02:41 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2024-08-31T00:02:41.691Z] 00:02:41 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2024-08-31T00:02:41.691Z] 00:02:41 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=pasteImage[#x-input]
[task 2024-08-31T00:02:41.691Z] 00:02:41 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SelectionActionDelegateTest
[task 2024-08-31T00:02:41.691Z] 00:02:41 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=853
[task 2024-08-31T00:02:41.691Z] 00:02:41 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2024-08-31T00:02:41.691Z] 00:02:41 INFO - TEST-START | org.mozilla.geckoview.test.SelectionActionDelegateTest#pasteImage[#x-input]
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=1162
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | Error in pasteImage[#x-input](org.mozilla.geckoview.test.SelectionActionDelegateTest):
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | org.mozilla.geckoview.test.rule.TestHarnessException: org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.initTest(GeckoSessionTestRule.java:1484)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0(GeckoSessionTestRule.java:1501)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.$r8$lambda$iCBopfpsbLU-HFWW53O-4m1PB6c(GeckoSessionTestRule.java)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2$$ExternalSyntheticLambda1.run(D8$$SyntheticClass:0)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at java.util.concurrent.FutureTask.run(FutureTask.java:237)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2024-08-31T00:03:12.893Z] 00:03:12 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2024-08-31T00:03:12.894Z] 00:03:12 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2024-08-31T00:03:12.894Z] 00:03:12 INFO - org.mozilla.geckoview.test | Caused by: org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2024-08-31T00:03:12.894Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutRunnable.run(UiThreadUtils.java:49)
[task 2024-08-31T00:03:12.894Z] 00:03:12 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2024-08-31T00:03:12.894Z] 00:03:12 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2024-08-31T00:03:12.894Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.util.UiThreadUtils.waitForCondition(UiThreadUtils.java:158)
[task 2024-08-31T00:03:12.894Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.openSession(GeckoSessionTestRule.java:1344)
[task 2024-08-31T00:03:12.894Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.prepareStatement(GeckoSessionTestRule.java:1278)
[task 2024-08-31T00:03:12.895Z] 00:03:12 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.initTest(GeckoSessionTestRule.java:1480)
[task 2024-08-31T00:03:12.895Z] 00:03:12 INFO - org.mozilla.geckoview.test | ... 13 more
[task 2024-08-31T00:03:12.895Z] 00:03:12 INFO - org.mozilla.geckoview.test |
[task 2024-08-31T00:03:12.895Z] 00:03:12 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2024-08-31T00:03:12.895Z] 00:03:12 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=pasteImage[#x-input]
[task 2024-08-31T00:03:12.895Z] 00:03:12 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SelectionActionDelegateTest
[task 2024-08-31T00:03:12.896Z] 00:03:12 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=org.mozilla.geckoview.test.rule.TestHarnessException: org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2024-08-31T00:03:12.896Z] 00:03:12 INFO - SUITE-END | took 1517s
[task 2024-08-31T00:03:12.896Z] 00:03:12 WARNING - TEST-UNEXPECTED-FAIL | runjunit.py | The previous test failed because of an error in the test harness | org.mozilla.geckoview.test.rule.TestHarnessException: org.mozilla.geckoview.test.util.UiThreadUtils$TimeoutException: Timed out after 30000ms
[task 2024-08-31T00:03:12.897Z] 00:03:12 INFO - Stopping web server
[task 2024-08-31T00:03:12.906Z] 00:03:12 INFO - Server shut down.
[task 2024-08-31T00:03:12.906Z] 00:03:12 INFO - Web server killed.
[task 2024-08-31T00:03:12.906Z] 00:03:12 INFO - Stopping web socket server
[task 2024-08-31T00:03:12.908Z] 00:03:12 INFO - Stopping ssltunnel
[task 2024-08-31T00:03:13.868Z] 00:03:13 INFO - Return code: 255
[task 2024-08-31T00:03:13.868Z] 00:03:13 ERROR - No tests run or test summary not found
[task 2024-08-31T00:03:13.868Z] 00:03:13 INFO - TinderboxPrint: geckoview-junit<br/><em class="testfail">T-FAIL</em>
[task 2024-08-31T00:03:13.868Z] 00:03:13 INFO - ##### geckoview-junit log ends
[task 2024-08-31T00:03:13.869Z] 00:03:13 WARNING - setting return code to 1
[task 2024-08-31T00:03:13.869Z] 00:03:13 INFO - The geckoview-junit suite: geckoview-junit ran with return status: WARNING
[task 2024-08-31T00:03:13.869Z] 00:03:13 INFO - Running post-action listener: _package_coverage_data
[task 2024-08-31T00:03:13.869Z] 00:03:13 INFO - Running post-action listener: _resource_record_post_action
[task 2024-08-31T00:03:13.869Z] 00:03:13 INFO - Running post-action listener: process_java_coverage_data
[task 2024-08-31T00:03:13.869Z] 00:03:13 INFO - Running post-action listener: stop_device
[task 2024-08-31T00:03:14.591Z] 00:03:14 INFO - /data/tombstones/tombstone_00 deleted
[task 2024-08-31T00:03:14.591Z] 00:03:14 INFO - Killing logcat pid 1404.
[task 2024-08-31T00:03:14.591Z] 00:03:14 INFO - Killing every process called qemu-system-x86_64
[task 2024-08-31T00:03:14.602Z] 00:03:14 INFO - [mozharness: 2024-08-31 00:03:14.602027Z] Finished run-tests step (success)
[task 2024-08-31T00:03:14.602Z] 00:03:14 INFO - Running post-run listener: _resource_record_post_run
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - Total resource usage - Wall time: 1564s; CPU: 37%; Read bytes: 4096; Write bytes: 630972416; Read time: 224; Write time: 535312
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - TinderboxPrint: CPU usage<br/>37.1%
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - TinderboxPrint: I/O read bytes / time<br/>4,096 / 224
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - TinderboxPrint: I/O write bytes / time<br/>630,972,416 / 535,312
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - TinderboxPrint: CPU guest<br/>2,252.3 (15.5%)
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - TinderboxPrint: CPU idle<br/>7,693.5 (52.9%)
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - TinderboxPrint: CPU system<br/>821.1 (5.6%)
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - TinderboxPrint: CPU user<br/>3,763.2 (25.9%)
[task 2024-08-31T00:03:15.638Z] 00:03:15 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2024-08-31T00:03:15.644Z] 00:03:15 INFO - start-emulator - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-08-31T00:03:15.653Z] 00:03:15 INFO - verify-device - Wall time: 31s; CPU: 26%; Read bytes: 0; Write bytes: 16019456; Read time: 0; Write time: 11588
[task 2024-08-31T00:03:15.659Z] 00:03:15 INFO - install - Wall time: 10s; CPU: 34%; Read bytes: 4096; Write bytes: 328904704; Read time: 224; Write time: 310264
[task 2024-08-31T00:03:15.829Z] 00:03:15 INFO - run-tests - Wall time: 1522s; CPU: 37%; Read bytes: 0; Write bytes: 273309696; Read time: 0; Write time: 199584
[task 2024-08-31T00:03:20.498Z] 00:03:20 WARNING - returning nonzero exit status 1
[task 2024-08-31T00:03:21.308Z] cleanup
[task 2024-08-31T00:03:21.308Z] + cleanup
[task 2024-08-31T00:03:21.308Z] + local rv=1
[task 2024-08-31T00:03:21.308Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2024-08-31T00:03:21.308Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2024-08-31T00:03:21.312Z] + '[' ']'
[task 2024-08-31T00:03:21.312Z] + true
[task 2024-08-31T00:03:21.312Z] + cleanup_xvfb
[task 2024-08-31T00:03:21.313Z] ++ pidof Xvfb
[task 2024-08-31T00:03:21.320Z] + local xvfb_pid=58
[task 2024-08-31T00:03:21.320Z] + local vnc=false
[task 2024-08-31T00:03:21.320Z] + local interactive=false
[task 2024-08-31T00:03:21.320Z] + '[' -n 58 ']'
[task 2024-08-31T00:03:21.320Z] + [[ false == false ]]
[task 2024-08-31T00:03:21.320Z] + [[ false == false ]]
[task 2024-08-31T00:03:21.320Z] + kill 58
[task 2024-08-31T00:03:21.320Z] + screen -XS xvfb quit
[task 2024-08-31T00:03:21.325Z] + exit 1
[taskcluster 2024-08-31 00:03:22.193Z] === Task Finished ===
[taskcluster 2024-08-31 00:03:25.608Z] Unsuccessful task run with exit code: 1 completed in 1981.012 seconds
| Comment hidden (Intermittent Failures Robot) |
You need to log in
before you can comment on or make changes to this bug.
Description
•