1791111 - Intermittent Android Wd TEST-UNEXPECTED-TIMEOUT | expected OK (TEST-INFO took 80003ms)

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=390623365&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MuOTw7euT_WBK-QCbX_32A/runs/0/artifacts/public/logs/live_backing.log

---

[task 2022-09-15T22:24:08.630Z] 22:24:08     INFO - PID 4352 | 1663280648629	webdriver::server	DEBUG	-> POST /session/b0ffaa3c-b3e3-4465-abe8-9a74df924395/frame {"id": null}
[task 2022-09-15T22:24:08.666Z] 22:24:08     INFO - PID 4352 | 1663280648665	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2022-09-15T22:24:08.670Z] 22:24:08     INFO - PID 4352 | 1663280648669	webdriver::server	DEBUG	-> DELETE /session/b0ffaa3c-b3e3-4465-abe8-9a74df924395
[task 2022-09-15T22:24:08.735Z] 22:24:08     INFO - PID 4352 | 1663280648734	webdriver::server	DEBUG	Teardown session
[task 2022-09-15T22:24:08.735Z] 22:24:08     INFO - PID 4352 | 1663280648734	geckodriver::android	DEBUG	Force stopping the Android package: org.mozilla.geckoview.test_runner
[task 2022-09-15T22:24:08.736Z] 22:24:08     INFO - PID 4352 | 1663280648734	mozdevice	DEBUG	Force stopping Android package: org.mozilla.geckoview.test_runner
[task 2022-09-15T22:24:08.736Z] 22:24:08     INFO - PID 4352 | 1663280648734	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-09-15T22:24:08.737Z] 22:24:08     INFO - PID 4352 | 1663280648734	mozdevice	TRACE	execute_host_command: << []
[task 2022-09-15T22:24:08.737Z] 22:24:08     INFO - PID 4352 | 1663280648734	mozdevice	TRACE	execute_host_command: >> "shell:am force-stop org.mozilla.geckoview.test_runner"
[task 2022-09-15T22:24:08.957Z] 22:24:08     INFO - PID 4352 | 1663280648956	mozdevice	TRACE	execute_host_command: << ""
[task 2022-09-15T22:24:08.957Z] 22:24:08     INFO - PID 4352 | 1663280648956	mozdevice	TRACE	execute_host_command: >> "host:transport:emulator-5554"
[task 2022-09-15T22:24:08.957Z] 22:24:08     INFO - PID 4352 | 1663280648956	mozdevice	TRACE	execute_host_command: << []
[task 2022-09-15T22:24:08.958Z] 22:24:08     INFO - PID 4352 | 1663280648956	mozdevice	TRACE	execute_host_command: >> "shell:am clear-debug-app org.mozilla.geckoview.test_runner"
[task 2022-09-15T22:24:09.149Z] 22:24:09     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/permissions/set.py | expected OK
[task 2022-09-15T22:24:09.149Z] 22:24:09     INFO - TEST-INFO took 80004ms
[task 2022-09-15T22:24:09.150Z] 22:24:09     INFO - Restarting browser for new test group
[task 2022-09-15T22:24:09.218Z] 22:24:09     INFO - Closing logging queue
[task 2022-09-15T22:24:09.219Z] 22:24:09     INFO - queue closed
[task 2022-09-15T22:24:09.308Z] 22:24:09     INFO - PID 4449 | 1663280649306	geckodriver	INFO	Listening on 127.0.0.1:34731
[task 2022-09-15T22:24:09.308Z] 22:24:09     INFO - Starting runner
[task 2022-09-15T22:24:09.539Z] 22:24:09     INFO - TEST-START | /webdriver/tests/release_actions/release.py

Comment 1

[Norisz Fay [:noriszfay]]

Hey Henrik, could this also be a different Wd issue or is it just part of one the bugs in "See Also"? Could you take a look please? Thank you!

P.S: There's also this failure, if you could take a look at it, seems to start the same but it looks different after the Force stopping the Android package: org.mozilla.geckoview.test_runner line

Comment 2

[Intermittent Failures Robot]

19 failures in 3023 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 17
• mozilla-central: 2

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 18
  • debug: 15
  • debug-isolated-process: 3
• android-em-7-0-x86_64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1791111&startday=2022-09-12&endday=2022-09-18&tree=all

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+1]]

This seems to be a regression from bug 1780219 which mainly affects debug builds on Android. As it looks like the devices or the network are slower then AWS. We should fix both bug 1791373 and bug 1757721.

Comment 4

[BugBot [:suhaib / :marco/ :calixte]]

:masterwayz, since you are the author of the regressor, bug 1780219, could you take a look?

For more information, please visit auto_nag documentation.

Comment 6

[Michelle Goossens [:masterwayz]]

Hi :whimboo, I assume this depends on another bug? Or what's the plan?

Comment 8

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Michelle, please see the marked dependencies which track further work to improve some misbehavior or inefficient code.

But basically there was a regression when moving to GCP. Do you know if we have a different worker configuration for the Android jobs in terms of SDD speed etc? I feel that disk throughput has been decrated.

Comment 9

[Michelle Goossens [:masterwayz]]

There's a difference I would bet due to the major difference in the overall instance size. However I'm not sure what the disk size and type is that AWS runs on.

Comment 10

[Michelle Goossens [:masterwayz]]

:ahal, do you know how we could best figure that out?

Comment 11

[Intermittent Failures Robot]

18 failures in 500 pushes (0.036 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-beta: 1
• autoland: 17

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 17
  • debug-isolated-process: 11
  • debug: 6
• android-em-7-0-x86_64-lite-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1791111&startday=2022-09-19&endday=2022-09-19&tree=all

Comment 12

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Not a single failure for the most recent merge from autoland to mozilla-central:
https://treeherder.mozilla.org/jobs?repo=mozilla-central&searchStr=wd%2Candroid

I'm going to mark this bug as fixed for both central and beta because the patch from bug 1757721 got already uplifted.

Note that any other timeout failure that might come up for Wdspec on Android will be related to bug 1790325 or bug 1790329.

Comment 13

[Intermittent Failures Robot]

56 failures in 2909 pushes (0.019 failures/push) were associated with this bug in the last 7 days.

This is the #8 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 43
• mozilla-beta: 3
• mozilla-central: 8
• try: 2

Platform and build breakdown:

• android-em-7-0-x86_64-qr: 54
  • debug: 25
  • debug-isolated-process: 29
• android-em-7-0-x86_64-lite-qr: 1
  • opt: 1
• linux1804-64-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1791111&startday=2022-09-19&endday=2022-09-25&tree=all

Comment 14

[Intermittent Failures Robot]

1 failures in 3743 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-lite-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1791111&startday=2022-10-24&endday=2022-10-30&tree=all

Comment 15

[Intermittent Failures Robot]

1 failures in 3530 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 1

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-lite-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1791111&startday=2023-01-09&endday=2023-01-15&tree=all

Comment 16

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.