Contextual logging in Kubernetes 1.29: Better troubleshooting and enhanced logging

Authors: Mengjiao Liu (DaoCloud), Patrick Ohly (Intel)

On behalf of the Structured Logging Working Group and SIG Instrumentation, we are pleased to announce that the contextual logging feature introduced in Kubernetes v1.24 has now been successfully migrated to two components (kube-scheduler and kube-controller-manager) as well as some directories. This feature aims to provide more useful logs for better troubleshooting of Kubernetes and to empower developers to enhance Kubernetes.

What is contextual logging?

Contextual logging is based on the go-logr API. The key idea is that libraries are passed a logger instance by their caller and use that for logging instead of accessing a global logger. The binary decides the logging implementation, not the libraries. The go-logr API is designed around structured logging and supports attaching additional information to a logger.

This enables additional use cases:

  • The caller can attach additional information to a logger:

    • WithName adds a "logger" key with the names concatenated by a dot as value
    • WithValues adds key/value pairs

    When passing this extended logger into a function, and the function uses it instead of the global logger, the additional information is then included in all log entries, without having to modify the code that generates the log entries. This is useful in highly parallel applications where it can become hard to identify all log entries for a certain operation, because the output from different operations gets interleaved.

  • When running unit tests, log output can be associated with the current test. Then, when a test fails, only the log output of the failed test gets shown by go test. That output can also be more verbose by default because it will not get shown for successful tests. Tests can be run in parallel without interleaving their output.

One of the design decisions for contextual logging was to allow attaching a logger as value to a context.Context. Since the logger encapsulates all aspects of the intended logging for the call, it is part of the context, and not just using it. A practical advantage is that many APIs already have a ctx parameter or can add one. This provides additional advantages, like being able to get rid of context.TODO() calls inside the functions.

How to use it

The contextual logging feature is alpha starting from Kubernetes v1.24, so it requires the ContextualLogging feature gate to be enabled. If you want to test the feature while it is alpha, you need to enable this feature gate on the kube-controller-manager and the kube-scheduler.

For the kube-scheduler, there is one thing to note, in addition to enabling the ContextualLogging feature gate, instrumentation also depends on log verbosity. To avoid slowing down the scheduler with the logging instrumentation for contextual logging added for 1.29, it is important to choose carefully when to add additional information:

  • At -v3 or lower, only WithValues("pod") is used once per scheduling cycle. This has the intended effect that all log messages for the cycle include the pod information. Once contextual logging is GA, "pod" key/value pairs can be removed from all log calls.
  • At -v4 or higher, richer log entries get produced where WithValues is also used for the node (when applicable) and WithName is used for the current operation and plugin.

Here is an example that demonstrates the effect:

I1113 08:43:37.029524 87144 default_binder.go:53] "Attempting to bind pod to node" logger="Bind.DefaultBinder" pod="kube-system/coredns-69cbfb9798-ms4pq" node="127.0.0.1"

The immediate benefit is that the operation and plugin name are visible in logger. pod and node are already logged as parameters in individual log calls in kube-scheduler code. Once contextual logging is supported by more packages outside of kube-scheduler, they will also be visible there (for example, client-go). Once it is GA, log calls can be simplified to avoid repeating those values.

In kube-controller-manager, WithName is used to add the user-visible controller name to log output, for example:

I1113 08:43:29.284360 87141 graph_builder.go:285] "garbage controller monitor not synced: no monitors" logger="garbage-collector-controller"

The logger=”garbage-collector-controller” was added by the kube-controller-manager core when instantiating that controller and appears in all of its log entries - at least as long as the code that it calls supports contextual logging. Further work is needed to convert shared packages like client-go.

Performance impact

Supporting contextual logging in a package, i.e. accepting a logger from a caller, is cheap. No performance impact was observed for the kube-scheduler. As noted above, adding WithName and WithValues needs to be done more carefully.

In Kubernetes 1.29, enabling contextual logging at production verbosity (-v3 or lower) caused no measurable slowdown for the kube-scheduler and is not expected for the kube-controller-manager either. At debug levels, a 28% slowdown for some test cases is still reasonable given that the resulting logs make debugging easier. For details, see the discussion around promoting the feature to beta.

Impact on downstream users

Log output is not part of the Kubernetes API and changes regularly in each release, whether it is because developers work on the code or because of the ongoing conversion to structured and contextual logging.

If downstream users have dependencies on specific logs, they need to be aware of how this change affects them.

Further reading

Get involved

If you're interested in getting involved, we always welcome new contributors to join us. Contextual logging provides a fantastic opportunity for you to contribute to Kubernetes development and make a meaningful impact. By joining Structured Logging WG, you can actively participate in the development of Kubernetes and make your first contribution. It's a great way to learn and engage with the community while gaining valuable experience.

We encourage you to explore the repository and familiarize yourself with the ongoing discussions and projects. It's a collaborative environment where you can exchange ideas, ask questions, and work together with other contributors.

If you have any questions or need guidance, don't hesitate to reach out to us and you can do so on our public Slack channel. If you're not already part of that Slack workspace, you can visit https://slack.k8s.io/ for an invitation.

We would like to express our gratitude to all the contributors who provided excellent reviews, shared valuable insights, and assisted in the implementation of this feature (in alphabetical order):