So:
But the update is still in "pending" state, no message to trigger CI were sent (for 18 days): https://apps.stg.fedoraproject.org/datagrepper/raw?topic=org.fedoraproject.stg.bodhi.update.status.testing.koji-build-group.build.complete
Is something mis-configured in staging?
In the logs of the consumer, I'm seeing:
2020-02-04 11:47:57,324 INFO [fedora_messaging.twisted.protocol][MainThread] Consuming message from topic org.fedoraproject.stg.buildsys.tag (message id 41fa4137-d700-4d20-be5a-2d24dabccab6) 2020-02-04 11:47:57,325 INFO [bodhi][PoolThread-twisted.internet.reactor-0] Received message from fedora-messaging with topic: org.fedoraproject.stg.buildsys.tag 2020-02-04 11:47:57,328 INFO [bodhi][PoolThread-twisted.internet.reactor-0] fedora-gather-easyfix-0.2.1-96.fc32 tagged into f32-updates-candidate 2020-02-04 11:47:57,350 INFO [bodhi][PoolThread-twisted.internet.reactor-0] Build was not submitted, skipping 2020-02-04 11:47:57,760 INFO [bodhi.server][PoolThread-twisted.internet.reactor-0] Sending mail to pingou@...: [Fedora Update] [comment] fedora-gather-easyfix-0.2.1-96.fc32 2020-02-04 11:47:57,760 INFO [bodhi.server][PoolThread-twisted.internet.reactor-0] Not sending email: No smtp_server defined 2020-02-04 11:47:57,958 INFO [fedora_messaging.twisted.protocol][MainThread] Successfully consumed message from topic org.fedoraproject.stg.buildsys.tag (message id 41fa4137-d700-4d20-be5a-2d24dabccab6) 2020-02-04 11:47:58,600 INFO [fedora_messaging.twisted.protocol][MainThread] Consuming message from topic org.fedoraproject.stg.buildsys.tag (message id afda1a71-b90e-4356-ac6a-201b47a2fc76) 2020-02-04 11:47:58,601 INFO [bodhi][PoolThread-twisted.internet.reactor-0] Received message from fedora-messaging with topic: org.fedoraproject.stg.buildsys.tag 2020-02-04 11:47:58,603 INFO [bodhi][PoolThread-twisted.internet.reactor-0] fedora-gather-easyfix-0.2.1-96.fc32 tagged into f32-signing-pending 2020-02-04 11:47:58,622 INFO [bodhi][PoolThread-twisted.internet.reactor-0] Tag is not pending_testing tag, skipping 2020-02-04 11:47:58,725 INFO [fedora_messaging.twisted.protocol][MainThread] Successfully consumed message from topic org.fedoraproject.stg.buildsys.tag (message id afda1a71-b90e-4356-ac6a-201b47a2fc76)
Hm, so this may be related to robosignatory in fact:
$ koji -p stg buildinfo fedora-gather-easyfix-0.2.1-96.fc32 BUILD: fedora-gather-easyfix-0.2.1-96.fc32 [1431786] State: COMPLETE Built by: pingou Source: git+https://src.stg.fedoraproject.org/rpms/fedora-gather-easyfix.git#99b24150c9c939e3b52d390d0cfd7797137a9d58 Volume: DEFAULT Task: 90003531 build (rawhide, /rpms/fedora-gather-easyfix.git:99b24150c9c939e3b52d390d0cfd7797137a9d58) Finished: Tue, 04 Feb 2020 11:47:56 CET Tags: f32-updates-candidate f32-signing-pending
But according to https://infrastructure.fedoraproject.org/cgit/ansible.git/tree/roles/robosignatory/templates/robosignatory.toml.j2#n221
[[consumer_config.koji_instances.primary.tags]] from = "f32-signing-pending" to = "f32-updates-testing-pending" key = "{{ (env == 'production')|ternary('fedora-32', 'testkey') }}" keyid = "{{ (env == 'production')|ternary('12c944d0', 'd300e724') }}"
robotsignatory should move the signed builds from f32-signing-pending to f32-updates-testing-pending.
f32-signing-pending
f32-updates-testing-pending
Alright, so robosignatory is failing, I've restarted it but it still fails with:
Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: [robosignatory INFO] Received message from fedora-messaging with topic: org.fedoraproject.stg.buildsys.tag Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: [robosignatory.tagconsumer INFO] Build dummy-test-package-gloster-0-13.fc32 (1431755) tagged into f32-signing-pending on primary Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: [robosignatory.tagconsumer INFO] Going to sign dummy-test-package-gloster-0-13.fc32 with testkey (d300e724) and move to f32-updates-testing-pending Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: [robosignatory.tagconsumer INFO] Signing and writing build dummy-test-package-gloster-0-13.fc32 Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: [robosignatory.tagconsumer INFO] RPMs to sign and move: [u'dummy-test-package-gloster-0-13.fc32.src (20120657, signed: True)', u'dummy-test-package-gloster-0-13.fc32.noarch (20120658, signed: True)'] Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: [robosignatory.tagconsumer INFO] Build was successfully signed, telling koji to write with key d300e724 Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: [robosignatory ERROR] sign permission required: Unable to handle message: Id: 8d95991e-d2e1-496f-8cb3-3ac472ebeeb8 Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: Topic: org.fedoraproject.stg.buildsys.tag Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: Headers: { Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "fedora_messaging_schema": "base.message", Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "fedora_messaging_severity": 20, Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "sent-at": "2020-01-24T21:11:08+00:00" Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: } Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: Body: { Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "build_id": 1431755, Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "instance": "primary", Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "name": "dummy-test-package-gloster", Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "owner": "pingou", Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "release": "13.fc32", Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "tag": "f32-signing-pending", Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "tag_id": 11523, Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "user": "bodhi", Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: "version": "0" Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: } Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: Traceback (most recent call last): Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: File "/usr/lib/python2.7/site-packages/robosignatory/consumer.py", line 44, in __call__ Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: self.tag_handler.consume(msg) Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: File "/usr/lib/python2.7/site-packages/robosignatory/tag.py", line 142, in consume Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: skip_tagging=False) Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: File "/usr/lib/python2.7/site-packages/robosignatory/tag.py", line 217, in dowork Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: self.signwrite_single_build(build_nvr, build_id, tag_info, instance, koji_instance) Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: File "/usr/lib/python2.7/site-packages/robosignatory/tag.py", line 281, in signwrite_single_build Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: instance['client'].writeSignedRPM(rpm['id'], tag_info['keyid']) Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: File "/usr/lib/python2.7/site-packages/koji/__init__.py", line 2135, in __call__ Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: return self.__func(self.__name, args, opts) Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: File "/usr/lib/python2.7/site-packages/koji/__init__.py", line 2650, in _callMethod Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: raise err Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: ActionNotAllowed: sign permission required Feb 04 12:39:40 autosign01.stg.phx2.fedoraproject.org fedora-messaging[9517]: [fedora_messaging.twisted.protocol WARNING] Returning message id 8d95991e-d2e1-496f-8cb3-3ac472ebeeb8 to the queue
So the problem was indeed the prod->stg sync.
It fixed the krb principal, but incomplete:
3638 | autosign/autosign01.phx2.fedoraproject.org@STG.FEDORAPROJECT.ORG
but in the config it's 'stg.phx2' so it doesn't match that and koji just makes a new user. That new user has no perms.
So, for now, I just deleted the other principal and fixed the user_id 3638 one to be correct.
We will need to fix our prod->stg sync to handle this.
So, I think it should be working now.
Metadata Update from @bowlofeggs: - Issue priority set to: Waiting on Assignee (was: Needs Review)
https://infrastructure.fedoraproject.org/cgit/ansible.git/commit/?id=fc02115 should fix the sync script.
Closing this.
Metadata Update from @cverna: - Issue close_status updated to: Fixed - Issue status updated to: Closed (was: Open)
Commit c6211bbb fixes this issue
Login to comment on this ticket.