argo-events icon indicating copy to clipboard operation
argo-events copied to clipboard

Check update reason in k8s resource eventsource

Open scottweitzner opened this issue 5 years ago • 8 comments

Description

My team and I noticed (due to an accumulation of finished jobs) that for resource eventsources if you have update events enabled then your downstream sensor/trigger will be triggered many times even when the resource (a configmap in our case) is not updated. This is due to the fact that the watcher dies. My guess is that when the watch is re-established argoevents can't (or doesn't) distinguish it from a true update.

Proposal

Within the resource sensor we can compare the old body object to the new body object and if they are identical, we can ignore the event. See here

/cc @VaibhavPage


Message from the maintainers:

If you wish to see this enhancement implemented please add a 👍 reaction to this issue! We often sort issues this way to know what to prioritize.

scottweitzner avatar Jan 20 '21 21:01 scottweitzner

This makes sense to me. Resource EventsSource can have a boolean field that users can use to opt-in for unique resource updates. @whynowy @alexec

VaibhavPage avatar Jan 22 '21 12:01 VaibhavPage

Is this a bug? I think I'd only like 1 update.

alexec avatar Jan 22 '21 16:01 alexec

I think this could be considered a bug. In fact this looks related to #760

to add some context:

k8s version: 1.18.8
argo events version: 1.1.0

scottweitzner avatar Jan 27 '21 03:01 scottweitzner

@scottweitzner - Have you specified afterStart: true filter in the event source?

https://github.com/argoproj/argo-events/blob/master/examples/event-sources/resource.yaml#L26?

whynowy avatar Mar 29 '21 23:03 whynowy

@whynowy I have afterStart: false on multiple eventsources and seeing the same issue as mentioned above, each time the watch dies, it triggers a workflow - for our environment, it's seemingly every hour.

afterStart: true fails to trigger any events on an object that has been updated since created and the argo-event pod has started. This looks to be related to the fact that afterStart is used on the Object its self and not the event object @ https://github.com/argoproj/argo-events/blob/release-1.2/eventsources/sources/resource/start.go#L264-L272

Some additional requirements/nice to have would be to check what value has changed (if at all possible) that way we could filter and only trigger if say one portion of a configmap changed from/to.

k8s: v1.19.9-gke.1400 argo-events: v2.12.8

davidcollom avatar Jun 04 '21 12:06 davidcollom

I've seen this behaviour as well. If i may add reproduce steps:

  1. deploy argo-events & argo-workflows as per docs.
  2. deploy the goodies at: my gist

The issue occurs when it seems that the ES pod "recollects" events from NATS.

      filter:
        afterStart: true
        fields:
        - key: metadata.name
          operation: ==
          value: scripts

Even with afterStart: true when one new event is created, after a kubectl edit cm/scripts in my case, it will trigger this looping behaviour.

## Actual correct event that needed to trigger the sensor
2021-11-19T11:58:34.552565588Z 2021-11-19T11:58:34.552Z	INFO	argo-events.eventsource	resource/start.go:201	detected update event	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T11:58:34.560127309Z 2021-11-19T11:58:34.560Z	INFO	argo-events.eventsource	eventsources/eventing.go:411	succeeded to publish an event	{"eventSourceName": "db-ops", "eventName": "configmap", "eventSourceType": "resource", "eventID": "64303432376339342d373835622d343136632d386562382d366162333033316536643037"}


## That "recollection" of events
2021-11-19T12:19:32.995552995Z 2021-11-19T12:19:32.995Z	INFO	argo-events.eventsource	resource/start.go:201	detected update event	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T12:19:32.995703951Z 2021-11-19T12:19:32.995Z	INFO	argo-events.eventsource	resource/start.go:279	Event happened before service start time. event-timestamp: 2021-11-12 07:42:16 +0000 UTC, start-timestamp: 2021-11-19 09:38:23.455093278 +0000 UTC
2021-11-19T12:19:32.995728172Z 	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T12:19:32.995793582Z 2021-11-19T12:19:32.995Z	INFO	argo-events.eventsource	resource/start.go:201	detected update event	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T12:19:32.997021412Z 2021-11-19T12:19:32.996Z	INFO	argo-events.eventsource	resource/start.go:279	Event happened before service start time. event-timestamp: 2021-11-18 08:39:59 +0000 UTC, start-timestamp: 2021-11-19 09:38:23.455093278 +0000 UTC
2021-11-19T12:19:32.997038818Z 	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T12:19:32.998353156Z 2021-11-19T12:19:32.998Z	INFO	argo-events.eventsource	resource/start.go:201	detected update event	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T12:19:33.000225192Z 2021-11-19T12:19:33.000Z	INFO	argo-events.eventsource	resource/start.go:201	detected update event	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T12:19:33.002181018Z 2021-11-19T12:19:33.002Z	INFO	argo-events.eventsource	eventsources/eventing.go:411	succeeded to publish an event	{"eventSourceName": "db-ops", "eventName": "configmap", "eventSourceType": "resource", "eventID": "39363032616162342d306138332d346431352d393163352d373338323137376437313936"}
2021-11-19T12:19:33.004068536Z 2021-11-19T12:19:33.003Z	INFO	argo-events.eventsource	resource/start.go:201	detected update event	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T12:19:33.005110340Z 2021-11-19T12:19:33.005Z	INFO	argo-events.eventsource	resource/start.go:279	Event happened before service start time. event-timestamp: 2021-11-18 08:39:59 +0000 UTC, start-timestamp: 2021-11-19 09:38:23.455093278 +0000 UTC
2021-11-19T12:19:33.005128844Z 	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}
2021-11-19T12:19:33.006099430Z 2021-11-19T12:19:33.006Z	INFO	argo-events.eventsource	resource/start.go:279	Event happened before service start time. event-timestamp: 2021-11-18 08:39:59 +0000 UTC, start-timestamp: 2021-11-19 09:38:23.455093278 +0000 UTC
2021-11-19T12:19:33.006117918Z 	{"eventSourceName": "db-ops", "eventSourceType": "resource", "eventName": "configmap"}

Siebjee avatar Nov 19 '21 10:11 Siebjee

Adding to this, when afterStart: true is set, this behaviour only gets triggered when a "new" event got created. After attaching a simple go informer to kubernetes to watch what happens we figured out it's not kubernetes that resends these events. But rather something within nats or the eventsource it self.

Informer used is found here

Siebjee avatar Nov 22 '21 07:11 Siebjee

I can confirm that v1.5.4 fixes the issue i've described above.

Siebjee avatar Dec 10 '21 13:12 Siebjee