From ccb00d6827cccccb86ad5dbd55b226f13aed30fc Mon Sep 17 00:00:00 2001 From: "James E. Blair" Date: Tue, 6 Sep 2022 15:04:09 -0700 Subject: Log more info on gerrit 403 errors If Gerrit returns a 403 on submit, log the text we get in reply to help diagnose the problem. Change-Id: I8c9b286bb63ba1703a6a8f3cd6cd9a4b86e62cf2 --- tests/base.py | 10 ++++++++++ tests/unit/test_gerrit.py | 19 +++++++++++++++++++ zuul/driver/gerrit/gerritconnection.py | 27 ++++++++++++++++----------- 3 files changed, 45 insertions(+), 11 deletions(-) diff --git a/tests/base.py b/tests/base.py index cebcf2e1f..cf6296f62 100644 --- a/tests/base.py +++ b/tests/base.py @@ -1031,6 +1031,11 @@ class GerritWebServer(object): self.send_response(500) self.end_headers() + def _403(self, msg): + self.send_response(403) + self.end_headers() + self.wfile.write(msg.encode('utf8')) + def _404(self): self.send_response(404) self.end_headers() @@ -1073,6 +1078,9 @@ class GerritWebServer(object): if not change: return self._404() + if not fake_gerrit._fake_submit_permission: + return self._403('submit not permitted') + candidate = self._get_change(change_id) sr = candidate.getSubmitRecords() if sr[0]['status'] != 'OK': @@ -1306,6 +1314,8 @@ class FakeGerritConnection(gerritconnection.GerritConnection): self._poller_event = poller_event self._ref_watcher_event = ref_watcher_event self._fake_submit_whole_topic = False + self._fake_submit_permission = True + self.submit_retry_backoff = 0 def onStop(self): super().onStop() diff --git a/tests/unit/test_gerrit.py b/tests/unit/test_gerrit.py index 47545b9be..e98cb80b5 100644 --- a/tests/unit/test_gerrit.py +++ b/tests/unit/test_gerrit.py @@ -359,6 +359,25 @@ class TestGerritWeb(ZuulTestCase): changes="1,1 2,1 3,1"), ], ordered=False) + def test_submit_failure(self): + # Test that we log the reason for a submit failure (403 error) + self.fake_gerrit._fake_submit_permission = False + A = self.fake_gerrit.addFakeChange('org/project1', "master", "A") + A.addApproval('Code-Review', 2) + with self.assertLogs('zuul.test.FakeGerritConnection', level='INFO' + ) as full_logs: + self.fake_gerrit.addEvent(A.addApproval('Approved', 1)) + self.waitUntilSettled() + self.log.debug("Full logs:") + for x in full_logs.output: + self.log.debug(x) + self.assertRegexInList( + r'Error submitting data to gerrit on attempt 3: ' + 'Received response 403: submit not permitted', + full_logs.output) + + self.assertEqual(A.data['status'], 'NEW') + class TestFileComments(AnsibleZuulTestCase): config_file = 'zuul-gerrit-web.conf' diff --git a/zuul/driver/gerrit/gerritconnection.py b/zuul/driver/gerrit/gerritconnection.py index 2213293f8..d8e4df586 100644 --- a/zuul/driver/gerrit/gerritconnection.py +++ b/zuul/driver/gerrit/gerritconnection.py @@ -589,6 +589,7 @@ class GerritConnection(ZKChangeCacheMixin, ZKBranchCacheMixin, BaseConnection): _poller_class = GerritPoller _ref_watcher_class = GitWatcher ref_watcher_poll_interval = 60 + submit_retry_backoff = 10 def __init__(self, driver, connection_name, connection_config): super(GerritConnection, self).__init__(driver, connection_name, @@ -753,7 +754,8 @@ class GerritConnection(ZKChangeCacheMixin, ZKBranchCacheMixin, BaseConnection): if r.status_code == 400: raise HTTPBadRequestException('Received response 400: %s' % r.text) elif r.status_code != 200: - raise Exception("Received response %s" % (r.status_code,)) + raise Exception("Received response %s: %s" % ( + r.status_code, r.text)) ret = None if r.text and len(r.text) > 4: try: @@ -1315,10 +1317,10 @@ class GerritConnection(ZKChangeCacheMixin, ZKBranchCacheMixin, BaseConnection): log.exception( "Bad request submitting check data to gerrit.") break - except Exception: - log.exception("Error submitting check data to gerrit, " - "attempt %s", x) - time.sleep(x * 10) + except Exception as e: + log.exception("Error submitting check data to gerrit on " + "attempt %s: %s", x, e) + time.sleep(x * self.submit_retry_backoff) def review_http(self, item, message, submit, labels, checks_api, file_comments, phase1, phase2, @@ -1375,10 +1377,12 @@ class GerritConnection(ZKChangeCacheMixin, ZKBranchCacheMixin, BaseConnection): log.exception( "Bad request submitting check data to gerrit.") break - except Exception: + except Exception as e: log.exception( - "Error submitting data to gerrit, attempt %s", x) - time.sleep(x * 10) + "Error submitting data to gerrit " + "on attempt %s: %s", + x, e) + time.sleep(x * self.submit_retry_backoff) if phase2 and change.is_current_patchset and submit: for x in range(1, 4): try: @@ -1392,10 +1396,11 @@ class GerritConnection(ZKChangeCacheMixin, ZKBranchCacheMixin, BaseConnection): log.exception( "Bad request submitting check data to gerrit.") break - except Exception: + except Exception as e: log.exception( - "Error submitting data to gerrit, attempt %s", x) - time.sleep(x * 10) + "Error submitting data to gerrit on attempt %s: %s", + x, e) + time.sleep(x * self.submit_retry_backoff) def queryChangeSSH(self, number, event=None): args = '--all-approvals --comments --commit-message' -- cgit v1.2.1