Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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 {

Expand All @@ -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";
Comment on lines +38 to +44
Copy link

Copilot AI Feb 19, 2026

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 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.

Suggested change
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";

Copilot uses AI. Check for mistakes.
Copy link
Collaborator

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 🤷

Copy link
Collaborator

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).

Copy link
Collaborator Author

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.


public static void addInformerEventInfo(
Copy link
Collaborator

Choose a reason for hiding this comment

The 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());
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@

public class Event {

private final ResourceID relatedCustomResource;
protected final ResourceID relatedCustomResource;

public Event(ResourceID targetCustomResource) {
this.relatedCustomResource = targetCustomResource;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -44,8 +44,6 @@
import io.javaoperatorsdk.operator.processing.retry.Retry;
import io.javaoperatorsdk.operator.processing.retry.RetryExecution;

import static io.javaoperatorsdk.operator.processing.KubernetesResourceUtils.getName;

public class EventProcessor<P extends HasMetadata> implements EventHandler, LifecycleAware {

private static final Logger log = LoggerFactory.getLogger(EventProcessor.class);
Expand Down Expand Up @@ -187,9 +185,8 @@ private void submitReconciliationExecution(ResourceState state) {
executor.execute(new ReconcilerExecutor(resourceID, executionScope));
} else {
log.debug(
"Skipping executing controller for resource id: {}. Controller in execution: {}. Latest"
"Skipping executing controller. Controller in execution: {}. Latest"
+ " Resource present: {}",
resourceID,
controllerUnderExecution,
maybeLatest.isPresent());
if (maybeLatest.isEmpty()) {
Expand All @@ -198,7 +195,7 @@ private void submitReconciliationExecution(ResourceState state) {
// resource. Other is that simply there is no primary resource present for an event, this
// might indicate issue with the implementation, but could happen also naturally, thus
// this is not necessarily a problem.
log.debug("no primary resource found in cache with resource id: {}", resourceID);
log.debug("No primary resource found in cache with resource id: {}", resourceID);
}
}
} finally {
Expand All @@ -209,7 +206,7 @@ private void submitReconciliationExecution(ResourceState state) {
@SuppressWarnings("unchecked")
private P getResourceFromState(ResourceState state) {
if (triggerOnAllEvents()) {
log.debug("Getting resource from state for {}", state.getId());
log.debug("Getting resource from state");
return (P) state.getLastKnownResource();
} else {
throw new IllegalStateException(
Expand All @@ -221,16 +218,15 @@ private void handleEventMarking(Event event, ResourceState state) {
final var relatedCustomResourceID = event.getRelatedCustomResourceID();
if (event instanceof ResourceEvent resourceEvent) {
if (resourceEvent.getAction() == ResourceAction.DELETED) {
log.debug("Marking delete event received for: {}", relatedCustomResourceID);
log.debug("Marking delete event received.");
state.markDeleteEventReceived(
resourceEvent.getResource().orElseThrow(),
((ResourceDeleteEvent) resourceEvent).isDeletedFinalStateUnknown());
} else {
if (state.processedMarkForDeletionPresent() && isResourceMarkedForDeletion(resourceEvent)) {
log.debug(
"Skipping mark of event received, since already processed mark for deletion and"
+ " resource marked for deletion: {}",
relatedCustomResourceID);
+ " resource marked for deletion");
return;
}
// Normally when eventMarker is in state PROCESSED_MARK_FOR_DELETION it is expected to
Expand Down Expand Up @@ -260,8 +256,7 @@ private boolean isResourceMarkedForDeletion(ResourceEvent resourceEvent) {

private void handleRateLimitedSubmission(ResourceID resourceID, Duration minimalDuration) {
var minimalDurationMillis = minimalDuration.toMillis();
log.debug(
"Rate limited resource: {}, rescheduled in {} millis", resourceID, minimalDurationMillis);
log.debug("Rate limited resource. rescheduled in {} millis", minimalDurationMillis);
retryEventSource()
.scheduleOnce(
resourceID, Math.max(minimalDurationMillis, MINIMAL_RATE_LIMIT_RESCHEDULE_DURATION));
Expand Down Expand Up @@ -334,7 +329,7 @@ private void reScheduleExecutionIfInstructed(
.ifPresentOrElse(
delay -> {
var resourceID = ResourceID.fromResource(customResource);
log.debug("Rescheduling event for resource: {} with delay: {}", resourceID, delay);
log.debug("Rescheduling event with delay: {}", delay);
retryEventSource().scheduleOnce(resourceID, delay);
},
() -> scheduleExecutionForMaxReconciliationInterval(customResource));
Expand All @@ -347,11 +342,7 @@ private void scheduleExecutionForMaxReconciliationInterval(P customResource) {
m -> {
var resourceID = ResourceID.fromResource(customResource);
var delay = m.toMillis();
log.debug(
"Rescheduling event for max reconciliation interval for resource: {} : "
+ "with delay: {}",
resourceID,
delay);
log.debug("Rescheduling event for max reconciliation interval with delay: {}", delay);
retryEventSource().scheduleOnce(resourceID, delay);
});
}
Expand All @@ -375,16 +366,15 @@ private void handleRetryOnException(ExecutionScope<P> executionScope, Exception

retryAwareErrorLogging(state.getRetry(), eventPresent, exception, executionScope);
if (eventPresent) {
log.debug("New events exists for for resource id: {}", resourceID);
log.debug("New events exist for resource id");
submitReconciliationExecution(state);
return;
}
Optional<Long> nextDelay = state.getRetry().nextDelay();

nextDelay.ifPresentOrElse(
delay -> {
log.debug(
"Scheduling timer event for retry with delay:{} for resource: {}", delay, resourceID);
log.debug("Scheduling timer event for retry with delay:{}", delay);
metrics.failedReconciliation(executionScope.getResource(), exception, metricsMetadata);
retryEventSource().scheduleOnce(resourceID, delay);
},
Expand Down Expand Up @@ -425,8 +415,7 @@ private void retryAwareErrorLogging(
}

private void cleanupOnSuccessfulExecution(ExecutionScope<P> executionScope) {
log.debug(
"Cleanup for successful execution for resource: {}", getName(executionScope.getResource()));
log.debug("Cleanup for successful execution");
if (isRetryConfigured()) {
resourceStateManager.getOrCreate(executionScope.getResourceID()).setRetry(null);
}
Expand All @@ -444,7 +433,7 @@ private ResourceState getOrInitRetryExecution(ExecutionScope<P> executionScope)
}

private void cleanupForDeletedEvent(ResourceID resourceID) {
log.debug("Cleaning up for delete event for: {}", resourceID);
log.debug("Cleaning up for delete event");
resourceStateManager.remove(resourceID);
metrics.cleanupDoneFor(resourceID, metricsMetadata);
}
Expand Down Expand Up @@ -509,6 +498,7 @@ public void run() {
log.debug("Event processor not running skipping resource processing: {}", resourceID);
return;
}
MDCUtils.addResourceIDInfo(resourceID);
log.debug("Running reconcile executor for: {}", executionScope);
// change thread name for easier debugging
final var thread = Thread.currentThread();
Expand All @@ -518,9 +508,7 @@ public void run() {
var actualResource = cache.get(resourceID);
if (actualResource.isEmpty()) {
if (triggerOnAllEvents()) {
log.debug(
"Resource not found in the cache, checking for delete event resource: {}",
resourceID);
log.debug("Resource not found in the cache, checking for delete event resource");
if (executionScope.isDeleteEvent()) {
var state = resourceStateManager.get(resourceID);
actualResource =
Expand All @@ -538,7 +526,7 @@ public void run() {
return;
}
} else {
log.debug("Skipping execution; primary resource missing from cache: {}", resourceID);
log.debug("Skipping execution; primary resource missing from cache");
return;
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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);

Expand Down Expand Up @@ -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,";
Expand Down Expand Up @@ -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();
Expand All @@ -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
Copy link

Copilot AI Feb 19, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There is a double space before "finalizer" in the log message. It should be "Delete control: {}, uses finalizer: {}" with a single space.

Copilot uses AI. Check for mistakes.
PostExecutionControl<P> postExecutionControl = PostExecutionControl.defaultDispatch();
Expand All @@ -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);

Expand Down Expand Up @@ -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);
Expand Down
Loading
Loading