improve: logging for resource filter cache#3167
improve: logging for resource filter cache#3167csviri wants to merge 19 commits intooperator-framework:nextfrom
Conversation
…ork#3106) - Adds utility that provides methods to update resources using comparable resource versions - Integrates this utility to the core of the framework (thus simplifying `ReconciliationDispatcher`) - note that this introduces a change in the behavior for the `UpdateControl.patchStatus` (and others), since it won't trigger the reconiliation for the event in that update. - Renames former `ReconcilerUtils` to `ReconcilerUtilsInternal`, this is breaking but that utils was never advertised for non-internal usage - Includes also fixes for ControllerEventSource event filtering - Improves TemporaryResourceCache event filtering algorithm Signed-off-by: Attila Mészáros <a_meszaros@apple.com> Signed-off-by: Steve Hawkins <shawkins@redhat.com> Co-authored-by: Steve Hawkins <shawkins@redhat.com>
Signed-off-by: Attila Mészáros <a_meszaros@apple.com>
There was a problem hiding this comment.
Pull request overview
This pull request enhances the logging infrastructure by integrating MDC (Mapped Diagnostic Context) support for event processing and sanitizing log messages to reduce redundancy. The changes remove explicit resource ID parameters from log messages since this information is now captured in MDC, making logs cleaner while maintaining the same level of detail through structured logging patterns.
Changes:
- Added MDC utility methods to capture event source information and resource IDs in logging context
- Updated all log4j2.xml files with a standardized pattern that includes MDC placeholders for resource and event information
- Refactored log messages across the framework to remove redundant resource ID parameters that are now in MDC
- Made fields protected in Event and ResourceEvent classes to support toString implementations in subclasses
Reviewed changes
Copilot reviewed 17 out of 17 changed files in this pull request and generated 10 comments.
Show a summary per file
| File | Description |
|---|---|
| sample-operators/webpage/src/main/resources/log4j2.xml | Updated log pattern to include MDC placeholders for resource and event metadata |
| sample-operators/tomcat-operator/src/main/resources/log4j2.xml | Updated log pattern and changed log level from info to debug |
| sample-operators/mysql-schema/src/main/resources/log4j2.xml | Updated log pattern and changed log level from info to debug |
| sample-operators/leader-election/src/main/resources/log4j2.xml | Updated log pattern to include MDC placeholders |
| sample-operators/controller-namespace-deletion/src/main/resources/log4j2.xml | Updated log pattern to include MDC placeholders |
| operator-framework/src/test/resources/log4j2.xml | Updated log pattern to include MDC placeholders |
| operator-framework-core/src/test/resources/log4j2.xml | Updated log pattern to include MDC placeholders |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/TemporaryResourceCache.java | Removed resource ID from debug logs and added new debug statements for cache operations |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java | Added withMDC method and refactored log messages to remove resource IDs |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerEventSource.java | Wrapped event handlers with MDC context and sanitized log messages |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ExtendedResourceEvent.java | Made previousResource field final and added toString, equals, and hashCode methods |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ResourceEvent.java | Changed action and resource fields from private to protected for subclass access |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/controller/ControllerEventSource.java | Wrapped event handlers with MDC context and sanitized log messages |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/ReconciliationDispatcher.java | Removed resource ID parameters from log messages |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/EventProcessor.java | Removed resource ID parameters from log messages and added MDC resource ID info in reconciler executor |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/Event.java | Changed relatedCustomResource field from private to protected |
| operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/MDCUtils.java | Added new utility methods for event MDC context management |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
...va/io/javaoperatorsdk/operator/processing/event/source/controller/ControllerEventSource.java
Outdated
Show resolved
Hide resolved
...n/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerEventSource.java
Outdated
Show resolved
Hide resolved
...ramework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/EventProcessor.java
Outdated
Show resolved
Hide resolved
operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/MDCUtils.java
Outdated
Show resolved
Hide resolved
| log.debug( | ||
| "Skipping finalizer remove for resource: {} with version: {}. delete control: {}, uses" | ||
| + " finalizer: {}", | ||
| getUID(resourceForExecution), | ||
| getVersion(resourceForExecution), | ||
| "Skipping finalizer remove for resource. Delete control: {}, uses finalizer: {}", | ||
| deleteControl, | ||
| useFinalizer); |
There was a problem hiding this comment.
There is a double space before "finalizer" in the log message. It should be "Delete control: {}, uses finalizer: {}" with a single space.
| log.debug("Processing event for resource"); | ||
| } | ||
| if (!unknownState) { | ||
| log.debug("Setting latest resource version to: {}", latestResourceVersion); |
There was a problem hiding this comment.
The log message is misleading. It logs "Setting latest resource version to: {}" but then shows the value of 'latestResourceVersion' (the old value) before it's updated on line 134. The message should either log the new value from 'resource.getMetadata().getResourceVersion()' or be reworded to reflect that it's showing the old value before updating.
| log.debug("Setting latest resource version to: {}", latestResourceVersion); | |
| log.debug( | |
| "Setting latest resource version to: {}", | |
| resource.getMetadata().getResourceVersion()); |
There was a problem hiding this comment.
This seems like a valid comment and should be addressed.
...ore/src/main/java/io/javaoperatorsdk/operator/processing/event/ReconciliationDispatcher.java
Outdated
Show resolved
Hide resolved
| private static final String EVENT_RESOURCE_NAME = "eventsource.event.resource.name"; | ||
| private static final String EVENT_RESOURCE_UID = "eventsource.event.resource.uid"; | ||
| private static final String EVENT_RESOURCE_NAMESPACE = "eventsource.event.resource.namespace"; | ||
| private static final String EVENT_RESOURCE_KIND = "eventsource.event.resource.kind"; | ||
| private static final String EVENT_RESOURCE_VERSION = "eventsource.event.resource.resourceVersion"; | ||
| private static final String EVENT_ACTION = "eventsource.event.action"; | ||
| private static final String EVENT_SOURCE_NAME = "eventsource.name"; |
There was a problem hiding this comment.
The MDC key names defined here do not match the keys used in the log4j2.xml pattern layouts. The log4j2.xml files reference keys like informer.name, informer.event.action, informer.event.resource.name, etc., but the code defines eventsource.name, eventsource.event.action, eventsource.event.resource.name, etc. This mismatch will cause the MDC values not to appear in the logs as expected.
| private static final String EVENT_RESOURCE_NAME = "eventsource.event.resource.name"; | |
| private static final String EVENT_RESOURCE_UID = "eventsource.event.resource.uid"; | |
| private static final String EVENT_RESOURCE_NAMESPACE = "eventsource.event.resource.namespace"; | |
| private static final String EVENT_RESOURCE_KIND = "eventsource.event.resource.kind"; | |
| private static final String EVENT_RESOURCE_VERSION = "eventsource.event.resource.resourceVersion"; | |
| private static final String EVENT_ACTION = "eventsource.event.action"; | |
| private static final String EVENT_SOURCE_NAME = "eventsource.name"; | |
| private static final String EVENT_RESOURCE_NAME = "informer.event.resource.name"; | |
| private static final String EVENT_RESOURCE_UID = "informer.event.resource.uid"; | |
| private static final String EVENT_RESOURCE_NAMESPACE = "informer.event.resource.namespace"; | |
| private static final String EVENT_RESOURCE_KIND = "informer.event.resource.kind"; | |
| private static final String EVENT_RESOURCE_VERSION = "informer.event.resource.resourceVersion"; | |
| private static final String EVENT_ACTION = "informer.event.action"; | |
| private static final String EVENT_SOURCE_NAME = "informer.name"; |
There was a problem hiding this comment.
This looks like an hallucination but I'm not super familiar with how MDC is used so 🤷
There was a problem hiding this comment.
Actually, these should be documented in the appropriate doc section, along with the way to enable / disable it (which I don't think is documented).
There was a problem hiding this comment.
Yes, will add this to the docs, although this is not that interesting for the user, since this happens outside the reconciliation, but should be in the docs at least mentioned.
| HasMetadata resource, Runnable runnable, String nameSourceName) { | ||
| withMDCForEvent(resource, null, runnable, nameSourceName); | ||
| } | ||
|
|
||
| public static void withMDCForEvent( | ||
| HasMetadata resource, ResourceAction action, Runnable runnable, String nameSourceName) { | ||
| try { | ||
| MDCUtils.addInformerEventInfo(resource, action, nameSourceName); |
There was a problem hiding this comment.
The parameter name 'nameSourceName' is misleading and appears to be a typo. It should likely be 'eventSourceName' to be consistent with the actual parameter being passed and the method signature on line 77.
| HasMetadata resource, Runnable runnable, String nameSourceName) { | |
| withMDCForEvent(resource, null, runnable, nameSourceName); | |
| } | |
| public static void withMDCForEvent( | |
| HasMetadata resource, ResourceAction action, Runnable runnable, String nameSourceName) { | |
| try { | |
| MDCUtils.addInformerEventInfo(resource, action, nameSourceName); | |
| HasMetadata resource, Runnable runnable, String eventSourceName) { | |
| withMDCForEvent(resource, null, runnable, eventSourceName); | |
| } | |
| public static void withMDCForEvent( | |
| HasMetadata resource, ResourceAction action, Runnable runnable, String eventSourceName) { | |
| try { | |
| MDCUtils.addInformerEventInfo(resource, action, eventSourceName); |
There was a problem hiding this comment.
Will fix in logger configs
...java/io/javaoperatorsdk/operator/processing/event/source/informer/ExtendedResourceEvent.java
Show resolved
Hide resolved
…tor/processing/event/source/informer/InformerEventSource.java Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
…tor/processing/event/EventProcessor.java Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
…tor/processing/MDCUtils.java Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
…tor/processing/event/ReconciliationDispatcher.java Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
| secondaryIDs = primaryToSecondaryMapper.toSecondaryResourceIDs(primary); | ||
| log.debug( | ||
| "Using PrimaryToSecondaryMapper to find secondary resources for primary: {}. Found" | ||
| "Using PrimaryToSecondaryMapper to find secondary resources for primary. Found" |
There was a problem hiding this comment.
The indentation rules that split constant Strings is rather stupid.
| updatedForLambda != null ? updatedForLambda : extendedResourcePrevVersion; | ||
| if (log.isDebugEnabled()) { | ||
| log.debug( | ||
| "Extended previous resource version: {} resource from update present: {}" |
| public R eventFilteringUpdateAndCacheResource(R resourceToUpdate, UnaryOperator<R> updateMethod) { | ||
| ResourceID id = ResourceID.fromResource(resourceToUpdate); | ||
| log.debug("Update and cache: {}", id); | ||
| log.debug("Starting event filter and cache update"); |
There was a problem hiding this comment.
filtering instead of filter
| log.debug("Processing event for resource"); | ||
| } | ||
| if (!unknownState) { | ||
| log.debug("Setting latest resource version to: {}", latestResourceVersion); |
There was a problem hiding this comment.
This seems like a valid comment and should be addressed.
| private static final String EVENT_RESOURCE_NAME = "eventsource.event.resource.name"; | ||
| private static final String EVENT_RESOURCE_UID = "eventsource.event.resource.uid"; | ||
| private static final String EVENT_RESOURCE_NAMESPACE = "eventsource.event.resource.namespace"; | ||
| private static final String EVENT_RESOURCE_KIND = "eventsource.event.resource.kind"; | ||
| private static final String EVENT_RESOURCE_VERSION = "eventsource.event.resource.resourceVersion"; | ||
| private static final String EVENT_ACTION = "eventsource.event.action"; | ||
| private static final String EVENT_SOURCE_NAME = "eventsource.name"; |
There was a problem hiding this comment.
This looks like an hallucination but I'm not super familiar with how MDC is used so 🤷
| private static final String EVENT_RESOURCE_NAME = "eventsource.event.resource.name"; | ||
| private static final String EVENT_RESOURCE_UID = "eventsource.event.resource.uid"; | ||
| private static final String EVENT_RESOURCE_NAMESPACE = "eventsource.event.resource.namespace"; | ||
| private static final String EVENT_RESOURCE_KIND = "eventsource.event.resource.kind"; | ||
| private static final String EVENT_RESOURCE_VERSION = "eventsource.event.resource.resourceVersion"; | ||
| private static final String EVENT_ACTION = "eventsource.event.action"; | ||
| private static final String EVENT_SOURCE_NAME = "eventsource.name"; |
There was a problem hiding this comment.
Actually, these should be documented in the appropriate doc section, along with the way to enable / disable it (which I don't think is documented).
| private static final String EVENT_ACTION = "eventsource.event.action"; | ||
| private static final String EVENT_SOURCE_NAME = "eventsource.name"; | ||
|
|
||
| public static void addInformerEventInfo( |
There was a problem hiding this comment.
More of a general comment due to my unfamiliarity with MDC: how does this work in a multi-threaded environment?
Sanitize logs:
Signed-off-by: Attila Mészáros a_meszaros@apple.com