Since we moved the koji fedmsg plugin to fedora-messaging no rpm.sign message were sent (see datagreeper link).
It would be good to use these message in order to monitor if robosignatory is doing its job or not.
https://apps.fedoraproject.org/datagrepper/raw?topic=org.fedoraproject.prod.buildsys.rpm.sign
A possible fix for that --> https://pagure.io/koji-fedmsg-plugin/pull-request/5#
FBR was sent for that --> https://lists.fedoraproject.org/archives/list/infrastructure@lists.fedoraproject.org/thread/IIO2A2K2WCF766MG7X6WAICWQAEVJ37Y/
Metadata Update from @kevin: - Issue assigned to pingou - Issue priority set to: Waiting on Assignee (was: Needs Review)
So some progress on this after playing with the plugin in staging.
I've added a print in the plugin to see the topic and the content of the message when they are being built.
This is the outcome:
[Wed Sep 04 08:29:50.859930 2019] [:error] [pid 23627] ******* [Wed Sep 04 08:29:50.859964 2019] [:error] [pid 23627] build.state.change [Wed Sep 04 08:29:50.859982 2019] [:error] [pid 23627] {'build_id': 1229966, 'old': 0, 'name': 'fedora-gather-easyfix', 'task_id': 90011055, 'attribute': 'state', 'request': ('git+https://src.stg.fedoraproject.org/rpms/fedora-gather-easyfix.git#63a4605a980d16a5b09de1b1b7e26762dbb51cd1', 'rawhide', {}), 'owner': 'pingou', 'epoch': None, 'version': '0.1.1', 'release': '49.fc31', 'new': 1} [Wed Sep 04 08:29:50.859987 2019] [:error] [pid 23627] ******* [Wed Sep 04 08:29:50.869311 2019] [:error] [pid 23627] ******* [Wed Sep 04 08:29:50.869322 2019] [:error] [pid 23627] rpm.sign [Wed Sep 04 08:29:50.869357 2019] [:error] [pid 23627] {'rpm': {'build_id': 1229966, 'name': 'fedora-gather-easyfix', 'extra': None, 'arch': 'src', 'buildtime': 1567585763L, 'id': 17013914, 'epoch': None, 'version': '0.1.1', 'metadata_only': False, 'external_repo_id': 0, 'release': '49.fc31', 'size': 24182L, 'buildroot_id': 15536569, 'external_repo_name': 'INTERNAL', 'payloadhash': 'afab270882cc50788027895744a93891'}, 'sigkey': '', 'sighash': 'fd568534e212132b31bc0b39edf518e1', 'build': {'cg_id': None, 'package_name': 'fedora-gather-easyfix', 'extra': {'source': {'original_url': 'git+https://src.stg.fedoraproject.org/rpms/fedora-gather-easyfix.git#63a4605a980d16a5b09de1b1b7e26762dbb51cd1'}}, 'creation_time': datetime.datetime(2019, 9, 4, 8, 28, 32, 282171), 'completion_time': 1567585790.0, 'package_id': 13376, 'cg_name': None, 'id': 1229966, 'build_id': 1229966, 'epoch': None, 'source': 'git+https://src.stg.fedoraproject.org/rpms/fedora-gather-easyfix.git#63a4605a980d16a5b09de1b1b7e26762dbb51cd1', 'state': 1, 'version': '0.1.1', 'completion_ts': 1567585790.8513, 'owner_id': 456, 'owner_name': 'pingou', 'nvr': 'fedora-gather-easyfix-0.1.1-49.fc31', 'start_time': 1567585712.0, 'creation_event_id': 41029570, 'start_ts': 1567585712.28217, 'volume_id': 0, 'creation_ts': 1567585712.28217, 'name': 'fedora-gather-easyfix', 'task_id': 90011055, 'volume_name': 'DEFAULT', 'release': '49.fc31'}} [Wed Sep 04 08:29:50.869365 2019] [:error] [pid 23627] ******* [Wed Sep 04 08:29:50.875675 2019] [:error] [pid 23627] ******* [Wed Sep 04 08:29:50.875686 2019] [:error] [pid 23627] rpm.sign [Wed Sep 04 08:29:50.875718 2019] [:error] [pid 23627] {'rpm': {'build_id': 1229966, 'name': 'fedora-gather-easyfix', 'extra': None, 'arch': 'noarch', 'buildtime': 1567585774L, 'id': 17013915, 'epoch': None, 'version': '0.1.1', 'metadata_only': False, 'external_repo_id': 0, 'release': '49.fc31', 'size': 23016L, 'buildroot_id': 15536569, 'external_repo_name': 'INTERNAL', 'payloadhash': '5462a7a965c106b1aa0d05ade89fb88d'}, 'sigkey': '', 'sighash': 'de75aa907a32bf492e553cf7d01c3713', 'build': {'cg_id': None, 'package_name': 'fedora-gather-easyfix', 'extra': {'source': {'original_url': 'git+https://src.stg.fedoraproject.org/rpms/fedora-gather-easyfix.git#63a4605a980d16a5b09de1b1b7e26762dbb51cd1'}}, 'creation_time': datetime.datetime(2019, 9, 4, 8, 28, 32, 282171), 'completion_time': 1567585790.0, 'package_id': 13376, 'cg_name': None, 'id': 1229966, 'build_id': 1229966, 'epoch': None, 'source': 'git+https://src.stg.fedoraproject.org/rpms/fedora-gather-easyfix.git#63a4605a980d16a5b09de1b1b7e26762dbb51cd1', 'state': 1, 'version': '0.1.1', 'completion_ts': 1567585790.8513, 'owner_id': 456, 'owner_name': 'pingou', 'nvr': 'fedora-gather-easyfix-0.1.1-49.fc31', 'start_time': 1567585712.0, 'creation_event_id': 41029570, 'start_ts': 1567585712.28217, 'volume_id': 0, 'creation_ts': 1567585712.28217, 'name': 'fedora-gather-easyfix', 'task_id': 90011055, 'volume_name': 'DEFAULT', 'release': '49.fc31'}} [Wed Sep 04 08:29:50.875741 2019] [:error] [pid 23627] ******* [Wed Sep 04 08:29:52.043309 2019] [:error] [pid 23259] ******* [Wed Sep 04 08:29:52.043337 2019] [:error] [pid 23259] tag [Wed Sep 04 08:29:52.043363 2019] [:error] [pid 23259] {'build_id': 1229966, 'name': 'fedora-gather-easyfix', 'tag_id': 6443, 'owner': 'pingou', 'tag': 'f31-updates-candidate', 'user': 'pingou', 'version': '0.1.1', 'release': '49.fc31'} [Wed Sep 04 08:29:52.043368 2019] [:error] [pid 23259] *******
What do we see here? - The build finishes and a message build.state.change is sent - A first rpm.sign message is sent, which is likely related to this comment koji apparently adds a dummy sig value when rpms are first imported Source: https://pagure.io/koji-fedmsg-plugin/blob/master/f/fedmsg-koji-plugin.py#_201 - A second rpm.sign message is sent, I expect this is the one we would want to send - The build is tagged and a message tag is sent
build.state.change
rpm.sign
koji apparently adds a dummy sig value when rpms are first imported
tag
The issue is that both rpm.sign message contain: 'sigkey': '', and the fedora-messaging plugin (and the fedmsg one before) are discarding all messages that do not have a sigkey specified (see comment and code at: https://pagure.io/koji-fedmsg-plugin/blob/master/f/fedmsg-koji-plugin.py#_201)
'sigkey': '',
sigkey
Since the plugin did not change the content of the message in anyway, I'm started to think this may be a koji bug.
I'll open a ticket upstream to see with them if they can help figuring this out.
Issue reported upstream at: https://pagure.io/koji/issue/1639
I did some investigation with @pingou on stage. the latest signed build is https://koji.stg.fedoraproject.org/koji/buildinfo?buildID=1229943. It was signed at 2019-08-21 15:39, but old logs have lost.
Could someone has the right permission(sign or admin) try to sign a build or import a signed build, in order that we could check if rpm.sign msg is sent with non-empty sigkey?
I just triggered a signing via autosign by doing:
stg-koji untag-pkg f31-updates-candidate adwaita-blue-gtk-theme-3.22.21.0-5.fc31; stg-koji tag-pkg f31-updates-candidate adwaita-blue-gtk-theme-3.22.21.0-5.fc31
I see the untag-tag:
https://apps.stg.fedoraproject.org/datagrepper/id?id=2019-5f3bb973-5bc7-4d58-a368-9969c634f836&is_raw=true&size=extra-large https://apps.stg.fedoraproject.org/datagrepper/id?id=2019-e17a126f-446e-4f27-86e5-11711fd4e68b&is_raw=true&size=extra-large
but no signing messages.
I think the stg koji plugin is dropping those?
# Don't publish these uninformative rpm.sign messages if there's no actual # sigkey present. Koji apparently adds a dummy sig value when rpms are # first imported and there's no need to spam the world about that. if topic == 'rpm.sign' and (body.get('info', {}).get('sigkey') == '' or body.get('sigkey') == ''): return
@pingou if you want to look at this more you're tomorrow, you should be able to untag/tag stuff in 'stg-koji list-tagged f31-updates-candidate' or just build something for f31 and autosign should sign it...
It looks the signing behavior happened around 2019-09-12 00:51, according to the "last modified date" of signcache folder @kevin, was the signing action from sigul?
Sorry for that awkward question. I'm not aware of how autosign works for fedora... and can't find any plugins related to it. (tag2distrepo plugin only writes the signed RPMs, and won't trigger "postRPMSign" event)
@pingou Is there any logs related to the action Kevin took?
autosign is a process that listens for fedmsgs and when it sees a koji tag message into a tag that it has configuration for, it asks sigul to sign that package and then it (optionally) moves it to another tag.
So, autosign is just listening passively and taking actions based on koji tagging.
So this is technically fixed, we have messages flowing in again: https://apps.fedoraproject.org/datagrepper/raw?topic=org.fedoraproject.prod.buildsys.rpm.sign
We had one issue with the koji-fedmsg-plugin that got fixed in: https://pagure.io/koji-fedmsg-plugin/pull-request/9
This doesn't solve the behavior we saw before about missing sigkey, but at this stage I think we can ignore it.
Let's close this as fixed and I'll be closing the koji issue as well :)
Metadata Update from @pingou: - Issue close_status updated to: Fixed - Issue status updated to: Closed (was: Open)
Login to comment on this ticket.