DEV Community

Oleksandr
Oleksandr

Posted on

Why did Reconcile() run again? Easy event tracing in controller-runtime

Gopher explores Kubernetes events
If you build Kubernetes operators in Go using controller-runtime (Kubebuilder or Operator SDK), you probably know this pain.

You update one small field in your Custom Resource, look at the logs, and see that Reconcile() was called 4 or 5 times in a row.

Why? Was it your Spec update? A Status update from a child Deployment? An external ConfigMap sync? Or just a standard requeue?

By default, controller-runtime gives you a very simple method signature:

func (r *MyReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error)
Enter fullscreen mode Exit fullscreen mode

Look at ctrl.Request - it contains only Namespace and Name.

The actual Kubernetes events that triggered this execution are lost inside the internal workqueue.

Why does this happen? (Workqueue Deduplication)

To protect the Kubernetes API Server from too many requests, controller-runtime uses a deduplicating workqueue.

If 5 events happen almost at the same time for default/my-cr (for example, Spec change + Deployment status update + Pod status change), the workqueue compresses them into a single Reconcile() call.

This is great for cluster performance, but it makes debugging really hard:

  • You don't see which resource actually triggered the call.
  • You don't see what changed (Spec, Status, or Metadata).
  • It's hard to trace child resources (Deployments, Services) back to the main CR loop.

My solution: whyreconcile

To solve this problem for my own projects, I built whyreconcile - a simple, lightweight Go package for controller-runtime.

It doesn't change your business logic. Instead, it hooks into event handlers, compares old and new object states (shallow diff), saves the cause metadata, and prints a clear summary right before your Reconcile() starts.

How it looks in your logs:

reconcile causes controller=my-controller target=default/my-cr causes=3 summary=PrimaryResourceSpecUpdate:1, SecondaryResourceStatusOrMetadata:2 sources=2
Enter fullscreen mode Exit fullscreen mode

In just one log line, you immediately see:

  • Target: Which resource is being reconciled (default/my-cr).
  • Causes count: 3 events happened since the last run.
  • Summary: 1 Spec update on the Primary CR and 2 Status/Metadata updates on secondary resources.

How it works under the hood

The idea is very straightforward:

  1. Catch events:

    • For Primary resources (For), it intercepts events using predicates and shallow diffs.
    • For Secondary/External resources (Watches), it uses a custom TypedEventHandler to map child objects (like Deployments) to the parent CR.
  2. Store causes: As events flow in, whyreconcile saves cause info in a thread-safe in-memory store under the target resource key (Namespace/Name).

  3. Print before Reconcile: When controller-runtime takes a request from the workqueue, whyreconcile extracts all stored causes for this key and prints them before calling your original Reconcile() code.

Quick Setup (takes 2 minutes)

You don't need to change anything inside your Reconcile() function. Just update SetupWithManager:

1. Install

go get https://github.com/arsenalzp/whyreconcile
Enter fullscreen mode Exit fullscreen mode

2. Wrap your setup code

import (
    "https://github.com/arsenalzp/whyreconcile"
    appsv1 "k8s.io/api/apps/v1"
    ctrl "sigs.k8s.io/controller-runtime"
)

func (r *MyReconciler) SetupWithManager(mgr ctrl.Manager) error {
    // 1. Create analyzer
    analyzer := whyreconcile.NewAnalyzer()

    return ctrl.NewControllerManagedBy(mgr).
        // 2. Wrap Primary resource
        For(&v1alpha1.MyCR{}, analyzer.NewPrimaryOpts()).
        // 3. Wrap Secondary resource (e.g., child Deployment)
        Watches(
            &appsv1.Deployment{},
            analyzer.NewSecondaryHandler(
                "child-deployment",
                handler.EnqueueRequestForOwner(
                    mgr.GetScheme(),
                    mgr.GetRESTMapper(),
                    &v1alpha1.MyCR{},
                ),
            ),
        ).
        // 4. Wrap your Reconciler
        Complete(analyzer.WrapReconcile(r))
}
Enter fullscreen mode Exit fullscreen mode

And that's it! Next time you run your operator locally or in a dev cluster, you will see exactly why each Reconcile() was triggered.

Try it out

The project is open-source and free to use:

📁 GitHub: github.com/arsenalzp/whyreconcile

If you write Kubernetes operators, give it a try in your dev environment! I'd love to hear your feedback or ideas in the comments.

Top comments (0)