1739375 - High frequency Btime [Tier 2] [taskcluster:error] Aborting task... | Task aborted - max run time exceeded

Status: RESOLVED FIXED

(Testing :: Raptor, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2021-11-04T11:42:29.181Z] 11:42:29     INFO -  raptor-perftest Info: starting test: wasm-misc
[task 2021-11-04T11:42:29.202Z] 11:42:29     INFO -  raptor-benchmark Info: bench_dir contains:
[task 2021-11-04T11:42:29.202Z] 11:42:29     INFO -  raptor-benchmark Info: ['six-speed', 'SunSpider', 'ARES-6', 'Speedometer', 'resources', 'StyleBench', 'MotionMark', 'wasm-misc', 'wasm-godot', 'webaudio']
[task 2021-11-04T11:42:29.202Z] 11:42:29     INFO -  raptor-benchmark Info: writing wptserve headers file
[task 2021-11-04T11:42:29.203Z] 11:42:29     INFO -  raptor-benchmark Info: wrote wpt headers file: /opt/worker/tasks/task_163602475673429/build/tests/raptor/raptor/tests/webkit/PerformanceTests/__dir__.headers
[task 2021-11-04T11:42:29.203Z] 11:42:29     INFO -  raptor-benchmark Info: starting webserver on '127.0.0.1:49290'
[task 2021-11-04T11:42:29.203Z] 11:42:29     INFO -  raptor-benchmark Info: serving benchmarks from here: /opt/worker/tasks/task_163602475673429/build/tests/raptor/raptor/tests/webkit/PerformanceTests
[task 2021-11-04T11:42:29.204Z] 11:42:29     INFO -  raptor-browsertime Info: test: {'here': '/opt/worker/tasks/task_163602475673429/build/tests/raptor/raptor/tests/benchmarks', 'alert_threshold': '2.0', 'apps': 'firefox, chrome, chromium', 'fetch_task': 'wasm-misc', 'lower_is_better': True, 'owner': ':lth and SpiderMonkey Team', 'page_cycles': '5', 'page_timeout': '1200000', 'test_url': 'http://127.0.0.1:49290/wasm-misc/index.html?raptor', 'type': 'benchmark', 'unit': 'ms', 'name': 'wasm-misc', 'manifest': '/opt/worker/tasks/task_163602475673429/build/tests/raptor/raptor/tests/benchmarks/wasm-misc.ini', 'manifest_relpath': 'tests/benchmarks/wasm-misc.ini', 'path': '/opt/worker/tasks/task_163602475673429/build/tests/raptor/raptor/tests/benchmarks/wasm-misc', 'relpath': 'tests/benchmarks/wasm-misc', 'ancestor_manifest': 'raptor.ini', 'expected': 'pass', 'browser_cycles': 1, 'cold': False, 'expected_browser_cycles': 1, 'browser_cycle': 1}
[task 2021-11-04T11:42:29.205Z] 11:42:29     INFO -  raptor-browsertime-desktop Info: binary_path: /opt/worker/tasks/task_163602475673429/build/application/Firefox Nightly.app/Contents/MacOS/firefox
[task 2021-11-04T11:42:29.205Z] 11:42:29     INFO -  raptor-browsertime Info: timeout (s): 1200000
[task 2021-11-04T11:42:29.205Z] 11:42:29     INFO -  raptor-browsertime Info: browsertime cwd: /opt/worker/tasks/task_163602475673429/build
[task 2021-11-04T11:42:29.207Z] 11:42:29     INFO -  raptor-browsertime Info: browsertime cmd: /opt/worker/tasks/task_163602475673429/fetches/node/bin/node /opt/worker/tasks/task_163602475673429/fetches/browsertime/node_modules/browsertime/bin/browsertime.js --firefox.geckodriverPath /opt/worker/tasks/task_163602475673429/fetches/geckodriver /opt/worker/tasks/task_163602475673429/build/tests/raptor/raptor/browsertime/../../browsertime/browsertime_benchmark.js --firefox.noDefaultPrefs --browsertime.page_cycle_delay 1000 --skipHar --pageLoadStrategy none --webdriverPageload true --firefox.disableBrowsertimeExtension true --pageCompleteCheckStartWait 5000 --pageCompleteCheckPollTimeout 1000 --timeouts.pageLoad 1200000 --timeouts.script 6000000 --browsertime.page_cycles 5 --pageCompleteWaitTime 5000 --browsertime.url http://127.0.0.1:49290/wasm-misc/index.html?raptor --browsertime.post_startup_delay 1000 --firefox.env MOZ_WEBRENDER=1 --firefox.env MOZ_ACCELERATED=1 --browsertime.commands  --viewPort 1024x768 --browser firefox --firefox.binaryPath /opt/worker/tasks/task_163602475673429/build/application/Firefox Nightly.app/Contents/MacOS/firefox --firefox.profileTemplate /var/folders/ly/p9f8v1392v3f7m_0t2jx899c000014/T/tmp6juqqk4g/profile --resultDir /opt/worker/tasks/task_163602475673429/build/blobber_upload_dir/browsertime-results/wasm-misc --video false --visualMetrics false -n 1
[task 2021-11-04T11:42:29.207Z] 11:42:29     INFO -  raptor-browsertime Info: PATH: /opt/worker/tasks/task_163602475673429/build/venv/bin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin
[task 2021-11-04T11:42:29.895Z] 11:42:29     INFO -  raptor-browsertime Info: Running tests using Firefox - 1 iteration(s)
[task 2021-11-04T11:42:29.897Z] 11:42:29     INFO -  raptor-browsertime Info: Skip setting default preferences for Firefox
[task 2021-11-04T11:42:32.934Z] 11:42:32     INFO -  raptor-browsertime Info: Starting a browsertime benchamrk
[task 2021-11-04T11:42:32.934Z] 11:42:32     INFO -  raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2021-11-04T11:42:34.079Z] 11:42:34     INFO -  raptor-browsertime Info: Navigating to about:blank
[task 2021-11-04T11:42:34.079Z] 11:42:34     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 1
[task 2021-11-04T11:42:39.154Z] 11:42:39     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2021-11-04T11:42:40.154Z] 11:42:40     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2021-11-04T11:42:40.155Z] 11:42:40     INFO -  raptor-browsertime Info: Testing url http://127.0.0.1:49290/wasm-misc/index.html?raptor iteration 1
[task 2021-11-04T11:42:45.476Z] 11:42:45     INFO -  raptor-browsertime Info: Benchmark custom metric collection
[task 2021-11-04T11:42:45.481Z] 11:42:45     INFO -  raptor-browsertime Info: Waiting 3000 ms for data from benchmark...
[task 2021-11-04T11:42:48.525Z] 11:42:48     INFO -  raptor-browsertime Info: Waiting 3000 ms for data from benchmark...
<...>
[task 2021-11-04T11:55:32.634Z] 11:55:32     INFO -  raptor-browsertime Info: Waiting 3000 ms for data from benchmark...
[task 2021-11-04T11:55:35.789Z] 11:55:35     INFO -  raptor-browsertime Info: Waiting 3000 ms for data from benchmark...
[task 2021-11-04T11:55:38.941Z] 11:55:38     INFO -  raptor-browsertime Info: Waiting 3000 ms for data from benchmark...
[taskcluster:error] Aborting task...
[taskcluster:warn 2021-11-04T11:55:39.483Z] no such process
[taskcluster 2021-11-04T11:55:39.483Z] === Task Finished ===
[taskcluster 2021-11-04T11:55:39.484Z] Task Duration: 15m0.100431s
[taskcluster 2021-11-04T11:55:39.595Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2022-11-04T11:40:34.029Z
[taskcluster 2021-11-04T11:55:39.824Z] Uploading redirect artifact public/logs/live.log to URL https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WqkHWItYSzqfnedaIR40tg/runs/0/artifacts/public%2Flogs%2Flive_backing.log with mime type "text/plain; charset=utf-8" and expiry 2022-11-04T11:40:34.029Z
[taskcluster:error] Task aborted - max run time exceeded

Comment 1

[Cristina Cozmuta (:CrissCozmuta)]

Hi, can you please take a look over https://treeherder.mozilla.org/logviewer?job_id=356982774&repo=autoland&lineNumber=1356
Thank you !

Comment 2

[Lars T Hansen [:lth]]

I don't think I even know what I'm looking at here. Can it be pinned to a specific commit?

(Could be the caching code I guess, not much else has landed this week. Yury?)

Comment 3

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

This has been identified as a regression from the changes in bug 1474842 which got backed out.

Comment 4

[Cristina Cozmuta (:CrissCozmuta)]

Hello,

The bug was Resolved as FIXED with the backout for bug 1474842
https://bugzilla.mozilla.org/show_bug.cgi?id=1474842

Backout link : https://hg.mozilla.org/integration/autoland/rev/8077dd2baa24b2e0d9609c03e24807ee64a5d2b0

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• macosx1015-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1739375&startday=2021-11-01&endday=2021-11-07&tree=all

Comment 6

[Geoff Brown [:gbrown]]

I don't think bug 1474842 can be related to the current perma-fails on central.

I'm trying to find a regression range:
https://treeherder.mozilla.org/jobs?repo=autoland&searchStr=ytp-h264-sfr%2Clinux&fromchange=da9d3297348d579aaa8c794e723095eaa992429a&tochange=c99ad983ac65754f93124b52b4e38a975e8e531f

Comment 7

[Geoff Brown [:gbrown]]

https://treeherder.mozilla.org/jobs?repo=autoland&searchStr=ytp-h264-sfr%2Clinux&fromchange=2b7f8924b7377b3cae5e03d899b06c52271ca7b1&tochange=f487c7cc71ab72e12ce23e29034e670878068e2f

indicates this was regressed by bug 1734414. It turns out that change has already been backed out, so I expect the frequent mozilla-central failures to self-correct soon.

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 14

Platform and build breakdown:

• windows10-64-shippable-qr: 6
  • opt: 6
• linux1804-64-shippable-qr: 3
  • opt: 3
• macosx1014-64-shippable-qr: 1
  • opt: 1
• macosx1015-64-shippable-qr: 2
  • opt: 2
• linux1804-64-clang-trunk-qr: 2
  • opt: 2

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

Comment 9

[Intermittent Failures Robot]

9 failures in 3170 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1
• mozilla-central: 8

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1
• macosx1015-64-shippable-qr: 8
  • opt: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1739375&startday=2021-11-29&endday=2021-12-05&tree=all

Comment 10

[Intermittent Failures Robot]

6 failures in 3319 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4
• autoland: 2

Platform and build breakdown:

• macosx1015-64-shippable-qr: 4
  • opt: 4
• windows10-64-2004-qr: 2
  • debug: 2

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

Comment 11

[Intermittent Failures Robot]

6 failures in 3263 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 6

Platform and build breakdown:

• macosx1015-64-shippable-qr: 4
  • opt: 4
• windows10-64-shippable-qr: 2
  • opt: 2

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

Comment 12

[Intermittent Failures Robot]

4 failures in 2286 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4

Platform and build breakdown:

• macosx1015-64-shippable-qr: 4
  • opt: 4

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

Comment 13

[Intermittent Failures Robot]

10 failures in 2801 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 10

Platform and build breakdown:

• macosx1015-64-shippable-qr: 10
  • opt: 10

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

Comment 14

[Intermittent Failures Robot]

12 failures in 3060 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 10
• try: 2

Platform and build breakdown:

• macosx1015-64-shippable-qr: 10
  • opt: 10
• macosx1100-64-shippable-qr: 1
  • opt: 1
• macosx1015-64-devedition-qr: 1
  • opt: 1

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

Comment 15

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 4

Platform and build breakdown:

• macosx1015-64-shippable-qr: 4
  • opt: 4

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

Comment 16

[Mathew Hodson]

This seems to have been fixed by big 1750611. I don't see any failures on treeherder after Jan. 18.

Comment 17

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 2

Platform and build breakdown:

• windows10-64: 2
  • opt: 2

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