Badges [moksha.hub ERROR] KeyError: 'msg.commit.username'

[hroncok]

As a followup after https://pagure.io/fedora-infrastructure/issue/6929 now I receive this:

Message

[2018-05-11 08:55:28][moksha.hub ERROR]

Rule: <fedbadges.models.BadgeRule: {'name': 'Long Life to Pagure (Pagure I)', 'creator': 'robyduck', 'discussion': 'https://pagure.io/design/issue/434', 'issuer_id': 'fedora-project', 'trigger': {'topic': 'pagure.git.receive'}, 'image_url': 'https://badges.fedoraproject.org/pngs/pagure-long-life-01.png', 'criteria': {'datanommer': {'filter': {'topics': ['%(topic)s'], 'users': ['%(msg.commit.username)s']}, 'operation': 'count', 'condition': {'greater than or equal to': 1}}}, 'badge_id': 'long-life-to-pagure-pagure-i', 'recipient': '%(msg.commit.username)s', 'description': 'Pushed 1 commit to a Pagure repository.'}>, message: {u'username': u'git', u'certificate': u'LS0tLS1CRUdJTiBDRVJUSUZJQ0FURS0tLS0tCk1JSUVTRENDQTdHZ0F3SUJBZ0lDQWZzd0RRWUpL\nb1pJaHZjTkFRRUZCUUF3Z2FBeEN6QUpCZ05WQkFZVEFsVlQKTVFzd0NRWURWUVFJRXdKT1F6RVFN\nQTRHQTFVRUJ4TUhVbUZzWldsbmFERVhNQlVHQTFVRUNoTU9SbVZrYjNKaApJRkJ5YjJwbFkzUXhE\nekFOQmdOVkJBc1RCbVpsWkcxelp6RVBNQTBHQTFVRUF4TUdabVZrYlhObk1ROHdEUVlEClZRUXBF\nd1ptWldSdGMyY3
 hKakFrQmdrcWhraUc5dzBCQ1FFV0YyRmtiV2x1UUdabFpHOXlZWEJ5YjJwbFkz\nUXUKYjNKbk1CNFhEVEUxTURVeE9ERTNNamMxTTFvWERUSTFNRFV4TlRFM01qYzFNMW93Z2RZeEN6\nQUpCZ05WQkFZVApBbFZUTVFzd0NRWURWUVFJRXdKT1F6RVFNQTRHQTFVRUJ4TUhVbUZzWldsbmFE\nRVhNQlVHQTFVRUNoTU9SbVZrCmIzSmhJRkJ5YjJwbFkzUXhEekFOQmdOVkJBc1RCbVpsWkcxelp6\nRXFNQ2dHQTFVRUF4TWhjR0ZuZFhKbExYQmgKWjNWeVpUQXhMbVpsWkc5eVlYQnliMnBsWTNRdWIz\nSm5NU293S0FZRFZRUXBFeUZ3WVdkMWNtVXRjR0ZuZFhKbApNREV1Wm1Wa2IzSmhjSEp2YW1WamRD\nNXZjbWN4SmpBa0Jna3Foa2lHOXcwQkNRRVdGMkZrYldsdVFHWmxaRzl5CllYQnliMnBsWTNRdWIz\nSm5NSUdmTUEwR0NTcUdTSWIzRFFFQkFRVUFBNEdOQURDQmlRS0JnUUN5RXZjRndxWUkKUXg2OWpo\nSEJYekExVlpoTFgySkRVUkdROGlLbXFXUFBHaVVEWHhDcURpa1M5YnN5VFBuN2ZTaWY1Uk5HUkZF\nZwpKQmlqRitaM09RMVh5Q1JrY1kxM0VLUDJpbVVEZW0xcnB3Umg3b2gyMlBZaDU4SHFLOWsvNGdk\nZVpXVGM2QmFjCk1RckZpMlFhbWVqL1ZpRW1KdVd2KzgyaitnN2RzV1ZNTVFJREFRQUJvNElCVnpD\nQ0FWTXdDUVlEVlIwVEJBSXcKQURBdEJnbGdoa2dCaHZoQ0FRMEVJQlllUldGemVTMVNVMEVnUjJW\ndVpYSmhkR1ZrSUVObGNuUnBabWxqWVhSbApNQjBHQTFVZERnUVdCQlFyZ09qazgyV05zdW1wbE1
 T\nbXJ1d3RVeTVIVERDQjFRWURWUjBqQklITk1JSEtnQlJyClFGcjVFZ2lKV2VkWjVRWDFBaDBLVG44\nVUFLR0JwcVNCb3pDQm9ERUxNQWtHQTFVRUJoTUNWVk14Q3pBSkJnTlYKQkFnVEFrNURNUkF3RGdZ\nRFZRUUhFd2RTWVd4bGFXZG9NUmN3RlFZRFZRUUtFdzVHWldSdmNtRWdVSEp2YW1WagpkREVQTUEw\nR0ExVUVDeE1HWm1Wa2JYTm5NUTh3RFFZRFZRUURFd1ptWldSdGMyY3hEekFOQmdOVkJDa1RCbVps\nClpHMXpaekVtTUNRR0NTcUdTSWIzRFFFSkFSWVhZV1J0YVc1QVptVmtiM0poY0hKdmFtVmpkQzV2\nY21lQ0NRRGoKVUI1SFR4Y2VSVEFUQmdOVkhTVUVEREFLQmdnckJnRUZCUWNEQWpBTEJnTlZIUThF\nQkFNQ0I0QXdEUVlKS29aSQpodmNOQVFFRkJRQURnWUVBSjhUVGdMMHJhZ3lCdlo5RlBhdis2ZE5B\nZzEza0poQnYrWS9xeU9rT0RadHFwOWovCkdkOHU1emQwVkFwdXlIMnFBYzg1cUcyaEVsY0ZqUytx\nOU95YmtkQnlwQzF5cklzRSt2akZTRHZqalQxMjV6d3EKS2FNV1UwSVgyTnp2d2l4cWxYN1pxc2cz\nMHIwNzgvUHNPTGRLTlo5VWR0QXJGUHZ2b3hQRHpsTTM4aUE9Ci0tLS0tRU5EIENFUlRJRklDQVRF\nLS0tLS0K\n', u'i': 1, u'timestamp': 1526028923, u'msg_id': u'2018-ef120f20-b617-446b-93bc-b603a4a92f85', u'crypto': u'x509', u'topic': u'io.pagure.prod.pagure.git.receive', u'signature': u'L7pErqc133FRl3E6igfz/pj5C
 k1lQDf5V5ai6m7uOGG4Sf4m/bMVAmSyt9pNXDPIblBXLz5V1fRw\nbFJXaoIKxXiHbqd5kU7tUb64JVJaro2Z8zK2Jh6j26Q5yjVE6aU67b5YnsmkXf7moY6yS3pNNMFh\nxjm7YPHlueH9cdT8GuY=\n', u'msg': {u'forced': False, u'agent': u'lsedlar', u'repo': {u'custom_keys': [], u'description': u'Distribution compose tool', u'parent': {u'custom_keys': [], u'description': u'Distribution compose tool', u'parent': None, u'date_modified': u'1519307921', u'name': u'pungi', u'access_users': {u'admin': [u'onosek'], u'commit': [], u'ticket': [], u'owner': [u'lsedlar']}, u'namespace': None, u'priorities': {}, u'close_status': [u'Invalid', u'Insufficient data', u'Fixed', u'Duplicate'], u'access_groups': {u'admin': [u'releng'], u'commit': [], u'ticket': []}, u'milestones': {u'F26': {u'active': True, u'date': u''}, u'F25': {u'active': True, u'date': u''}, u'Planned': {u'active': True, u'date': u''}}, u'user': {u'fullname': u'Lubom\xedr Sedl\xe1\u0159', u'name': u'lsedlar'}, u'date_created': u'1431529680', u'fullname': u'pungi', u'url_path
 ': u'pungi', u'id': 8, u'tags': [u'releng compose distribution'], u'settings': {u'issues_default_to_private': False, u'Minimum_score_to_merge_pull-request': -1, u'project_documentation': True, u'pull_request_access_only': False, u'Web-hooks': None, u'fedmsg_notifications': True, u'always_merge': False, u'stomp_notifications': True, u'Enforce_signed-off_commits_in_pull-request': True, u'notify_on_commit_flag': False, u'issue_tracker': True, u'notify_on_pull-request_flag': False, u'pull_requests': True, u'Only_assignee_can_merge_pull-request': False, u'roadmap_on_issues_page': False}}, u'date_modified': u'1447057736', u'name': u'pungi', u'access_users': {u'admin': [], u'commit': [], u'ticket': [], u'owner': [u'lsedlar']}, u'namespace': None, u'priorities': {}, u'close_status': [u'Invalid', u'Insufficient data', u'Fixed', u'Duplicate'], u'access_groups': {u'admin': [], u'commit': [], u'ticket': []}, u'milestones': {}, u'user': {u'fullname': u'Lubom\xedr Sedl\xe1\u0159', u'name': u'lsed
 lar'}, u'date_created': u'1447057736', u'fullname': u'forks/lsedlar/pungi', u'url_path': u'fork/lsedlar/pungi', u'id': 244, u'tags': [], u'settings': {u'issues_default_to_private': False, u'Minimum_score_to_merge_pull-request': -1, u'project_documentation': False, u'pull_request_access_only': False, u'Web-hooks': None, u'fedmsg_notifications': True, u'always_merge': False, u'stomp_notifications': True, u'Enforce_signed-off_commits_in_pull-request': False, u'notify_on_commit_flag': False, u'issue_tracker': False, u'notify_on_pull-request_flag': False, u'pull_requests': False, u'Only_assignee_can_merge_pull-request': False, u'roadmap_on_issues_page': False}}, u'end_commit': u'686d450e3c8a0b027dfe087c1ca8458946e23e60', u'branch': u'createiso-cleanup', u'authors': [{u'fullname': u'Lubom\xedr Sedl\xe1\u0159', u'name': u'lsedlar'}, {u'fullname': u'Ondrej Nosek', u'name': u'onosek'}, u'Petr \u0160abata', {u'fullname': u'Jan Kalu\u017ea', u'name': u'jkaluza'}, {u'fullname': u'rmarshall', u'
 name': u'rmarshall'}, {u'fullname': u'Patrick "\u30de\u30eb\u30bf\u30a4\u30f3\u30a2\u30f3\u30c9\u30ec\u30a2\u30b9" Uiterwijk', u'name': u'puiterwijk'}], u'total_commits': 62, u'start_commit': u'071792bdd0dd75b75501e4375cf4e03edec1a0d5'}}

Process Details

• host: badges-backend01.phx2.fedoraproject.org
• PID: 25090
• name: fedmsg-hub
• command: /usr/bin/python2 /usr/bin/fedmsg-hub
• msg_id: 2018-ef120f20-b617-446b-93bc-b603a4a92f85

Callstack that lead to the logging statement

  File "/usr/lib64/python2.7/threading.py", line 785 in __bootstrap
    self.__bootstrap_inner()
  File "/usr/lib64/python2.7/threading.py", line 812 in __bootstrap_inner
    self.run()
  File "/usr/lib64/python2.7/threading.py", line 765 in run
    self.__target(*self.__args, **self.__kwargs)
  File "/usr/lib64/python2.7/site-packages/twisted/python/threadpool.py", line 167 in _worker
    result = context.call(ctx, function, *args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/twisted/python/context.py", line 118 in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib64/python2.7/site-packages/twisted/python/context.py", line 81 in callWithContext
    return func(*args,**kw)
  File "/usr/lib/python2.7/site-packages/moksha/hub/api/consumer.py", line 185 in _work_loop
    self._do_work(message)
  File "/usr/lib/python2.7/site-packages/moksha/hub/api/consumer.py", line 206 in _do_work
    self.consume(message)
  File "/usr/lib/python2.7/site-packages/fedbadges/consumers.py", line 234 in consume
    log.exception("Rule: %r, message: %r" % (badge_rule, msg))

Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/fedbadges/consumers.py", line 231, in consume
    for recipient in badge_rule.matches(msg):
  File "/usr/lib/python2.7/site-packages/fedbadges/rules.py", line 166, in matches
    obj = format_args(self.recipient_key, subs)
  File "/usr/lib/python2.7/site-packages/fedbadges/utils.py", line 56, in format_args
    obj = obj % subs
KeyError: 'msg.commit.username'

@puiterwijk says it's a bug in fedmsg-meta, I have no idea about that, but filling it here.