1381882 - publish to Balrog fails in 55.0b10 due to expired signoffs timestamp

Status: RESOLVED DUPLICATE of bug 1380796

(Release Engineering :: Release Automation: Other, defect)

Description

[Mihai Tabara [:mtabara]⌚️GMT]

Sounds like we have a signoff relative timestamp in the past. 
08:45:37     INFO -  Balrog request to https://aus4-admin.mozilla.org/api/rules/32
08:45:37     INFO -  Data sent: None
08:45:37     INFO -  Starting new HTTPS connection (1): aus4-admin.mozilla.org
08:45:37     INFO -  /builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/scripts/build-promotion/../../lib/python/vendor/requests-2.7.0/requests/packages/urllib3/util/ssl_.py:90: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. For more information, see https://urllib3.readthedocs.org/en/latest/security.html#insecureplatformwarning.
08:45:37     INFO -    InsecurePlatformWarning
08:45:38     INFO -  "GET /api/rules/32 HTTP/1.1" 200 451
08:45:38     INFO -  REQUEST STATS: {"url": "https://aus4-admin.mozilla.org/api/rules/32", "timestamp": 1500392738.34772, "method": "GET", "elapsed_secs": 0.540459156036377, "status_code": 200}
08:45:38     INFO -  Balrog request to https://aus4-admin.mozilla.org/api/rules/32
08:45:38     INFO -  Data sent: None
08:45:38     INFO -  Starting new HTTPS connection (1): aus4-admin.mozilla.org
08:45:38     INFO -  /builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/scripts/build-promotion/../../lib/python/vendor/requests-2.7.0/requests/packages/urllib3/util/ssl_.py:90: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. For more information, see https://urllib3.readthedocs.org/en/latest/security.html#insecureplatformwarning.
08:45:38     INFO -    InsecurePlatformWarning
08:45:39     INFO -  "HEAD /api/rules/32 HTTP/1.1" 200 0
08:45:39     INFO -  REQUEST STATS: {"url": "https://aus4-admin.mozilla.org/api/rules/32", "timestamp": 1500392739.418307, "method": "HEAD", "elapsed_secs": 1.0644500255584717, "status_code": 200}
08:45:39     INFO -  Balrog request to https://aus4-admin.mozilla.org/api/scheduled_changes/rules
08:45:39     INFO -  Data sent: {u'comment': None, 'change_type': 'update', u'fallbackMapping': u'Firefox-55.0b9-build2', u'buildID': None, u'backgroundRate': 100, u'product': u'Firefox', u'mapping': 'Firefox-55.0b10-build1', u'alias': u'firefox-beta', u'headerArchitecture': None, u'buildTarget': None, 'data_verison': 322, u'osVersion': None, u'distVersion': None, u'systemCapabilities': None, u'data_version': 322, 'when': 1500390000000, u'priority': 90, u'locale': None, u'version': None, u'update_type': u'minor', u'distribution': None, u'rule_id': '32', u'channel': u'beta'}
08:45:39     INFO -  "POST /api/scheduled_changes/rules HTTP/1.1" 400 54
08:45:39     INFO -  Caught HTTPError: {"when": ["Changes may not be scheduled in the past"]}
08:45:39     INFO -  REQUEST STATS: {"url": "https://aus4-admin.mozilla.org/api/scheduled_changes/rules", "timestamp": 1500392739.716355, "method": "POST", "elapsed_secs": 0.297713041305542, "status_code": 400}
08:45:39     INFO -  Traceback (most recent call last):
08:45:39     INFO -    File "/builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/scripts/build-promotion/balrog-release-shipper.py", line 53, in <module>
08:45:39     INFO -      args.build_number, args.rule_ids, args.schedule_at)
08:45:39     INFO -    File "/builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/scripts/build-promotion/../../lib/python/balrog/submitter/cli.py", line 522, in run
08:45:39     INFO -      ).add_scheduled_rule_change(**data)
08:45:39     INFO -    File "/builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/lib/python/vendor/balrogclient-0.0.4/balrogclient/api.py", line 254, in add_scheduled_rule_change
08:45:39     INFO -      return self.request(method='POST', data=rule_data)
08:45:39     INFO -    File "/builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/lib/python/vendor/balrogclient-0.0.4/balrogclient/api.py", line 111, in request
08:45:39     INFO -      return self.do_request(url, data, method)
08:45:39     INFO -    File "/builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/lib/python/vendor/balrogclient-0.0.4/balrogclient/api.py", line 130, in do_request
08:45:39     INFO -      req.raise_for_status()
08:45:39     INFO -    File "/builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/scripts/build-promotion/../../lib/python/vendor/requests-2.7.0/requests/models.py", line 851, in raise_for_status
08:45:39     INFO -      raise HTTPError(http_error_msg, response=self)
08:45:39     INFO -  requests.exceptions.HTTPError: 400 Client Error: BAD REQUEST
08:45:39    ERROR - Return code: 1
08:45:39    ERROR - 1 not in success codes: [0]
08:45:39  WARNING - setting return code to 2
08:45:39    FATAL - Halting on failure while running ['/tools/buildbot/bin/python', '/builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/tools/scripts/build-promotion/balrog-release-shipper.py', '--api-root', u'https://aus4-admin.mozilla.org/api', '--credentials-file', '/builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/oauth.txt', '--username', 'balrog-ffxbld', '--version', u'55.0b10', '--product', u'firefox', '--build-number', '1', '--verbose', '--rules', '32', '--schedule-at', u'2017-07-18T15:00:00+00:00']
08:45:39    FATAL - Running post_fatal callback...
08:45:39    FATAL - Exiting 2
08:45:39     INFO - [mozharness: 2017-07-18 15:45:39.731023Z] Finished submit-to-balrog step (failed)
08:45:39     INFO - Running post-run listener: copy_logs_to_upload_dir
08:45:39     INFO - Copying logs to upload dir...
08:45:39     INFO - mkdir: /builds/slave/rel-m-beta-fx_sc_p_in_balrog-0/build/upload/logs
program finished with exit code 2


Full log[1]

[1]: https://archive.mozilla.org/pub/firefox/tinderbox-builds/mozilla-beta-noarch/release-mozilla-beta-firefox_schedule_publishing_in_balrog-bm74-build1-build1.txt.gz

Comment 1

[[e-mail] (:bhearsum)]

It's probably obvious, but in case it's not: this is because Balrog doesn't allow you to schedule changes in the future.

https://bugzilla.mozilla.org/show_bug.cgi?id=1380796 is probably the right fix for this -- there's no reason to wait to schedule publishing until so late in the release promotion process.

Comment 2

[Mihai Tabara [:mtabara]⌚️GMT]

Note to self: short time solutions for this:

0. Have RelMan set better ETA in Ship-it - to rather later dates than earlier.

1. We could remove the "schedule balrog change" from the "human decision task" dependencies and chain it up to the latest automation step we have, but before the human decision task. This way the task runs along with the rest of the tasks and doesn't necessarily needs to wait upon human decision task which usually happens the next day after QE signoff. See bug 1380796 for that.

Comment 3

[Mihai Tabara [:mtabara]⌚️GMT]

I'll go ahead and close this, continuing any work in bug 1380796 which is already tracking https://bugzilla.mozilla.org/show_bug.cgi?id=1381882#c2 1).