async def handle_event(
registry: registries.BaseRegistry,
resource: registries.Resource,
logger: Union[logging.LoggerAdapter, logging.Logger],
patch: dict,
event: dict,
):
"""
Handle a received event, log but ignore all errors.
This is a lightweight version of the cause handling, but for the raw events,
without any progress persistence. Multi-step calls are also not supported.
If the handler fails, it fails and is never retried.
"""
handlers = registry.get_event_handlers(resource=resource, event=event)
for handler in handlers:
# The exceptions are handled locally and are not re-raised, to keep the operator running.
try:
logger.debug(f"Invoking handler {handler.id!r}.")
# TODO: also set the context-vars, despite most of the make no sense here.
result = await invocation.invoke(
handler.fn,
event=event,
patch=patch,
logger=logger,
)
except Exception:
logger.exception(f"Handler {handler.id!r} failed with an exception. Will ignore.")
else:
logger.info(f"Handler {handler.id!r} succeeded.")
status.store_result(patch=patch, handler=handler, result=result)
async def handle_event_watching_cause(
lifecycle: lifecycles.LifeCycleFn,
registry: registries.BaseRegistry,
cause: causation.EventWatchingCause,
) -> None:
"""
Handle a received event, log but ignore all errors.
This is a lightweight version of the cause handling, but for the raw events,
without any progress persistence. Multi-step calls are also not supported.
If the handler fails, it fails and is never retried.
Note: K8s-event posting is skipped for `kopf.on.event` handlers,
as they should be silent. Still, the messages are logged normally.
"""
logger = cause.logger
handlers = registry.get_event_watching_handlers(cause=cause)
for handler in handlers:
# The exceptions are handled locally and are not re-raised, to keep the operator running.
try:
logger.debug(f"Invoking handler {handler.id!r}.")
result = await _call_handler(
handler,
cause=cause,
lifecycle=lifecycle,
)
except Exception:
logger.exception(
f"Handler {handler.id!r} failed with an exception. Will ignore.",
local=True)
else:
logger.info(f"Handler {handler.id!r} succeeded.", local=True)
state.store_result(patch=cause.patch,
handler=handler,
result=result)
async def handle_cause(
lifecycle: Callable,
registry: registries.BaseRegistry,
cause: causation.Cause,
):
"""
Handle a detected cause, as part of the bigger handler routine.
"""
logger = cause.logger
patch = cause.patch # TODO get rid of this alias
body = cause.body # TODO get rid of this alias
delay = None
done = None
skip = None
# Regular causes invoke the handlers.
if cause.event in causation.HANDLER_CAUSES:
title = causation.TITLES.get(cause.event, repr(cause.event))
logger.debug(f"{title.capitalize()} event: %r", body)
if cause.diff is not None:
logger.debug(f"{title.capitalize()} diff: %r", cause.diff)
handlers = registry.get_cause_handlers(cause=cause)
if handlers:
try:
await _execute(
lifecycle=lifecycle,
handlers=handlers,
cause=cause,
)
except HandlerChildrenRetry as e:
# on the top-level, no patches -- it is pre-patched.
delay = e.delay
done = False
else:
logger.info(f"All handlers succeeded for {title}.")
await events.info_async(
cause.body,
reason='Success',
message=f"All handlers succeeded for {title}.")
done = True
else:
skip = True
# Regular causes also do some implicit post-handling when all handlers are done.
if done or skip:
lastseen.refresh_state(body=body, patch=patch)
if done:
status.purge_progress(body=body, patch=patch)
if cause.event == causation.DELETE:
logger.debug(
"Removing the finalizer, thus allowing the actual deletion.")
finalizers.remove_finalizers(body=body, patch=patch)
# Informational causes just print the log lines.
if cause.event == causation.NEW:
logger.debug("First appearance: %r", body)
if cause.event == causation.GONE:
logger.debug("Deleted, really deleted, and we are notified.")
if cause.event == causation.FREE:
logger.debug(
"Deletion event, but we are done with it, and we do not care.")
if cause.event == causation.NOOP:
logger.debug(
"Something has changed, but we are not interested (state is the same)."
)
# For the case of a newly created object, lock it to this operator.
# TODO: make it conditional.
if cause.event == causation.NEW:
logger.debug(
"Adding the finalizer, thus preventing the actual deletion.")
finalizers.append_finalizers(body=body, patch=patch)
# The delay is then consumed by the main handling routine (in different ways).
return delay
async def handle_cause(
lifecycle: Callable,
registry: registries.BaseRegistry,
cause: causation.Cause,
):
"""
Handle a detected cause, as part of the bigger handler routine.
"""
logger = cause.logger
patch = cause.patch # TODO get rid of this alias
body = cause.body # TODO get rid of this alias
delay = None
done = None
skip = None
# Regular causes invoke the handlers.
if cause.event in causation.HANDLER_CAUSES:
title = causation.TITLES.get(cause.event, repr(cause.event))
logger.debug(f"{title.capitalize()} event: %r", body)
if cause.diff is not None and cause.old is not None and cause.new is not None:
logger.debug(f"{title.capitalize()} diff: %r", cause.diff)
handlers = registry.get_cause_handlers(cause=cause)
if handlers:
try:
await _execute(
lifecycle=lifecycle,
handlers=handlers,
cause=cause,
)
except HandlerChildrenRetry as e:
# on the top-level, no patches -- it is pre-patched.
delay = e.delay
done = False
else:
logger.info(f"All handlers succeeded for {title}.")
posting.info(cause.body, reason='Success', message=f"All handlers succeeded for {title}.")
done = True
else:
skip = True
# Regular causes also do some implicit post-handling when all handlers are done.
if done or skip:
extra_fields = registry.get_extra_fields(resource=cause.resource)
lastseen.refresh_state(body=body, patch=patch, extra_fields=extra_fields)
if done:
status.purge_progress(body=body, patch=patch)
if cause.event == causation.DELETE:
logger.debug("Removing the finalizer, thus allowing the actual deletion.")
finalizers.remove_finalizers(body=body, patch=patch)
# Informational causes just print the log lines.
if cause.event == causation.GONE:
logger.debug("Deleted, really deleted, and we are notified.")
if cause.event == causation.FREE:
logger.debug("Deletion event, but we are done with it, and we do not care.")
if cause.event == causation.NOOP:
logger.debug("Something has changed, but we are not interested (state is the same).")
# For the case of a newly created object, or one that doesn't have the correct
# finalizers, lock it to this operator. Not all newly created objects will
# produce an 'ACQUIRE' causation event. This only happens when there are
# mandatory deletion handlers registered for the given object, i.e. if finalizers
# are required.
if cause.event == causation.ACQUIRE:
logger.debug("Adding the finalizer, thus preventing the actual deletion.")
finalizers.append_finalizers(body=body, patch=patch)
# Remove finalizers from an object, since the object currently has finalizers, but
# shouldn't, thus releasing the locking of the object to this operator.
if cause.event == causation.RELEASE:
logger.debug("Removing the finalizer, as there are no handlers requiring it.")
finalizers.remove_finalizers(body=body, patch=patch)
# The delay is then consumed by the main handling routine (in different ways).
return delay
async def _execute(
lifecycle: Callable,
registry: registries.BaseRegistry,
cause: Cause,
retry_on_errors: bool = True,
) -> None:
"""
Call the next handler(s) from the chain of the handlers.
Keep the record on the progression of the handlers in the object's status,
and use it on the next invocation to determined which handler(s) to call.
This routine is used both for the global handlers (via global registry),
and for the sub-handlers (via a simple registry of the current handler).
Raises `HandlerChildrenRetry` if there are children handlers to be executed
on the next call, and implicitly provokes such a call by making the changes
to the status fields (on the handler progression and number of retries).
Exits normally if all handlers for this cause are fully done.
"""
logger = cause.logger
# Filter and select the handlers to be executed right now, on this event reaction cycle.
handlers = registry.get_handlers(cause=cause)
handlers_done = [
h for h in handlers if status.is_finished(body=cause.body, handler=h)
]
handlers_wait = [
h for h in handlers if status.is_sleeping(body=cause.body, handler=h)
]
handlers_todo = [
h for h in handlers if status.is_awakened(body=cause.body, handler=h)
]
handlers_plan = [
h
for h in await invocation.invoke(lifecycle, handlers_todo, cause=cause)
]
handlers_left = [
h for h in handlers_todo if h.id not in {h.id
for h in handlers_plan}
]
# Set the timestamps -- even if not executed on this event, but just got registered.
for handler in handlers:
if not status.is_started(body=cause.body, handler=handler):
status.set_start_time(body=cause.body,
patch=cause.patch,
handler=handler)
# Execute all planned (selected) handlers in one event reaction cycle, even if there are few.
for handler in handlers_plan:
# Restore the handler's progress status. It can be useful in the handlers.
retry = status.get_retry_count(body=cause.body, handler=handler)
started = status.get_start_time(body=cause.body,
handler=handler,
patch=cause.patch)
runtime = datetime.datetime.utcnow() - started
# The exceptions are handled locally and are not re-raised, to keep the operator running.
try:
logger.debug(f"Invoking handler {handler.id!r}.")
if handler.timeout is not None and runtime.total_seconds(
) > handler.timeout:
raise HandlerTimeoutError(
f"Handler {handler.id!r} has timed out after {runtime}.")
result = await _call_handler(
handler,
cause=cause,
retry=retry,
started=started,
runtime=runtime,
lifecycle=
lifecycle, # just a default for the sub-handlers, not used directly.
)
# Unfinished children cause the regular retry, but with less logging and event reporting.
except HandlerChildrenRetry as e:
logger.info(
f"Handler {handler.id!r} has unfinished sub-handlers. Will retry soon."
)
status.set_retry_time(body=cause.body,
patch=cause.patch,
handler=handler,
delay=e.delay)
handlers_left.append(handler)
# Definitely retriable error, no matter what is the error-reaction mode.
except HandlerRetryError as e:
logger.exception(
f"Handler {handler.id!r} failed with an retry exception. Will retry."
)
events.exception(
cause.body,
message=f"Handler {handler.id!r} failed. Will retry.")
status.set_retry_time(body=cause.body,
patch=cause.patch,
handler=handler,
delay=e.delay)
handlers_left.append(handler)
# Definitely fatal error, no matter what is the error-reaction mode.
except HandlerFatalError as e:
logger.exception(
f"Handler {handler.id!r} failed with an fatal exception. Will stop."
)
events.exception(
cause.body,
message=f"Handler {handler.id!r} failed. Will stop.")
status.store_failure(body=cause.body,
patch=cause.patch,
handler=handler,
exc=e)
# TODO: report the handling failure somehow (beside logs/events). persistent status?
# Regular errors behave as either retriable or fatal depending on the error-reaction mode.
except Exception as e:
if retry_on_errors:
logger.exception(
f"Handler {handler.id!r} failed with an exception. Will retry."
)
events.exception(
cause.body,
message=f"Handler {handler.id!r} failed. Will retry.")
status.set_retry_time(body=cause.body,
patch=cause.patch,
handler=handler,
delay=DEFAULT_RETRY_DELAY)
handlers_left.append(handler)
else:
logger.exception(
f"Handler {handler.id!r} failed with an exception. Will stop."
)
events.exception(
cause.body,
message=f"Handler {handler.id!r} failed. Will stop.")
status.store_failure(body=cause.body,
patch=cause.patch,
handler=handler,
exc=e)
# TODO: report the handling failure somehow (beside logs/events). persistent status?
# No errors means the handler should be excluded from future runs in this reaction cycle.
else:
logger.info(f"Handler {handler.id!r} succeeded.")
events.info(cause.body,
reason='Success',
message=f"Handler {handler.id!r} succeeded.")
status.store_success(body=cause.body,
patch=cause.patch,
handler=handler,
result=result)
# Provoke the retry of the handling cycle if there were any unfinished handlers,
# either because they were not selected by the lifecycle, or failed and need a retry.
if handlers_left:
raise HandlerChildrenRetry(delay=None)
# If there are delayed handlers, block this object's cycle; but do keep-alives every few mins.
# Other (non-delayed) handlers will continue as normlally, due to raise few lines above.
# Other objects will continue as normally in their own handling asyncio tasks.
if handlers_wait:
times = [
status.get_awake_time(body=cause.body, handler=handler)
for handler in handlers_wait
]
until = min(times) # the soonest awake datetime.
delay = (until - datetime.datetime.utcnow()).total_seconds()
delay = max(0, min(WAITING_KEEPALIVE_INTERVAL, delay))
raise HandlerChildrenRetry(delay=delay)