address review comments

exp/runtime/internal/controllers/extensionconfig_controller.go

@@ -152,6 +152,7 @@ func (r *Reconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Resu
 	}
 
 	// Register the ExtensionConfig if it was found and patched without error.
+	log.Info("Registering ExtensionConfig information into registry")
 	if err = r.RuntimeClient.Register(discoveredExtensionConfig); err != nil {
 		return ctrl.Result{}, errors.Wrapf(err, "failed to register ExtensionConfig %s/%s", extensionConfig.Namespace, extensionConfig.Name)
 	}
@@ -178,7 +179,7 @@ func patchExtensionConfig(ctx context.Context, client client.Client, original, m
 // effort deletion that may not catch all cases.
 func (r *Reconciler) reconcileDelete(ctx context.Context, extensionConfig *runtimev1.ExtensionConfig) (ctrl.Result, error) {
 	log := ctrl.LoggerFrom(ctx)
-	log.Info("Un-registering extension information from extension registry")
+	log.Info("Unregistering ExtensionConfig information from registry")
 	if err := r.RuntimeClient.Unregister(extensionConfig); err != nil {
 		return ctrl.Result{}, errors.Wrapf(err, "failed to unregister %s", tlog.KObj{Obj: extensionConfig})
 	}
@@ -235,7 +236,7 @@ func reconcileCABundle(ctx context.Context, client client.Client, config *runtim
 	}
 	secretName := splitNamespacedName(secretNameRaw)
 
-	log.Info(fmt.Sprintf("Injecting CA Bundle into extension '%s/%s' from secret '%s'", config.Namespace, config.Name, secretName))
+	log.Info(fmt.Sprintf("Injecting CA Bundle into ExtensionConfig from secret %q", secretNameRaw))
 
 	if secretName.Namespace == "" || secretName.Name == "" {
 		return errors.Errorf("failed to reconcile caBundle: secret name %q must be in the form <namespace>/<name>", secretNameRaw)

exp/runtime/internal/controllers/warmup.go

@@ -23,6 +23,7 @@ import (
 	"github.com/pkg/errors"
 	kerrors "k8s.io/apimachinery/pkg/util/errors"
 	"k8s.io/apimachinery/pkg/util/wait"
+	"k8s.io/klog/v2"
 	ctrl "sigs.k8s.io/controller-runtime"
 	"sigs.k8s.io/controller-runtime/pkg/client"
 	"sigs.k8s.io/controller-runtime/pkg/manager"
@@ -102,6 +103,9 @@ func warmupRegistry(ctx context.Context, client client.Client, reader client.Rea
 		extensionConfig := &extensionConfigList.Items[i]
 		original := extensionConfig.DeepCopy()
 
+		log := log.WithValues("extensionConfig", klog.KObj(extensionConfig), "name", extensionConfig.Name, "namespace", extensionConfig.Namespace)
+		ctx := ctrl.LoggerInto(ctx, log)
+
 		// Inject CABundle from secret if annotation is set. Otherwise https calls may fail.
 		if err := reconcileCABundle(ctx, client, extensionConfig); err != nil {
 			errs = append(errs, err)

internal/controllers/topology/cluster/cluster_controller.go

@@ -353,7 +353,7 @@ func (r *Reconciler) reconcileDelete(ctx context.Context, cluster *clusterv1.Clu
 				return ctrl.Result{}, err
 			}
 			if hookResponse.RetryAfterSeconds != 0 {
-				log.Infof("Cluster deletion is blocked by %s hook", runtimecatalog.HookName(runtimehooksv1.BeforeClusterDelete))
+				log.Infof("Cluster deletion is blocked by %q hook", runtimecatalog.HookName(runtimehooksv1.BeforeClusterDelete))
 				return ctrl.Result{RequeueAfter: time.Duration(hookResponse.RetryAfterSeconds) * time.Second}, nil
 			}
 			// The BeforeClusterDelete hook returned a non-blocking response. Now the cluster is ready to be deleted.

internal/controllers/topology/cluster/desired_state.go

@@ -336,7 +336,7 @@ func (r *Reconciler) computeControlPlaneVersion(ctx context.Context, s *scope.Sc
 				// change the UpgradeTracker accordingly, otherwise the hook call is completed and we
 				// can remove this hook from the list of pending-hooks.
 				if hookResponse.RetryAfterSeconds != 0 {
-					log.Infof("MachineDeployments upgrade to version '%s' are blocked by %s hook", desiredVersion, runtimecatalog.HookName(runtimehooksv1.AfterControlPlaneUpgrade))
+					log.Infof("MachineDeployments upgrade to version %q are blocked by %q hook", desiredVersion, runtimecatalog.HookName(runtimehooksv1.AfterControlPlaneUpgrade))
 					s.UpgradeTracker.MachineDeployments.HoldUpgrades(true)
 				} else {
 					if err := hooks.MarkAsDone(ctx, r.Client, s.Current.Cluster, runtimehooksv1.AfterControlPlaneUpgrade); err != nil {
@@ -386,7 +386,7 @@ func (r *Reconciler) computeControlPlaneVersion(ctx context.Context, s *scope.Sc
 		s.HookResponseTracker.Add(runtimehooksv1.BeforeClusterUpgrade, hookResponse)
 		if hookResponse.RetryAfterSeconds != 0 {
 			// Cannot pickup the new version right now. Need to try again later.
-			log.Infof("Cluster upgrade to version '%s' is blocked by %s hook", desiredVersion, runtimecatalog.HookName(runtimehooksv1.BeforeClusterUpgrade))
+			log.Infof("Cluster upgrade to version %q is blocked by %s hook", desiredVersion, runtimecatalog.HookName(runtimehooksv1.BeforeClusterUpgrade))
 			return *currentVersion, nil
 		}
 

internal/runtime/client/client.go

@@ -120,7 +120,7 @@ func (c *client) IsReady() bool {
 
 func (c *client) Discover(ctx context.Context, extensionConfig *runtimev1.ExtensionConfig) (*runtimev1.ExtensionConfig, error) {
 	log := ctrl.LoggerFrom(ctx)
-	log.Info(fmt.Sprintf("Performing discovery for Extension %s/%s", extensionConfig.Namespace, extensionConfig.Name))
+	log.Info("Performing discovery for ExtensionConfig")
 
 	hookGVH, err := c.catalog.GroupVersionHook(runtimehooksv1.Discovery)
 	if err != nil {
@@ -193,9 +193,10 @@ func (c *client) Unregister(extensionConfig *runtimev1.ExtensionConfig) error {
 // The aggregated result of the ExtensionHandlers is updated into the response object passed to the function.
 func (c *client) CallAllExtensions(ctx context.Context, hook runtimecatalog.Hook, forObject metav1.Object, request runtime.Object, response runtimehooksv1.ResponseObject) error {
 	log := ctrl.LoggerFrom(ctx)
+	hookName := runtimecatalog.HookName(hook)
 	gvh, err := c.catalog.GroupVersionHook(hook)
 	if err != nil {
-		return errors.Wrapf(err, "failed to call extension handlers for hook %q: failed to compute GroupVersionHook", runtimecatalog.HookName(hook))
+		return errors.Wrapf(err, "failed to call extension handlers for hook %q: failed to compute GroupVersionHook", hookName)
 	}
 	// Make sure the request is compatible with the hook.
 	if err := c.catalog.ValidateRequest(gvh, request); err != nil {
@@ -211,7 +212,7 @@ func (c *client) CallAllExtensions(ctx context.Context, hook runtimecatalog.Hook
 		return errors.Wrapf(err, "failed to call extension handlers for hook %q", gvh.GroupHook())
 	}
 
-	log.Info(fmt.Sprintf("Calling all extensions of hook '%s'", runtimecatalog.HookName(hook)))
+	log.Info(fmt.Sprintf("Calling all extensions of hook %q", hookName))
 	responses := []runtimehooksv1.ResponseObject{}
 	for _, registration := range registrations {
 		// Creates a new instance of the response parameter.
@@ -297,6 +298,7 @@ func lowestNonZeroRetryAfterSeconds(i, j int32) int32 {
 // - Error when ExtensionHandler returns a response with `Status` set to `Failure`.
 func (c *client) CallExtension(ctx context.Context, hook runtimecatalog.Hook, forObject metav1.Object, name string, request runtime.Object, response runtimehooksv1.ResponseObject) error {
 	log := ctrl.LoggerFrom(ctx)
+	hookName := runtimecatalog.HookName(hook)
 	hookGVH, err := c.catalog.GroupVersionHook(hook)
 	if err != nil {
 		return errors.Wrapf(err, "failed to call extension handler %q: failed to compute GroupVersionHook", name)
@@ -328,7 +330,7 @@ func (c *client) CallExtension(ctx context.Context, hook runtimecatalog.Hook, fo
 		return errors.Errorf("failed to call extension handler %q: namespaceSelector did not match object %s", name, util.ObjectKey(forObject))
 	}
 
-	log.Info(fmt.Sprintf("Calling extension '%s' of hook '%s'", name, runtimecatalog.HookName(hook)))
+	log.Info(fmt.Sprintf("Calling extension %q of hook %q", name, hookName))
 	var timeoutDuration time.Duration
 	if registration.TimeoutSeconds != nil {
 		timeoutDuration = time.Duration(*registration.TimeoutSeconds) * time.Second
@@ -348,6 +350,7 @@ func (c *client) CallExtension(ctx context.Context, hook runtimecatalog.Hook, fo
 		ignore := *registration.FailurePolicy == runtimev1.FailurePolicyIgnore
 		if _, ok := err.(errCallingExtensionHandler); ok && ignore {
 			// Update the response to a default success response and return.
+			log.V(5).Info(fmt.Sprintf("error calling extension %q of hook %q ignored because of FailurePolicy %q", name, hookName, *registration.FailurePolicy))
 			response.SetStatus(runtimehooksv1.ResponseStatusSuccess)
 			response.SetMessage("")
 			return nil
@@ -360,6 +363,10 @@ func (c *client) CallExtension(ctx context.Context, hook runtimecatalog.Hook, fo
 		return errors.Errorf("failed to call extension handler %q: got failure response with message %q", name, response.GetMessage())
 	}
 
+	if retryResponse, ok := response.(runtimehooksv1.RetryResponseObject); ok && retryResponse.GetRetryAfterSeconds() != 0 {
+		log.Info(fmt.Sprintf("extension %q of hook %q returned blocking response with retryAfterSeconds of %q", name, hookName, retryResponse.GetRetryAfterSeconds()))
+	}
+
 	// Received a successful response from the extension handler. The `response` object
 	// has been populated with the result. Return no error.
 	return nil
@@ -399,7 +406,7 @@ func httpCall(ctx context.Context, request, response runtime.Object, opts *httpC
 	responseLocal := response
 
 	if requireConversion {
-		log.V(5).Info(fmt.Sprintf("Supported hook version of extension is different. Converting request to %s", opts.registrationGVH))
+		log.V(5).Info(fmt.Sprintf("Hook version of supported request is %s. Converting request from %s", opts.registrationGVH, opts.hookGVH))
 		// The request and response objects need to be converted to match the version supported by
 		// the ExtensionHandler.
 		var err error
@@ -496,7 +503,7 @@ func httpCall(ctx context.Context, request, response runtime.Object, opts *httpC
 	}
 
 	if requireConversion {
-		log.V(5).Info(fmt.Sprintf("Hook version of received response is different. Converting response back to %s", opts.hookGVH))
+		log.V(5).Info(fmt.Sprintf("Hook version of received response is %s. Converting response to %s", opts.registrationGVH, opts.hookGVH))
 		// Convert the received response to the original version of the response object.
 		if err := opts.catalog.Convert(responseLocal, response, ctx); err != nil {
 			return errors.Wrapf(err, "http call failed: failed to convert response from %T to %T", requestLocal, response)