fedora-ci / general

#118 Test result missing in bodhi update
Closed by bgoncalv. Opened by churchyard.

Closed
Reopen Issue

This gated update has test results missing:

https://bodhi.fedoraproject.org/updates/FEDORA-2020-4123db1162

There is no actionable error :(

(13:25:07) bgoncalv: mhroncok: hi, it looks a real issue
(13:25:21) bgoncalv: I see bodhi published the message https://apps.fedoraproject.org/datagrepper/id?id=2020-42728e17-a38f-4eab-86f8-678bf80341c7&is_raw=true&size=extra-large
(13:25:35) bgoncalv: but the pipeline that trigger on fedmsg didn't get it
(13:25:50) bgoncalv: abompard: pingou could would you be able to help me?
(13:26:21) bgoncalv: mhroncok: can you open a general issue? I can workaround it by triggering it manually
(13:26:38) mhroncok: bgoncalv: can do
(13:29:01) pingou: bgoncalv: is this recent or could it be an artifact of the colo move?
(13:29:16) bgoncalv: pingou: very recent, about 40 mins ago
(13:36:48) bgoncalv: I think msrb trigger one same topic in the same jenkins also didn't run and we also have another trigger on different jenkins that didn't react to this message as well
(13:37:17) ***msrb reading the log for context

cc @lbalhar

So bodhi sent the message: https://apps.fedoraproject.org/datagrepper/id?id=2020-42728e17-a38f-4eab-86f8-678bf80341c7&is_raw=true&size=extra-large

Our pipeline for some reason didn't trigger on it [1]. The pipeline listens on FedMsg for this topic.
I noticed our pipeline triggered for other builds at similar time.

Also we have same triggered configured on different Jenkins instance that also didn't get this message.

[1] https://jenkins-continuous-infra.apps.ci.centos.org/view/Fedora%20All%20Packages%20Pipeline/job/fedora-build-pipeline-trigger/
[2] https://github.com/CentOS-PaaS-SIG/upstream-fedora-pipeline/blob/master/JenkinsfileBuildTrigger#L34

For this specifically build I triggered the test manually: https://jenkins-continuous-infra.apps.ci.centos.org/job/fedora-rawhide-build-pipeline/13857/console

We still need to know why we missed the trigger message

Another possible example:
https://bodhi.fedoraproject.org/updates/FEDORA-2020-024093e374

The above may differ; I didn't see the topic bodhi.update.status.testing.koji-build-group.build.complete when running:

http get https://apps.fedoraproject.org/datagrepper/raw delta==345600 package==bolt

I pinged Bruno and Michel via email and will follow up tomorrow morning to see what's happening here and to make sure I know how to datagrepper correctly :)

I found to message using:

https://apps.fedoraproject.org/datagrepper/raw?topic=org.fedoraproject.prod.bodhi.update.status.testing.koji-build-group.build.complete&delta=3600000&contains=bolt-0.9-1.fc32

and started the job manually
https://jenkins-continuous-infra.apps.ci.centos.org/view/Fedora%20All%20Packages%20Pipeline/job/fedora-f32-build-pipeline/760/

This is strange. If messages land in datagrepper, it means they were successfully sent and received+processed by broker. So this means that it's the CentOS Jenkins that causes this.

There are some strange "connection timeout" errors in the logs (although this seems to be related to staging broker):

INFO: prometheus_async_worker thread is still running. Execution aborted.
Jun 18, 2020 5:41:11 AM com.redhat.jenkins.plugins.ci.messaging.RabbitMQMessagingWorker connect
SEVERE: Unable to connect to rabbitmq.stg.fedoraproject.org:5671 connect timed out
Jun 18, 2020 5:41:53 AM com.rabbitmq.client.impl.ForgivingExceptionHandler log
SEVERE: Caught an exception during connection recovery!
java.net.SocketTimeoutException: connect timed out
    at java.base/java.net.PlainSocketImpl.socketConnect(Native Method)
    at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399)
    at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242)
    at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224)
    at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:403)
    at java.base/java.net.Socket.connect(Socket.java:591)
    at java.base/sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:285)
    at com.rabbitmq.client.impl.SocketFrameHandlerFactory.create(SocketFrameHandlerFactory.java:60)
    at com.rabbitmq.client.impl.recovery.RecoveryAwareAMQConnectionFactory.newConnection(RecoveryAwareAMQConnectionFactory.java:62)
    at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.recoverConnection(AutorecoveringConnection.java:605)
    at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.beginAutomaticRecovery(AutorecoveringConnection.java:567)
    at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.lambda$addAutomaticRecoveryListener$3(AutorecoveringConnection.java:509)
    at com.rabbitmq.client.impl.AMQConnection.notifyRecoveryCanBeginListeners(AMQConnection.java:750)
    at com.rabbitmq.client.impl.AMQConnection.doFinalShutdown(AMQConnection.java:727)
    at com.rabbitmq.client.impl.AMQConnection$MainLoop.run(AMQConnection.java:611)
    at java.base/java.lang.Thread.run(Thread.java:834)
Jun 18, 2020 5:42:13 AM com.redhat.jenkins.plugins.ci.messaging.RabbitMQMessagingWorker connect
SEVERE: Unable to connect to rabbitmq.stg.fedoraproject.org:5671 connect timed out
  • few other weirdnesses. I deleted few jobs that were created by me in the past, but were disabled now. And there were some builds stuck in running state for a very long time.

I still don't know what's causing this, but triggering seems to be completely random right now:

https://bodhi.fedoraproject.org/updates/FEDORA-2020-7345436c6f

At the time of writing this comment, only the new rpmdeplint pipeline triggered.

@msrb about "So this means that it's the CentOS Jenkins that causes this."

I'm also missing these messages on a separated Jenkins instance using same trigger.

Another example: https://bodhi.fedoraproject.org/updates/FEDORA-2020-9d34ea38db

INFO: prometheus_async_worker thread is still running. Execution aborted.
Jun 18, 2020 9:19:28 AM com.redhat.jenkins.plugins.ci.messaging.RabbitMQMessagingWorker connect
SEVERE: Unable to connect to rabbitmq.stg.fedoraproject.org:5671 connect timed out
Jun 18, 2020 9:19:45 AM com.redhat.jenkins.plugins.ci.messaging.RabbitMQMessagingWorker lambda$subscribe$0
INFO: Received 'org.fedoraproject.prod.bodhi.update.status.testing.koji-build-group.build.complete':
Message id: 'b2fbcd37-b888-4d2d-ae96-6e9f75deed55'
'{"contact": {"name": "Bodhi", "email": "admin@fp.o", "team": "Fedora CI", "docs": "https://docs.fedoraproject.org/en-US/ci/"}, "artifact": {"type": "koji-build-group", "id": "FEDORA-2020-9d34ea38db-bfda45c31fe018db02aab85d112339ca08de8c76", "repository": "https://bodhi.fedoraproject.org/updates/FEDORA-2020-9d34ea38db", "builds": [{"type": "koji-build", "id": 1524749, "task_id": 45849896, "issuer": "jplesnik", "component": "perl-DBIx-Class", "nvr": "perl-DBIx-Class-0.082842-1.fc33", "scratch": false}], "release": "f33"}, "generated_at": "2020-06-18T09:19:44.880937Z", "version": "0.2.2", "agent": "bodhi", "re-trigger": false}'
Jun 18, 2020 9:20:30 AM com.redhat.jenkins.plugins.ci.messaging.RabbitMQMessagingWorker connect
SEVERE: Unable to connect to rabbitmq.stg.fedoraproject.org:5671 connect timed out
Jun 18, 2020 9:20:33 AM hudson.model.AsyncPeriodicWork doRun
INFO: prometheus_async_worker thread is still running. Execution aborted.
Jun 18, 2020 9:21:29 AM com.redhat.jenkins.plugins.ci.messaging.RabbitMQMessagingWorker lambda$subscribe$0
INFO: Received 'org.centos.prod.ci.koji-build.test.running':
Message id: '2020-c0af800c-456a-491d-bca8-436efc174dfe'
'{"artifact":{"type":"koji-build","id":45849896,"component":"perl-DBIx-Class","issuer":"jplesnik","nvr":"perl-DBIx-Class-0.082842-1.fc33","scratch":false,"source":"git+https://src.fedoraproject.org/rpms/perl-DBIx-Class.git#6a3aaea3d7a54fe881c8ae6e762de4feb55d603a"},"pipeline":{"id":"e0cd8514-9cb2-4076-8071-436ee06771fd","name":"fedora-rpminspect","stage":{"name":"prepare-environment"},"build":"30635"},"test":{"category":"functional","namespace":"fedora-ci.koji-build","type":"rpminspect"},"generated_at":"2020-06-18T09:21:25.751378Z","contact":{"name":"fedora-ci","team":"fedora-ci","docs":"https://github.com/tflink/fedora-ci-generic-checks","email":"ci@lists.fedoraproject.org","irc":"#fedora-ci","url":"http://fedora-build-checks.apps.ci.centos.org/"},"run":{"url":"http://fedora-build-checks.apps.ci.centos.org/blue/organizations/jenkins/fedora-rpminspect/detail/fedora-rpminspect/30635/pipeline/","log":"http://fedora-build-checks.apps.ci.centos.org/job/fedora-rpminspect/30635/console","rebuild":"http://fedora-build-checks.apps.ci.centos.org/job/fedora-rpminspect/30635/rebuild/parameterized"},"version":"0.2.1"}'
Jun 18, 2020 9:21:29 AM com.redhat.jenkins.plugins.ci.messaging.JMSMessagingWorker trigger
INFO: Scheduling job 'bgoncalv-test-Prod-FedoraMessagingTrigger' based on message:
{"artifact":{"type":"koji-build","id":45849896,"component":"perl-DBIx-Class","issuer":"jplesnik","nvr":"perl-DBIx-Class-0.082842-1.fc33","scratch":false,"source":"git+https://src.fedoraproject.org/rpms/perl-DBIx-Class.git#6a3aaea3d7a54fe881c8ae6e762de4feb55d603a"},"pipeline":{"id":"e0cd8514-9cb2-4076-8071-436ee06771fd","name":"fedora-rpminspect","stage":{"name":"prepare-environment"},"build":"30635"},"test":{"category":"functional","namespace":"fedora-ci.koji-build","type":"rpminspect"},"generated_at":"2020-06-18T09:21:25.751378Z","contact":{"name":"fedora-ci","team":"fedora-ci","docs":"https://github.com/tflink/fedora-ci-generic-checks","email":"ci@lists.fedoraproject.org","irc":"#fedora-ci","url":"http://fedora-build-checks.apps.ci.centos.org/"},"run":{"url":"http://fedora-build-checks.apps.ci.centos.org/blue/organizations/jenkins/fedora-rpminspect/detail/fedora-rpminspect/30635/pipeline/","log":"http://fedora-build-checks.apps.ci.centos.org/job/fedora-rpminspect/30635/console","rebuild":"http://fedora-build-checks.apps.ci.centos.org/job/fedora-rpminspect/30635/rebuild/parameterized"},"version":"0.2.1"}
Jun 18, 2020 9:21:32 AM com.redhat.jenkins.plugins.ci.messaging.RabbitMQMessagingWorker connect
SEVERE: Unable to connect to rabbitmq.stg.fedoraproject.org:5671 connect timed out

So Jenkins received the message about perl-DBIx-Class-0.082842-1.fc33 on org.fedoraproject.prod.bodhi.update.status.testing.koji-build-group.build.complete topic via fedmsg, but did not trigger any jobs...

Also triggered manually the test for https://bodhi.fedoraproject.org/updates/FEDORA-2020-453ac50c1a

Current workaround for people who have permission to trigger jobs manually:

  1. Search for the message in datagrepper:

    https://apps.fedoraproject.org/datagrepper/raw?topic=org.fedoraproject.prod.bodhi.update.status.testing.koji-build-group.build.complete&delta=3600000&contains=

  2. use the content of msg field as trigger parameter:
    https://jenkins-continuous-infra.apps.ci.centos.org/view/Fedora%20All%20Packages%20Pipeline/job/fedora-build-pipeline-trigger/build?delay=0sec

    {     "re-trigger": false,      "artifact": {       "release": "f33",        "type": "koji-build-group",        "builds": [         {           "nvr": "podman-2.0.0-0.165.dev.gitb5f7afd.fc33",            "task_id": 45850965,            "scratch": false,            "component": "podman",            "type": "koji-build",            "id": 1524758,            "issuer": "rhcontainerbot"         }       ],        "repository": "https://bodhi.fedoraproject.org/updates/FEDORA-2020-453ac50c1a",        "id": "FEDORA-2020-453ac50c1a-e530e8ad4927a9a9185a7436cf94c7630773ca01"     },      "contact": {       "docs": "https://docs.fedoraproject.org/en-US/ci/",        "team": "Fedora CI",        "email": "admin@fp.o",        "name": "Bodhi"     },      "version": "0.2.2",      "agent": "bodhi",      "generated_at": "2020-06-18T10:16:54.360404Z"   }
Edited by bgoncalv

I don't understand the "use" part in point 2. Use how?

(That probably just means I don't have permission to trigger jobs manually and hence I miss some UI on the link, sorry.)

(That probably just means I don't have permission to trigger jobs manually and hence I miss some UI on the link, sorry.)

Correct you need to be able to login to the Jenkins to have the "Build with Parameters" option.

I did not notice this before, but this looks really fishy:

SEVERE: Unable to connect to rabbitmq.stg.fedoraproject.org:5671 connect timed out
Jun 18, 2020 2:48:47 PM org.csanchez.jenkins.plugins.kubernetes.pipeline.ContainerExecDecorator$1 doLaunch
INFO: Created process inside pod: [fedora-cloud-8dd1a9f0-7ce1-4d45-ac82-21fcf85cd2a8-allpkgs-zwmmx], container: [fedoraci-runner] with pid:[-1]
Jun 18, 2020 2:48:53 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger stopTriggerThreads
INFO: Stopping thread (11491) for 'fedora-build-pipeline-trigger'.
Jun 18, 2020 2:48:53 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker prepareForInterrupt
INFO: poller not closed yet. Sleeping for 1 sec...
Jun 18, 2020 2:48:53 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker receive
INFO: We have been interrupted...
Jun 18, 2020 2:48:53 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker unsubscribe
INFO: We are being interrupted. Skipping unsubscribe...
Jun 18, 2020 2:48:54 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker prepareForInterrupt
INFO: Un-subscribing job 'fedora-build-pipeline-trigger' from org.fedoraproject.prod.bodhi.update.status.testing.koji-build-group.build.complete topic.
Jun 18, 2020 2:48:54 PM com.redhat.jenkins.plugins.ci.threads.FedMsgTriggerThread shutdown
WARNING: Thread 11491 FedMsg Provider is NOT connected AND subscribed;  join!
Jun 18, 2020 2:48:54 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger stopTriggerThreads
INFO: Removed thread lock for 'fedora-build-pipeline-trigger'.
Jun 18, 2020 2:48:54 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger stop
INFO: job is null! Not stopping trigger thread!
Jun 18, 2020 2:48:54 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger stopTriggerThreads
INFO: Removed thread lock for 'fedora-build-pipeline-trigger'.
Jun 18, 2020 2:48:54 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger startTriggerThreads
INFO: Starting thread (12374) for 'fedora-build-pipeline-trigger'.
Jun 18, 2020 2:48:54 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker subscribe
INFO: Subscribing job 'fedora-build-pipeline-trigger' to org.fedoraproject.prod.bodhi.update.status.testing.koji-build-group.build.complete topic.
Jun 18, 2020 2:48:54 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker subscribe
INFO: Successfully subscribed job 'fedora-build-pipeline-trigger' to topic 'org.fedoraproject.prod.bodhi.update.status.testing.koji-build-group.build.complete'.
Jun 18, 2020 2:49:18 PM org.csanchez.jenkins.plugins.kubernetes.pipeline.ContainerExecDecorator$1 doLaunch
INFO: Created process inside pod: [fedora-cloud-8dd1a9f0-7ce1-4d45-ac82-21fcf85cd2a8-allpkgs-zwmmx], container: [fedoraci-runner] with pid:[-1]
Jun 18, 2020 2:49:35 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger stopTriggerThreads
INFO: Stopping thread (12088) for 'fedora-pr-comment-trigger'.
Jun 18, 2020 2:49:35 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker prepareForInterrupt
INFO: poller not closed yet. Sleeping for 1 sec...
Jun 18, 2020 2:49:35 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker receive
INFO: We have been interrupted...
Jun 18, 2020 2:49:35 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker unsubscribe
INFO: We are being interrupted. Skipping unsubscribe...
Jun 18, 2020 2:49:36 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker prepareForInterrupt
INFO: Un-subscribing job 'fedora-pr-comment-trigger' from org.fedoraproject.prod.pagure.pull-request.comment.added topic.
Jun 18, 2020 2:49:36 PM com.redhat.jenkins.plugins.ci.threads.FedMsgTriggerThread shutdown
WARNING: Thread 12088 FedMsg Provider is NOT connected AND subscribed;  join!
Jun 18, 2020 2:49:36 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger stopTriggerThreads
INFO: Removed thread lock for 'fedora-pr-comment-trigger'.
Jun 18, 2020 2:49:36 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger stop
INFO: job is null! Not stopping trigger thread!
Jun 18, 2020 2:49:36 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger stopTriggerThreads
INFO: Removed thread lock for 'fedora-pr-comment-trigger'.
Jun 18, 2020 2:49:36 PM com.redhat.jenkins.plugins.ci.CIBuildTrigger startTriggerThreads
INFO: Starting thread (12520) for 'fedora-pr-comment-trigger'.
Jun 18, 2020 2:49:36 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker subscribe
INFO: Subscribing job 'fedora-pr-comment-trigger' to org.fedoraproject.prod.pagure.pull-request.comment.added topic.
Jun 18, 2020 2:49:36 PM com.redhat.jenkins.plugins.ci.messaging.FedMsgMessagingWorker subscribe
INFO: Successfully subscribed job 'fedora-pr-comment-trigger' to topic 'org.fedoraproject.prod.pagure.pull-request.comment.added'.
Jun 18, 2020 2:49:38 PM com.redhat.jenkins.plugins.ci.messaging.RabbitMQMessagingWorker connect
SEVERE: Unable to connect to rabbitmq.stg.fedoraproject.org:5671 connect timed out
Jun 18, 2020 2:49:40 PM org.csanchez.jenkins.plugins.kubernetes.pipeline.ContainerExecDecorator$1 doLaunch
INFO: Created process inside pod: [fedora-cloud-8dd1a9f0-7ce1-4d45-ac82-21fcf85cd2a8-allpkgs-zwmmx], container: [fedoraci-runner] with pid:[-1]
Jun 18, 2020 2:50:07 PM org.jenkinsci.plugins.workflow.job.WorkflowRun finish
INFO: fedora-pr-comment-trigger #19888 completed: SUCCESS

Unfortunately it's not clear what's causing it. I will try to look into the source code of the JMS plugin...

Could you please trigger the CI in this update?

https://bodhi.fedoraproject.org/updates/FEDORA-2020-65702d1faa

Thanks.

Could you please trigger the CI in this update?
https://bodhi.fedoraproject.org/updates/FEDORA-2020-65702d1faa
Thanks.

The pipeline actually triggered it :)
https://jenkins-continuous-infra.apps.ci.centos.org/job/fedora-rawhide-build-pipeline/13889/
Edited by bgoncalv

Yesterday we switched the pipeline to use FedoraMessaging, each trigger has has queue, we should not be missing messages anymore. I'm closing this ticket.

I've you find any trigger missing for recent builds or PR, please open a new ticket.

Metadata Update from @bgoncalv:
- Issue status updated to: Closed (was: Open)

The pipeline actually triggered it :)

In that case, the UX is very confusing. I got an e-mail that the tests "failed" - and when looking for details, it said the results are missing. Hence I assumed something is wrong.

Anyway, all seem to be good here, sorry for the noise.
Metadata
None
None
None
None
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.