Duplicate notifications while replay log is processed

[julianbrost]

To Reproduce

1. Have a HA cluster ready
2. Create a bunch of services on the same object (+ have some standard notification rules in your config):

   object Host "68f57ebf" {
   	check_command = "dummy"
   }
   
   apply Service "test-" for (n in range(10)) {
   	check_command = "dummy"
   	assign where host.name == "68f57ebf"
   }
   

   The corresponding notification objects should now be distributed evenly across both nodes:

   $ curl -ksSu root:icinga -H 'Accept: application/json' -H 'X-HTTP-Method-Override: GET' 'https://127.0.0.1:5665/v1/objects/notifications' -d '{"filter":"host.name==n && match(s, service.name)", "filter_vars":{"n":"68f57ebf", "s":"test-*"}}' | jq -r '.results|.[]|(.name + " " + (.attrs.paused|tostring))' | sort
   68f57ebf!test-0!dummy-service-notification false
   68f57ebf!test-1!dummy-service-notification true
   68f57ebf!test-2!dummy-service-notification false
   68f57ebf!test-3!dummy-service-notification true
   68f57ebf!test-4!dummy-service-notification false
   68f57ebf!test-5!dummy-service-notification true
   68f57ebf!test-6!dummy-service-notification false
   68f57ebf!test-7!dummy-service-notification true
   68f57ebf!test-8!dummy-service-notification false
   68f57ebf!test-9!dummy-service-notification true

3. Stop one of the nodes
4. Send a custom notification
5. Start the other node again

Actual behavior

master-1

This node was running all the time and sent the notification for all 10 services:

[2022-02-28 12:51:46 +0100] information/cli: Icinga application loader (version: v2.13.0-209-g9d3eba838; debug)
[...]
[2022-02-28 12:52:58 +0100] information/Checkable: Checkable '68f57ebf!test-0' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:58 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-0!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:58 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-0!dummy-service-notification' for checkable '68f57ebf!test-0' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:58 +0100] information/Checkable: Checkable '68f57ebf!test-1' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:58 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-1!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:58 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-1!dummy-service-notification' for checkable '68f57ebf!test-1' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:58 +0100] information/Checkable: Checkable '68f57ebf!test-2' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:58 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-2!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:58 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-2!dummy-service-notification' for checkable '68f57ebf!test-2' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:59 +0100] information/Checkable: Checkable '68f57ebf!test-3' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:59 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-3!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:59 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-3!dummy-service-notification' for checkable '68f57ebf!test-3' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:59 +0100] information/Checkable: Checkable '68f57ebf!test-4' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:59 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-4!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:59 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-4!dummy-service-notification' for checkable '68f57ebf!test-4' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:59 +0100] information/Checkable: Checkable '68f57ebf!test-5' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:59 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-5!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:59 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-5!dummy-service-notification' for checkable '68f57ebf!test-5' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:59 +0100] information/Checkable: Checkable '68f57ebf!test-6' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:59 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-6!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:59 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-6!dummy-service-notification' for checkable '68f57ebf!test-6' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:59 +0100] information/Checkable: Checkable '68f57ebf!test-7' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:59 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-7!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:59 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-7!dummy-service-notification' for checkable '68f57ebf!test-7' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:59 +0100] information/Checkable: Checkable '68f57ebf!test-8' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:59 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-8!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:59 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-8!dummy-service-notification' for checkable '68f57ebf!test-8' and user 'dummy' using command 'dummy'.
[2022-02-28 12:52:59 +0100] information/Checkable: Checkable '68f57ebf!test-9' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:52:59 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-9!dummy-service-notification' for user 'dummy'
[2022-02-28 12:52:59 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-9!dummy-service-notification' for checkable '68f57ebf!test-9' and user 'dummy' using command 'dummy'.

master-2

This node was stopped and resent notifications for the services with odd numbers in their names. These are the ones that are active on master-2 when both nodes are operational:

[2022-02-28 12:52:39 +0100] information/IcingaApplication: Icinga has shut down.
[...]
[2022-02-28 12:53:07 +0100] information/cli: Icinga application loader (version: v2.13.0-209-g9d3eba838; debug)
[...]
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-0' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-1' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-1!dummy-service-notification' for user 'dummy'
[2022-02-28 12:53:19 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-1!dummy-service-notification' for checkable '68f57ebf!test-1' and user 'dummy' using command 'dummy'.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-2' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-3' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-3!dummy-service-notification' for user 'dummy'
[2022-02-28 12:53:19 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-3!dummy-service-notification' for checkable '68f57ebf!test-3' and user 'dummy' using command 'dummy'.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-4' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-5' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-5!dummy-service-notification' for user 'dummy'
[2022-02-28 12:53:19 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-5!dummy-service-notification' for checkable '68f57ebf!test-5' and user 'dummy' using command 'dummy'.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-6' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-7' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-7!dummy-service-notification' for user 'dummy'
[2022-02-28 12:53:19 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-7!dummy-service-notification' for checkable '68f57ebf!test-7' and user 'dummy' using command 'dummy'.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-8' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Checkable: Checkable '68f57ebf!test-9' has 1 notification(s). Checking filters for type 'Custom', sends will be logged.
[2022-02-28 12:53:19 +0100] information/Notification: Sending 'Custom' notification '68f57ebf!test-9!dummy-service-notification' for user 'dummy'
[2022-02-28 12:53:19 +0100] information/Notification: Completed sending 'Custom' notification '68f57ebf!test-9!dummy-service-notification' for checkable '68f57ebf!test-9' and user 'dummy' using command 'dummy'.

Expected behavior

Notifications should not be resent by the second node when processing the replay log as they were already sent by the first node.

Your Environment

Tested with current master branch (9d3eba8)

[Al2Klimov]

• Send a custom notification

Hmm.. have you tried #7818?

[julianbrost]

I haven't done any further testing on this so far, it's just something I noticed when testing another PR.

[yhabteab]

I just tested this with #7818, and the answer is: No, it does not fix this issue.