-
Notifications
You must be signed in to change notification settings - Fork 236
improve: logging for resource filter cache #3167
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: next
Are you sure you want to change the base?
Changes from all commits
c91c4ce
99dd0be
603a4da
f33c78a
7991b21
a2a5601
4c4a297
54a0838
2dab16e
044e43c
f0bccda
fa26af9
6d75382
1a0d81f
c4369de
fce0a08
08d8a58
cb30b56
13d8b4a
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -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,72 @@ public class MDCUtils { | |
| private static final boolean enabled = | ||
| Utils.getBooleanFromSystemPropsOrDefault(Utils.USE_MDC_ENV_KEY, true); | ||
|
|
||
| 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"; | ||
|
|
||
| public static void addInformerEventInfo( | ||
|
Collaborator
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. More of a general comment due to my unfamiliarity with MDC: how does this work in a multi-threaded environment? |
||
| HasMetadata resource, ResourceAction action, String eventSourceName) { | ||
| if (enabled) { | ||
| MDC.put(EVENT_RESOURCE_NAME, resource.getMetadata().getName()); | ||
| MDC.put(EVENT_RESOURCE_NAMESPACE, resource.getMetadata().getNamespace()); | ||
| MDC.put(EVENT_RESOURCE_KIND, HasMetadata.getKind(resource.getClass())); | ||
| MDC.put(EVENT_RESOURCE_VERSION, resource.getMetadata().getResourceVersion()); | ||
| MDC.put(EVENT_RESOURCE_UID, resource.getMetadata().getUid()); | ||
| MDC.put(EVENT_ACTION, action == null ? null : action.name()); | ||
| MDC.put(EVENT_SOURCE_NAME, eventSourceName); | ||
| } | ||
| } | ||
|
|
||
| public static void removeInformerEventInfo() { | ||
| if (enabled) { | ||
| MDC.remove(EVENT_RESOURCE_NAME); | ||
| MDC.remove(EVENT_RESOURCE_NAMESPACE); | ||
| MDC.remove(EVENT_RESOURCE_KIND); | ||
| MDC.remove(EVENT_RESOURCE_VERSION); | ||
| MDC.remove(EVENT_RESOURCE_UID); | ||
| MDC.remove(EVENT_ACTION); | ||
| MDC.remove(EVENT_SOURCE_NAME); | ||
| } | ||
| } | ||
|
|
||
| public static void withMDCForEvent( | ||
| 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); | ||
| runnable.run(); | ||
| } finally { | ||
| MDCUtils.removeInformerEventInfo(); | ||
| } | ||
| } | ||
|
|
||
| public static void withMDCForResourceID(ResourceID resourceID, Runnable runnable) { | ||
| try { | ||
| MDCUtils.addResourceIDInfo(resourceID); | ||
| runnable.run(); | ||
| } finally { | ||
| MDCUtils.removeResourceIDInfo(); | ||
| } | ||
| } | ||
|
|
||
| public static void withMDCForPrimary(HasMetadata primary, Runnable runnable) { | ||
| try { | ||
| MDCUtils.addResourceInfo(primary); | ||
| runnable.run(); | ||
| } finally { | ||
| MDCUtils.removeResourceInfo(); | ||
| } | ||
| } | ||
|
|
||
| public static void addResourceIDInfo(ResourceID resourceID) { | ||
| if (enabled) { | ||
| MDC.put(NAME, resourceID.getName()); | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -83,19 +83,13 @@ PostExecutionControl<P> handleDispatch(ExecutionScope<P> executionScope, Context | |
| throws Exception { | ||
| P originalResource = executionScope.getResource(); | ||
| var resourceForExecution = cloneResource(originalResource); | ||
| log.debug( | ||
| "Handling dispatch for resource name: {} namespace: {}", | ||
| getName(originalResource), | ||
| originalResource.getMetadata().getNamespace()); | ||
| log.debug("Handling dispatch"); | ||
|
|
||
| final var markedForDeletion = originalResource.isMarkedForDeletion(); | ||
| if (!triggerOnAllEvents() | ||
| && markedForDeletion | ||
| && shouldNotDispatchToCleanupWhenMarkedForDeletion(originalResource)) { | ||
| log.debug( | ||
| "Skipping cleanup of resource {} because finalizer(s) {} don't allow processing yet", | ||
| getName(originalResource), | ||
| originalResource.getMetadata().getFinalizers()); | ||
| log.debug("Skipping cleanup because finalizer(s) don't allow processing yet"); | ||
| return PostExecutionControl.defaultDispatch(); | ||
| } | ||
| // context can be provided only for testing purposes | ||
|
|
@@ -165,11 +159,7 @@ private PostExecutionControl<P> reconcileExecution( | |
| P originalResource, | ||
| Context<P> context) | ||
| throws Exception { | ||
| log.debug( | ||
| "Reconciling resource {} with version: {} with execution scope: {}", | ||
| getName(resourceForExecution), | ||
| getVersion(resourceForExecution), | ||
| executionScope); | ||
| log.debug("Reconciling resource execution scope: {}", executionScope); | ||
|
|
||
| UpdateControl<P> updateControl = controller.reconcile(resourceForExecution, context); | ||
|
|
||
|
|
@@ -246,9 +236,8 @@ public boolean isLastAttempt() { | |
| exceptionLevel = Level.DEBUG; | ||
| failedMessage = " due to conflict"; | ||
| log.info( | ||
| "ErrorStatusUpdateControl.patchStatus of {} failed due to a conflict, but the next" | ||
| + " reconciliation is imminent.", | ||
| ResourceID.fromResource(originalResource)); | ||
| "ErrorStatusUpdateControl.patchStatus failed due to a conflict, but the next" | ||
| + " reconciliation is imminent"); | ||
| } else { | ||
| exceptionLevel = Level.WARN; | ||
| failedMessage = ", but will be retried soon,"; | ||
|
|
@@ -312,10 +301,7 @@ private void updatePostExecutionControlWithReschedule( | |
| private PostExecutionControl<P> handleCleanup( | ||
| P resourceForExecution, Context<P> context, ExecutionScope<P> executionScope) { | ||
| if (log.isDebugEnabled()) { | ||
| log.debug( | ||
| "Executing delete for resource: {} with version: {}", | ||
| ResourceID.fromResource(resourceForExecution), | ||
| getVersion(resourceForExecution)); | ||
| log.debug("Executing delete for resource"); | ||
| } | ||
| DeleteControl deleteControl = controller.cleanup(resourceForExecution, context); | ||
| final var useFinalizer = controller.useFinalizer(); | ||
|
|
@@ -329,10 +315,7 @@ private PostExecutionControl<P> handleCleanup( | |
| } | ||
| } | ||
| 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); | ||
|
Comment on lines
317
to
320
|
||
| PostExecutionControl<P> postExecutionControl = PostExecutionControl.defaultDispatch(); | ||
|
|
@@ -342,11 +325,7 @@ private PostExecutionControl<P> handleCleanup( | |
|
|
||
| private P patchResource(Context<P> context, P resource, P originalResource) { | ||
| if (log.isDebugEnabled()) { | ||
| log.debug( | ||
| "Updating resource: {} with version: {}; SSA: {}", | ||
| resource.getMetadata().getName(), | ||
| getVersion(resource), | ||
| useSSA); | ||
| log.debug("Updating resource; SSA: {}", useSSA); | ||
| } | ||
| log.trace("Resource before update: {}", resource); | ||
|
|
||
|
|
@@ -384,10 +363,7 @@ public CustomResourceFacade(ControllerConfiguration<R> configuration, Cloner clo | |
|
|
||
| public R patchResource(Context<R> context, R resource, R originalResource) { | ||
| if (log.isDebugEnabled()) { | ||
| log.debug( | ||
| "Trying to replace resource {}, version: {}", | ||
| ResourceID.fromResource(resource), | ||
| resource.getMetadata().getResourceVersion()); | ||
| log.debug("Trying to replace resource"); | ||
| } | ||
| if (useSSA) { | ||
| return context.resourceOperations().serverSideApplyPrimary(resource); | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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 defineseventsource.name,eventsource.event.action,eventsource.event.resource.name, etc. This mismatch will cause the MDC values not to appear in the logs as expected.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This looks like an hallucination but I'm not super familiar with how MDC is used so 🤷
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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.