1618731 - Intermittent CRITICAL - Chain of Trust verification error! | ERROR - Hit ScriptWorkerException: "'payload'"

Status: RESOLVED FIXED

(Release Engineering :: General, defect)

Description

[Razvan Maries]

Push with failure: https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedJob=290869837&resultStatus=testfailed%2Cbusted%2Cexception&revision=9cd1c479544f94ddac8c615d381ed9a3cf60cf47&searchStr=os%2Cx%2Ccross%2Ccompiled%2Cshippable%2Copt%2Cbuild-signing-macosx64-shippable%2Fopt%2C%28bs%29

Falilure log: https://firefoxci.taskcluster-artifacts.net/I3EfGDR1RMG-K6pbKudvmw/0/public/logs/chain_of_trust.log

2020-02-28T00:21:35 INFO - Running scriptworker version 32.0.2
2020-02-28T00:21:35 INFO - build_task_dependencies signing I3EfGDR1RMG-K6pbKudvmw
2020-02-28T00:21:35 INFO - find_sorted_task_dependencies signing I3EfGDR1RMG-K6pbKudvmw
2020-02-28T00:21:35 INFO - found dependencies: [('signing:parent', 'a2Ct7e-_R7e11mCZ2C82qw'), ('signing:build', 'PscoxBI4SlusqdqTtdEf7Q')]
2020-02-28T00:21:35 DEBUG - signing:parent a2Ct7e-_R7e11mCZ2C82qw is docker-worker
2020-02-28T00:21:35 DEBUG - makedirs(/builds/dep1/work/cot/a2Ct7e-_R7e11mCZ2C82qw)
2020-02-28T00:21:35 INFO - build_task_dependencies signing:parent a2Ct7e-_R7e11mCZ2C82qw
2020-02-28T00:21:35 INFO - find_sorted_task_dependencies signing:parent a2Ct7e-_R7e11mCZ2C82qw
2020-02-28T00:21:35 INFO - found dependencies: [('signing:parent:parent', 'a2Ct7e-_R7e11mCZ2C82qw')]
2020-02-28T00:21:35 DEBUG - signing:build PscoxBI4SlusqdqTtdEf7Q is docker-worker
2020-02-28T00:21:35 DEBUG - makedirs(/builds/dep1/work/cot/PscoxBI4SlusqdqTtdEf7Q)
2020-02-28T00:21:35 INFO - build_task_dependencies signing:build PscoxBI4SlusqdqTtdEf7Q
2020-02-28T00:21:35 INFO - find_sorted_task_dependencies signing:build PscoxBI4SlusqdqTtdEf7Q
2020-02-28T00:21:35 INFO - found dependencies: [('signing:build:parent', 'a2Ct7e-_R7e11mCZ2C82qw'), ('signing:build:docker-image', 'IIEnKGrFS36vh4xj9p_DqQ')]
2020-02-28T00:21:35 DEBUG - signing:build:docker-image IIEnKGrFS36vh4xj9p_DqQ is docker-worker
2020-02-28T00:21:35 DEBUG - makedirs(/builds/dep1/work/cot/IIEnKGrFS36vh4xj9p_DqQ)
2020-02-28T00:21:35 INFO - build_task_dependencies signing:build:docker-image IIEnKGrFS36vh4xj9p_DqQ
2020-02-28T00:21:35 INFO - find_sorted_task_dependencies signing:build:docker-image IIEnKGrFS36vh4xj9p_DqQ
2020-02-28T00:21:35 INFO - found dependencies: [('signing:build:docker-image:parent', 'WbhpFZUARK-oX1VKy_6h_w'), ('signing:build:docker-image:docker-image', 'Qc1jybi4TFC0VSCNvcRJ4g')]
2020-02-28T00:21:35 CRITICAL - Chain of Trust verification error!
Traceback (most recent call last):
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 1900, in verify_chain_of_trust
await build_task_dependencies(chain, chain.task, chain.name, chain.task_id)
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 606, in build_task_dependencies
await build_link(chain, task_name, task_id)
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 581, in build_link
await build_task_dependencies(chain, task_defn, task_name, task_id)
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 606, in build_task_dependencies
await build_link(chain, task_name, task_id)
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 581, in build_link
await build_task_dependencies(chain, task_defn, task_name, task_id)
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 606, in build_task_dependencies
await build_link(chain, task_name, task_id)
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 575, in build_link
link.task = task_defn
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 246, in task
self.task_type = guess_task_type(self.name, self.task)
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/cot/verify.py", line 389, in guess_task_type
if is_action(task_defn):
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/task.py", line 531, in is_action
if _extract_from_env_in_payload(task, "ACTION_CALLBACK"):
File "/builds/dep1/lib/python3.7/site-packages/scriptworker/task.py", line 255, in _extract_from_env_in_payload
return task["payload"].get("env", {}).get(key, default)
KeyError: 'payload'
2020-02-28T00:21:35 ERROR - Hit ScriptWorkerException: "'payload'"
2020-02-28T00:21:35 DEBUG - "/builds/dep1/artifacts/public/logs/chain_of_trust.log" is encoded with "None" and has mime/type "text/plain"
2020-02-28T00:21:35 INFO - "/builds/dep1/artifacts/public/logs/chain_of_trust.log" can be gzip'd. Compressing...

Comment 1

[Aki Sasaki (not active)]

That's bizarre. I don't know if a task can exist without a payload. All of the taskIds listed appear to have payloads.
I wonder if we got a hiccup in response from taskcluster, querying a task's definition?

Comment 2

[Aki Sasaki (not active)]

Happened again: https://firefoxci.taskcluster-artifacts.net/X5Q9cxUwSLucCNWSCUGwdA/0/public/logs/chain_of_trust.log

Comment 3

[Cosmin Sabou [:CosminS]]

Also here: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&searchStr=os%2Cx%2Ccross%2Ccompiled%2Cshippable%2Copt%2Clocalised%2Crepacks%2Cshippable-l10n-signing-macosx64-shippable-15%2Fopt%2Cl10n%28bs15%29&revision=7af89df4d3721a884d7b9e8f5e572ca6628f637e

Failure log: https://firefox-ci-tc.services.mozilla.com/tasks/XXrOf4E7QSKgs_XiN73NWg/runs/0/logs/https%3A%2F%2Ffirefox-ci-tc.services.mozilla.com%2Fapi%2Fqueue%2Fv1%2Ftask%2FXXrOf4E7QSKgs_XiN73NWg%2Fruns%2F0%2Fartifacts%2Fpublic%2Flogs%2Fchain_of_trust.log

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• mozilla-central: 3

Platform breakdown:

• osx-shippable: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618731&startday=2020-02-24&endday=2020-03-01&tree=all

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-esr68: 1

Platform breakdown:

• osx-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618731&startday=2020-03-30&endday=2020-04-05&tree=all

Comment 7

[Aki Sasaki (not active)]

Attachment: [scriptworker] retry getting task definiton

Comment 8

[Aki Sasaki (not active)]

Attachment: [scriptworker-scripts] scriptworker 33.1.0

Comment 9

[Aki Sasaki (not active)]

Pushed to the mac signing pool. I'll merge to the docker scriptworkers shortly.

Comment 10

[Aki Sasaki (not active)]

This should be fixed on our end, with detection+retries.
Bug 1628088 tracks fixing the queue.