1346396 - Intermittent googleapiclient.errors.HttpError: <HttpError 403 when requesting https://www.googleapis.com/upload/androidpublisher/v2/applications/org.mozilla.fennec_aurora/edits/14997794091118478425/apks?uploadType=media&alt=json returned "APK specifies...

Status: RESOLVED DUPLICATE of bug 1317783

(Release Engineering :: General, defect)

Description

[Treeherder Bug Filer]

Filed by: rvandermeulen [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=83084340&repo=mozilla-aurora

https://queue.taskcluster.net/v1/task/UNyXi2e8RsmOovWe_xWZFw/runs/0/artifacts/public/logs/live_backing.log

googleapiclient.errors.HttpError: <HttpError 403 when requesting https://www.googleapis.com/upload/androidpublisher/v2/applications/org.mozilla.fennec_aurora/edits/14997794091118478425/apks?uploadType=media&alt=json returned "APK specifies a version code that has already been used.">

Comment 1

[Ryan VanderMeulen [:RyanVM]]

Johan, do you know what this error means? I'm wondering if it's due to us disabling uploads to Google Play.

Comment 2

[Johan Lorenzo [:jlorenzo]]

Thanks for filing this bug, Ryan, You're right, that's related to disabling uploads on Play Store. This error means: These APKs have already been uploaded and we can't upload them once more.

What happened is the following:
1. I turned the task creator[1] back on at 5:04pm UTC.
2. There were half a dozen messages in the pulse queue which the task creator reads from. All of them were processed. This includes auroras that were built between bug 1345559 and March 10th. This is one problem.
3. Normally, the task creator looks up on Treeherder if a similar task exists[2]. In this case, it went so fast, that Treeherder reported twice no tasks were created.

That's why 3 tasks popped up, but only the first once succeeded. This won't happen until the next time we deactivate Aurora.

Hence, the fixes are:
* short term: each time we shut down the task creator, we also delete the pulse queue[3]. That queue will be automatically recreated when the task creator is back.
* long term fix: stop using that task creator, in favor of an in-tree task. This requires bug 1317783, which I'm gonna tackle this week.


Here below, the logs which show how it happened.

> 2017-03-10 17:04:58,951 - worker.py - INFO - Processing revision "a7744be94bea4581220cfce7c48e22fb96ac2bf3" from repository "mozilla-aurora" (triggered by completed task "B_dd179ZRGu4-xeTwPZCoA") 
> 2017-03-10 17:05:03,948 - publish.py - INFO - Created task ajg4khETQ_aGXP72yO6B5w: {'status': {'schedulerId': '-', 'workerType': 'pushapk-v1', 'expires': '2018-03-10T18:05:01.238Z', 'deadline': '2017-03-10T18:05:01.238Z', 'state': 'pending', 'runs': [{'state': 'pending', 'scheduled': '2017-03-10T17:05:03.723Z', 'reasonCreated': 'scheduled', 'runId': 0}], 'taskId': 'ajg4khETQ_aGXP72yO6B5w', 'taskGroupId': 'ajg4khETQ_aGXP72yO6B5w', 'provisionerId': 'scriptworker-prov-v1', 'retriesLeft': 0}} 
> 2017-03-10 17:05:03,948 - worker.py - INFO - Marking message as read. Processed task "B_dd179ZRGu4-xeTwPZCoA" 
> 2017-03-10 17:05:04,224 - worker.py - INFO - Processing revision "a7744be94bea4581220cfce7c48e22fb96ac2bf3" from repository "mozilla-aurora" (triggered by completed task "Qd_zGQx7QNWq6dLSC5ebOA") 
> 2017-03-10 17:05:07,420 - publish.py - INFO - Created task UNyXi2e8RsmOovWe_xWZFw: {'status': {'schedulerId': '-', 'workerType': 'pushapk-v1', 'expires': '2018-03-10T18:05:05.853Z', 'deadline': '2017-03-10T18:05:05.853Z', 'state': 'pending', 'runs': [{'state': 'pending', 'scheduled': '2017-03-10T17:05:07.182Z', 'reasonCreated': 'scheduled', 'runId': 0}], 'taskId': 'UNyXi2e8RsmOovWe_xWZFw', 'taskGroupId': 'UNyXi2e8RsmOovWe_xWZFw', 'provisionerId': 'scriptworker-prov-v1', 'retriesLeft': 0}} 
> 2017-03-10 17:05:07,421 - worker.py - INFO - Marking message as read. Processed task "Qd_zGQx7QNWq6dLSC5ebOA" 
> 2017-03-10 17:05:07,697 - worker.py - INFO - Processing revision "a7744be94bea4581220cfce7c48e22fb96ac2bf3" from repository "mozilla-aurora" (triggered by completed task "Kw6quZJfT9uzBFBN1hh6Fg") 
> 2017-03-10 17:05:10,813 - publish.py - INFO - Created task eFShBlzQToeP4MlZT398hA: {'status': {'schedulerId': '-', 'workerType': 'pushapk-v1', 'expires': '2018-03-10T18:05:09.305Z', 'deadline': '2017-03-10T18:05:09.305Z', 'state': 'pending', 'runs': [{'state': 'pending', 'scheduled': '2017-03-10T17:05:10.574Z', 'reasonCreated': 'scheduled', 'runId': 0}], 'taskId': 'eFShBlzQToeP4MlZT398hA', 'taskGroupId': 'eFShBlzQToeP4MlZT398hA', 'provisionerId': 'scriptworker-prov-v1', 'retriesLeft': 0}} 
> 2017-03-10 17:05:10,814 - worker.py - INFO - Marking message as read. Processed task "Kw6quZJfT9uzBFBN1hh6Fg" 
> 2017-03-10 17:05:11,092 - worker.py - INFO - Processing revision "a7744be94bea4581220cfce7c48e22fb96ac2bf3" from repository "mozilla-aurora" (triggered by completed task "LqV_4gnYRB6fE_G0wjgp1g") 
> 2017-03-10 17:05:11,384 - worker.py - WARNING - A treeherder job already exists for revision "a7744be94bea4581220cfce7c48e22fb96ac2bf3" in repository "mozilla-aurora" 
> 2017-03-10 17:05:11,384 - worker.py - INFO - Marking message as read. Processed task "LqV_4gnYRB6fE_G0wjgp1g" 
> 2017-03-11 09:33:45,593 - worker.py - INFO - Processing revision "858b0ab812dfd88fa701a3e4f307f56bb1246e80" from repository "mozilla-aurora" (triggered by completed task "bNXTYHDMT3itfE9bfDmstQ") 


[1] https://github.com/mozilla-releng/fennec-aurora-task-creator
[2] https://github.com/mozilla-releng/fennec-aurora-task-creator/blob/master/fennec_aurora_task_creator/publish.py#L25
[3] https://pulseguardian.mozilla.org/queues

Comment 3

[Johan Lorenzo [:jlorenzo]]

The task creator is not needed anymore thanks to the task being in-tree (bug 1317783). We shouldn't see that failure anymore. Please reopen if it comes back.