1776751 - Permanent condprof TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 370 seconds with no output when version increase hasn't been merged to autoland yet

Status: RESOLVED INCOMPLETE

(Testing :: Performance, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=382653011&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/CTf_roecQL6-SKZSN9GgGQ/runs/0/artifacts/public/logs/live_backing.log

---

mozilla-central got the version increased from 103 to 104 and a new conditioned profile artifact got created. On autoland, the version is still 103 (merge back is scheduled after the next merge from autoland to mozilla-central, also merging autoland to mozilla-central could be blocked for older, good merge candidates).

The tests with conditioned profile fail on autoland because the application has a lower version number and rejects to launch with the profile with a higher version number.

Comment 1

[Intermittent Failures Robot]

85 failures in 562 pushes (0.151 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 85

Platform and build breakdown:

• linux1804-64-qr: 45
  • opt: 45
• windows10-64-2004-shippable-qr: 16
  • opt: 16
• linux1804-64-shippable-qr: 16
  • opt: 16
• windows10-64-2004-qr: 8
  • opt: 8

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

Comment 2

[Cosmin Sabou [:CosminS]]

These didn't show up beginning with this range, looks like they're fixed.

Comment 3

[Greg Mierzwinski [:sparky]]

:jmaher, this is very likely to come back again. One idea to resolve this could be to somehow perform a profile upgrade in condprof just before the test. This would be similar to having it upgraded on mozilla-central.

Comment 4

[Joel Maher ( :jmaher ) (UTC -8)]

:sparky, I am leaning towards a versioned profile in the index- then we can retrigger older stuff. Do you have thoughts on versioned profiles vs upgrade in place?

Comment 5

[Greg Mierzwinski [:sparky]]

Good idea :jmaher! If you can trigger condprof to run on version changes in autoland, that should resolve this issue (assuming version changes are the only thing that impact the profile compatibility).

Comment 6

[Joel Maher ( :jmaher ) (UTC -8)]

oh, I wasn't thinking that- I might consider that. I was thinking of just calling the artifact profile-v104-linux64-full.tgz or something like that. I guess if there are other needs to upgrade the profile then we are sort of screwed. I have a mostly completed patch to add versions with a fallback to existing profiles- not sure if it makes sense to continue on with that, or investigate ways to upload artifacts to an index from autoland and trigger as needed

Comment 7

[Greg Mierzwinski [:sparky]]

Is there someone we could ask about whether version changes are the only culprit or if there are others?

This is why I suggested upgrading the profile with condprof before using it in the test. I'm not suggesting a full re-run of the conditioning scenarios, but just opening the profile, allowing an upgrade, then using it in the test. It's relatively simple to use condprof within the test harnesses also, here's where we make use of it in raptor: https://searchfox.org/mozilla-central/source/testing/raptor/raptor/perftest.py#274

If you set force_new to false, then it'll take the latest archive produced on m-c and update it. You'd need to add some code to skip running the scenarios though: https://searchfox.org/mozilla-central/source/testing/condprofile/condprof/creator.py#180

Comment 8

[Joel Maher ( :jmaher ) (UTC -8)]

that seems straightforward, launch the profile, let it upgrade, then use it for copies for tests that need it.

in a scenario where we need to downgrade, we are sort of screwed. I think we need to take both approaches:

1. add an artifact which includes the version number so we can always reference it. This will allow for "downgrades" or older try pushes to work
2. add a profile upgrade step after downloading a profile, basically download, run firefox and let it upgrade, then copy the profile around as needed for tests.

Comment 9

[Greg Mierzwinski [:sparky]]

Good point! I agree, using both approaches solves the issue. The only question now is if the version is enough.

Comment 10

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: Bug 1776751 - use version with conditioned profile. r=sparky!

Comment 11

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

A patch has been attached on this bug, which was already closed. Filing a separate bug will ensure better tracking. If this was not by mistake and further action is needed, please alert the appropriate party.

Comment 12

[Intermittent Failures Robot]

85 failures in 3312 pushes (0.026 failures/push) were associated with this bug in the last 7 days.

This is the #6 most frequent failure this week.

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

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

Repository breakdown:

• autoland: 85

Platform and build breakdown:

• linux1804-64-qr: 45
  • opt: 45
• windows10-64-2004-shippable-qr: 16
  • opt: 16
• linux1804-64-shippable-qr: 16
  • opt: 16
• windows10-64-2004-qr: 8
  • opt: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1776751&startday=2022-06-27&endday=2022-07-03&tree=all

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/72650713a83e
use version with conditioned profile. r=sparky

Comment 14

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/72650713a83e

Comment 15

[Joel Maher ( :jmaher ) (UTC -8)]

going to fix this to update the INDEX with a version, not just the artifact name.

Comment 17

[Intermittent Failures Robot]

48 failures in 525 pushes (0.091 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 48

Platform and build breakdown:

• linux1804-64-shippable-qr: 38
  • opt: 38
• linux1804-64-qr: 8
  • opt: 8
• windows10-64-2004-shippable-qr: 2
  • opt: 2

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

Comment 18

[Intermittent Failures Robot]

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

This is the #12 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: 48
• try: 8

Platform and build breakdown:

• linux1804-64-shippable-qr: 38
  • opt: 38
• linux1804-64-qr: 8
  • opt: 8
• windows10-64-2004-shippable-qr: 2
  • opt: 2
• windows10-64-2004-qr: 8
  • opt: 8

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

Comment 19

[Intermittent Failures Robot]

15 failures in 565 pushes (0.027 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 15

Platform and build breakdown:

• windows10-64-2004-qr: 7
  • opt: 7
• windows10-64-2004-shippable-qr: 8
  • opt: 8

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

Comment 20

[Intermittent Failures Robot]

15 failures in 3293 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 15

Platform and build breakdown:

• windows10-64-2004-qr: 7
  • opt: 7
• windows10-64-2004-shippable-qr: 8
  • opt: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1776751&startday=2022-08-22&endday=2022-08-28&tree=all

Comment 21

[Intermittent Failures Robot]

42 failures in 500 pushes (0.084 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 42

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 21
  • opt: 21
• linux1804-64-shippable-qr: 21
  • opt: 21

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

Comment 22

[Marian-Vasile Laza]

There have been 43 total failures in the last 7 days, recent failure log.
Affected platforms are:

• linux1804-64-shippable-qr
• windows10-64-2004-qr
• windows10-64-2004-shippable-qr

[task 2022-09-21T19:00:54.750Z] 19:00:54     INFO - TEST-INFO | started process GECKO(824)
[task 2022-09-21T19:00:55.214Z] 19:00:55     INFO - GECKO(824) | 1663786855226	Marionette	INFO	Marionette enabled
[task 2022-09-21T19:00:55.228Z] 19:00:55     INFO - GECKO(824) | 1663786855228	Marionette	TRACE	Received observer notification final-ui-startup
[task 2022-09-21T19:00:55.230Z] 19:00:55     INFO - GECKO(824) | 1663786855229	Marionette	INFO	Listening on port 2828
[task 2022-09-21T19:00:55.231Z] 19:00:55     INFO - GECKO(824) | 1663786855229	Marionette	DEBUG	Marionette is listening
[task 2022-09-21T19:03:55.735Z] 19:03:55     INFO - runtests.py | Waiting for browser...
[task 2022-09-21T19:07:05.246Z] 19:07:05     INFO - Buffered messages finished
[task 2022-09-21T19:07:05.248Z] 19:07:05    ERROR - TEST-UNEXPECTED-TIMEOUT | automation.py | application timed out after 370 seconds with no output
[task 2022-09-21T19:07:05.248Z] 19:07:05    ERROR - Force-terminating active process(es).
[task 2022-09-21T19:07:05.249Z] 19:07:05     INFO - Determining child pids from psutil...
[task 2022-09-21T19:07:05.253Z] 19:07:05     INFO - [8264]
[task 2022-09-21T19:07:05.254Z] 19:07:05     INFO - ==> process 8264 launched child process 2360 ("Z:\task_166378584991358\build\application\firefox\firefox.exe" -contentproc --channel="8264.0.787247084\2020129246" -parentBuildID 20220921180701 -prefsHandle 1900 -prefMapHandle 1892 -prefsLen 21845 -prefMapSize 255114 -appDir "Z:\task_166378584991358\build\application\firefox\browser" - {c1a50efb-7386-47b1-ae34-f73b13038234} 8264 "\\.\pipe\gecko-crash-server-pipe.8264" 1980 158a2df8258 gpu)
[task 2022-09-21T19:07:05.254Z] 19:07:05     INFO - Found child pids: {8264, 2360}
[task 2022-09-21T19:07:05.255Z] 19:07:05     INFO - Killing process: 8264
[task 2022-09-21T19:07:05.261Z] 19:07:05     INFO - TEST-INFO | started process screenshot
[task 2022-09-21T19:07:05.335Z] 19:07:05     INFO - TEST-INFO | screenshot: exit 0

Comment 23

[Intermittent Failures Robot]

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

This is the #14 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

Platform and build breakdown:

• linux1804-64-shippable-qr: 21
  • opt: 21
• windows10-64-2004-shippable-qr: 21
  • opt: 21
• windows10-64-2004-qr: 1
  • opt: 1

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

Comment 24

[Joel Maher ( :jmaher ) (UTC -8)]

another issue with bumping firefox versions- one of these days I need to fix this.

Comment 25

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 26

[Jens Stutte [:jstutte]]

This seems to happen again? Plain central run: https://treeherder.mozilla.org/jobs?repo=try&revision=f0a9b60b2c0471af9dd9e385a68bc5070d33cd10

Comment 27

[Joel Maher ( :jmaher ) (UTC -8)]

we never did get a fix for condprof tasks and the version change. My simple half day of hacking didn't work. The good news is this seems to be the last remaining condprof issue (we had a lot of small issues when we first turned these on)

Comment 28

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=399360530&repo=autoland

Comment 29

[Intermittent Failures Robot]

24 failures in 542 pushes (0.044 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 24

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 5
  • opt: 5
• linux1804-64-qr: 9
  • opt: 9
• linux1804-64-shippable-qr: 4
  • opt: 4
• windows10-64-2004-qr: 6
  • opt: 6

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

Comment 30

[Intermittent Failures Robot]

24 failures in 3558 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 24

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 5
  • opt: 5
• linux1804-64-qr: 9
  • opt: 9
• linux1804-64-shippable-qr: 4
  • opt: 4
• windows10-64-2004-qr: 6
  • opt: 6

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

Comment 31

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 32

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=402539489&repo=autoland

Comment 33

[Cosmin Sabou [:CosminS]]

Joel, could you have another go at this? Each release cycle we're hitting this again and it's not really pleasant. Thank you.

Comment 34

[Intermittent Failures Robot]

37 failures in 601 pushes (0.062 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 37

Platform and build breakdown:

• linux1804-64-shippable-qr: 15
  • opt: 15
• windows10-64-2004-shippable-qr: 9
  • opt: 9
• linux1804-64-qr: 9
  • opt: 9
• windows10-64-2004-qr: 4
  • opt: 4

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

Comment 35

[Intermittent Failures Robot]

37 failures in 3717 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

** 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: 37

Platform and build breakdown:

• linux1804-64-shippable-qr: 15
  • opt: 15
• windows10-64-2004-shippable-qr: 9
  • opt: 9
• linux1804-64-qr: 9
  • opt: 9
• windows10-64-2004-qr: 4
  • opt: 4

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

Comment 36

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: Bug 1776751 - allow condprof tests to fallback to previous version. r=sparky!

Comment 37

[Joel Maher ( :jmaher ) (UTC -8)]

we will know in a few weeks if this fix works reliably.

Comment 38

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/54c6a2aa9f2e
allow condprof tests to fallback to previous version. r=sparky

Comment 39

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/54c6a2aa9f2e

Comment 40

[Cristian Tuns]

I will reopen this because it is happening again on autoland only for now. On linux/windows https://treeherder.mozilla.org/logviewer?job_id=411863229&repo=autoland / https://treeherder.mozilla.org/logviewer?job_id=411860037&repo=autoland

Comment 41

[Joel Maher ( :jmaher ) (UTC -8)]

this failed again, what happened was:

• we bumped firefox to v114.0a1
• condprof client tried to download m-c.latest.firefox v113.0a1
• it fell back to 2 days prior 2023.04.08.firefox.latest
  • this failed because it didn't exist- only 1 task on m-c ran that day and it was a fixed_by_commit: https://treeherder.mozilla.org/jobs?repo=mozilla-central&searchStr=firefox-full&revision=80d1079b264cb63cae33dca7270a13dad4269708
• finally went with latest which is firefox v114

so this is an edge case- really the only case I saw in the last 6 weeks.

:sparky- any thoughts on what to do here? leave it alone, fix something?

Comment 42

[Intermittent Failures Robot]

25 failures in 320 pushes (0.078 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 25

Platform and build breakdown:

• linux1804-64-qr: 6
  • opt: 6
• windows11-64-2009-qr: 9
  • opt: 9
• linux1804-64-shippable-qr: 8
  • opt: 8
• windows11-64-2009-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1776751&startday=2023-04-10&endday=2023-04-10&tree=all

Comment 43

[Greg Mierzwinski [:sparky]]

I agree, I don't think we'll see this happen too often either so we can leave it alone.

Comment 44

[Intermittent Failures Robot]

25 failures in 3206 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 25

Platform and build breakdown:

• linux1804-64-qr: 6
  • opt: 6
• windows11-64-2009-qr: 9
  • opt: 9
• linux1804-64-shippable-qr: 8
  • opt: 8
• windows11-64-2009-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1776751&startday=2023-04-10&endday=2023-04-16&tree=all

Comment 45

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1776751&startday=2023-04-17&endday=2023-04-23&tree=all

Comment 46

[Intermittent Failures Robot]

2 failures in 3177 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 2

Platform and build breakdown:

• linux1804-64-qr: 2
  • opt: 2

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

Comment 47

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.