greenwave

Clone

#395 Greenwave sends fedmsgs over and over again, even though there are no new test results
Closed: Fixed 5 years ago by lholecek. Opened 5 years ago by bowlofeggs.

Closed: Fixed
Reopen Issue

I've been getting lots of Greenwave messages today about a bodhi bodhi update:

14:52 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
14:52 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
14:52 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
14:52 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:07 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:07 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:07 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:07 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:22 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:22 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:23 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:23 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:38 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:38 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30) seconds ago https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:38 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:38 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:52 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:52 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:52 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_testing" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)
15:52 <fedora-notif> greenwave is a GO on bodhi-3.13.3-1.fc30 for "bodhi_update_push_stable" (fedora-30)  https://taskotron.fedoraproject.org/resultsdb/results?item=bodhi-3.13.3-1.fc30&type=koji_build (triggered by https://apps.fedoraproject.org/notifications/bowlofeggs.id.fedoraproject.org/irc/45874)

This is just a snapshot - there were even more earlier in the day.

Hello Randy, thank you for bringing that up. I'm sorry you received all these messaging.
The reason is that for every message from resultsdb there are 2 policies in Greenwave that match the corresponding message (about the new result).
As you can see here the new results actually exist: https://apps.fedoraproject.org/datagrepper/raw?category=resultsdb&delta=127800&contains=bodhi-3.13.3-1.fc30

For each of these there are 2 Greenwave messages because 2 policies matches:
https://greenwave.fedoraproject.org/api/v1.0/policies
Specifically the ones with id: "taskotron_release_critical_tasks_for_testing" and "taskotron_release_critical_tasks_for_stable".

Here the Greenwave messages: https://apps.fedoraproject.org/datagrepper/raw?category=greenwave&delta=127800&contains=bodhi-3.13.3-1.fc30

This is an expected behavior. If it seems not correct to you, I would advice to change the policies defined in Greenwave. But I'm not sure who actually wrote them.
If you need help changing them, please let me know.

Are there new results db entries today though? I haven't seen a fedmsg from resultsdb about my update in about 22 hours, but Greenwave is sending me constant messages about it, even just now. So far I've received 130 messages from Greenwave about bodhi-3.13.3-1:

$ grep -i greenwave irc.freenode.fedora-notif.weechatlog  | grep bodhi-3.13.3-1 | wc
    130    2380   42943

There were only 27 messages about tests for that build, and they finished yesterday:

$ grep -i PASSED irc.freenode.fedora-notif.weechatlog | grep 3.13.3-1.fc30 | wc
     27     319    8208

Yes, there are new results for that nvr also today.
You can check them here: https://apps.fedoraproject.org/datagrepper/raw?category=resultsdb&delta=127800&contains=bodhi-3.13.3-1.fc30

The last one was: 15:25:27 UTC
As well as last Greenwave message about it: 15:25:28 UTC

Why does Greenwave not have a simple check to see if the decision has changed before sending a message?

Bodhi does this before sending a message for this very same event:

https://github.com/fedora-infra/bodhi/blob/a101713/bodhi/server/models.py#L3560

This is going to cause unnecessary load on Bodhi if every update gets 100 messages a day that Bodhi has to respond to.

That it is what it is supposed to do.
It doesn't seem to work in the Fedora instance. I'm not really sure why. The code seems fine, it works internally and the conf in the Fedora instance looks fine.
Randy, do you have an idea about which day that started for you? The last deploy of the pod in the openshift instance was 7 days ago.

@pingou are you aware of any change in the conf that could cause that? Or could you point me to someone that might know why?

I wonder if the rabbitmq/fedmsg bridge could be causing some confusions here

Since Bodhi is still consuming from fedmsg and ResultsDB & Greenwave are still emitting on fedmsg, I don't think the amqp bridges are involved.

I'm blindly looking for a solution...
Might that be a cache problem? The last deployment was 4 months ago and I don't see logs there.
@pingou could you please redeploy the pod responsible for the cache? I don't have permission to do that.

@pingou could you please redeploy the pod responsible for the cache? I don't have permission to do that.

Could you open an infra ticket for this? Sorry but I don't think I have the permissions either (and this may require a FBR as well)

It seems that Greenwave compares the decision change in a wrong way. E.g. If there is new result with ID 28015899, Greenwave basically compares following two data outputs.

> http -b https://greenwave.fedoraproject.org/api/v1.0/decision <<< '{"decision_context": "bodhi_update_push_stable", "product_version": "fedora-30", "subject_type": "koji_build", "subject_identifier": "bodhi-3.13.3-1.fc30"}'                             
{
    "applicable_policies": [
        "taskotron_release_critical_tasks_for_stable"
    ],
    "policies_satisfied": true,
    "satisfied_requirements": [
        {
            "result_id": 27968725,
            "testcase": "dist.abicheck",
            "type": "test-result-passed"
        },
        {
            "result_id": 28015899,
            "testcase": "dist.rpmdeplint",
            "type": "test-result-passed"
        }
    ],
    "summary": "All required tests passed",
    "unsatisfied_requirements": []
}

> http -b https://greenwave.fedoraproject.org/api/v1.0/decision <<< '{"decision_context": "bodhi_update_push_stable", "product_version": "fedora-30", "subject_type": "koji_build", "subject_identifier": "bodhi-3.13.3-1.fc30", "ignore_result": [28015899]}'
{
    "applicable_policies": [
        "taskotron_release_critical_tasks_for_stable"
    ],
    "policies_satisfied": true,
    "satisfied_requirements": [
        {
            "result_id": 27968725,
            "testcase": "dist.abicheck",
            "type": "test-result-passed"
        },
        {
            "result_id": 28015726,
            "testcase": "dist.rpmdeplint",
            "type": "test-result-passed"
        }
    ],
    "summary": "All required tests passed",
    "unsatisfied_requirements": []
}

Since those two are different, it will publish decision.update message.

I think the simple fix is to remove the result_id from satisfied_requirements and unsatisfied_requirements lists.

@lholecek thanks for looking into it.
Or just check 



decision['policies_satisfied'] == old_decision['policies_satisfied']

instead of:



decision == old_decision

?

@gnaponie IIRC there was discussion somewhere that simple policies_satisfied compare was unwanted. I think the reason was that you want to know if some items move from unsatisfied_requirements to satisfied_requirements (or vice versa).

Possible fix in #398.

Do we know that the new result IDs are the cause of the duplicate messages originally reported here? If so, why do the result IDs keep changing? Are the same tests being run over and over again?

Commit 883f179 fixes this issue

Login to comment on this ticket.

Metadata
None
None
None
None
None
Related Pull Requests
  • #398 Merged 5 years ago
  • #393 Merged 5 years ago
Powered by Pagure 5.13.3
Documentation • File an Issue • About • SSH Hostkey/Fingerprint
© Red Hat, Inc. and others.