From c844532048cbb524cae12b74e697d057dda95eae Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Attila=20M=C3=A9sz=C3=A1ros?= Date: Thu, 12 Feb 2026 15:56:16 +0100 Subject: [PATCH 1/3] improve: logging for resource filter cache MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Attila Mészáros --- .../operator/processing/event/Event.java | 2 +- .../source/controller/ResourceEvent.java | 4 +-- .../informer/ExtendedResourceEvent.java | 30 ++++++++++++++++++- .../informer/ManagedInformerEventSource.java | 11 ++++++- .../informer/TemporaryResourceCache.java | 7 +++++ 5 files changed, 49 insertions(+), 5 deletions(-) diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/Event.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/Event.java index 036274c5d3..1f17aafe7c 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/Event.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/Event.java @@ -19,7 +19,7 @@ public class Event { - private final ResourceID relatedCustomResource; + protected final ResourceID relatedCustomResource; public Event(ResourceID targetCustomResource) { this.relatedCustomResource = targetCustomResource; diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ResourceEvent.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ResourceEvent.java index 88f9bf8716..083e0b329d 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ResourceEvent.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ResourceEvent.java @@ -25,8 +25,8 @@ public class ResourceEvent extends Event { - private final ResourceAction action; - private final HasMetadata resource; + protected final ResourceAction action; + protected final HasMetadata resource; public ResourceEvent(ResourceAction action, ResourceID resourceID, HasMetadata resource) { super(resourceID); diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ExtendedResourceEvent.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ExtendedResourceEvent.java index 4ae476a3de..774bd4ca06 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ExtendedResourceEvent.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ExtendedResourceEvent.java @@ -15,6 +15,7 @@ */ package io.javaoperatorsdk.operator.processing.event.source.informer; +import java.util.Objects; import java.util.Optional; import io.fabric8.kubernetes.api.model.HasMetadata; @@ -25,7 +26,7 @@ /** Used only for resource event filtering. */ public class ExtendedResourceEvent extends ResourceEvent { - private HasMetadata previousResource; + private final HasMetadata previousResource; public ExtendedResourceEvent( ResourceAction action, @@ -39,4 +40,31 @@ public ExtendedResourceEvent( public Optional getPreviousResource() { return Optional.ofNullable(previousResource); } + + @Override + public String toString() { + return "ExtendedResourceEvent{" + + "previousResourceVersion=" + + previousResource.getMetadata().getResourceVersion() + + ", action=" + + action + + ", resourceVersion=" + + resource.getMetadata().getResourceVersion() + + ", relatedCustomResource=" + + relatedCustomResource + + '}'; + } + + @Override + public boolean equals(Object o) { + if (o == null || getClass() != o.getClass()) return false; + if (!super.equals(o)) return false; + ExtendedResourceEvent that = (ExtendedResourceEvent) o; + return Objects.equals(previousResource, that.previousResource); + } + + @Override + public int hashCode() { + return Objects.hash(super.hashCode(), previousResource); + } } diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java index 301ece4424..d9650292d7 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java @@ -93,11 +93,12 @@ public void changeNamespaces(Set namespaces) { @SuppressWarnings("unchecked") public R eventFilteringUpdateAndCacheResource(R resourceToUpdate, UnaryOperator updateMethod) { ResourceID id = ResourceID.fromResource(resourceToUpdate); - log.debug("Update and cache: {}", id); + log.debug("Starting event filter and cache update for: {}", id); R updatedResource = null; try { temporaryResourceCache.startEventFilteringModify(id); updatedResource = updateMethod.apply(resourceToUpdate); + log.debug("Resource update successful: {}", id); handleRecentResourceUpdate(id, updatedResource, resourceToUpdate); return updatedResource; } finally { @@ -124,6 +125,14 @@ public R eventFilteringUpdateAndCacheResource(R resourceToUpdate, UnaryOperator< : null; R prevVersionOfResource = updatedForLambda != null ? updatedForLambda : extendedResourcePrevVersion; + if (log.isDebugEnabled()) { + log.debug( + "Extended previous resource version: {} resource from update present: {}" + + " extendedPrevResource present: {}", + prevVersionOfResource.getMetadata().getResourceVersion(), + updatedForLambda != null, + extendedResourcePrevVersion != null); + } handleEvent( r.getAction(), latestResource, diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/TemporaryResourceCache.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/TemporaryResourceCache.java index 1dbbf36043..079f5f58e6 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/TemporaryResourceCache.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/TemporaryResourceCache.java @@ -133,6 +133,7 @@ private synchronized EventHandling onEvent( resource.getMetadata().getResourceVersion()); } if (!unknownState) { + log.debug("Setting latest resource version to: {}", latestResourceVersion); latestResourceVersion = resource.getMetadata().getResourceVersion(); } var cached = cache.get(resourceId); @@ -140,6 +141,11 @@ private synchronized EventHandling onEvent( if (cached != null) { int comp = ReconcilerUtilsInternal.compareResourceVersions(resource, cached); if (comp >= 0 || unknownState) { + log.debug( + "Removing resource from temp cache. id: {} comparison: {} unknown state: {}", + resourceId, + comp, + unknownState); cache.remove(resourceId); // we propagate event only for our update or newer other can be discarded since we know we // will receive @@ -151,6 +157,7 @@ private synchronized EventHandling onEvent( } var ed = activeUpdates.get(resourceId); if (ed != null && result != EventHandling.OBSOLETE) { + log.debug("Setting last event for id: {} delete: {}", resourceId, delete); ed.setLastEvent( delete ? new ResourceDeleteEvent(ResourceAction.DELETED, resourceId, resource, unknownState) From df441552535970742c279742201f678efc5d121a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Attila=20M=C3=A9sz=C3=A1ros?= Date: Fri, 13 Feb 2026 15:36:28 +0100 Subject: [PATCH 2/3] wip MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Attila Mészáros --- .../operator/processing/MDCUtils.java | 33 +++++++++ .../controller/ControllerEventSource.java | 24 +++++-- .../source/informer/InformerEventSource.java | 72 +++++++++++-------- .../informer/ManagedInformerEventSource.java | 10 +++ 4 files changed, 105 insertions(+), 34 deletions(-) diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/MDCUtils.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/MDCUtils.java index 01a8b62e9d..cfd48dfc13 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/MDCUtils.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/MDCUtils.java @@ -20,6 +20,7 @@ import io.fabric8.kubernetes.api.model.HasMetadata; import io.javaoperatorsdk.operator.api.config.Utils; import io.javaoperatorsdk.operator.processing.event.ResourceID; +import io.javaoperatorsdk.operator.processing.event.source.ResourceAction; public class MDCUtils { @@ -34,6 +35,38 @@ public class MDCUtils { private static final boolean enabled = Utils.getBooleanFromSystemPropsOrDefault(Utils.USE_MDC_ENV_KEY, true); + private static final String INFORMER_EVENT_RESOURCE_NAME = "informer.event.resource.name"; + private static final String INFORMER_EVENT_RESOURCE_NAMESPACE = + "informer.event.resource.namespace"; + private static final String INFORMER_EVENT_RESOURCE_KIND = "informer.event.resource.kind"; + private static final String INFORMER_EVENT_RESOURCE_VERSION = + "informer.event.resource.resourceVersion"; + private static final String INFORMER_EVENT_ACTION = "informer.event.action"; + private static final String INFORMER_NAME = "informer.name"; + + public static void addInformerEventInfo( + HasMetadata resource, ResourceAction action, String eventSourceName) { + if (enabled) { + MDC.put(INFORMER_EVENT_RESOURCE_NAME, resource.getMetadata().getName()); + MDC.put(INFORMER_EVENT_RESOURCE_NAMESPACE, resource.getMetadata().getNamespace()); + MDC.put(INFORMER_EVENT_RESOURCE_KIND, HasMetadata.getKind(resource.getClass())); + MDC.put(INFORMER_EVENT_RESOURCE_VERSION, resource.getMetadata().getNamespace()); + MDC.put(INFORMER_EVENT_ACTION, action.name()); + MDC.put(INFORMER_NAME, eventSourceName); + } + } + + public static void removeInformerEventInfo() { + if (enabled) { + MDC.remove(INFORMER_EVENT_RESOURCE_NAME); + MDC.remove(INFORMER_EVENT_RESOURCE_NAMESPACE); + MDC.remove(INFORMER_EVENT_RESOURCE_KIND); + MDC.remove(INFORMER_EVENT_RESOURCE_VERSION); + MDC.remove(INFORMER_EVENT_ACTION); + MDC.remove(INFORMER_NAME); + } + } + public static void addResourceIDInfo(ResourceID resourceID) { if (enabled) { MDC.put(NAME, resourceID.getName()); diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ControllerEventSource.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ControllerEventSource.java index 8412e1ccbe..29b363dab6 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ControllerEventSource.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ControllerEventSource.java @@ -135,12 +135,18 @@ private boolean isAcceptedByFilters(ResourceAction action, T resource, T oldReso @Override public synchronized void onAdd(T resource) { - handleOnAddOrUpdate(ResourceAction.ADDED, null, resource); + withMDC( + resource, + ResourceAction.ADDED, + () -> handleOnAddOrUpdate(ResourceAction.ADDED, null, resource)); } @Override public synchronized void onUpdate(T oldCustomResource, T newCustomResource) { - handleOnAddOrUpdate(ResourceAction.UPDATED, oldCustomResource, newCustomResource); + withMDC( + newCustomResource, + ResourceAction.UPDATED, + () -> handleOnAddOrUpdate(ResourceAction.UPDATED, oldCustomResource, newCustomResource)); } private void handleOnAddOrUpdate( @@ -160,10 +166,16 @@ private void handleOnAddOrUpdate( @Override public synchronized void onDelete(T resource, boolean deletedFinalStateUnknown) { - temporaryResourceCache.onDeleteEvent(resource, deletedFinalStateUnknown); - // delete event is quite special here, that requires special care, since we clean up caches on - // delete event. - handleEvent(ResourceAction.DELETED, resource, null, deletedFinalStateUnknown); + withMDC( + resource, + ResourceAction.DELETED, + () -> { + temporaryResourceCache.onDeleteEvent(resource, deletedFinalStateUnknown); + // delete event is quite special here, that requires special care, since we clean up + // caches on + // delete event. + handleEvent(ResourceAction.DELETED, resource, null, deletedFinalStateUnknown); + }); } @Override diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerEventSource.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerEventSource.java index b778747417..738dbc77ec 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerEventSource.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerEventSource.java @@ -100,42 +100,58 @@ private InformerEventSource( @Override public void onAdd(R newResource) { - if (log.isDebugEnabled()) { - log.debug( - "On add event received for resource id: {} type: {} version: {}", - ResourceID.fromResource(newResource), - resourceType().getSimpleName(), - newResource.getMetadata().getResourceVersion()); - } - onAddOrUpdate(ResourceAction.ADDED, newResource, null); + withMDC( + newResource, + ResourceAction.ADDED, + () -> { + if (log.isDebugEnabled()) { + log.debug( + "On add event received for resource id: {} type: {} version: {}", + ResourceID.fromResource(newResource), + resourceType().getSimpleName(), + newResource.getMetadata().getResourceVersion()); + } + onAddOrUpdate(ResourceAction.ADDED, newResource, null); + }); } @Override public void onUpdate(R oldObject, R newObject) { - if (log.isDebugEnabled()) { - log.debug( - "On update event received for resource id: {} type: {} version: {} old version: {} ", - ResourceID.fromResource(newObject), - resourceType().getSimpleName(), - newObject.getMetadata().getResourceVersion(), - oldObject.getMetadata().getResourceVersion()); - } - onAddOrUpdate(ResourceAction.UPDATED, newObject, oldObject); + withMDC( + newObject, + ResourceAction.UPDATED, + () -> { + if (log.isDebugEnabled()) { + log.debug( + "On update event received for resource id: {} type: {} version: {} old version: {}" + + " ", + ResourceID.fromResource(newObject), + resourceType().getSimpleName(), + newObject.getMetadata().getResourceVersion(), + oldObject.getMetadata().getResourceVersion()); + } + onAddOrUpdate(ResourceAction.UPDATED, newObject, oldObject); + }); } @Override public synchronized void onDelete(R resource, boolean b) { - if (log.isDebugEnabled()) { - log.debug( - "On delete event received for resource id: {} type: {}", - ResourceID.fromResource(resource), - resourceType().getSimpleName()); - } - primaryToSecondaryIndex.onDelete(resource); - temporaryResourceCache.onDeleteEvent(resource, b); - if (acceptedByDeleteFilters(resource, b)) { - propagateEvent(resource); - } + withMDC( + resource, + ResourceAction.DELETED, + () -> { + if (log.isDebugEnabled()) { + log.debug( + "On delete event received for resource id: {} type: {}", + ResourceID.fromResource(resource), + resourceType().getSimpleName()); + } + primaryToSecondaryIndex.onDelete(resource); + temporaryResourceCache.onDeleteEvent(resource, b); + if (acceptedByDeleteFilters(resource, b)) { + propagateEvent(resource); + } + }); } @Override diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java index d9650292d7..596ddab2c4 100644 --- a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java +++ b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java @@ -40,6 +40,7 @@ import io.javaoperatorsdk.operator.health.InformerHealthIndicator; import io.javaoperatorsdk.operator.health.InformerWrappingEventSourceHealthIndicator; import io.javaoperatorsdk.operator.health.Status; +import io.javaoperatorsdk.operator.processing.MDCUtils; import io.javaoperatorsdk.operator.processing.event.ResourceID; import io.javaoperatorsdk.operator.processing.event.source.*; import io.javaoperatorsdk.operator.processing.event.source.ResourceAction; @@ -266,4 +267,13 @@ public String toString() { public void setControllerConfiguration(ControllerConfiguration controllerConfiguration) { this.controllerConfiguration = controllerConfiguration; } + + protected void withMDC(R resource, ResourceAction action, Runnable runnable) { + try { + MDCUtils.addInformerEventInfo(resource, action, name()); + runnable.run(); + } finally { + MDCUtils.removeInformerEventInfo(); + } + } } From 6750a5f79e2310f983909c690008222aeb5a038a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Attila=20M=C3=A9sz=C3=A1ros?= Date: Fri, 13 Feb 2026 16:24:32 +0100 Subject: [PATCH 3/3] wip MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Attila Mészáros --- operator-framework/src/test/resources/log4j2.xml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/operator-framework/src/test/resources/log4j2.xml b/operator-framework/src/test/resources/log4j2.xml index e922079cc8..c9cbee45f6 100644 --- a/operator-framework/src/test/resources/log4j2.xml +++ b/operator-framework/src/test/resources/log4j2.xml @@ -19,7 +19,7 @@ - +