[FIX] runbot_merge: incorrectly logged PRs

A while back I implemented name_get/display_name to print PRs using
the canonical github format (owner/repo#number), however looks like
some of the logging calls were still using bespoke formatting.

runbot_merge/controllers/__init__.py

@@ -60,7 +60,7 @@ def handle_pr(env, event):
         'labeled', 'unlabeled'
     ]:
         _logger.debug(
-            'Ignoring pull_request[%s] on %s:%s',
+            'Ignoring pull_request[%s] on %s#%s',
             event['action'],
             event['pull_request']['base']['repo']['full_name'],
             event['pull_request']['number'],
@@ -129,7 +129,7 @@ def handle_pr(env, event):
         return "Nothing to update ({})".format(event['changes'].keys())
 
     if not branch:
-        _logger.info("Ignoring PR for un-managed branch %s:%s", r, b)
+        _logger.info("Ignoring PR for un-managed branch %s#%s", r, b)
         return "Not set up to care about {}:{}".format(r, b)
 
     author_name = pr['user']['login']
@@ -140,21 +140,21 @@ def handle_pr(env, event):
             'github_login': author_name,
         })
 
-    _logger.info("%s: %s:%s (%s) (%s)", event['action'], repo.name, pr['number'], pr['title'].strip(), author.github_login)
+    _logger.info("%s: %s#%s (%s) (%s)", event['action'], repo.name, pr['number'], pr['title'].strip(), author.github_login)
     if event['action'] == 'opened':
         pr_obj = env['runbot_merge.pull_requests']._from_gh(pr)
         return "Tracking PR as {}".format(pr_obj.id)
 
     pr_obj = env['runbot_merge.pull_requests']._get_or_schedule(r, pr['number'])
     if not pr_obj:
-        _logger.warning("webhook %s on unknown PR %s:%s, scheduled fetch", event['action'], repo.name, pr['number'])
+        _logger.warning("webhook %s on unknown PR %s#%s, scheduled fetch", event['action'], repo.name, pr['number'])
         return "Unknown PR {}:{}, scheduling fetch".format(repo.name, pr['number'])
     if event['action'] == 'synchronize':
         if pr_obj.head == pr['head']['sha']:
             return 'No update to pr head'
 
         if pr_obj.state in ('closed', 'merged'):
-            _logger.error("Tentative sync to closed PR %s:%s", repo.name, pr['number'])
+            _logger.error("Tentative sync to closed PR %s", pr.display_name)
             return "It's my understanding that closed/merged PRs don't get sync'd"
 
         if pr_obj.state == 'ready':
@@ -245,7 +245,7 @@ def handle_comment(env, event):
     issue = event['issue']['number']
     author = event['comment']['user']['login']
     comment = event['comment']['body']
-    _logger.info('comment[%s]: %s %s:%s "%s"', event['action'], author, repo, issue, comment)
+    _logger.info('comment[%s]: %s %s#%s "%s"', event['action'], author, repo, issue, comment)
     if event['action'] != 'created':
         return "Ignored: action (%r) is not 'created'" % event['action']
 
@@ -257,7 +257,7 @@ def handle_review(env, event):
     author = event['review']['user']['login']
     comment = event['review']['body'] or ''
 
-    _logger.info('review[%s]: %s %s:%s "%s"', event['action'], author, repo, pr, comment)
+    _logger.info('review[%s]: %s %s#%s "%s"', event['action'], author, repo, pr, comment)
     if event['action'] != 'submitted':
         return "Ignored: action (%r) is not 'submitted'" % event['action']
 

runbot_merge/github.py

@@ -158,7 +158,7 @@ class GH(object):
             if _is_json(r.response):
                 body = r.response.json()
                 if any(e.message == 'User is blocked' for e in (body.get('errors') or [])):
-                    _logger.warning("comment(%s:%s) failed: user likely blocked", self._repo, pr)
+                    _logger.warning("comment(%s#%s) failed: user likely blocked", self._repo, pr)
                     return
             raise
         _logger.debug('comment(%s, %s, %s)', self._repo, pr, shorten(message))

runbot_merge/models/pull_requests.py

@@ -108,7 +108,7 @@ class Project(models.Model):
                 gh.change_tags(pr, to_tags)
             except Exception:
                 _logger.exception(
-                    "Error while trying to change the tags of %s:%s from %s to %s",
+                    "Error while trying to change the tags of %s#%s from %s to %s",
                     repo.name, pr, _TAGS[from_ or False], to_tags,
                 )
             else:
@@ -142,7 +142,7 @@ class Project(models.Model):
                     gh.comment(f.pull_request, message)
             except Exception:
                 _logger.exception(
-                    "Error while trying to %s %s:%s (%s)",
+                    "Error while trying to %s %s#%s (%s)",
                     'close' if f.close else 'send a comment to',
                     repo.name, f.pull_request,
                     utils.shorten(f.message, 200)
@@ -715,9 +715,8 @@ class PullRequests(models.Model):
         Feedback = self.env['runbot_merge.pull_requests.feedback']
         if not is_author:
             # no point even parsing commands
-            _logger.info("ignoring comment of %s (%s): no ACL to %s:%s",
-                          login, name,
-                          self.repository.name, self.number)
+            _logger.info("ignoring comment of %s (%s): no ACL to %s",
+                          login, name, self.display_name)
             Feedback.create({
                 'repository': self.repository.id,
                 'pull_request': self.number,
@@ -798,8 +797,8 @@ class PullRequests(models.Model):
                     self.priority = param
                     if param == 0:
                         self.target.active_staging_id.cancel(
-                            "P=0 on %s:%s by %s, unstaging target %s",
-                            self.repository.name, self.number,
+                            "P=0 on %s by %s, unstaging target %s",
+                            self.display_name,
                             author.github_login, self.target.name,
                         )
             elif command == 'method':
@@ -814,10 +813,9 @@ class PullRequests(models.Model):
                     })
 
             _logger.info(
-                "%s %s(%s) on %s:%s by %s (%s)",
+                "%s %s(%s) on %s by %s (%s)",
                 "applied" if ok else "ignored",
-                command, param,
-                self.repository.name, self.number,
+                command, param, self.display_name,
                 author.github_login, author.display_name,
             )
             if ok:
@@ -1210,8 +1208,8 @@ class PullRequests(models.Model):
                 'state_to': 'closed',
             })
             self.unstage(
-                "PR %s:%s closed by %s",
-                self.repository.name, self.number,
+                "PR %s closed by %s",
+                self.display_name,
                 by
             )
         return True
@@ -1728,8 +1726,8 @@ class Batch(models.Model):
             gh = meta[pr.repository]['gh']
 
             _logger.info(
-                "Staging pr %s:%s for target %s; squash=%s",
-                pr.repository.name, pr.number, pr.target.name, pr.squash
+                "Staging pr %s for target %s; squash=%s",
+                pr.display_name, pr.target.name, pr.squash
             )
 
             target = 'tmp.{}'.format(pr.target.name)
@@ -1737,9 +1735,8 @@ class Batch(models.Model):
             try:
                 method, new_heads[pr] = pr._stage(gh, target, related_prs=(prs - pr))
                 _logger.info(
-                    "Staged pr %s:%s to %s by %s: %s -> %s",
-                    pr.repository.name, pr.number,
-                    pr.target.name, method,
+                    "Staged pr %s to %s by %s: %s -> %s",
+                    pr.display_name, pr.target.name, method,
                     original_head, new_heads[pr]
                 )
             except (exceptions.MergeError, AssertionError) as e: