1654988 - Intermittent taskgraph.util.bugbug.BugbugTimeoutException: Timed out waiting for result from 'https://bugbug.herokuapp.com/push/integration/autoland/f6dc8b4c1814928ee3b8bfe1ea33a14ce9ae2328/schedules'

Status: RESOLVED FIXED

(Firefox Build System :: Task Configuration, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2020-07-24T05:46:54.467Z] optimize: source-test-wpt-manifest-upload removed because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.468Z] no files found matching a pattern in skip-unless-changed for source-test-wpt-metadata-summary
[task 2020-07-24T05:46:54.468Z] optimize: source-test-wpt-metadata-summary removed because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-arm-sim-linux32/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-arm64-sim-linux64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-asan-linux64/opt kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-compacting-linux64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-compacting-win64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-fuzzing-linux64/opt kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-gdb-linux64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-mozjs-sys-linux64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-nojit-linux64/opt kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-nonunified-linux64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-package-linux64/opt kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-plain-linux64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-plain-linux64/opt kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-plain-win64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.470Z] optimize: spidermonkey-sm-plain-win64/opt kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.471Z] optimize: spidermonkey-sm-rootanalysis-linux64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.471Z] optimize: spidermonkey-sm-rust-bindings-linux64/debug kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.471Z] optimize: spidermonkey-sm-tsan-linux64/opt kept because of 'skip-unless-changed (skip-unless-changed)' strategy
[task 2020-07-24T05:46:54.471Z] optimize: system-symbols-mac-upload-symbols kept because of 'never' strategy
[task 2020-07-24T05:46:54.471Z] optimize: system-symbols-win-upload-symbols kept because of 'never' strategy
[task 2020-07-24T05:54:58.722Z] Retrieving low-value jobs list from SETA
[task 2020-07-24T05:54:58.722Z] attempt 1/2
[task 2020-07-24T05:54:58.722Z] retry: calling get with args: ('https://treeherder.mozilla.org/api/project/autoland/seta/job-priorities/?build_system_type=taskcluster&priority=5',), kwargs: {'headers': '', 'timeout': 60}, attempt #1
[task 2020-07-24T05:55:02.968Z] PERFHERDER_DATA: {"suites": [{"name": "bugbug_push_schedules_time", "shouldAlert": false, "subtests": [], "lowerIsBetter": true, "value": 484.2503911440001}, {"name": "bugbug_push_schedules_retries", "shouldAlert": false, "subtests": [], "lowerIsBetter": true, "value": 48}], "framework": {"name": "build_metrics"}}
[task 2020-07-24T05:55:02.968Z] Traceback (most recent call last):
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/bugbug.py", line 68, in should_remove_task
[task 2020-07-24T05:55:02.968Z] data = push_schedules(branch, rev)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/python/mozbuild/mozbuild/util.py", line 1009, in call
[task 2020-07-24T05:55:02.968Z] self[args] = self.func(*args)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/util/bugbug.py", line 111, in push_schedules
[task 2020-07-24T05:55:02.968Z] raise BugbugTimeoutException("Timed out waiting for result from '{}'".format(url))
[task 2020-07-24T05:55:02.968Z] taskgraph.util.bugbug.BugbugTimeoutException: Timed out waiting for result from 'https://bugbug.herokuapp.com/push/integration/autoland/f6dc8b4c1814928ee3b8bfe1ea33a14ce9ae2328/schedules'
[task 2020-07-24T05:55:02.968Z]
[task 2020-07-24T05:55:02.968Z] During handling of the above exception, another exception occurred:
[task 2020-07-24T05:55:02.968Z]
[task 2020-07-24T05:55:02.968Z] Traceback (most recent call last):
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/mach_commands.py", line 205, in taskgraph_decision
[task 2020-07-24T05:55:02.968Z] return taskgraph.decision.taskgraph_decision(options)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/decision.py", line 266, in taskgraph_decision
[task 2020-07-24T05:55:02.968Z] write_artifact('task-graph.json', tgg.morphed_task_graph.to_json())
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/generator.py", line 213, in morphed_task_graph
[task 2020-07-24T05:55:02.968Z] return self._run_until('morphed_task_graph')
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/generator.py", line 374, in _run_until
[task 2020-07-24T05:55:02.968Z] k, v = next(self._run)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/generator.py", line 360, in _run
[task 2020-07-24T05:55:02.968Z] strategy_override=strategies,
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/init.py", line 64, in optimize_task_graph
[task 2020-07-24T05:55:02.968Z] do_not_optimize=do_not_optimize)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/init.py", line 140, in remove_tasks
[task 2020-07-24T05:55:02.968Z] if opt.should_remove_task(task, params, arg):
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/init.py", line 336, in should_remove_task
[task 2020-07-24T05:55:02.968Z] return self.reduce(results)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/init.py", line 376, in reduce
[task 2020-07-24T05:55:02.968Z] for rv in results:
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/init.py", line 332, in _generate_results
[task 2020-07-24T05:55:02.968Z] yield getattr(sub, fname)(task, params, arg)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/init.py", line 336, in should_remove_task
[task 2020-07-24T05:55:02.968Z] return self.reduce(results)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/init.py", line 356, in reduce
[task 2020-07-24T05:55:02.968Z] for rv in results:
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/init.py", line 332, in _generate_results
[task 2020-07-24T05:55:02.968Z] yield getattr(sub, fname)(task, params, arg)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/bugbug.py", line 74, in should_remove_task
[task 2020-07-24T05:55:02.968Z] return self.should_remove_task(task, params, importance)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/bugbug.py", line 65, in should_remove_task
[task 2020-07-24T05:55:02.968Z] return seta.is_low_value_task(task.label, params['project'])
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/seta.py", line 171, in is_low_value_task
[task 2020-07-24T05:55:02.968Z] self.low_value_tasks[project] = self.query_low_value_tasks(project)
[task 2020-07-24T05:55:02.968Z] File "/builds/worker/checkouts/gecko/taskcluster/taskgraph/optimize/seta.py", line 67, in query_low_value_tasks
[task 2020-07-24T05:55:02.968Z] task_list = json.loads(response.content).get('jobtypes', '')
[task 2020-07-24T05:55:02.968Z] File "/usr/lib/python3.5/json/init.py", line 312, in loads
[task 2020-07-24T05:55:02.968Z] s.class.name))
[task 2020-07-24T05:55:02.968Z] TypeError: the JSON object must be str, not 'bytes'
[taskcluster 2020-07-24 05:55:05.102Z] === Task Finished ===
[taskcluster 2020-07-24 05:55:20.556Z] Unsuccessful task run with exit code: 1 completed in 778.241 seconds

Comment 1

[Andreea Pavel [:apavel]]

First seen here https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&selectedTaskRun=e704Ia57R2GBF8hs1LFLUg.0&resultStatus=testfailed%2Cbusted%2Cexception&revision=d9e15f6cc3505d97898daafe3e6c7282060f2021

Comment 2

[Marco Castelluccio [:marco]]

It looks like bugbug timed out and its fallback (SETA) failed too.

Comment 3

[Natalia Csoregi [:nataliaCs]]

:ahal is there any chance you could help us out with this one? It's messing with the Gecko Decision tasks.
Thank you.

Comment 4

[Marco Castelluccio [:marco]]

With the changes I'm making as part of https://github.com/mozilla/bugbug/issues/1673 (https://bugzilla.mozilla.org/show_bug.cgi?id=1652572) the bugbug timeouts should become less frequent, but we have to fix the SETA error (or switch to something else as a fallback).

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 7

Platform breakdown:

• gecko-decision: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1654988&startday=2020-07-20&endday=2020-07-26&tree=all

Comment 6

[Marco Castelluccio [:marco]]

Callek pointed out it's a Python 3 issue in the SETA code. I'll fix it.

Comment 7

[Marco Castelluccio [:marco]]

Attachment: Bug 1654988 - Use response.json to parse the response from SETA. r=Callek

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/42a165c8ad37
Use response.json to parse the response from SETA. r=Callek

Comment 9

[Cristina Coroiu [:ccoroiu]]

https://hg.mozilla.org/mozilla-central/rev/42a165c8ad37

Comment 10

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 4

Platform breakdown:

• gecko-decision: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1654988&startday=2020-07-27&endday=2020-08-02&tree=all

Comment 11

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 2

Platform and build breakdown:

• gecko-decision: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1654988&startday=2021-02-08&endday=2021-02-14&tree=all