Skip to content

Commit 645c77b

Browse files
authored
feat: downgrade uncaught error log when reconciler handles the error (#3494)
When a reconciler's updateErrorStatus returns any ErrorStatusUpdateControl other than defaultErrorProcessing(), the error is now considered handled by the reconciler. Native retry (including @GradualRetry exponential backoff) is kept intact, but the framework logs the error on DEBUG level instead of emitting the "Uncaught error during event processing" WARN. This lets a reconciler keep retrying an expected, recoverable condition without producing a continuous stream of WARN messages, while it remains free to log the error at whatever level it wants inside updateErrorStatus. Returning defaultErrorProcessing() preserves the previous behavior, including the warning. - PostExecutionControl carries an errorHandledByReconciler flag - ReconciliationDispatcher marks the exception control as handled instead of rethrowing when a non-default control still wants retry - EventProcessor downgrades the retry-aware and no-retry-configured error logs to DEBUG when the error was handled by the reconciler Signed-off-by: Attila Mészáros <a_meszaros@apple.com>
1 parent 5e169c9 commit 645c77b

5 files changed

Lines changed: 95 additions & 4 deletions

File tree

docs/content/en/docs/documentation/error-handling-retries.md

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -108,6 +108,22 @@ Retry can be skipped in cases of unrecoverable errors:
108108
ErrorStatusUpdateControl.patchStatus(customResource).withNoRetry();
109109
```
110110

111+
When `updateErrorStatus` returns any `ErrorStatusUpdateControl` other than
112+
`ErrorStatusUpdateControl.defaultErrorProcessing()`, the framework considers the error handled by
113+
the reconciler and, while retry attempts remain, no longer logs the "Uncaught error during event
114+
processing" warning; the error is logged on `DEBUG` level instead. This lets a reconciler keep
115+
retrying an expected, recoverable condition without producing a continuous stream of `WARN`
116+
messages, while it remains free to log the error at whatever level it deems appropriate inside
117+
`updateErrorStatus`.
118+
119+
This log downgrade applies only when retry is actually taking place, i.e. a retry is configured and
120+
the returned control does not disable it. Controls that explicitly disable retry — `withNoRetry()`
121+
and `rescheduleAfter()` — cancel the native retry and its `@GradualRetry` backoff, so nothing is
122+
retried in those cases. Likewise, on the last retry attempt (or when no retry is configured) the
123+
failure is final, so the framework keeps its higher-severity logging to avoid hiding a
124+
non-recoverable error. Returning `ErrorStatusUpdateControl.defaultErrorProcessing()` preserves the
125+
default behavior, including the warning.
126+
111127
### Correctness and Automatic Retries
112128

113129
While it is possible to deactivate automatic retries, this is not desirable unless there is a particular reason.

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/EventProcessor.java

Lines changed: 22 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -297,7 +297,9 @@ synchronized void eventProcessingFinished(
297297
&& postExecutionControl.exceptionDuringExecution()
298298
&& (!state.deleteEventPresent() || triggerOnAllEvents())) {
299299
handleRetryOnException(
300-
executionScope, postExecutionControl.getRuntimeException().orElseThrow());
300+
executionScope,
301+
postExecutionControl.getRuntimeException().orElseThrow(),
302+
postExecutionControl.isErrorHandledByReconciler());
301303
return;
302304
}
303305
cleanupOnSuccessfulExecution(executionScope);
@@ -327,6 +329,9 @@ private boolean isTriggerOnAllEventAndDeleteEventPresent(ResourceState state) {
327329
private void logErrorIfNoRetryConfigured(
328330
ExecutionScope<P> executionScope, PostExecutionControl<P> postExecutionControl) {
329331
if (!isRetryConfigured() && postExecutionControl.exceptionDuringExecution()) {
332+
// No retry is configured, so this failure is final. Even if the reconciler handled the error
333+
// in updateErrorStatus, we keep the higher-severity log so a non-recoverable failure is not
334+
// hidden from operators.
330335
log.error(
331336
"Error during event processing {}",
332337
executionScope,
@@ -369,14 +374,16 @@ TimerEventSource<P> retryEventSource() {
369374
* events (received meanwhile retry is in place or already in buffer) instantly or always wait
370375
* according to the retry timing if there was an exception.
371376
*/
372-
private void handleRetryOnException(ExecutionScope<P> executionScope, Exception exception) {
377+
private void handleRetryOnException(
378+
ExecutionScope<P> executionScope, Exception exception, boolean errorHandledByReconciler) {
373379
final var state = getOrInitRetryExecution(executionScope);
374380
var resourceID = state.getId();
375381
boolean eventPresent =
376382
state.eventPresent()
377383
|| (triggerOnAllEvents() && state.isAdditionalEventPresentAfterDeleteEvent());
378384
state.markEventReceived(triggerOnAllEvents());
379-
retryAwareErrorLogging(state.getRetry(), eventPresent, exception, executionScope);
385+
retryAwareErrorLogging(
386+
state.getRetry(), eventPresent, errorHandledByReconciler, exception, executionScope);
380387
metrics.reconciliationFailed(
381388
executionScope.getResource(), state.getRetry(), exception, metricsMetadata);
382389
if (eventPresent) {
@@ -408,17 +415,29 @@ private void handleRetryOnException(ExecutionScope<P> executionScope, Exception
408415
private void retryAwareErrorLogging(
409416
RetryExecution retry,
410417
boolean eventPresent,
418+
boolean errorHandledByReconciler,
411419
Exception exception,
412420
ExecutionScope<P> executionScope) {
413421
if (!retry.isLastAttempt()
414422
&& exception instanceof KubernetesClientException ex
415423
&& ex.getCode() == HttpURLConnection.HTTP_CONFLICT) {
424+
// The conflict branch is already low-noise (DEBUG + INFO) and provides actionable info, so it
425+
// keeps precedence over the handled-error downgrade below.
416426
log.debug("Full client conflict error during event processing {}", executionScope, exception);
417427
log.info(
418428
"Resource Kubernetes Resource Creator/Update Conflict during reconciliation. Message:"
419429
+ " {} Resource name: {}",
420430
ex.getMessage(),
421431
ex.getFullResourceName());
432+
} else if (errorHandledByReconciler && !retry.isLastAttempt()) {
433+
// The reconciler already handled the error in updateErrorStatus (and had the chance to log it
434+
// as needed), so while there are retries remaining the framework only logs it on debug level.
435+
// On the last attempt we still fall through to the higher-severity logging below, so a final,
436+
// non-recoverable failure is not hidden from operators.
437+
log.debug(
438+
"Error during event processing {}, but was handled by the reconciler",
439+
executionScope,
440+
exception);
422441
} else if (eventPresent || !retry.isLastAttempt()) {
423442
log.warn(
424443
"Uncaught error during event processing {} - but another reconciliation will be attempted"

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/PostExecutionControl.java

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,7 @@ final class PostExecutionControl<R extends HasMetadata> {
2727
private final Exception runtimeException;
2828

2929
private Long reScheduleDelay = null;
30+
private boolean errorHandledByReconciler = false;
3031

3132
private PostExecutionControl(
3233
boolean finalizerRemoved,
@@ -68,6 +69,22 @@ public static <R extends HasMetadata> PostExecutionControl<R> exceptionDuringExe
6869
return new PostExecutionControl<>(false, null, false, exception);
6970
}
7071

72+
/**
73+
* Marks that the exception was handled by the reconciler's {@code updateErrorStatus} (i.e. the
74+
* reconciler did not return {@link
75+
* io.javaoperatorsdk.operator.api.reconciler.ErrorStatusUpdateControl#defaultErrorProcessing()}),
76+
* but the error is still retried. In this case the framework logs the error on a lower level,
77+
* since the reconciler already had the chance to handle and log it as needed.
78+
*/
79+
public PostExecutionControl<R> withErrorHandledByReconciler() {
80+
this.errorHandledByReconciler = true;
81+
return this;
82+
}
83+
84+
public boolean isErrorHandledByReconciler() {
85+
return errorHandledByReconciler;
86+
}
87+
7188
public Optional<R> getUpdatedCustomResource() {
7289
return Optional.ofNullable(updatedCustomResource);
7390
}

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/ReconciliationDispatcher.java

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -266,7 +266,12 @@ public boolean isLastAttempt() {
266266
errorStatusUpdateControl.getScheduleDelay().ifPresent(postExecutionControl::withReSchedule);
267267
return postExecutionControl;
268268
}
269-
throw e;
269+
// The reconciler handled the error via updateErrorStatus (it did not return
270+
// defaultErrorProcessing()) but still wants the error to be retried. The retry (and its
271+
// backoff) is kept intact, but since the reconciler already had the chance to handle and log
272+
// the error, the framework logs it on a lower level instead of emitting an "uncaught error"
273+
// warning.
274+
return PostExecutionControl.<P>exceptionDuringExecution(e).withErrorHandledByReconciler();
270275
}
271276

272277
private PostExecutionControl<P> createPostExecutionControl(

operator-framework-core/src/test/java/io/javaoperatorsdk/operator/processing/event/ReconciliationDispatcherTest.java

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -481,6 +481,40 @@ void callErrorStatusHandlerEvenOnFirstError() {
481481
assertThat(postExecControl.exceptionDuringExecution()).isTrue();
482482
}
483483

484+
@Test
485+
void errorHandledByReconcilerMarkedWhenErrorStatusHandledButRetried() {
486+
testCustomResource.addFinalizer(DEFAULT_FINALIZER);
487+
reconciler.reconcile =
488+
(r, c) -> {
489+
throw new IllegalStateException("Error Status Test");
490+
};
491+
reconciler.errorHandler = () -> ErrorStatusUpdateControl.patchStatus(testCustomResource);
492+
493+
var postExecControl =
494+
reconciliationDispatcher.handleExecution(
495+
new ExecutionScope(null, null, false, false).setResource(testCustomResource));
496+
497+
assertThat(postExecControl.exceptionDuringExecution()).isTrue();
498+
assertThat(postExecControl.isErrorHandledByReconciler()).isTrue();
499+
}
500+
501+
@Test
502+
void errorNotHandledByReconcilerOnDefaultErrorProcessing() {
503+
testCustomResource.addFinalizer(DEFAULT_FINALIZER);
504+
reconciler.reconcile =
505+
(r, c) -> {
506+
throw new IllegalStateException("Error Status Test");
507+
};
508+
reconciler.errorHandler = () -> ErrorStatusUpdateControl.defaultErrorProcessing();
509+
510+
var postExecControl =
511+
reconciliationDispatcher.handleExecution(
512+
new ExecutionScope(null, null, false, false).setResource(testCustomResource));
513+
514+
assertThat(postExecControl.exceptionDuringExecution()).isTrue();
515+
assertThat(postExecControl.isErrorHandledByReconciler()).isFalse();
516+
}
517+
484518
@Test
485519
void errorHandlerCanInstructNoRetryWithUpdate() {
486520
testCustomResource.addFinalizer(DEFAULT_FINALIZER);

0 commit comments

Comments
 (0)