kopf icon indicating copy to clipboard operation
kopf copied to clipboard

Support more than namespace/name for the provided logger types

Open bergerx opened this issue 3 years ago • 1 comments

Problem

We have kopf operating on several CRDs. The current logger only support namespace/name prefix, which lacks the crucial kind metadata.

Currently, we are using a workaround like this to replace [{namespace}/{name}] prefix with [{kind}/{name}]:

class ProvisionerFormatter(logging.Formatter):
    """Prefix log messages per-object.

    This is a modified copy from kopf:
    https://github.com/nolar/kopf/blob/1.35.2/kopf/_core/actions/loggers.py#L80-L89

    We effectively replace the msg prefix like this
    [{namespace}/{name}] --> [{kind}/{name}]
    """

    def format(self, record: logging.LogRecord) -> str:
        if hasattr(record, "k8s_ref"):
            ref = getattr(record, "k8s_ref")
            kind = ref.get("kind", "")
            name = ref.get("name", "")
            prefix = f"[{kind}/{name}]"
            record = copy.copy(record)  # shallow
            record.msg = f"{prefix} {record.msg}"
        return super().format(record)


def update_kopf_root_logger():
    # WARNING: Here we hack some logger settings placed by kopf which are not part if its contract,
    # this can be broken without any further notice as we upgrade kopf.

    root_logger = logging.getLogger()
    default_stream_handler = root_logger.handlers[0]

    # We don't want to mess with kopf config other than changing the prefix, so we keep format untouched.
    current_log_fmt_set_by_kopf = default_stream_handler.formatter._fmt

    # Replace the formatter of the root loggers stream handler set on
    # https://github.com/nolar/kopf/blob/1.35.2/kopf/_core/actions/loggers.py#L182
    default_stream_handler.setFormatter(ProvisionerFormatter(current_log_fmt_set_by_kopf))


...
@kopf.on.startup()
def startup_tasks(settings: kopf.OperatorSettings, **_):
    ...
    update_kopf_root_logger()

Proposal

kopf's logger kwargs should be configurable further maybe through some exposed settings.

We mostly need kind, namespace, and name. So including just the kind would already be a good enough improvement.

We usually have many handlers all acting on different fields of the same resource at once, and we used to have many updates run in parallel. Just having name/namespace/kind makes it quite hard to identify the actual entrypoint.

I wanted to implement something to include the handler's name into the log msg prefix, since they actually point to the actual starting point/context/handler of the code without a mistake, that would make the log lines a lot longer but we can always know which exact handler is in action when that logline is printed. E.g.: image

Unfortunately, even if I can extract the handler method name by investigating the stack I can't find a way to get the field name (the part after the / in above screenshot). Extracting the field information via the current set of kwargs doesn't seem possible.

Code

No response

Additional information

No response

bergerx avatar Oct 29 '21 15:10 bergerx

Oh my! I just realized I've been looking into the old zalando-incubator/kopf repo to check the source code. But the core point still stands. I'll update the issue whenever I can. (Edit: updated!)

bergerx avatar Oct 29 '21 15:10 bergerx