Merge pull request #1054 from vincepri/reconciler-context

⚠ Add a context w/ logger to Reconciler interface

example_test.go

@@ -116,17 +116,17 @@ type ReplicaSetReconciler struct {
 // * Read the ReplicaSet
 // * Read the Pods
 // * Set a Label on the ReplicaSet with the Pod count
-func (a *ReplicaSetReconciler) Reconcile(req controllers.Request) (controllers.Result, error) {
+func (a *ReplicaSetReconciler) Reconcile(ctx context.Context, req controllers.Request) (controllers.Result, error) {
 	// Read the ReplicaSet
 	rs := &appsv1.ReplicaSet{}
-	err := a.Get(context.TODO(), req.NamespacedName, rs)
+	err := a.Get(ctx, req.NamespacedName, rs)
 	if err != nil {
 		return controllers.Result{}, err
 	}
 
 	// List the Pods matching the PodTemplate Labels
 	pods := &corev1.PodList{}
-	err = a.List(context.TODO(), pods, client.InNamespace(req.Namespace), client.MatchingLabels(rs.Spec.Template.Labels))
+	err = a.List(ctx, pods, client.InNamespace(req.Namespace), client.MatchingLabels(rs.Spec.Template.Labels))
 	if err != nil {
 		return controllers.Result{}, err
 	}

examples/builtins/controller.go

@@ -20,27 +20,25 @@ import (
 	"context"
 	"fmt"
 
-	"github.com/go-logr/logr"
-
 	appsv1 "k8s.io/api/apps/v1"
 	"k8s.io/apimachinery/pkg/api/errors"
 	"sigs.k8s.io/controller-runtime/pkg/client"
+	"sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/reconcile"
 )
 
 // reconcileReplicaSet reconciles ReplicaSets
 type reconcileReplicaSet struct {
 	// client can be used to retrieve objects from the APIServer.
 	client client.Client
-	log    logr.Logger
 }
 
 // Implement reconcile.Reconciler so the controller can reconcile objects
 var _ reconcile.Reconciler = &reconcileReplicaSet{}
 
-func (r *reconcileReplicaSet) Reconcile(request reconcile.Request) (reconcile.Result, error) {
+func (r *reconcileReplicaSet) Reconcile(ctx context.Context, request reconcile.Request) (reconcile.Result, error) {
 	// set up a convenient log object so we don't have to type request over and over again
-	log := r.log.WithValues("request", request)
+	log := log.FromContext(ctx)
 
 	// Fetch the ReplicaSet from the cache
 	rs := &appsv1.ReplicaSet{}

examples/builtins/main.go

@@ -25,19 +25,20 @@ import (
 	"sigs.k8s.io/controller-runtime/pkg/client/config"
 	"sigs.k8s.io/controller-runtime/pkg/controller"
 	"sigs.k8s.io/controller-runtime/pkg/handler"
-	logf "sigs.k8s.io/controller-runtime/pkg/log"
+	"sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/log/zap"
 	"sigs.k8s.io/controller-runtime/pkg/manager"
 	"sigs.k8s.io/controller-runtime/pkg/manager/signals"
 	"sigs.k8s.io/controller-runtime/pkg/source"
 	"sigs.k8s.io/controller-runtime/pkg/webhook"
 )
 
-var log = logf.Log.WithName("example-controller")
+func init() {
+	log.SetLogger(zap.New())
+}
 
 func main() {
-	logf.SetLogger(zap.New())
-	entryLog := log.WithName("entrypoint")
+	entryLog := log.Log.WithName("entrypoint")
 
 	// Setup a Manager
 	entryLog.Info("setting up manager")
@@ -50,7 +51,7 @@ func main() {
 	// Setup a new controller to reconcile ReplicaSets
 	entryLog.Info("Setting up controller")
 	c, err := controller.New("foo-controller", mgr, controller.Options{
-		Reconciler: &reconcileReplicaSet{client: mgr.GetClient(), log: log.WithName("reconciler")},
+		Reconciler: &reconcileReplicaSet{client: mgr.GetClient()},
 	})
 	if err != nil {
 		entryLog.Error(err, "unable to set up individual controller")

examples/crd/main.go

@@ -29,23 +29,22 @@ import (
 	ctrl "sigs.k8s.io/controller-runtime"
 	api "sigs.k8s.io/controller-runtime/examples/crd/pkg"
 	"sigs.k8s.io/controller-runtime/pkg/client"
+	"sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/log/zap"
 )
 
 var (
 	setupLog = ctrl.Log.WithName("setup")
-	recLog   = ctrl.Log.WithName("reconciler")
 )
 
 type reconciler struct {
 	client.Client
 	scheme *runtime.Scheme
 }
 
-func (r *reconciler) Reconcile(req ctrl.Request) (ctrl.Result, error) {
-	log := recLog.WithValues("chaospod", req.NamespacedName)
+func (r *reconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
+	log := log.FromContext(ctx).WithValues("chaospod", req.NamespacedName)
 	log.V(1).Info("reconciling chaos pod")
-	ctx := context.Background()
 
 	var chaospod api.ChaosPod
 	if err := r.Get(ctx, req.NamespacedName, &chaospod); err != nil {

pkg/builder/controller.go

@@ -130,6 +130,12 @@ func (blder *Builder) WithOptions(options controller.Options) *Builder {
 	return blder
 }
 
+// WithLogger overrides the controller options's logger used.
+func (blder *Builder) WithLogger(log logr.Logger) *Builder {
+	blder.log = log
+	return blder
+}
+
 // Named sets the name of the controller to the given name.  The name shows up
 // in metrics, among other things, and thus should be a prometheus compatible name
 // (underscores and alphanumeric characters only).
@@ -140,12 +146,6 @@ func (blder *Builder) Named(name string) *Builder {
 	return blder
 }
 
-// WithLogger overrides the controller options's logger used.
-func (blder *Builder) WithLogger(log logr.Logger) *Builder {
-	blder.log = log
-	return blder
-}
-
 // Complete builds the Application ControllerManagedBy.
 func (blder *Builder) Complete(r reconcile.Reconciler) error {
 	_, err := blder.Build(r)

pkg/builder/controller_test.go

@@ -44,7 +44,7 @@ import (
 
 type typedNoop struct{}
 
-func (typedNoop) Reconcile(reconcile.Request) (reconcile.Result, error) {
+func (typedNoop) Reconcile(context.Context, reconcile.Request) (reconcile.Result, error) {
 	return reconcile.Result{}, nil
 }
 
@@ -60,7 +60,9 @@ var _ = Describe("application", func() {
 		close(stop)
 	})
 
-	noop := reconcile.Func(func(req reconcile.Request) (reconcile.Result, error) { return reconcile.Result{}, nil })
+	noop := reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) {
+		return reconcile.Result{}, nil
+	})
 
 	Describe("New", func() {
 		It("should return success if given valid objects", func() {
@@ -302,7 +304,7 @@ func doReconcileTest(nameSuffix string, stop chan struct{}, blder *Builder, mgr
 
 	By("Creating the application")
 	ch := make(chan reconcile.Request)
-	fn := reconcile.Func(func(req reconcile.Request) (reconcile.Result, error) {
+	fn := reconcile.Func(func(_ context.Context, req reconcile.Request) (reconcile.Result, error) {
 		defer GinkgoRecover()
 		if !strings.HasSuffix(req.Name, nameSuffix) {
 			// From different test, ignore this request.  Etcd is shared across tests.

pkg/builder/example_test.go

@@ -79,25 +79,24 @@ type ReplicaSetReconciler struct {
 // * Read the ReplicaSet
 // * Read the Pods
 // * Set a Label on the ReplicaSet with the Pod count
-func (a *ReplicaSetReconciler) Reconcile(req reconcile.Request) (reconcile.Result, error) {
+func (a *ReplicaSetReconciler) Reconcile(ctx context.Context, req reconcile.Request) (reconcile.Result, error) {
 	// Read the ReplicaSet
 	rs := &appsv1.ReplicaSet{}
-	err := a.Get(context.TODO(), req.NamespacedName, rs)
+	err := a.Get(ctx, req.NamespacedName, rs)
 	if err != nil {
 		return reconcile.Result{}, err
 	}
 
 	// List the Pods matching the PodTemplate Labels
 	pods := &corev1.PodList{}
-	err = a.List(context.TODO(), pods, client.InNamespace(req.Namespace),
-		client.MatchingLabels(rs.Spec.Template.Labels))
+	err = a.List(ctx, pods, client.InNamespace(req.Namespace), client.MatchingLabels(rs.Spec.Template.Labels))
 	if err != nil {
 		return reconcile.Result{}, err
 	}
 
 	// Update the ReplicaSet
 	rs.Labels["pod-count"] = fmt.Sprintf("%v", len(pods.Items))
-	err = a.Update(context.TODO(), rs)
+	err = a.Update(ctx, rs)
 	if err != nil {
 		return reconcile.Result{}, err
 	}

pkg/controller/controller.go

@@ -43,7 +43,8 @@ type Options struct {
 	// The overall is a token bucket and the per-item is exponential.
 	RateLimiter ratelimiter.RateLimiter
 
-	// Log is the logger used for this controller.
+	// Log is the logger used for this controller and passed to each reconciliation
+	// request via the context field.
 	Log logr.Logger
 }
 
@@ -91,6 +92,10 @@ func NewUnmanaged(name string, mgr manager.Manager, options Options) (Controller
 		return nil, fmt.Errorf("must specify Name for Controller")
 	}
 
+	if options.Log == nil {
+		options.Log = mgr.GetLogger()
+	}
+
 	if options.MaxConcurrentReconciles <= 0 {
 		options.MaxConcurrentReconciles = 1
 	}
@@ -117,6 +122,6 @@ func NewUnmanaged(name string, mgr manager.Manager, options Options) (Controller
 		MaxConcurrentReconciles: options.MaxConcurrentReconciles,
 		SetFields:               mgr.SetFields,
 		Name:                    name,
-		Log:                     options.Log.WithName("controller").WithValues("controller", name),
+		Log:                     options.Log.WithName("controller").WithName(name),
 	}, nil
 }

pkg/controller/controller_integration_test.go

@@ -62,7 +62,7 @@ var _ = Describe("controller", func() {
 			By("Creating the Controller")
 			instance, err := controller.New("foo-controller", cm, controller.Options{
 				Reconciler: reconcile.Func(
-					func(request reconcile.Request) (reconcile.Result, error) {
+					func(_ context.Context, request reconcile.Request) (reconcile.Result, error) {
 						reconciled <- request
 						return reconcile.Result{}, nil
 					}),

pkg/controller/controller_test.go

@@ -17,6 +17,7 @@ limitations under the License.
 package controller_test
 
 import (
+	"context"
 	"fmt"
 	rt "runtime"
 
@@ -33,7 +34,7 @@ import (
 var _ = Describe("controller.Controller", func() {
 	var stop chan struct{}
 
-	rec := reconcile.Func(func(reconcile.Request) (reconcile.Result, error) {
+	rec := reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) {
 		return reconcile.Result{}, nil
 	})
 	BeforeEach(func() {
@@ -123,7 +124,7 @@ var _ inject.Client = &failRec{}
 
 type failRec struct{}
 
-func (*failRec) Reconcile(reconcile.Request) (reconcile.Result, error) {
+func (*failRec) Reconcile(context.Context, reconcile.Request) (reconcile.Result, error) {
 	return reconcile.Result{}, nil
 }
 

pkg/controller/example_test.go

@@ -17,6 +17,7 @@ limitations under the License.
 package controller_test
 
 import (
+	"context"
 	"os"
 
 	corev1 "k8s.io/api/core/v1"
@@ -41,7 +42,7 @@ var (
 // manager.Manager will be used to Start the Controller, and will provide it a shared Cache and Client.
 func ExampleNew() {
 	_, err := controller.New("pod-controller", mgr, controller.Options{
-		Reconciler: reconcile.Func(func(o reconcile.Request) (reconcile.Result, error) {
+		Reconciler: reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) {
 			// Your business logic to implement the API by creating, updating, deleting objects goes here.
 			return reconcile.Result{}, nil
 		}),
@@ -59,7 +60,7 @@ func ExampleController() {
 	// Create a new Controller that will call the provided Reconciler function in response
 	// to events.
 	c, err := controller.New("pod-controller", mgr, controller.Options{
-		Reconciler: reconcile.Func(func(o reconcile.Request) (reconcile.Result, error) {
+		Reconciler: reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) {
 			// Your business logic to implement the API by creating, updating, deleting objects goes here.
 			return reconcile.Result{}, nil
 		}),
@@ -90,7 +91,7 @@ func ExampleController_unstructured() {
 	// Create a new Controller that will call the provided Reconciler function in response
 	// to events.
 	c, err := controller.New("pod-controller", mgr, controller.Options{
-		Reconciler: reconcile.Func(func(o reconcile.Request) (reconcile.Result, error) {
+		Reconciler: reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) {
 			// Your business logic to implement the API by creating, updating, deleting objects goes here.
 			return reconcile.Result{}, nil
 		}),
@@ -129,7 +130,7 @@ func ExampleNewUnmanaged() {
 	// Configure creates a new controller but does not add it to the supplied
 	// manager.
 	c, err := controller.NewUnmanaged("pod-controller", mgr, controller.Options{
-		Reconciler: reconcile.Func(func(_ reconcile.Request) (reconcile.Result, error) {
+		Reconciler: reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) {
 			return reconcile.Result{}, nil
 		}),
 	})

pkg/internal/controller/controller.go

@@ -17,6 +17,7 @@ limitations under the License.
 package controller
 
 import (
+	"context"
 	"fmt"
 	"sync"
 	"time"
@@ -27,6 +28,7 @@ import (
 	"k8s.io/client-go/util/workqueue"
 	"sigs.k8s.io/controller-runtime/pkg/handler"
 	ctrlmetrics "sigs.k8s.io/controller-runtime/pkg/internal/controller/metrics"
+	logf "sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/predicate"
 	"sigs.k8s.io/controller-runtime/pkg/reconcile"
 	"sigs.k8s.io/controller-runtime/pkg/runtime/inject"
@@ -86,8 +88,10 @@ type watchDescription struct {
 }
 
 // Reconcile implements reconcile.Reconciler
-func (c *Controller) Reconcile(r reconcile.Request) (reconcile.Result, error) {
-	return c.Do.Reconcile(r)
+func (c *Controller) Reconcile(ctx context.Context, req reconcile.Request) (reconcile.Result, error) {
+	log := c.Log.WithValues("name", req.Name, "namespace", req.Namespace)
+	ctx = logf.IntoContext(ctx, log)
+	return c.Do.Reconcile(ctx, req)
 }
 
 // Watch implements controller.Controller
@@ -229,12 +233,15 @@ func (c *Controller) reconcileHandler(obj interface{}) bool {
 	}
 
 	log := c.Log.WithValues("name", req.Name, "namespace", req.Namespace)
+	ctx := logf.IntoContext(context.Background(), log)
 
 	// RunInformersAndControllers the syncHandler, passing it the namespace/Name string of the
 	// resource to be synced.
-	if result, err := c.Do.Reconcile(req); err != nil {
+	if result, err := c.Do.Reconcile(ctx, req); err != nil {
 		c.Queue.AddRateLimited(req)
-		log.Error(err, "Reconciler error")
+		if log.V(3).Enabled() {
+			log.Error(err, "Reconciler error")
+		}
 		ctrlmetrics.ReconcileErrors.WithLabelValues(c.Name).Inc()
 		ctrlmetrics.ReconcileTotal.WithLabelValues(c.Name, "error").Inc()
 		return false
@@ -258,7 +265,7 @@ func (c *Controller) reconcileHandler(obj interface{}) bool {
 	c.Queue.Forget(obj)
 
 	// TODO(directxman12): What does 1 mean?  Do we want level constants?  Do we want levels at all?
-	log.V(1).Info("Successfully Reconciled")
+	log.V(5).Info("Successfully Reconciled")
 
 	ctrlmetrics.ReconcileTotal.WithLabelValues(c.Name, "success").Inc()
 	// Return true, don't take a break

pkg/internal/controller/controller_test.go

@@ -78,10 +78,10 @@ var _ = Describe("controller", func() {
 
 	Describe("Reconciler", func() {
 		It("should call the Reconciler function", func() {
-			ctrl.Do = reconcile.Func(func(reconcile.Request) (reconcile.Result, error) {
+			ctrl.Do = reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) {
 				return reconcile.Result{Requeue: true}, nil
 			})
-			result, err := ctrl.Reconcile(
+			result, err := ctrl.Reconcile(context.Background(),
 				reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "foo", Name: "bar"}})
 			Expect(err).NotTo(HaveOccurred())
 			Expect(result).To(Equal(reconcile.Result{Requeue: true}))
@@ -304,7 +304,7 @@ var _ = Describe("controller", func() {
 		})
 
 		It("should continue to process additional queue items after the first", func(done Done) {
-			ctrl.Do = reconcile.Func(func(reconcile.Request) (reconcile.Result, error) {
+			ctrl.Do = reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) {
 				defer GinkgoRecover()
 				Fail("Reconciler should not have been called")
 				return reconcile.Result{}, nil
@@ -766,7 +766,7 @@ func (f *fakeReconciler) AddResult(res reconcile.Result, err error) {
 	f.results <- fakeReconcileResultPair{Result: res, Err: err}
 }
 
-func (f *fakeReconciler) Reconcile(r reconcile.Request) (reconcile.Result, error) {
+func (f *fakeReconciler) Reconcile(_ context.Context, r reconcile.Request) (reconcile.Result, error) {
 	res := <-f.results
 	if f.Requests != nil {
 		f.Requests <- r