k8s.io/kubernetes@v1.31.0-alpha.0.0.20240520171757-56147500dadc/pkg/controller/volume/persistentvolume/pv_controller.go (about)

     1  /*
     2  Copyright 2016 The Kubernetes Authors.
     3  
     4  Licensed under the Apache License, Version 2.0 (the "License");
     5  you may not use this file except in compliance with the License.
     6  You may obtain a copy of the License at
     7  
     8      http://www.apache.org/licenses/LICENSE-2.0
     9  
    10  Unless required by applicable law or agreed to in writing, software
    11  distributed under the License is distributed on an "AS IS" BASIS,
    12  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    13  See the License for the specific language governing permissions and
    14  limitations under the License.
    15  */
    16  
    17  package persistentvolume
    18  
    19  import (
    20  	"context"
    21  	"fmt"
    22  	"reflect"
    23  	"strings"
    24  	"time"
    25  
    26  	utilfeature "k8s.io/apiserver/pkg/util/feature"
    27  	"k8s.io/kubernetes/pkg/features"
    28  	"k8s.io/kubernetes/pkg/util/slice"
    29  
    30  	v1 "k8s.io/api/core/v1"
    31  	storage "k8s.io/api/storage/v1"
    32  	apierrors "k8s.io/apimachinery/pkg/api/errors"
    33  	"k8s.io/apimachinery/pkg/api/resource"
    34  	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
    35  	"k8s.io/apimachinery/pkg/util/sets"
    36  	clientset "k8s.io/client-go/kubernetes"
    37  	"k8s.io/client-go/kubernetes/scheme"
    38  	corelisters "k8s.io/client-go/listers/core/v1"
    39  	storagelisters "k8s.io/client-go/listers/storage/v1"
    40  	"k8s.io/client-go/tools/cache"
    41  	"k8s.io/client-go/tools/record"
    42  	ref "k8s.io/client-go/tools/reference"
    43  	"k8s.io/client-go/util/workqueue"
    44  	volerr "k8s.io/cloud-provider/volume/errors"
    45  	storagehelpers "k8s.io/component-helpers/storage/volume"
    46  	"k8s.io/kubernetes/pkg/controller/volume/common"
    47  	"k8s.io/kubernetes/pkg/controller/volume/events"
    48  	"k8s.io/kubernetes/pkg/controller/volume/persistentvolume/metrics"
    49  	"k8s.io/kubernetes/pkg/util/goroutinemap"
    50  	"k8s.io/kubernetes/pkg/util/goroutinemap/exponentialbackoff"
    51  	vol "k8s.io/kubernetes/pkg/volume"
    52  	"k8s.io/kubernetes/pkg/volume/util"
    53  	"k8s.io/kubernetes/pkg/volume/util/recyclerclient"
    54  	volumetypes "k8s.io/kubernetes/pkg/volume/util/types"
    55  
    56  	"k8s.io/klog/v2"
    57  )
    58  
    59  // ==================================================================
    60  // PLEASE DO NOT ATTEMPT TO SIMPLIFY THIS CODE.
    61  // KEEP THE SPACE SHUTTLE FLYING.
    62  // ==================================================================
    63  //
    64  // This controller is intentionally written in a very verbose style. You will
    65  // notice:
    66  //
    67  // 1. Every 'if' statement has a matching 'else' (exception: simple error
    68  //    checks for a client API call)
    69  // 2. Things that may seem obvious are commented explicitly
    70  //
    71  // We call this style 'space shuttle style'. Space shuttle style is meant to
    72  // ensure that every branch and condition is considered and accounted for -
    73  // the same way code is written at NASA for applications like the space
    74  // shuttle.
    75  //
    76  // Originally, the work of this controller was split amongst three
    77  // controllers. This controller is the result a large effort to simplify the
    78  // PV subsystem. During that effort, it became clear that we needed to ensure
    79  // that every single condition was handled and accounted for in the code, even
    80  // if it resulted in no-op code branches.
    81  //
    82  // As a result, the controller code may seem overly verbose, commented, and
    83  // 'branchy'. However, a large amount of business knowledge and context is
    84  // recorded here in order to ensure that future maintainers can correctly
    85  // reason through the complexities of the binding behavior. For that reason,
    86  // changes to this file should preserve and add to the space shuttle style.
    87  //
    88  // ==================================================================
    89  // PLEASE DO NOT ATTEMPT TO SIMPLIFY THIS CODE.
    90  // KEEP THE SPACE SHUTTLE FLYING.
    91  // ==================================================================
    92  
    93  // Design:
    94  //
    95  // The fundamental key to this design is the bi-directional "pointer" between
    96  // PersistentVolumes (PVs) and PersistentVolumeClaims (PVCs), which is
    97  // represented here as pvc.Spec.VolumeName and pv.Spec.ClaimRef. The bi-
    98  // directionality is complicated to manage in a transactionless system, but
    99  // without it we can't ensure sane behavior in the face of different forms of
   100  // trouble. For example, a rogue HA controller instance could end up racing
   101  // and making multiple bindings that are indistinguishable, resulting in
   102  // potential data loss.
   103  //
   104  // This controller is designed to work in active-passive high availability
   105  // mode. It *could* work also in active-active HA mode, all the object
   106  // transitions are designed to cope with this, however performance could be
   107  // lower as these two active controllers will step on each other toes
   108  // frequently.
   109  //
   110  // This controller supports pre-bound (by the creator) objects in both
   111  // directions: a PVC that wants a specific PV or a PV that is reserved for a
   112  // specific PVC.
   113  //
   114  // The binding is two-step process. PV.Spec.ClaimRef is modified first and
   115  // PVC.Spec.VolumeName second. At any point of this transaction, the PV or PVC
   116  // can be modified by user or other controller or completely deleted. Also,
   117  // two (or more) controllers may try to bind different volumes to different
   118  // claims at the same time. The controller must recover from any conflicts
   119  // that may arise from these conditions.
   120  
   121  // Number of retries when we create a PV object for a provisioned volume.
   122  const createProvisionedPVRetryCount = 5
   123  
   124  // Interval between retries when we create a PV object for a provisioned volume.
   125  const createProvisionedPVInterval = 10 * time.Second
   126  
   127  // CSINameTranslator can get the CSI Driver name based on the in-tree plugin name
   128  type CSINameTranslator interface {
   129  	GetCSINameFromInTreeName(pluginName string) (string, error)
   130  }
   131  
   132  // CSIMigratedPluginManager keeps track of CSI migration status of a plugin
   133  type CSIMigratedPluginManager interface {
   134  	IsMigrationEnabledForPlugin(pluginName string) bool
   135  }
   136  
   137  // PersistentVolumeController is a controller that synchronizes
   138  // PersistentVolumeClaims and PersistentVolumes. It starts two
   139  // cache.Controllers that watch PersistentVolume and PersistentVolumeClaim
   140  // changes.
   141  type PersistentVolumeController struct {
   142  	volumeLister       corelisters.PersistentVolumeLister
   143  	volumeListerSynced cache.InformerSynced
   144  	claimLister        corelisters.PersistentVolumeClaimLister
   145  	claimListerSynced  cache.InformerSynced
   146  	classLister        storagelisters.StorageClassLister
   147  	classListerSynced  cache.InformerSynced
   148  	podLister          corelisters.PodLister
   149  	podListerSynced    cache.InformerSynced
   150  	podIndexer         cache.Indexer
   151  	NodeLister         corelisters.NodeLister
   152  	NodeListerSynced   cache.InformerSynced
   153  
   154  	kubeClient                clientset.Interface
   155  	eventBroadcaster          record.EventBroadcaster
   156  	eventRecorder             record.EventRecorder
   157  	volumePluginMgr           vol.VolumePluginMgr
   158  	enableDynamicProvisioning bool
   159  	resyncPeriod              time.Duration
   160  
   161  	// Cache of the last known version of volumes and claims. This cache is
   162  	// thread safe as long as the volumes/claims there are not modified, they
   163  	// must be cloned before any modification. These caches get updated both by
   164  	// "xxx added/updated/deleted" events from etcd and by the controller when
   165  	// it saves newer version to etcd.
   166  	// Why local cache: binding a volume to a claim generates 4 events, roughly
   167  	// in this order (depends on goroutine ordering):
   168  	// - volume.Spec update
   169  	// - volume.Status update
   170  	// - claim.Spec update
   171  	// - claim.Status update
   172  	// With these caches, the controller can check that it has already saved
   173  	// volume.Status and claim.Spec+Status and does not need to do anything
   174  	// when e.g. volume.Spec update event arrives before all the other events.
   175  	// Without this cache, it would see the old version of volume.Status and
   176  	// claim in the informers (it has not been updated from API server events
   177  	// yet) and it would try to fix these objects to be bound together.
   178  	// Any write to API server would fail with version conflict - these objects
   179  	// have been already written.
   180  	volumes persistentVolumeOrderedIndex
   181  	claims  cache.Store
   182  
   183  	// Work queues of claims and volumes to process. Every queue should have
   184  	// exactly one worker thread, especially syncClaim() is not reentrant.
   185  	// Two syncClaims could bind two different claims to the same volume or one
   186  	// claim to two volumes. The controller would recover from this (due to
   187  	// version errors in API server and other checks in this controller),
   188  	// however overall speed of multi-worker controller would be lower than if
   189  	// it runs single thread only.
   190  	claimQueue  *workqueue.Typed[string]
   191  	volumeQueue *workqueue.Typed[string]
   192  
   193  	// Map of scheduled/running operations.
   194  	runningOperations goroutinemap.GoRoutineMap
   195  
   196  	// For testing only: hook to call before an asynchronous operation starts.
   197  	// Not used when set to nil.
   198  	preOperationHook func(operationName string)
   199  
   200  	createProvisionedPVRetryCount int
   201  	createProvisionedPVInterval   time.Duration
   202  
   203  	// operationTimestamps caches start timestamp of operations
   204  	// (currently provision + binding/deletion) for metric recording.
   205  	// Detailed lifecycle/key for each operation
   206  	// 1. provision + binding
   207  	//     key:        claimKey
   208  	//     start time: user has NOT provide any volume ref in the claim AND
   209  	//                 there is no existing volume found for the claim,
   210  	//                 "provisionClaim" is called with a valid plugin/external provisioner
   211  	//                 to provision a volume
   212  	//     end time:   after a volume has been provisioned and bound to the claim successfully
   213  	//                 the corresponding timestamp entry will be deleted from cache
   214  	//     abort:      claim has not been bound to a volume yet but a claim deleted event
   215  	//                 has been received from API server
   216  	// 2. deletion
   217  	//     key:        volumeName
   218  	//     start time: when "reclaimVolume" process a volume with reclaim policy
   219  	//                 set to be "PersistentVolumeReclaimDelete"
   220  	//     end time:   after a volume deleted event has been received from API server
   221  	//                 the corresponding timestamp entry will be deleted from cache
   222  	//     abort:      N.A.
   223  	operationTimestamps metrics.OperationStartTimeCache
   224  
   225  	translator               CSINameTranslator
   226  	csiMigratedPluginManager CSIMigratedPluginManager
   227  }
   228  
   229  // syncClaim is the main controller method to decide what to do with a claim.
   230  // It's invoked by appropriate cache.Controller callbacks when a claim is
   231  // created, updated or periodically synced. We do not differentiate between
   232  // these events.
   233  // For easier readability, it was split into syncUnboundClaim and syncBoundClaim
   234  // methods.
   235  func (ctrl *PersistentVolumeController) syncClaim(ctx context.Context, claim *v1.PersistentVolumeClaim) error {
   236  	logger := klog.FromContext(ctx)
   237  	logger.V(4).Info("Synchronizing PersistentVolumeClaim", "PVC", klog.KObj(claim), "claimStatus", getClaimStatusForLogging(claim))
   238  
   239  	// Set correct "migrated-to" annotations on PVC and update in API server if
   240  	// necessary
   241  	newClaim, err := ctrl.updateClaimMigrationAnnotations(ctx, claim)
   242  	if err != nil {
   243  		// Nothing was saved; we will fall back into the same
   244  		// condition in the next call to this method
   245  		return err
   246  	}
   247  	claim = newClaim
   248  
   249  	if !metav1.HasAnnotation(claim.ObjectMeta, storagehelpers.AnnBindCompleted) {
   250  		return ctrl.syncUnboundClaim(ctx, claim)
   251  	} else {
   252  		return ctrl.syncBoundClaim(ctx, claim)
   253  	}
   254  }
   255  
   256  // checkVolumeSatisfyClaim checks if the volume requested by the claim satisfies the requirements of the claim
   257  func checkVolumeSatisfyClaim(volume *v1.PersistentVolume, claim *v1.PersistentVolumeClaim) error {
   258  	requestedQty := claim.Spec.Resources.Requests[v1.ResourceName(v1.ResourceStorage)]
   259  	requestedSize := requestedQty.Value()
   260  
   261  	// check if PV's DeletionTimeStamp is set, if so, return error.
   262  	if volume.ObjectMeta.DeletionTimestamp != nil {
   263  		return fmt.Errorf("the volume is marked for deletion %q", volume.Name)
   264  	}
   265  
   266  	volumeQty := volume.Spec.Capacity[v1.ResourceStorage]
   267  	volumeSize := volumeQty.Value()
   268  	if volumeSize < requestedSize {
   269  		return fmt.Errorf("requested PV is too small")
   270  	}
   271  
   272  	requestedClass := storagehelpers.GetPersistentVolumeClaimClass(claim)
   273  	if storagehelpers.GetPersistentVolumeClass(volume) != requestedClass {
   274  		return fmt.Errorf("storageClassName does not match")
   275  	}
   276  
   277  	if storagehelpers.CheckVolumeModeMismatches(&claim.Spec, &volume.Spec) {
   278  		return fmt.Errorf("incompatible volumeMode")
   279  	}
   280  
   281  	if !storagehelpers.CheckAccessModes(claim, volume) {
   282  		return fmt.Errorf("incompatible accessMode")
   283  	}
   284  
   285  	return nil
   286  }
   287  
   288  // emitEventForUnboundDelayBindingClaim generates informative event for claim
   289  // if it's in delay binding mode and not bound yet.
   290  func (ctrl *PersistentVolumeController) emitEventForUnboundDelayBindingClaim(claim *v1.PersistentVolumeClaim) error {
   291  	reason := events.WaitForFirstConsumer
   292  	message := "waiting for first consumer to be created before binding"
   293  	podNames, err := ctrl.findNonScheduledPodsByPVC(claim)
   294  	if err != nil {
   295  		return err
   296  	}
   297  	if len(podNames) > 0 {
   298  		reason = events.WaitForPodScheduled
   299  		if len(podNames) > 1 {
   300  			// Although only one pod is taken into account in
   301  			// volume scheduling, more than one pods can reference
   302  			// the PVC at the same time. We can't know which pod is
   303  			// used in scheduling, all pods are included.
   304  			message = fmt.Sprintf("waiting for pods %s to be scheduled", strings.Join(podNames, ","))
   305  		} else {
   306  			message = fmt.Sprintf("waiting for pod %s to be scheduled", podNames[0])
   307  		}
   308  	}
   309  	ctrl.eventRecorder.Event(claim, v1.EventTypeNormal, reason, message)
   310  	return nil
   311  }
   312  
   313  // syncUnboundClaim is the main controller method to decide what to do with an
   314  // unbound claim.
   315  func (ctrl *PersistentVolumeController) syncUnboundClaim(ctx context.Context, claim *v1.PersistentVolumeClaim) error {
   316  	// This is a new PVC that has not completed binding
   317  	// OBSERVATION: pvc is "Pending"
   318  	logger := klog.FromContext(ctx)
   319  	if claim.Spec.VolumeName == "" {
   320  		// User did not care which PV they get.
   321  		delayBinding, err := storagehelpers.IsDelayBindingMode(claim, ctrl.classLister)
   322  		if err != nil {
   323  			return err
   324  		}
   325  
   326  		// [Unit test set 1]
   327  		volume, err := ctrl.volumes.findBestMatchForClaim(claim, delayBinding)
   328  		if err != nil {
   329  			logger.V(2).Info("Synchronizing unbound PersistentVolumeClaim, Error finding PV for claim", "PVC", klog.KObj(claim), "err", err)
   330  			return fmt.Errorf("error finding PV for claim %q: %w", claimToClaimKey(claim), err)
   331  		}
   332  		if volume == nil {
   333  			logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, no volume found", "PVC", klog.KObj(claim))
   334  			// No PV could be found. Try to provision one if possible.
   335  			// OBSERVATION: pvc is "Pending", will retry
   336  
   337  			logger.V(4).Info("Attempting to assign storage class to unbound PersistentVolumeClaim", "PVC", klog.KObj(claim))
   338  			updated, err := ctrl.assignDefaultStorageClass(ctx, claim)
   339  			if err != nil {
   340  				metrics.RecordRetroactiveStorageClassMetric(false)
   341  				return fmt.Errorf("can't update PersistentVolumeClaim[%q]: %w", claimToClaimKey(claim), err)
   342  			}
   343  			if updated {
   344  				logger.V(4).Info("PersistentVolumeClaim update successful, restarting claim sync", "PVC", klog.KObj(claim))
   345  				metrics.RecordRetroactiveStorageClassMetric(true)
   346  				return nil
   347  			}
   348  
   349  			switch {
   350  			case delayBinding && !storagehelpers.IsDelayBindingProvisioning(claim):
   351  				// Scheduler does not observe any pod using this claim.
   352  				if err = ctrl.emitEventForUnboundDelayBindingClaim(claim); err != nil {
   353  					return err
   354  				}
   355  			case storagehelpers.GetPersistentVolumeClaimClass(claim) != "":
   356  				// The provisionClaim function may start a new asynchronous operation to provision a volume,
   357  				// or the operation is already running. The claim will be updated in the asynchronous operation,
   358  				// so the branch should be returned directly and the bind operation is expected to continue in
   359  				// the next sync loop.
   360  				if err = ctrl.provisionClaim(ctx, claim); err != nil {
   361  					return err
   362  				}
   363  				return nil
   364  			default:
   365  				ctrl.eventRecorder.Event(claim, v1.EventTypeNormal, events.FailedBinding, "no persistent volumes available for this claim and no storage class is set")
   366  			}
   367  
   368  			// Mark the claim as Pending and try to find a match in the next
   369  			// periodic syncClaim
   370  			if _, err = ctrl.updateClaimStatus(ctx, claim, v1.ClaimPending, nil); err != nil {
   371  				return err
   372  			}
   373  			return nil
   374  		} else /* pv != nil */ {
   375  			// Found a PV for this claim
   376  			// OBSERVATION: pvc is "Pending", pv is "Available"
   377  			claimKey := claimToClaimKey(claim)
   378  			logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, volume found", "PVC", klog.KObj(claim), "volumeName", volume.Name, "volumeStatus", getVolumeStatusForLogging(volume))
   379  			if err = ctrl.bind(ctx, volume, claim); err != nil {
   380  				// On any error saving the volume or the claim, subsequent
   381  				// syncClaim will finish the binding.
   382  				// record count error for provision if exists
   383  				// timestamp entry will remain in cache until a success binding has happened
   384  				metrics.RecordMetric(claimKey, &ctrl.operationTimestamps, err)
   385  				return err
   386  			}
   387  			// OBSERVATION: claim is "Bound", pv is "Bound"
   388  			// if exists a timestamp entry in cache, record end to end provision latency and clean up cache
   389  			// End of the provision + binding operation lifecycle, cache will be cleaned by "RecordMetric"
   390  			// [Unit test 12-1, 12-2, 12-4]
   391  			metrics.RecordMetric(claimKey, &ctrl.operationTimestamps, nil)
   392  			return nil
   393  		}
   394  	} else /* pvc.Spec.VolumeName != nil */ {
   395  		// [Unit test set 2]
   396  		// User asked for a specific PV.
   397  		logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, volume requested", "PVC", klog.KObj(claim), "volumeName", claim.Spec.VolumeName)
   398  		obj, found, err := ctrl.volumes.store.GetByKey(claim.Spec.VolumeName)
   399  		if err != nil {
   400  			return err
   401  		}
   402  		if !found {
   403  			// User asked for a PV that does not exist.
   404  			// OBSERVATION: pvc is "Pending"
   405  			// Retry later.
   406  			logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, volume requested and not found, will try again next time", "PVC", klog.KObj(claim), "volumeName", claim.Spec.VolumeName)
   407  			if _, err = ctrl.updateClaimStatus(ctx, claim, v1.ClaimPending, nil); err != nil {
   408  				return err
   409  			}
   410  			return nil
   411  		} else {
   412  			volume, ok := obj.(*v1.PersistentVolume)
   413  			if !ok {
   414  				return fmt.Errorf("cannot convert object from volume cache to volume %q!?: %+v", claim.Spec.VolumeName, obj)
   415  			}
   416  			logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, volume requested and found", "PVC", klog.KObj(claim), "volumeName", claim.Spec.VolumeName, "volumeStatus", getVolumeStatusForLogging(volume))
   417  			if volume.Spec.ClaimRef == nil {
   418  				// User asked for a PV that is not claimed
   419  				// OBSERVATION: pvc is "Pending", pv is "Available"
   420  				logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, volume is unbound, binding", "PVC", klog.KObj(claim))
   421  				if err = checkVolumeSatisfyClaim(volume, claim); err != nil {
   422  					logger.V(4).Info("Can't bind the claim to volume", "volumeName", volume.Name, "err", err)
   423  					// send an event
   424  					msg := fmt.Sprintf("Cannot bind to requested volume %q: %s", volume.Name, err)
   425  					ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.VolumeMismatch, msg)
   426  					// volume does not satisfy the requirements of the claim
   427  					if _, err = ctrl.updateClaimStatus(ctx, claim, v1.ClaimPending, nil); err != nil {
   428  						return err
   429  					}
   430  				} else if err = ctrl.bind(ctx, volume, claim); err != nil {
   431  					// On any error saving the volume or the claim, subsequent
   432  					// syncClaim will finish the binding.
   433  					return err
   434  				}
   435  				// OBSERVATION: pvc is "Bound", pv is "Bound"
   436  				return nil
   437  			} else if storagehelpers.IsVolumeBoundToClaim(volume, claim) {
   438  				// User asked for a PV that is claimed by this PVC
   439  				// OBSERVATION: pvc is "Pending", pv is "Bound"
   440  				logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, volume already bound, finishing the binding", "PVC", klog.KObj(claim))
   441  
   442  				// Finish the volume binding by adding claim UID.
   443  				if err = ctrl.bind(ctx, volume, claim); err != nil {
   444  					return err
   445  				}
   446  				// OBSERVATION: pvc is "Bound", pv is "Bound"
   447  				return nil
   448  			} else {
   449  				// User asked for a PV that is claimed by someone else
   450  				// OBSERVATION: pvc is "Pending", pv is "Bound"
   451  				if !metav1.HasAnnotation(claim.ObjectMeta, storagehelpers.AnnBoundByController) {
   452  					logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, volume already bound to different claim by user, will retry later", "PVC", klog.KObj(claim))
   453  					claimMsg := fmt.Sprintf("volume %q already bound to a different claim.", volume.Name)
   454  					ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.FailedBinding, claimMsg)
   455  					// User asked for a specific PV, retry later
   456  					if _, err = ctrl.updateClaimStatus(ctx, claim, v1.ClaimPending, nil); err != nil {
   457  						return err
   458  					}
   459  					return nil
   460  				} else {
   461  					// This should never happen because someone had to remove
   462  					// AnnBindCompleted annotation on the claim.
   463  					logger.V(4).Info("Synchronizing unbound PersistentVolumeClaim, volume already bound to different claim by controller, THIS SHOULD NEVER HAPPEN", "PVC", klog.KObj(claim), "boundClaim", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name))
   464  					claimMsg := fmt.Sprintf("volume %q already bound to a different claim.", volume.Name)
   465  					ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.FailedBinding, claimMsg)
   466  
   467  					return fmt.Errorf("invalid binding of claim %q to volume %q: volume already claimed by %q", claimToClaimKey(claim), claim.Spec.VolumeName, claimrefToClaimKey(volume.Spec.ClaimRef))
   468  				}
   469  			}
   470  		}
   471  	}
   472  }
   473  
   474  // syncBoundClaim is the main controller method to decide what to do with a
   475  // bound claim.
   476  func (ctrl *PersistentVolumeController) syncBoundClaim(ctx context.Context, claim *v1.PersistentVolumeClaim) error {
   477  	// HasAnnotation(pvc, storagehelpers.AnnBindCompleted)
   478  	// This PVC has previously been bound
   479  	// OBSERVATION: pvc is not "Pending"
   480  	// [Unit test set 3]
   481  
   482  	logger := klog.FromContext(ctx)
   483  
   484  	if claim.Spec.VolumeName == "" {
   485  		// Claim was bound before but not any more.
   486  		if _, err := ctrl.updateClaimStatusWithEvent(ctx, claim, v1.ClaimLost, nil, v1.EventTypeWarning, "ClaimLost", "Bound claim has lost reference to PersistentVolume. Data on the volume is lost!"); err != nil {
   487  			return err
   488  		}
   489  		return nil
   490  	}
   491  	obj, found, err := ctrl.volumes.store.GetByKey(claim.Spec.VolumeName)
   492  	if err != nil {
   493  		return err
   494  	}
   495  	if !found {
   496  		// Claim is bound to a non-existing volume.
   497  		if _, err = ctrl.updateClaimStatusWithEvent(ctx, claim, v1.ClaimLost, nil, v1.EventTypeWarning, "ClaimLost", "Bound claim has lost its PersistentVolume. Data on the volume is lost!"); err != nil {
   498  			return err
   499  		}
   500  		return nil
   501  	} else {
   502  		volume, ok := obj.(*v1.PersistentVolume)
   503  		if !ok {
   504  			return fmt.Errorf("cannot convert object from volume cache to volume %q!?: %#v", claim.Spec.VolumeName, obj)
   505  		}
   506  
   507  		logger.V(4).Info("Synchronizing bound PersistentVolumeClaim, volume found", "PVC", klog.KObj(claim), "volumeName", claim.Spec.VolumeName, "volumeStatus", getVolumeStatusForLogging(volume))
   508  		if volume.Spec.ClaimRef == nil {
   509  			// Claim is bound but volume has come unbound.
   510  			// Or, a claim was bound and the controller has not received updated
   511  			// volume yet. We can't distinguish these cases.
   512  			// Bind the volume again and set all states to Bound.
   513  			logger.V(4).Info("Synchronizing bound PersistentVolumeClaim, volume is unbound, fixing", "PVC", klog.KObj(claim))
   514  			if err = ctrl.bind(ctx, volume, claim); err != nil {
   515  				// Objects not saved, next syncPV or syncClaim will try again
   516  				return err
   517  			}
   518  			return nil
   519  		} else if volume.Spec.ClaimRef.UID == claim.UID {
   520  			// All is well
   521  			// NOTE: syncPV can handle this so it can be left out.
   522  			// NOTE: bind() call here will do nothing in most cases as
   523  			// everything should be already set.
   524  			logger.V(4).Info("Synchronizing bound PersistentVolumeClaim, claim is already correctly bound", "PVC", klog.KObj(claim))
   525  			if err = ctrl.bind(ctx, volume, claim); err != nil {
   526  				// Objects not saved, next syncPV or syncClaim will try again
   527  				return err
   528  			}
   529  			return nil
   530  		} else {
   531  			// Claim is bound but volume has a different claimant.
   532  			// Set the claim phase to 'Lost', which is a terminal
   533  			// phase.
   534  			if _, err = ctrl.updateClaimStatusWithEvent(ctx, claim, v1.ClaimLost, nil, v1.EventTypeWarning, "ClaimMisbound", "Two claims are bound to the same volume, this one is bound incorrectly"); err != nil {
   535  				return err
   536  			}
   537  			return nil
   538  		}
   539  	}
   540  }
   541  
   542  // syncVolume is the main controller method to decide what to do with a volume.
   543  // It's invoked by appropriate cache.Controller callbacks when a volume is
   544  // created, updated or periodically synced. We do not differentiate between
   545  // these events.
   546  func (ctrl *PersistentVolumeController) syncVolume(ctx context.Context, volume *v1.PersistentVolume) error {
   547  	logger := klog.FromContext(ctx)
   548  	logger.V(4).Info("Synchronizing PersistentVolume", "volumeName", volume.Name, "volumeStatus", getVolumeStatusForLogging(volume))
   549  	// Set correct "migrated-to" annotations and modify finalizers on PV and update in API server if
   550  	// necessary
   551  	newVolume, err := ctrl.updateVolumeMigrationAnnotationsAndFinalizers(ctx, volume)
   552  	if err != nil {
   553  		// Nothing was saved; we will fall back into the same
   554  		// condition in the next call to this method
   555  		return err
   556  	}
   557  	volume = newVolume
   558  
   559  	// [Unit test set 4]
   560  	if volume.Spec.ClaimRef == nil {
   561  		// Volume is unused
   562  		logger.V(4).Info("Synchronizing PersistentVolume, volume is unused", "volumeName", volume.Name)
   563  		if _, err := ctrl.updateVolumePhase(ctx, volume, v1.VolumeAvailable, ""); err != nil {
   564  			// Nothing was saved; we will fall back into the same
   565  			// condition in the next call to this method
   566  			return err
   567  		}
   568  		return nil
   569  	} else /* pv.Spec.ClaimRef != nil */ {
   570  		// Volume is bound to a claim.
   571  		if volume.Spec.ClaimRef.UID == "" {
   572  			// The PV is reserved for a PVC; that PVC has not yet been
   573  			// bound to this PV; the PVC sync will handle it.
   574  			logger.V(4).Info("Synchronizing PersistentVolume, volume is pre-bound to claim", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name), "volumeName", volume.Name)
   575  			if _, err := ctrl.updateVolumePhase(ctx, volume, v1.VolumeAvailable, ""); err != nil {
   576  				// Nothing was saved; we will fall back into the same
   577  				// condition in the next call to this method
   578  				return err
   579  			}
   580  			return nil
   581  		}
   582  		logger.V(4).Info("Synchronizing PersistentVolume, volume is bound to claim", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name), "volumeName", volume.Name)
   583  		// Get the PVC by _name_
   584  		var claim *v1.PersistentVolumeClaim
   585  		claimName := claimrefToClaimKey(volume.Spec.ClaimRef)
   586  		obj, found, err := ctrl.claims.GetByKey(claimName)
   587  		if err != nil {
   588  			return err
   589  		}
   590  		if !found {
   591  			// If the PV was created by an external PV provisioner or
   592  			// bound by external PV binder (e.g. kube-scheduler), it's
   593  			// possible under heavy load that the corresponding PVC is not synced to
   594  			// controller local cache yet. So we need to double-check PVC in
   595  			//   1) informer cache
   596  			//   2) apiserver if not found in informer cache
   597  			// to make sure we will not reclaim a PV wrongly.
   598  			// Note that only non-released and non-failed volumes will be
   599  			// updated to Released state when PVC does not exist.
   600  			if volume.Status.Phase != v1.VolumeReleased && volume.Status.Phase != v1.VolumeFailed {
   601  				obj, err = ctrl.claimLister.PersistentVolumeClaims(volume.Spec.ClaimRef.Namespace).Get(volume.Spec.ClaimRef.Name)
   602  				if err != nil && !apierrors.IsNotFound(err) {
   603  					return err
   604  				}
   605  				found = !apierrors.IsNotFound(err)
   606  				if !found {
   607  					obj, err = ctrl.kubeClient.CoreV1().PersistentVolumeClaims(volume.Spec.ClaimRef.Namespace).Get(ctx, volume.Spec.ClaimRef.Name, metav1.GetOptions{})
   608  					if err != nil && !apierrors.IsNotFound(err) {
   609  						return err
   610  					}
   611  					found = !apierrors.IsNotFound(err)
   612  				}
   613  			}
   614  		}
   615  		if !found {
   616  			logger.V(4).Info("Synchronizing PersistentVolume, claim not found", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name), "volumeName", volume.Name)
   617  			// Fall through with claim = nil
   618  		} else {
   619  			var ok bool
   620  			claim, ok = obj.(*v1.PersistentVolumeClaim)
   621  			if !ok {
   622  				return fmt.Errorf("cannot convert object from volume cache to volume %q!?: %#v", claim.Spec.VolumeName, obj)
   623  			}
   624  			logger.V(4).Info("Synchronizing PersistentVolume, claim found", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name), "claimStatus", getClaimStatusForLogging(claim), "volumeName", volume.Name)
   625  		}
   626  		if claim != nil && claim.UID != volume.Spec.ClaimRef.UID {
   627  			// The claim that the PV was pointing to was deleted, and another
   628  			// with the same name created.
   629  			// in some cases, the cached claim is not the newest, and the volume.Spec.ClaimRef.UID is newer than cached.
   630  			// so we should double check by calling apiserver and get the newest claim, then compare them.
   631  			logger.V(4).Info("Maybe cached claim is not the newest one, we should fetch it from apiserver", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name))
   632  
   633  			claim, err = ctrl.kubeClient.CoreV1().PersistentVolumeClaims(volume.Spec.ClaimRef.Namespace).Get(ctx, volume.Spec.ClaimRef.Name, metav1.GetOptions{})
   634  			if err != nil && !apierrors.IsNotFound(err) {
   635  				return err
   636  			} else if claim != nil {
   637  				// Treat the volume as bound to a missing claim.
   638  				if claim.UID != volume.Spec.ClaimRef.UID {
   639  					logger.V(4).Info("Synchronizing PersistentVolume, claim has a newer UID than pv.ClaimRef, the old one must have been deleted", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name), "volumeName", volume.Name)
   640  					claim = nil
   641  				} else {
   642  					logger.V(4).Info("Synchronizing PersistentVolume, claim has a same UID with pv.ClaimRef", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name), "volumeName", volume.Name)
   643  				}
   644  			}
   645  		}
   646  
   647  		if claim == nil {
   648  			// If we get into this block, the claim must have been deleted;
   649  			// NOTE: reclaimVolume may either release the PV back into the pool or
   650  			// recycle it or do nothing (retain)
   651  
   652  			// Do not overwrite previous Failed state - let the user see that
   653  			// something went wrong, while we still re-try to reclaim the
   654  			// volume.
   655  			if volume.Status.Phase != v1.VolumeReleased && volume.Status.Phase != v1.VolumeFailed {
   656  				// Also, log this only once:
   657  				logger.V(2).Info("Volume is released and reclaim policy will be executed", "volumeName", volume.Name, "reclaimPolicy", volume.Spec.PersistentVolumeReclaimPolicy)
   658  				if volume, err = ctrl.updateVolumePhase(ctx, volume, v1.VolumeReleased, ""); err != nil {
   659  					// Nothing was saved; we will fall back into the same condition
   660  					// in the next call to this method
   661  					return err
   662  				}
   663  			}
   664  			if err = ctrl.reclaimVolume(ctx, volume); err != nil {
   665  				// Release failed, we will fall back into the same condition
   666  				// in the next call to this method
   667  				return err
   668  			}
   669  			if volume.Spec.PersistentVolumeReclaimPolicy == v1.PersistentVolumeReclaimRetain {
   670  				// volume is being retained, it references a claim that does not exist now.
   671  				logger.V(4).Info("PersistentVolume references a claim that is not found", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name), "claimUID", volume.Spec.ClaimRef.UID, "volumeName", volume.Name)
   672  			}
   673  			return nil
   674  		} else if claim.Spec.VolumeName == "" {
   675  			if storagehelpers.CheckVolumeModeMismatches(&claim.Spec, &volume.Spec) {
   676  				// Binding for the volume won't be called in syncUnboundClaim,
   677  				// because findBestMatchForClaim won't return the volume due to volumeMode mismatch.
   678  				volumeMsg := fmt.Sprintf("Cannot bind PersistentVolume to requested PersistentVolumeClaim %q due to incompatible volumeMode.", claim.Name)
   679  				ctrl.eventRecorder.Event(volume, v1.EventTypeWarning, events.VolumeMismatch, volumeMsg)
   680  				claimMsg := fmt.Sprintf("Cannot bind PersistentVolume %q to requested PersistentVolumeClaim due to incompatible volumeMode.", volume.Name)
   681  				ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.VolumeMismatch, claimMsg)
   682  				// Skipping syncClaim
   683  				return nil
   684  			}
   685  
   686  			if metav1.HasAnnotation(volume.ObjectMeta, storagehelpers.AnnBoundByController) {
   687  				// The binding is not completed; let PVC sync handle it
   688  				logger.V(4).Info("Synchronizing PersistentVolume, volume not bound yet, waiting for syncClaim to fix it", "volumeName", volume.Name)
   689  			} else {
   690  				// Dangling PV; try to re-establish the link in the PVC sync
   691  				logger.V(4).Info("Synchronizing PersistentVolume, volume was bound and got unbound (by user?), waiting for syncClaim to fix it", "volumeName", volume.Name)
   692  			}
   693  			// In both cases, the volume is Bound and the claim is Pending.
   694  			// Next syncClaim will fix it. To speed it up, we enqueue the claim
   695  			// into the controller, which results in syncClaim to be called
   696  			// shortly (and in the right worker goroutine).
   697  			// This speeds up binding of provisioned volumes - provisioner saves
   698  			// only the new PV and it expects that next syncClaim will bind the
   699  			// claim to it.
   700  			ctrl.claimQueue.Add(claimToClaimKey(claim))
   701  			return nil
   702  		} else if claim.Spec.VolumeName == volume.Name {
   703  			// Volume is bound to a claim properly, update status if necessary
   704  			logger.V(4).Info("Synchronizing PersistentVolume, all is bound", "volumeName", volume.Name)
   705  			if _, err = ctrl.updateVolumePhase(ctx, volume, v1.VolumeBound, ""); err != nil {
   706  				// Nothing was saved; we will fall back into the same
   707  				// condition in the next call to this method
   708  				return err
   709  			}
   710  			return nil
   711  		} else {
   712  			// Volume is bound to a claim, but the claim is bound elsewhere
   713  			if metav1.HasAnnotation(volume.ObjectMeta, storagehelpers.AnnDynamicallyProvisioned) && volume.Spec.PersistentVolumeReclaimPolicy == v1.PersistentVolumeReclaimDelete {
   714  				// This volume was dynamically provisioned for this claim. The
   715  				// claim got bound elsewhere, and thus this volume is not
   716  				// needed. Delete it.
   717  				// Mark the volume as Released for external deleters and to let
   718  				// the user know. Don't overwrite existing Failed status!
   719  				if volume.Status.Phase != v1.VolumeReleased && volume.Status.Phase != v1.VolumeFailed {
   720  					// Also, log this only once:
   721  					logger.V(2).Info("Dynamically provisioned volume is released and it will be deleted", "volumeName", volume.Name)
   722  					if volume, err = ctrl.updateVolumePhase(ctx, volume, v1.VolumeReleased, ""); err != nil {
   723  						// Nothing was saved; we will fall back into the same condition
   724  						// in the next call to this method
   725  						return err
   726  					}
   727  				}
   728  				if err = ctrl.reclaimVolume(ctx, volume); err != nil {
   729  					// Deletion failed, we will fall back into the same condition
   730  					// in the next call to this method
   731  					return err
   732  				}
   733  				return nil
   734  			} else {
   735  				// Volume is bound to a claim, but the claim is bound elsewhere
   736  				// and it's not dynamically provisioned.
   737  				if metav1.HasAnnotation(volume.ObjectMeta, storagehelpers.AnnBoundByController) {
   738  					// This is part of the normal operation of the controller; the
   739  					// controller tried to use this volume for a claim but the claim
   740  					// was fulfilled by another volume. We did this; fix it.
   741  					logger.V(4).Info("Synchronizing PersistentVolume, volume is bound by controller to a claim that is bound to another volume, unbinding", "volumeName", volume.Name)
   742  					if err = ctrl.unbindVolume(ctx, volume); err != nil {
   743  						return err
   744  					}
   745  					return nil
   746  				} else {
   747  					// The PV must have been created with this ptr; leave it alone.
   748  					logger.V(4).Info("Synchronizing PersistentVolume, volume is bound by user to a claim that is bound to another volume, waiting for the claim to get unbound", "volumeName", volume.Name)
   749  					// This just updates the volume phase and clears
   750  					// volume.Spec.ClaimRef.UID. It leaves the volume pre-bound
   751  					// to the claim.
   752  					if err = ctrl.unbindVolume(ctx, volume); err != nil {
   753  						return err
   754  					}
   755  					return nil
   756  				}
   757  			}
   758  		}
   759  	}
   760  }
   761  
   762  // updateClaimStatus saves new claim.Status to API server.
   763  // Parameters:
   764  //
   765  //	claim - claim to update
   766  //	phase - phase to set
   767  //	volume - volume which Capacity is set into claim.Status.Capacity
   768  func (ctrl *PersistentVolumeController) updateClaimStatus(ctx context.Context, claim *v1.PersistentVolumeClaim, phase v1.PersistentVolumeClaimPhase, volume *v1.PersistentVolume) (*v1.PersistentVolumeClaim, error) {
   769  	logger := klog.FromContext(ctx)
   770  	logger.V(4).Info("Updating PersistentVolumeClaim status", "PVC", klog.KObj(claim), "setPhase", phase)
   771  
   772  	dirty := false
   773  
   774  	claimClone := claim.DeepCopy()
   775  	if claim.Status.Phase != phase {
   776  		claimClone.Status.Phase = phase
   777  		dirty = true
   778  	}
   779  
   780  	if volume == nil {
   781  		// Need to reset AccessModes and Capacity
   782  		if claim.Status.AccessModes != nil {
   783  			claimClone.Status.AccessModes = nil
   784  			dirty = true
   785  		}
   786  		if claim.Status.Capacity != nil {
   787  			claimClone.Status.Capacity = nil
   788  			dirty = true
   789  		}
   790  	} else {
   791  		// Need to update AccessModes and Capacity
   792  		if !reflect.DeepEqual(claim.Status.AccessModes, volume.Spec.AccessModes) {
   793  			claimClone.Status.AccessModes = volume.Spec.AccessModes
   794  			dirty = true
   795  		}
   796  
   797  		// Update Capacity if the claim is becoming Bound, not if it was already.
   798  		// A discrepancy can be intentional to mean that the PVC filesystem size
   799  		// doesn't match the PV block device size, so don't clobber it
   800  		if claim.Status.Phase != phase {
   801  			volumeCap, ok := volume.Spec.Capacity[v1.ResourceStorage]
   802  			if !ok {
   803  				return nil, fmt.Errorf("PersistentVolume %q is without a storage capacity", volume.Name)
   804  			}
   805  			claimCap, ok := claim.Status.Capacity[v1.ResourceStorage]
   806  			// If PV has a resize annotation, set the claim's request capacity
   807  			if metav1.HasAnnotation(volume.ObjectMeta, util.AnnPreResizeCapacity) {
   808  				logger.V(2).Info("Volume requires filesystem resize: setting pvc status capacity", "PVC", klog.KObj(claim), "volumeName", volume.Name, "statusCapacity", volume.ObjectMeta.Annotations[util.AnnPreResizeCapacity])
   809  				preQty, err := resource.ParseQuantity(volume.ObjectMeta.Annotations[util.AnnPreResizeCapacity])
   810  				if err != nil {
   811  					logger.Info("Parsing pre-resize-capacity from PV failed", "volumeName", volume.Name, "err", err)
   812  					preQty = volume.Spec.Capacity[v1.ResourceStorage]
   813  				}
   814  				if claimClone.Status.Capacity == nil {
   815  					claimClone.Status.Capacity = make(map[v1.ResourceName]resource.Quantity)
   816  				}
   817  				claimClone.Status.Capacity[v1.ResourceStorage] = preQty
   818  				dirty = true
   819  			} else if !ok || volumeCap.Cmp(claimCap) != 0 {
   820  				claimClone.Status.Capacity = volume.Spec.Capacity
   821  				dirty = true
   822  			}
   823  		}
   824  	}
   825  
   826  	if !dirty {
   827  		// Nothing to do.
   828  		logger.V(4).Info("Updating PersistentVolumeClaim status, phase already set", "PVC", klog.KObj(claim), "phase", phase)
   829  		return claim, nil
   830  	}
   831  
   832  	newClaim, err := ctrl.kubeClient.CoreV1().PersistentVolumeClaims(claimClone.Namespace).UpdateStatus(ctx, claimClone, metav1.UpdateOptions{})
   833  	if err != nil {
   834  		logger.V(4).Info("Updating PersistentVolumeClaim status, set phase failed", "PVC", klog.KObj(claim), "phase", phase, "err", err)
   835  		return newClaim, err
   836  	}
   837  	_, err = ctrl.storeClaimUpdate(logger, newClaim)
   838  	if err != nil {
   839  		logger.V(4).Info("Updating PersistentVolumeClaim status: cannot update internal cache", "PVC", klog.KObj(claim), "err", err)
   840  		return newClaim, err
   841  	}
   842  	logger.V(2).Info("Claim entered phase", "PVC", klog.KObj(claim), "phase", phase)
   843  	return newClaim, nil
   844  }
   845  
   846  // updateClaimStatusWithEvent saves new claim.Status to API server and emits
   847  // given event on the claim. It saves the status and emits the event only when
   848  // the status has actually changed from the version saved in API server.
   849  // Parameters:
   850  //
   851  //	claim - claim to update
   852  //	phase - phase to set
   853  //	volume - volume which Capacity is set into claim.Status.Capacity
   854  //	eventtype, reason, message - event to send, see EventRecorder.Event()
   855  func (ctrl *PersistentVolumeController) updateClaimStatusWithEvent(ctx context.Context, claim *v1.PersistentVolumeClaim, phase v1.PersistentVolumeClaimPhase, volume *v1.PersistentVolume, eventtype, reason, message string) (*v1.PersistentVolumeClaim, error) {
   856  	logger := klog.FromContext(ctx)
   857  	logger.V(4).Info("Updating updateClaimStatusWithEvent", "PVC", klog.KObj(claim), "setPhase", phase)
   858  	if claim.Status.Phase == phase {
   859  		// Nothing to do.
   860  		logger.V(4).Info("Updating updateClaimStatusWithEvent, phase already set", "PVC", klog.KObj(claim), "phase", phase)
   861  		return claim, nil
   862  	}
   863  
   864  	newClaim, err := ctrl.updateClaimStatus(ctx, claim, phase, volume)
   865  	if err != nil {
   866  		return nil, err
   867  	}
   868  
   869  	// Emit the event only when the status change happens, not every time
   870  	// syncClaim is called.
   871  	logger.V(3).Info("Claim changed status", "PVC", klog.KObj(claim), "phase", phase, "message", message)
   872  	ctrl.eventRecorder.Event(newClaim, eventtype, reason, message)
   873  
   874  	return newClaim, nil
   875  }
   876  
   877  // updateVolumePhase saves new volume phase to API server.
   878  func (ctrl *PersistentVolumeController) updateVolumePhase(ctx context.Context, volume *v1.PersistentVolume, phase v1.PersistentVolumePhase, message string) (*v1.PersistentVolume, error) {
   879  	logger := klog.FromContext(ctx)
   880  	logger.V(4).Info("Updating PersistentVolume", "volumeName", volume.Name, "setPhase", phase)
   881  	if volume.Status.Phase == phase {
   882  		// Nothing to do.
   883  		logger.V(4).Info("Updating PersistentVolume: phase already set", "volumeName", volume.Name, "phase", phase)
   884  		return volume, nil
   885  	}
   886  
   887  	volumeClone := volume.DeepCopy()
   888  	volumeClone.Status.Phase = phase
   889  	volumeClone.Status.Message = message
   890  
   891  	newVol, err := ctrl.kubeClient.CoreV1().PersistentVolumes().UpdateStatus(ctx, volumeClone, metav1.UpdateOptions{})
   892  	if err != nil {
   893  		logger.V(4).Info("Updating PersistentVolume: set phase failed", "volumeName", volume.Name, "phase", phase, "err", err)
   894  		return newVol, err
   895  	}
   896  	_, err = ctrl.storeVolumeUpdate(logger, newVol)
   897  	if err != nil {
   898  		logger.V(4).Info("Updating PersistentVolume: cannot update internal cache", "volumeName", volume.Name, "err", err)
   899  		return newVol, err
   900  	}
   901  	logger.V(2).Info("Volume entered phase", "volumeName", volume.Name, "phase", phase)
   902  	return newVol, err
   903  }
   904  
   905  // updateVolumePhaseWithEvent saves new volume phase to API server and emits
   906  // given event on the volume. It saves the phase and emits the event only when
   907  // the phase has actually changed from the version saved in API server.
   908  func (ctrl *PersistentVolumeController) updateVolumePhaseWithEvent(ctx context.Context, volume *v1.PersistentVolume, phase v1.PersistentVolumePhase, eventtype, reason, message string) (*v1.PersistentVolume, error) {
   909  	logger := klog.FromContext(ctx)
   910  	logger.V(4).Info("Updating updateVolumePhaseWithEvent", "volumeName", volume.Name, "setPhase", phase)
   911  	if volume.Status.Phase == phase {
   912  		// Nothing to do.
   913  		logger.V(4).Info("Updating updateVolumePhaseWithEvent: phase already set", "volumeName", volume.Name, "phase", phase)
   914  		return volume, nil
   915  	}
   916  
   917  	newVol, err := ctrl.updateVolumePhase(ctx, volume, phase, message)
   918  	if err != nil {
   919  		return nil, err
   920  	}
   921  
   922  	// Emit the event only when the status change happens, not every time
   923  	// syncClaim is called.
   924  	logger.V(3).Info("Volume changed status", "volumeName", volume.Name, "changedPhase", phase, "message", message)
   925  	ctrl.eventRecorder.Event(newVol, eventtype, reason, message)
   926  
   927  	return newVol, nil
   928  }
   929  
   930  // assignDefaultStorageClass updates the claim storage class if there is any, the claim is updated to the API server.
   931  // Ignores claims that already have a storage class.
   932  // TODO: if resync is ever changed to a larger period, we might need to change how we set the default class on existing unbound claims
   933  func (ctrl *PersistentVolumeController) assignDefaultStorageClass(ctx context.Context, claim *v1.PersistentVolumeClaim) (bool, error) {
   934  	logger := klog.FromContext(ctx)
   935  
   936  	if storagehelpers.PersistentVolumeClaimHasClass(claim) {
   937  		// The user asked for a class.
   938  		return false, nil
   939  	}
   940  
   941  	class, err := util.GetDefaultClass(ctrl.classLister)
   942  	if err != nil {
   943  		return false, err
   944  	} else if class == nil {
   945  		logger.V(4).Info("Can not assign storage class to PersistentVolumeClaim: default storage class not found", "PVC", klog.KObj(claim))
   946  		return false, nil
   947  	}
   948  
   949  	logger.V(4).Info("Assigning StorageClass to PersistentVolumeClaim", "PVC", klog.KObj(claim), "storageClassName", class.Name)
   950  	claim.Spec.StorageClassName = &class.Name
   951  	_, err = ctrl.kubeClient.CoreV1().PersistentVolumeClaims(claim.GetNamespace()).Update(ctx, claim, metav1.UpdateOptions{})
   952  	if err != nil {
   953  		return false, err
   954  	}
   955  
   956  	logger.V(4).Info("Successfully assigned StorageClass to PersistentVolumeClaim", "PVC", klog.KObj(claim), "storageClassName", class.Name)
   957  	return true, nil
   958  }
   959  
   960  // bindVolumeToClaim modifies given volume to be bound to a claim and saves it to
   961  // API server. The claim is not modified in this method!
   962  func (ctrl *PersistentVolumeController) bindVolumeToClaim(ctx context.Context, volume *v1.PersistentVolume, claim *v1.PersistentVolumeClaim) (*v1.PersistentVolume, error) {
   963  	logger := klog.FromContext(ctx)
   964  	logger.V(4).Info("Updating PersistentVolume: binding to claim", "PVC", klog.KObj(claim), "volumeName", volume.Name)
   965  
   966  	volumeClone, dirty, err := storagehelpers.GetBindVolumeToClaim(volume, claim)
   967  	if err != nil {
   968  		return nil, err
   969  	}
   970  
   971  	// Save the volume only if something was changed
   972  	if dirty {
   973  		return ctrl.updateBindVolumeToClaim(ctx, volumeClone, true)
   974  	}
   975  
   976  	logger.V(4).Info("Updating PersistentVolume: already bound to claim", "PVC", klog.KObj(claim), "volumeName", volume.Name)
   977  	return volume, nil
   978  }
   979  
   980  // updateBindVolumeToClaim modifies given volume to be bound to a claim and saves it to
   981  // API server. The claim is not modified in this method!
   982  func (ctrl *PersistentVolumeController) updateBindVolumeToClaim(ctx context.Context, volumeClone *v1.PersistentVolume, updateCache bool) (*v1.PersistentVolume, error) {
   983  	logger := klog.FromContext(ctx)
   984  	logger.V(2).Info("Claim bound to volume", "PVC", klog.KRef(volumeClone.Spec.ClaimRef.Namespace, volumeClone.Spec.ClaimRef.Name), "volumeName", volumeClone.Name)
   985  	newVol, err := ctrl.kubeClient.CoreV1().PersistentVolumes().Update(ctx, volumeClone, metav1.UpdateOptions{})
   986  	if err != nil {
   987  		logger.V(4).Info("Updating PersistentVolume: binding to claim failed", "PVC", klog.KRef(volumeClone.Spec.ClaimRef.Namespace, volumeClone.Spec.ClaimRef.Name), "volumeName", volumeClone.Name, "err", err)
   988  		return newVol, err
   989  	}
   990  	if updateCache {
   991  		_, err = ctrl.storeVolumeUpdate(logger, newVol)
   992  		if err != nil {
   993  			logger.V(4).Info("Updating PersistentVolume: cannot update internal cache", "volumeName", volumeClone.Name, "err", err)
   994  			return newVol, err
   995  		}
   996  	}
   997  	logger.V(4).Info("Updating PersistentVolume: bound to claim", "PVC", klog.KRef(volumeClone.Spec.ClaimRef.Namespace, volumeClone.Spec.ClaimRef.Name), "volumeName", newVol.Name)
   998  	return newVol, nil
   999  }
  1000  
  1001  // bindClaimToVolume modifies the given claim to be bound to a volume and
  1002  // saves it to API server. The volume is not modified in this method!
  1003  func (ctrl *PersistentVolumeController) bindClaimToVolume(ctx context.Context, claim *v1.PersistentVolumeClaim, volume *v1.PersistentVolume) (*v1.PersistentVolumeClaim, error) {
  1004  	logger := klog.FromContext(ctx)
  1005  	logger.V(4).Info("Updating PersistentVolumeClaim: binding to volume", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1006  
  1007  	dirty := false
  1008  
  1009  	// Check if the claim was already bound (either by controller or by user)
  1010  	shouldBind := false
  1011  	if volume.Name != claim.Spec.VolumeName {
  1012  		shouldBind = true
  1013  	}
  1014  
  1015  	// The claim from method args can be pointing to watcher cache. We must not
  1016  	// modify these, therefore create a copy.
  1017  	claimClone := claim.DeepCopy()
  1018  
  1019  	if shouldBind {
  1020  		dirty = true
  1021  		// Bind the claim to the volume
  1022  		claimClone.Spec.VolumeName = volume.Name
  1023  
  1024  		// Set AnnBoundByController if it is not set yet
  1025  		if !metav1.HasAnnotation(claimClone.ObjectMeta, storagehelpers.AnnBoundByController) {
  1026  			metav1.SetMetaDataAnnotation(&claimClone.ObjectMeta, storagehelpers.AnnBoundByController, "yes")
  1027  		}
  1028  	}
  1029  
  1030  	// Set AnnBindCompleted if it is not set yet
  1031  	if !metav1.HasAnnotation(claimClone.ObjectMeta, storagehelpers.AnnBindCompleted) {
  1032  		metav1.SetMetaDataAnnotation(&claimClone.ObjectMeta, storagehelpers.AnnBindCompleted, "yes")
  1033  		dirty = true
  1034  	}
  1035  
  1036  	if dirty {
  1037  		logger.V(2).Info("Volume bound to claim", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1038  		newClaim, err := ctrl.kubeClient.CoreV1().PersistentVolumeClaims(claim.Namespace).Update(ctx, claimClone, metav1.UpdateOptions{})
  1039  		if err != nil {
  1040  			logger.V(4).Info("Updating PersistentVolumeClaim: binding to volume failed", "PVC", klog.KObj(claim), "volumeName", volume.Name, "err", err)
  1041  			return newClaim, err
  1042  		}
  1043  		_, err = ctrl.storeClaimUpdate(logger, newClaim)
  1044  		if err != nil {
  1045  			logger.V(4).Info("Updating PersistentVolumeClaim: cannot update internal cache", "PVC", klog.KObj(claim), "err", err)
  1046  			return newClaim, err
  1047  		}
  1048  		logger.V(4).Info("Updating PersistentVolumeClaim: bound to volume", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1049  		return newClaim, nil
  1050  	}
  1051  
  1052  	logger.V(4).Info("Updating PersistentVolumeClaim: already bound to volume", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1053  	return claim, nil
  1054  }
  1055  
  1056  // bind saves binding information both to the volume and the claim and marks
  1057  // both objects as Bound. Volume is saved first.
  1058  // It returns on first error, it's up to the caller to implement some retry
  1059  // mechanism.
  1060  func (ctrl *PersistentVolumeController) bind(ctx context.Context, volume *v1.PersistentVolume, claim *v1.PersistentVolumeClaim) error {
  1061  	var err error
  1062  	// use updateClaim/updatedVolume to keep the original claim/volume for
  1063  	// logging in error cases.
  1064  	var updatedClaim *v1.PersistentVolumeClaim
  1065  	var updatedVolume *v1.PersistentVolume
  1066  
  1067  	logger := klog.FromContext(ctx)
  1068  	logger.V(4).Info("Binding volume to claim", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1069  
  1070  	if updatedVolume, err = ctrl.bindVolumeToClaim(ctx, volume, claim); err != nil {
  1071  		logger.V(3).Info("Error binding volume to claim: failed saving the volume", "PVC", klog.KObj(claim), "volumeName", volume.Name, "err", err)
  1072  		return err
  1073  	}
  1074  	volume = updatedVolume
  1075  
  1076  	if updatedVolume, err = ctrl.updateVolumePhase(ctx, volume, v1.VolumeBound, ""); err != nil {
  1077  		logger.V(3).Info("Error binding volume to claim: failed saving the volume status", "PVC", klog.KObj(claim), "volumeName", volume.Name, "err", err)
  1078  		return err
  1079  	}
  1080  	volume = updatedVolume
  1081  
  1082  	if updatedClaim, err = ctrl.bindClaimToVolume(ctx, claim, volume); err != nil {
  1083  		logger.V(3).Info("Error binding volume to claim: failed saving the claim", "PVC", klog.KObj(claim), "volumeName", volume.Name, "err", err)
  1084  		return err
  1085  	}
  1086  	claim = updatedClaim
  1087  
  1088  	if updatedClaim, err = ctrl.updateClaimStatus(ctx, claim, v1.ClaimBound, volume); err != nil {
  1089  		logger.V(3).Info("Error binding volume to claim: failed saving the claim status", "PVC", klog.KObj(claim), "volumeName", volume.Name, "err", err)
  1090  		return err
  1091  	}
  1092  	claim = updatedClaim
  1093  
  1094  	logger.V(4).Info("Volume bound to claim", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1095  	logger.V(4).Info("Volume status after binding", "volumeName", volume.Name, "volumeStatus", getVolumeStatusForLogging(volume))
  1096  	logger.V(4).Info("Claim status after binding", "PVC", klog.KObj(claim), "claimStatus", getClaimStatusForLogging(claim))
  1097  	return nil
  1098  }
  1099  
  1100  // unbindVolume rolls back previous binding of the volume. This may be necessary
  1101  // when two controllers bound two volumes to single claim - when we detect this,
  1102  // only one binding succeeds and the second one must be rolled back.
  1103  // This method updates both Spec and Status.
  1104  // It returns on first error, it's up to the caller to implement some retry
  1105  // mechanism.
  1106  func (ctrl *PersistentVolumeController) unbindVolume(ctx context.Context, volume *v1.PersistentVolume) error {
  1107  	logger := klog.FromContext(ctx)
  1108  	logger.V(4).Info("Updating PersistentVolume: rolling back binding from claim", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name), "volumeName", volume.Name)
  1109  
  1110  	// Save the PV only when any modification is necessary.
  1111  	volumeClone := volume.DeepCopy()
  1112  
  1113  	if metav1.HasAnnotation(volume.ObjectMeta, storagehelpers.AnnBoundByController) {
  1114  		// The volume was bound by the controller.
  1115  		volumeClone.Spec.ClaimRef = nil
  1116  		delete(volumeClone.Annotations, storagehelpers.AnnBoundByController)
  1117  		if len(volumeClone.Annotations) == 0 {
  1118  			// No annotations look better than empty annotation map (and it's easier
  1119  			// to test).
  1120  			volumeClone.Annotations = nil
  1121  		}
  1122  	} else {
  1123  		// The volume was pre-bound by user. Clear only the binding UID.
  1124  		volumeClone.Spec.ClaimRef.UID = ""
  1125  	}
  1126  
  1127  	newVol, err := ctrl.kubeClient.CoreV1().PersistentVolumes().Update(ctx, volumeClone, metav1.UpdateOptions{})
  1128  	if err != nil {
  1129  		logger.V(4).Info("Updating PersistentVolume: rollback failed", "volumeName", volume.Name, "err", err)
  1130  		return err
  1131  	}
  1132  	_, err = ctrl.storeVolumeUpdate(logger, newVol)
  1133  	if err != nil {
  1134  		logger.V(4).Info("Updating PersistentVolume: cannot update internal cache", "volumeName", volume.Name, "err", err)
  1135  		return err
  1136  	}
  1137  	logger.V(4).Info("Updating PersistentVolume: rolled back", "volumeName", newVol.Name)
  1138  
  1139  	// Update the status
  1140  	_, err = ctrl.updateVolumePhase(ctx, newVol, v1.VolumeAvailable, "")
  1141  	return err
  1142  }
  1143  
  1144  // reclaimVolume implements volume.Spec.PersistentVolumeReclaimPolicy and
  1145  // starts appropriate reclaim action.
  1146  func (ctrl *PersistentVolumeController) reclaimVolume(ctx context.Context, volume *v1.PersistentVolume) error {
  1147  	logger := klog.FromContext(ctx)
  1148  	if migrated := volume.Annotations[storagehelpers.AnnMigratedTo]; len(migrated) > 0 {
  1149  		// PV is Migrated. The PV controller should stand down and the external
  1150  		// provisioner will handle this PV
  1151  		return nil
  1152  	}
  1153  	switch volume.Spec.PersistentVolumeReclaimPolicy {
  1154  	case v1.PersistentVolumeReclaimRetain:
  1155  		logger.V(4).Info("ReclaimVolume: policy is Retain, nothing to do", "volumeName", volume.Name)
  1156  
  1157  	case v1.PersistentVolumeReclaimRecycle:
  1158  		logger.V(4).Info("ReclaimVolume: policy is Recycle", "volumeName", volume.Name)
  1159  		opName := fmt.Sprintf("recycle-%s[%s]", volume.Name, string(volume.UID))
  1160  		ctrl.scheduleOperation(logger, opName, func() error {
  1161  			ctrl.recycleVolumeOperation(ctx, volume)
  1162  			return nil
  1163  		})
  1164  
  1165  	case v1.PersistentVolumeReclaimDelete:
  1166  		logger.V(4).Info("ReclaimVolume: policy is Delete", "volumeName", volume.Name)
  1167  		opName := fmt.Sprintf("delete-%s[%s]", volume.Name, string(volume.UID))
  1168  		// create a start timestamp entry in cache for deletion operation if no one exists with
  1169  		// key = volume.Name, pluginName = provisionerName, operation = "delete"
  1170  		ctrl.operationTimestamps.AddIfNotExist(volume.Name, ctrl.getProvisionerNameFromVolume(volume), "delete")
  1171  		ctrl.scheduleOperation(logger, opName, func() error {
  1172  			_, err := ctrl.deleteVolumeOperation(ctx, volume)
  1173  			if err != nil {
  1174  				// only report error count to "volume_operation_total_errors"
  1175  				// latency reporting will happen when the volume get finally
  1176  				// deleted and a volume deleted event is captured
  1177  				metrics.RecordMetric(volume.Name, &ctrl.operationTimestamps, err)
  1178  			}
  1179  			return err
  1180  		})
  1181  
  1182  	default:
  1183  		// Unknown PersistentVolumeReclaimPolicy
  1184  		if _, err := ctrl.updateVolumePhaseWithEvent(ctx, volume, v1.VolumeFailed, v1.EventTypeWarning, "VolumeUnknownReclaimPolicy", "Volume has unrecognized PersistentVolumeReclaimPolicy"); err != nil {
  1185  			return err
  1186  		}
  1187  	}
  1188  	return nil
  1189  }
  1190  
  1191  // recycleVolumeOperation recycles a volume. This method is running in
  1192  // standalone goroutine and already has all necessary locks.
  1193  func (ctrl *PersistentVolumeController) recycleVolumeOperation(ctx context.Context, volume *v1.PersistentVolume) {
  1194  	logger := klog.FromContext(ctx)
  1195  	logger.V(4).Info("RecycleVolumeOperation started", "volumeName", volume.Name)
  1196  
  1197  	// This method may have been waiting for a volume lock for some time.
  1198  	// Previous recycleVolumeOperation might just have saved an updated version,
  1199  	// so read current volume state now.
  1200  	newVolume, err := ctrl.kubeClient.CoreV1().PersistentVolumes().Get(ctx, volume.Name, metav1.GetOptions{})
  1201  	if err != nil {
  1202  		logger.V(3).Info("Error reading persistent volume", "volumeName", volume.Name, "err", err)
  1203  		return
  1204  	}
  1205  	needsReclaim, err := ctrl.isVolumeReleased(logger, newVolume)
  1206  	if err != nil {
  1207  		logger.V(3).Info("Error reading claim for volume", "volumeName", volume.Name, "err", err)
  1208  		return
  1209  	}
  1210  	if !needsReclaim {
  1211  		logger.V(3).Info("Volume no longer needs recycling, skipping", "volumeName", volume.Name)
  1212  		return
  1213  	}
  1214  	pods, used, err := ctrl.isVolumeUsed(newVolume)
  1215  	if err != nil {
  1216  		logger.V(3).Info("Can't recycle volume", "volumeName", volume.Name, "err", err)
  1217  		return
  1218  	}
  1219  
  1220  	// Verify the claim is in cache: if so, then it is a different PVC with the same name
  1221  	// since the volume is known to be released at this moment. The new (cached) PVC must use
  1222  	// a different PV -- we checked that the PV is unused in isVolumeReleased.
  1223  	// So the old PV is safe to be recycled.
  1224  	claimName := claimrefToClaimKey(volume.Spec.ClaimRef)
  1225  	_, claimCached, err := ctrl.claims.GetByKey(claimName)
  1226  	if err != nil {
  1227  		logger.V(3).Info("Error getting the claim from cache", "PVC", klog.KRef(volume.Spec.ClaimRef.Namespace, volume.Spec.ClaimRef.Name))
  1228  		return
  1229  	}
  1230  
  1231  	if used && !claimCached {
  1232  		msg := fmt.Sprintf("Volume is used by pods: %s", strings.Join(pods, ","))
  1233  		logger.V(3).Info("Can't recycle volume", "volumeName", volume.Name, "msg", msg)
  1234  		ctrl.eventRecorder.Event(volume, v1.EventTypeNormal, events.VolumeFailedRecycle, msg)
  1235  		return
  1236  	}
  1237  
  1238  	// Use the newest volume copy, this will save us from version conflicts on
  1239  	// saving.
  1240  	volume = newVolume
  1241  
  1242  	// Find a plugin.
  1243  	spec := vol.NewSpecFromPersistentVolume(volume, false)
  1244  	plugin, err := ctrl.volumePluginMgr.FindRecyclablePluginBySpec(spec)
  1245  	if err != nil {
  1246  		// No recycler found. Emit an event and mark the volume Failed.
  1247  		if _, err = ctrl.updateVolumePhaseWithEvent(ctx, volume, v1.VolumeFailed, v1.EventTypeWarning, events.VolumeFailedRecycle, "No recycler plugin found for the volume!"); err != nil {
  1248  			logger.V(4).Info("RecycleVolumeOperation: failed to mark volume as failed", "volumeName", volume.Name, "err", err)
  1249  			// Save failed, retry on the next deletion attempt
  1250  			return
  1251  		}
  1252  		// Despite the volume being Failed, the controller will retry recycling
  1253  		// the volume in every syncVolume() call.
  1254  		return
  1255  	}
  1256  
  1257  	// Plugin found
  1258  	recorder := ctrl.newRecyclerEventRecorder(volume)
  1259  
  1260  	if err = plugin.Recycle(volume.Name, spec, recorder); err != nil {
  1261  		// Recycler failed
  1262  		strerr := fmt.Sprintf("Recycle failed: %s", err)
  1263  		if _, err = ctrl.updateVolumePhaseWithEvent(ctx, volume, v1.VolumeFailed, v1.EventTypeWarning, events.VolumeFailedRecycle, strerr); err != nil {
  1264  			logger.V(4).Info("RecycleVolumeOperation: failed to mark volume as failed", "volumeName", volume.Name, "err", err)
  1265  			// Save failed, retry on the next deletion attempt
  1266  			return
  1267  		}
  1268  		// Despite the volume being Failed, the controller will retry recycling
  1269  		// the volume in every syncVolume() call.
  1270  		return
  1271  	}
  1272  
  1273  	logger.V(2).Info("Volume recycled", "volumeName", volume.Name)
  1274  	// Send an event
  1275  	ctrl.eventRecorder.Event(volume, v1.EventTypeNormal, events.VolumeRecycled, "Volume recycled")
  1276  	// Make the volume available again
  1277  	if err = ctrl.unbindVolume(ctx, volume); err != nil {
  1278  		// Oops, could not save the volume and therefore the controller will
  1279  		// recycle the volume again on next update. We _could_ maintain a cache
  1280  		// of "recently recycled volumes" and avoid unnecessary recycling, this
  1281  		// is left out as future optimization.
  1282  		logger.V(3).Info("RecycleVolumeOperation: failed to make recycled volume 'Available', we will recycle the volume again", "volumeName", volume.Name, "err", err)
  1283  		return
  1284  	}
  1285  }
  1286  
  1287  // deleteVolumeOperation deletes a volume. This method is running in standalone
  1288  // goroutine and already has all necessary locks.
  1289  func (ctrl *PersistentVolumeController) deleteVolumeOperation(ctx context.Context, volume *v1.PersistentVolume) (string, error) {
  1290  	logger := klog.FromContext(ctx)
  1291  	logger.V(4).Info("DeleteVolumeOperation started", "volumeName", volume.Name)
  1292  
  1293  	// This method may have been waiting for a volume lock for some time.
  1294  	// Previous deleteVolumeOperation might just have saved an updated version, so
  1295  	// read current volume state now.
  1296  	newVolume, err := ctrl.kubeClient.CoreV1().PersistentVolumes().Get(ctx, volume.Name, metav1.GetOptions{})
  1297  	if err != nil {
  1298  		logger.V(3).Info("Error reading persistent volume", "volumeName", volume.Name, "err", err)
  1299  		return "", nil
  1300  	}
  1301  
  1302  	if !utilfeature.DefaultFeatureGate.Enabled(features.HonorPVReclaimPolicy) {
  1303  		if newVolume.GetDeletionTimestamp() != nil {
  1304  			logger.V(3).Info("Volume is already being deleted", "volumeName", volume.Name)
  1305  			return "", nil
  1306  		}
  1307  	}
  1308  	needsReclaim, err := ctrl.isVolumeReleased(logger, newVolume)
  1309  	if err != nil {
  1310  		logger.V(3).Info("Error reading claim for volume", "volumeName", volume.Name, "err", err)
  1311  		return "", nil
  1312  	}
  1313  	if !needsReclaim {
  1314  		logger.V(3).Info("Volume no longer needs deletion, skipping", "volumeName", volume.Name)
  1315  		return "", nil
  1316  	}
  1317  
  1318  	pluginName, deleted, err := ctrl.doDeleteVolume(ctx, volume)
  1319  	if err != nil {
  1320  		// Delete failed, update the volume and emit an event.
  1321  		logger.V(3).Info("Deletion of volume failed", "volumeName", volume.Name, "err", err)
  1322  		if volerr.IsDeletedVolumeInUse(err) {
  1323  			// The plugin needs more time, don't mark the volume as Failed
  1324  			// and send Normal event only
  1325  			ctrl.eventRecorder.Event(volume, v1.EventTypeNormal, events.VolumeDelete, err.Error())
  1326  		} else {
  1327  			// The plugin failed, mark the volume as Failed and send Warning
  1328  			// event
  1329  			if _, err := ctrl.updateVolumePhaseWithEvent(ctx, volume, v1.VolumeFailed, v1.EventTypeWarning, events.VolumeFailedDelete, err.Error()); err != nil {
  1330  				logger.V(4).Info("DeleteVolumeOperation: failed to mark volume as failed", "volumeName", volume.Name, "err", err)
  1331  				// Save failed, retry on the next deletion attempt
  1332  				return pluginName, err
  1333  			}
  1334  		}
  1335  
  1336  		// Despite the volume being Failed, the controller will retry deleting
  1337  		// the volume in every syncVolume() call.
  1338  		return pluginName, err
  1339  	}
  1340  	if !deleted {
  1341  		// The volume waits for deletion by an external plugin. Do nothing.
  1342  		return pluginName, nil
  1343  	}
  1344  
  1345  	logger.V(4).Info("DeleteVolumeOperation: success", "volumeName", volume.Name)
  1346  	// Delete the volume
  1347  	if err = ctrl.kubeClient.CoreV1().PersistentVolumes().Delete(ctx, volume.Name, metav1.DeleteOptions{}); err != nil {
  1348  		// Oops, could not delete the volume and therefore the controller will
  1349  		// try to delete the volume again on next update. We _could_ maintain a
  1350  		// cache of "recently deleted volumes" and avoid unnecessary deletion,
  1351  		// this is left out as future optimization.
  1352  		logger.V(3).Info("Failed to delete volume from database", "volumeName", volume.Name, "err", err)
  1353  		return pluginName, nil
  1354  	}
  1355  	return pluginName, nil
  1356  }
  1357  
  1358  // isVolumeReleased returns true if given volume is released and can be recycled
  1359  // or deleted, based on its retain policy. I.e. the volume is bound to a claim
  1360  // and the claim does not exist or exists and is bound to different volume.
  1361  func (ctrl *PersistentVolumeController) isVolumeReleased(logger klog.Logger, volume *v1.PersistentVolume) (bool, error) {
  1362  	// A volume needs reclaim if it has ClaimRef and appropriate claim does not
  1363  	// exist.
  1364  	if volume.Spec.ClaimRef == nil {
  1365  		logger.V(4).Info("isVolumeReleased: ClaimRef is nil", "volumeName", volume.Name)
  1366  		return false, nil
  1367  	}
  1368  	if volume.Spec.ClaimRef.UID == "" {
  1369  		// This is a volume bound by user and the controller has not finished
  1370  		// binding to the real claim yet.
  1371  		logger.V(4).Info("isVolumeReleased: ClaimRef is not bound", "volumeName", volume.Name)
  1372  		return false, nil
  1373  	}
  1374  
  1375  	var claim *v1.PersistentVolumeClaim
  1376  	claimName := claimrefToClaimKey(volume.Spec.ClaimRef)
  1377  	obj, found, err := ctrl.claims.GetByKey(claimName)
  1378  	if err != nil {
  1379  		return false, err
  1380  	}
  1381  	if !found {
  1382  		// Fall through with claim = nil
  1383  	} else {
  1384  		var ok bool
  1385  		claim, ok = obj.(*v1.PersistentVolumeClaim)
  1386  		if !ok {
  1387  			return false, fmt.Errorf("cannot convert object from claim cache to claim!?: %#v", obj)
  1388  		}
  1389  	}
  1390  	if claim != nil && claim.UID == volume.Spec.ClaimRef.UID {
  1391  		// the claim still exists and has the right UID
  1392  
  1393  		if len(claim.Spec.VolumeName) > 0 && claim.Spec.VolumeName != volume.Name {
  1394  			// the claim is bound to another PV, this PV *is* released
  1395  			return true, nil
  1396  		}
  1397  
  1398  		logger.V(4).Info("isVolumeReleased: ClaimRef is still valid, volume is not released", "volumeName", volume.Name)
  1399  		return false, nil
  1400  	}
  1401  
  1402  	logger.V(2).Info("isVolumeReleased: volume is released", "volumeName", volume.Name)
  1403  	return true, nil
  1404  }
  1405  
  1406  func (ctrl *PersistentVolumeController) findPodsByPVCKey(key string) ([]*v1.Pod, error) {
  1407  	pods := []*v1.Pod{}
  1408  	objs, err := ctrl.podIndexer.ByIndex(common.PodPVCIndex, key)
  1409  	if err != nil {
  1410  		return pods, err
  1411  	}
  1412  	for _, obj := range objs {
  1413  		pod, ok := obj.(*v1.Pod)
  1414  		if !ok {
  1415  			continue
  1416  		}
  1417  		pods = append(pods, pod)
  1418  	}
  1419  	return pods, err
  1420  }
  1421  
  1422  // isVolumeUsed returns list of active pods that use given PV.
  1423  func (ctrl *PersistentVolumeController) isVolumeUsed(pv *v1.PersistentVolume) ([]string, bool, error) {
  1424  	if pv.Spec.ClaimRef == nil {
  1425  		return nil, false, nil
  1426  	}
  1427  	podNames := sets.NewString()
  1428  	pvcKey := fmt.Sprintf("%s/%s", pv.Spec.ClaimRef.Namespace, pv.Spec.ClaimRef.Name)
  1429  	pods, err := ctrl.findPodsByPVCKey(pvcKey)
  1430  	if err != nil {
  1431  		return nil, false, fmt.Errorf("error finding pods by pvc %q: %s", pvcKey, err)
  1432  	}
  1433  	for _, pod := range pods {
  1434  		if util.IsPodTerminated(pod, pod.Status) {
  1435  			continue
  1436  		}
  1437  		podNames.Insert(pod.Namespace + "/" + pod.Name)
  1438  	}
  1439  	return podNames.List(), podNames.Len() != 0, nil
  1440  }
  1441  
  1442  // findNonScheduledPodsByPVC returns list of non-scheduled active pods that reference given PVC.
  1443  func (ctrl *PersistentVolumeController) findNonScheduledPodsByPVC(pvc *v1.PersistentVolumeClaim) ([]string, error) {
  1444  	pvcKey := fmt.Sprintf("%s/%s", pvc.Namespace, pvc.Name)
  1445  	pods, err := ctrl.findPodsByPVCKey(pvcKey)
  1446  	if err != nil {
  1447  		return nil, err
  1448  	}
  1449  	podNames := []string{}
  1450  	for _, pod := range pods {
  1451  		if util.IsPodTerminated(pod, pod.Status) {
  1452  			continue
  1453  		}
  1454  		if len(pod.Spec.NodeName) == 0 {
  1455  			podNames = append(podNames, pod.Name)
  1456  		}
  1457  	}
  1458  	return podNames, nil
  1459  }
  1460  
  1461  // doDeleteVolume finds appropriate delete plugin and deletes given volume, returning
  1462  // the volume plugin name. Also, it returns 'true', when the volume was deleted and
  1463  // 'false' when the volume cannot be deleted because the deleter is external. No
  1464  // error should be reported in this case.
  1465  func (ctrl *PersistentVolumeController) doDeleteVolume(ctx context.Context, volume *v1.PersistentVolume) (string, bool, error) {
  1466  	logger := klog.FromContext(ctx)
  1467  	logger.V(4).Info("doDeleteVolume", "volumeName", volume.Name)
  1468  	var err error
  1469  
  1470  	plugin, err := ctrl.findDeletablePlugin(volume)
  1471  	if err != nil {
  1472  		return "", false, err
  1473  	}
  1474  	if plugin == nil {
  1475  		// External deleter is requested, do nothing
  1476  		logger.V(3).Info("External deleter for volume requested, ignoring", "volumeName", volume.Name)
  1477  		return "", false, nil
  1478  	}
  1479  
  1480  	// Plugin found
  1481  	pluginName := plugin.GetPluginName()
  1482  	logger.V(5).Info("Found a deleter plugin for volume", "pluginName", pluginName, "volumeName", volume.Name)
  1483  	spec := vol.NewSpecFromPersistentVolume(volume, false)
  1484  	deleter, err := plugin.NewDeleter(logger, spec)
  1485  	if err != nil {
  1486  		// Cannot create deleter
  1487  		return pluginName, false, fmt.Errorf("failed to create deleter for volume %q: %w", volume.Name, err)
  1488  	}
  1489  
  1490  	opComplete := util.OperationCompleteHook(pluginName, "volume_delete")
  1491  	err = deleter.Delete()
  1492  	opComplete(volumetypes.CompleteFuncParam{Err: &err})
  1493  	if err != nil {
  1494  		// Deleter failed
  1495  		return pluginName, false, err
  1496  	}
  1497  	logger.V(2).Info("Volume deleted", "volumeName", volume.Name)
  1498  	// Remove in-tree delete finalizer on the PV as the volume has been deleted from the underlying storage
  1499  	if utilfeature.DefaultFeatureGate.Enabled(features.HonorPVReclaimPolicy) {
  1500  		err = ctrl.removeDeletionProtectionFinalizer(ctx, volume)
  1501  		if err != nil {
  1502  			return pluginName, true, err
  1503  		}
  1504  	}
  1505  	return pluginName, true, nil
  1506  }
  1507  
  1508  func (ctrl *PersistentVolumeController) removeDeletionProtectionFinalizer(ctx context.Context, volume *v1.PersistentVolume) error {
  1509  	var err error
  1510  	pvUpdateNeeded := false
  1511  	// Retrieve latest version
  1512  	logger := klog.FromContext(ctx)
  1513  	newVolume, err := ctrl.kubeClient.CoreV1().PersistentVolumes().Get(ctx, volume.Name, metav1.GetOptions{})
  1514  	if err != nil {
  1515  		logger.Error(err, "Error reading persistent volume", "volumeName", volume.Name)
  1516  		return err
  1517  	}
  1518  	volume = newVolume
  1519  	volumeClone := volume.DeepCopy()
  1520  	pvFinalizers := volumeClone.Finalizers
  1521  	if pvFinalizers != nil && slice.ContainsString(pvFinalizers, storagehelpers.PVDeletionInTreeProtectionFinalizer, nil) {
  1522  		pvUpdateNeeded = true
  1523  		pvFinalizers = slice.RemoveString(pvFinalizers, storagehelpers.PVDeletionInTreeProtectionFinalizer, nil)
  1524  	}
  1525  	if pvUpdateNeeded {
  1526  		volumeClone.SetFinalizers(pvFinalizers)
  1527  		_, err = ctrl.kubeClient.CoreV1().PersistentVolumes().Update(ctx, volumeClone, metav1.UpdateOptions{})
  1528  		if err != nil {
  1529  			return fmt.Errorf("persistent volume controller can't update finalizer: %v", err)
  1530  		}
  1531  		_, err = ctrl.storeVolumeUpdate(logger, volumeClone)
  1532  		if err != nil {
  1533  			return fmt.Errorf("persistent Volume Controller can't anneal migration finalizer: %v", err)
  1534  		}
  1535  		logger.V(2).Info("PV in-tree protection finalizer removed from volume", "volumeName", volume.Name)
  1536  	}
  1537  	return nil
  1538  }
  1539  
  1540  // provisionClaim starts new asynchronous operation to provision a claim if
  1541  // provisioning is enabled.
  1542  func (ctrl *PersistentVolumeController) provisionClaim(ctx context.Context, claim *v1.PersistentVolumeClaim) error {
  1543  	if !ctrl.enableDynamicProvisioning {
  1544  		return nil
  1545  	}
  1546  	logger := klog.FromContext(ctx)
  1547  	logger.V(4).Info("provisionClaim: started", "PVC", klog.KObj(claim))
  1548  	opName := fmt.Sprintf("provision-%s[%s]", claimToClaimKey(claim), string(claim.UID))
  1549  	plugin, storageClass, err := ctrl.findProvisionablePlugin(claim)
  1550  	// findProvisionablePlugin does not return err for external provisioners
  1551  	if err != nil {
  1552  		ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, err.Error())
  1553  		logger.Error(err, "Error finding provisioning plugin for claim", "PVC", klog.KObj(claim))
  1554  		// failed to find the requested provisioning plugin, directly return err for now.
  1555  		// controller will retry the provisioning in every syncUnboundClaim() call
  1556  		// retain the original behavior of returning nil from provisionClaim call
  1557  		return nil
  1558  	}
  1559  	ctrl.scheduleOperation(logger, opName, func() error {
  1560  		// create a start timestamp entry in cache for provision operation if no one exists with
  1561  		// key = claimKey, pluginName = provisionerName, operation = "provision"
  1562  		claimKey := claimToClaimKey(claim)
  1563  		ctrl.operationTimestamps.AddIfNotExist(claimKey, ctrl.getProvisionerName(plugin, storageClass), "provision")
  1564  		var err error
  1565  		if plugin == nil {
  1566  			_, err = ctrl.provisionClaimOperationExternal(ctx, claim, storageClass)
  1567  		} else {
  1568  			_, err = ctrl.provisionClaimOperation(ctx, claim, plugin, storageClass)
  1569  		}
  1570  		// if error happened, record an error count metric
  1571  		// timestamp entry will remain in cache until a success binding has happened
  1572  		if err != nil {
  1573  			metrics.RecordMetric(claimKey, &ctrl.operationTimestamps, err)
  1574  		}
  1575  		return err
  1576  	})
  1577  	return nil
  1578  }
  1579  
  1580  // provisionClaimOperation provisions a volume. This method is running in
  1581  // standalone goroutine and already has all necessary locks.
  1582  func (ctrl *PersistentVolumeController) provisionClaimOperation(
  1583  	ctx context.Context,
  1584  	claim *v1.PersistentVolumeClaim,
  1585  	plugin vol.ProvisionableVolumePlugin,
  1586  	storageClass *storage.StorageClass) (string, error) {
  1587  	claimClass := storagehelpers.GetPersistentVolumeClaimClass(claim)
  1588  	logger := klog.FromContext(ctx)
  1589  	logger.V(4).Info("provisionClaimOperation started", "PVC", klog.KObj(claim), "storageClassName", claimClass)
  1590  
  1591  	// called from provisionClaim(), in this case, plugin MUST NOT be nil
  1592  	// NOTE: checks on plugin/storageClass has been saved
  1593  	pluginName := plugin.GetPluginName()
  1594  	if pluginName != "kubernetes.io/csi" && claim.Spec.DataSource != nil {
  1595  		// Only CSI plugin can have a DataSource. Fail the operation
  1596  		// if Datasource in Claim is not nil and it is not a CSI plugin,
  1597  		strerr := fmt.Sprintf("plugin %q is not a CSI plugin. Only CSI plugin can provision a claim with a datasource", pluginName)
  1598  		logger.V(2).Info(strerr)
  1599  		ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, strerr)
  1600  		return pluginName, fmt.Errorf(strerr)
  1601  
  1602  	}
  1603  	provisionerName := storageClass.Provisioner
  1604  	logger.V(4).Info("provisionClaimOperation", "PVC", klog.KObj(claim), "pluginName", pluginName, "provisionerName", provisionerName)
  1605  
  1606  	// Add provisioner annotation to be consistent with external provisioner workflow
  1607  	newClaim, err := ctrl.setClaimProvisioner(ctx, claim, provisionerName)
  1608  	if err != nil {
  1609  		// Save failed, the controller will retry in the next sync
  1610  		logger.V(2).Info("Error saving claim", "PVC", klog.KObj(claim), "err", err)
  1611  		return pluginName, err
  1612  	}
  1613  	claim = newClaim
  1614  
  1615  	// internal provisioning
  1616  
  1617  	//  A previous provisionClaimOperation may just have finished while we were waiting for
  1618  	//  the locks. Check that PV (with deterministic name) hasn't been provisioned
  1619  	//  yet.
  1620  
  1621  	pvName := ctrl.getProvisionedVolumeNameForClaim(claim)
  1622  	volume, err := ctrl.kubeClient.CoreV1().PersistentVolumes().Get(ctx, pvName, metav1.GetOptions{})
  1623  	if err != nil && !apierrors.IsNotFound(err) {
  1624  		logger.V(3).Info("Error reading persistent volume", "PV", klog.KRef("", pvName), "err", err)
  1625  		return pluginName, err
  1626  	}
  1627  	if err == nil && volume != nil {
  1628  		// Volume has been already provisioned, nothing to do.
  1629  		logger.V(4).Info("provisionClaimOperation: volume already exists, skipping", "PVC", klog.KObj(claim))
  1630  		return pluginName, err
  1631  	}
  1632  
  1633  	// Prepare a claimRef to the claim early (to fail before a volume is
  1634  	// provisioned)
  1635  	claimRef, err := ref.GetReference(scheme.Scheme, claim)
  1636  	if err != nil {
  1637  		logger.V(3).Info("Unexpected error getting claim reference", "err", err)
  1638  		return pluginName, err
  1639  	}
  1640  
  1641  	options := vol.VolumeOptions{
  1642  		PersistentVolumeReclaimPolicy: *storageClass.ReclaimPolicy,
  1643  		MountOptions:                  storageClass.MountOptions,
  1644  		PVName:                        pvName,
  1645  		PVC:                           claim,
  1646  		Parameters:                    storageClass.Parameters,
  1647  	}
  1648  
  1649  	// Refuse to provision if the plugin doesn't support mount options, creation
  1650  	// of PV would be rejected by validation anyway
  1651  	if !plugin.SupportsMountOption() && len(options.MountOptions) > 0 {
  1652  		strerr := fmt.Sprintf("Mount options are not supported by the provisioner but StorageClass %q has mount options %v", storageClass.Name, options.MountOptions)
  1653  		logger.V(2).Info("Mount options are not supported by the provisioner but claim's StorageClass has mount options", "PVC", klog.KObj(claim), "storageClassName", storageClass.Name, "options", options.MountOptions)
  1654  		ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, strerr)
  1655  		return pluginName, fmt.Errorf("provisioner %q doesn't support mount options", plugin.GetPluginName())
  1656  	}
  1657  
  1658  	// Provision the volume
  1659  	provisioner, err := plugin.NewProvisioner(logger, options)
  1660  	if err != nil {
  1661  		strerr := fmt.Sprintf("Failed to create provisioner: %v", err)
  1662  		logger.V(2).Info("Failed to create provisioner for claim with StorageClass", "PVC", klog.KObj(claim), "storageClassName", storageClass.Name, "err", err)
  1663  		ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, strerr)
  1664  		return pluginName, err
  1665  	}
  1666  
  1667  	var selectedNode *v1.Node = nil
  1668  	if nodeName, ok := claim.Annotations[storagehelpers.AnnSelectedNode]; ok {
  1669  		selectedNode, err = ctrl.NodeLister.Get(nodeName)
  1670  		if err != nil {
  1671  			strerr := fmt.Sprintf("Failed to get target node: %v", err)
  1672  			logger.V(3).Info("Unexpected error getting target node for claim", "node", klog.KRef("", nodeName), "PVC", klog.KObj(claim), "err", err)
  1673  			ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, strerr)
  1674  			return pluginName, err
  1675  		}
  1676  	}
  1677  	allowedTopologies := storageClass.AllowedTopologies
  1678  
  1679  	opComplete := util.OperationCompleteHook(plugin.GetPluginName(), "volume_provision")
  1680  	volume, err = provisioner.Provision(selectedNode, allowedTopologies)
  1681  	opComplete(volumetypes.CompleteFuncParam{Err: &err})
  1682  	if err != nil {
  1683  		// Other places of failure have nothing to do with VolumeScheduling,
  1684  		// so just let controller retry in the next sync. We'll only call func
  1685  		// rescheduleProvisioning here when the underlying provisioning actually failed.
  1686  		ctrl.rescheduleProvisioning(ctx, claim)
  1687  
  1688  		strerr := fmt.Sprintf("Failed to provision volume with StorageClass %q: %v", storageClass.Name, err)
  1689  		logger.V(2).Info("Failed to provision volume for claim with StorageClass", "PVC", klog.KObj(claim), "storageClassName", storageClass.Name, "err", err)
  1690  		ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, strerr)
  1691  		return pluginName, err
  1692  	}
  1693  
  1694  	logger.V(3).Info("Volume for claim created", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1695  
  1696  	// Create Kubernetes PV object for the volume.
  1697  	if volume.Name == "" {
  1698  		volume.Name = pvName
  1699  	}
  1700  	// Bind it to the claim
  1701  	volume.Spec.ClaimRef = claimRef
  1702  	volume.Status.Phase = v1.VolumeBound
  1703  	volume.Spec.StorageClassName = claimClass
  1704  
  1705  	// Add AnnBoundByController (used in deleting the volume)
  1706  	metav1.SetMetaDataAnnotation(&volume.ObjectMeta, storagehelpers.AnnBoundByController, "yes")
  1707  	metav1.SetMetaDataAnnotation(&volume.ObjectMeta, storagehelpers.AnnDynamicallyProvisioned, plugin.GetPluginName())
  1708  
  1709  	if utilfeature.DefaultFeatureGate.Enabled(features.HonorPVReclaimPolicy) {
  1710  		if volume.Spec.PersistentVolumeReclaimPolicy == v1.PersistentVolumeReclaimDelete {
  1711  			// Add In-Tree protection finalizer here only when the reclaim policy is `Delete`
  1712  			volume.SetFinalizers([]string{storagehelpers.PVDeletionInTreeProtectionFinalizer})
  1713  		}
  1714  	}
  1715  
  1716  	// Try to create the PV object several times
  1717  	for i := 0; i < ctrl.createProvisionedPVRetryCount; i++ {
  1718  		logger.V(4).Info("provisionClaimOperation: trying to save volume", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1719  		var newVol *v1.PersistentVolume
  1720  		if newVol, err = ctrl.kubeClient.CoreV1().PersistentVolumes().Create(ctx, volume, metav1.CreateOptions{}); err == nil || apierrors.IsAlreadyExists(err) {
  1721  			// Save succeeded.
  1722  			if err != nil {
  1723  				logger.V(3).Info("Volume for claim already exists, reusing", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1724  				err = nil
  1725  			} else {
  1726  				logger.V(3).Info("Volume for claim saved", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1727  
  1728  				_, updateErr := ctrl.storeVolumeUpdate(logger, newVol)
  1729  				if updateErr != nil {
  1730  					// We will get an "volume added" event soon, this is not a big error
  1731  					logger.V(4).Info("provisionClaimOperation: cannot update internal cache", "volumeName", volume.Name, "err", updateErr)
  1732  				}
  1733  			}
  1734  			break
  1735  		}
  1736  		// Save failed, try again after a while.
  1737  		logger.V(3).Info("Failed to save volume for claim", "PVC", klog.KObj(claim), "volumeName", volume.Name, "err", err)
  1738  		time.Sleep(ctrl.createProvisionedPVInterval)
  1739  	}
  1740  
  1741  	if err != nil {
  1742  		// Save failed. Now we have a storage asset outside of Kubernetes,
  1743  		// but we don't have appropriate PV object for it.
  1744  		// Emit some event here and try to delete the storage asset several
  1745  		// times.
  1746  		strerr := fmt.Sprintf("Error creating provisioned PV object for claim %s: %v. Deleting the volume.", claimToClaimKey(claim), err)
  1747  		logger.V(3).Info(strerr)
  1748  		ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, strerr)
  1749  
  1750  		var deleteErr error
  1751  		var deleted bool
  1752  		for i := 0; i < ctrl.createProvisionedPVRetryCount; i++ {
  1753  			_, deleted, deleteErr = ctrl.doDeleteVolume(ctx, volume)
  1754  			if deleteErr == nil && deleted {
  1755  				// Delete succeeded
  1756  				logger.V(4).Info("provisionClaimOperation: cleaning volume succeeded", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1757  				break
  1758  			}
  1759  			if !deleted {
  1760  				// This is unreachable code, the volume was provisioned by an
  1761  				// internal plugin and therefore there MUST be an internal
  1762  				// plugin that deletes it.
  1763  				logger.Error(nil, "Error finding internal deleter for volume plugin", "plugin", plugin.GetPluginName())
  1764  				break
  1765  			}
  1766  			// Delete failed, try again after a while.
  1767  			logger.V(3).Info("Failed to delete volume", "volumeName", volume.Name, "err", deleteErr)
  1768  			time.Sleep(ctrl.createProvisionedPVInterval)
  1769  		}
  1770  
  1771  		if deleteErr != nil {
  1772  			// Delete failed several times. There is an orphaned volume and there
  1773  			// is nothing we can do about it.
  1774  			strerr := fmt.Sprintf("Error cleaning provisioned volume for claim %s: %v. Please delete manually.", claimToClaimKey(claim), deleteErr)
  1775  			logger.V(2).Info(strerr)
  1776  			ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningCleanupFailed, strerr)
  1777  		}
  1778  	} else {
  1779  		logger.V(2).Info("Volume provisioned for claim", "PVC", klog.KObj(claim), "volumeName", volume.Name)
  1780  		msg := fmt.Sprintf("Successfully provisioned volume %s using %s", volume.Name, plugin.GetPluginName())
  1781  		ctrl.eventRecorder.Event(claim, v1.EventTypeNormal, events.ProvisioningSucceeded, msg)
  1782  	}
  1783  	return pluginName, nil
  1784  }
  1785  
  1786  // provisionClaimOperationExternal provisions a volume using external provisioner async-ly
  1787  // This method will be running in a standalone go-routine scheduled in "provisionClaim"
  1788  func (ctrl *PersistentVolumeController) provisionClaimOperationExternal(
  1789  	ctx context.Context,
  1790  	claim *v1.PersistentVolumeClaim,
  1791  	storageClass *storage.StorageClass) (string, error) {
  1792  	claimClass := storagehelpers.GetPersistentVolumeClaimClass(claim)
  1793  	logger := klog.FromContext(ctx)
  1794  	logger.V(4).Info("provisionClaimOperationExternal started", "PVC", klog.KObj(claim), "storageClassName", claimClass)
  1795  	// Set provisionerName to external provisioner name by setClaimProvisioner
  1796  	var err error
  1797  	provisionerName := storageClass.Provisioner
  1798  	if ctrl.csiMigratedPluginManager.IsMigrationEnabledForPlugin(storageClass.Provisioner) {
  1799  		// update the provisioner name to use the migrated CSI plugin name
  1800  		provisionerName, err = ctrl.translator.GetCSINameFromInTreeName(storageClass.Provisioner)
  1801  		if err != nil {
  1802  			strerr := fmt.Sprintf("error getting CSI name for In tree plugin %s: %v", storageClass.Provisioner, err)
  1803  			logger.V(2).Info(strerr)
  1804  			ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, strerr)
  1805  			return provisionerName, err
  1806  		}
  1807  	}
  1808  	// Add provisioner annotation so external provisioners know when to start
  1809  	newClaim, err := ctrl.setClaimProvisioner(ctx, claim, provisionerName)
  1810  	if err != nil {
  1811  		// Save failed, the controller will retry in the next sync
  1812  		strerr := fmt.Sprintf("Error saving claim: %v", err)
  1813  		logger.V(2).Info("Error saving claim", "PVC", klog.KObj(claim), "err", err)
  1814  		ctrl.eventRecorder.Event(claim, v1.EventTypeWarning, events.ProvisioningFailed, strerr)
  1815  		return provisionerName, err
  1816  	}
  1817  	claim = newClaim
  1818  	msg := fmt.Sprintf("Waiting for a volume to be created either by the external provisioner '%s' "+
  1819  		"or manually by the system administrator. If volume creation is delayed, please verify that "+
  1820  		"the provisioner is running and correctly registered.", provisionerName)
  1821  	// External provisioner has been requested for provisioning the volume
  1822  	// Report an event and wait for external provisioner to finish
  1823  	ctrl.eventRecorder.Event(claim, v1.EventTypeNormal, events.ExternalProvisioning, msg)
  1824  	logger.V(3).Info("provisionClaimOperationExternal provisioning claim", "PVC", klog.KObj(claim), "msg", msg)
  1825  	// return provisioner name here for metric reporting
  1826  	return provisionerName, nil
  1827  }
  1828  
  1829  // rescheduleProvisioning signal back to the scheduler to retry dynamic provisioning
  1830  // by removing the AnnSelectedNode annotation
  1831  func (ctrl *PersistentVolumeController) rescheduleProvisioning(ctx context.Context, claim *v1.PersistentVolumeClaim) {
  1832  	if _, ok := claim.Annotations[storagehelpers.AnnSelectedNode]; !ok {
  1833  		// Provisioning not triggered by the scheduler, skip
  1834  		return
  1835  	}
  1836  
  1837  	// The claim from method args can be pointing to watcher cache. We must not
  1838  	// modify these, therefore create a copy.
  1839  	newClaim := claim.DeepCopy()
  1840  	delete(newClaim.Annotations, storagehelpers.AnnSelectedNode)
  1841  	// Try to update the PVC object
  1842  	logger := klog.FromContext(ctx)
  1843  	if _, err := ctrl.kubeClient.CoreV1().PersistentVolumeClaims(newClaim.Namespace).Update(ctx, newClaim, metav1.UpdateOptions{}); err != nil {
  1844  		logger.V(4).Info("Failed to delete annotation 'storagehelpers.AnnSelectedNode' for PersistentVolumeClaim", "PVC", klog.KObj(newClaim), "err", err)
  1845  		return
  1846  	}
  1847  	if _, err := ctrl.storeClaimUpdate(logger, newClaim); err != nil {
  1848  		// We will get an "claim updated" event soon, this is not a big error
  1849  		logger.V(4).Info("Updating PersistentVolumeClaim: cannot update internal cache", "PVC", klog.KObj(newClaim), "err", err)
  1850  	}
  1851  }
  1852  
  1853  // getProvisionedVolumeNameForClaim returns PV.Name for the provisioned volume.
  1854  // The name must be unique.
  1855  func (ctrl *PersistentVolumeController) getProvisionedVolumeNameForClaim(claim *v1.PersistentVolumeClaim) string {
  1856  	return "pvc-" + string(claim.UID)
  1857  }
  1858  
  1859  // scheduleOperation starts given asynchronous operation on given volume. It
  1860  // makes sure the operation is already not running.
  1861  func (ctrl *PersistentVolumeController) scheduleOperation(logger klog.Logger, operationName string, operation func() error) {
  1862  	logger.V(4).Info("scheduleOperation", "operationName", operationName)
  1863  
  1864  	// Poke test code that an operation is just about to get started.
  1865  	if ctrl.preOperationHook != nil {
  1866  		ctrl.preOperationHook(operationName)
  1867  	}
  1868  
  1869  	err := ctrl.runningOperations.Run(operationName, operation)
  1870  	if err != nil {
  1871  		switch {
  1872  		case goroutinemap.IsAlreadyExists(err):
  1873  			logger.V(4).Info("Operation is already running, skipping", "operationName", operationName)
  1874  		case exponentialbackoff.IsExponentialBackoff(err):
  1875  			logger.V(4).Info("Operation postponed due to exponential backoff", "operationName", operationName)
  1876  		default:
  1877  			logger.Error(err, "Error scheduling operation", "operationName", operationName)
  1878  		}
  1879  	}
  1880  }
  1881  
  1882  // newRecyclerEventRecorder returns a RecycleEventRecorder that sends all events
  1883  // to given volume.
  1884  func (ctrl *PersistentVolumeController) newRecyclerEventRecorder(volume *v1.PersistentVolume) recyclerclient.RecycleEventRecorder {
  1885  	return func(eventtype, message string) {
  1886  		ctrl.eventRecorder.Eventf(volume, eventtype, events.RecyclerPod, "Recycler pod: %s", message)
  1887  	}
  1888  }
  1889  
  1890  // findProvisionablePlugin finds a provisioner plugin for a given claim.
  1891  // It returns either the provisioning plugin or nil when an external
  1892  // provisioner is requested.
  1893  func (ctrl *PersistentVolumeController) findProvisionablePlugin(claim *v1.PersistentVolumeClaim) (vol.ProvisionableVolumePlugin, *storage.StorageClass, error) {
  1894  	// provisionClaim() which leads here is never called with claimClass=="", we
  1895  	// can save some checks.
  1896  	claimClass := storagehelpers.GetPersistentVolumeClaimClass(claim)
  1897  	class, err := ctrl.classLister.Get(claimClass)
  1898  	if err != nil {
  1899  		return nil, nil, err
  1900  	}
  1901  
  1902  	// Find a plugin for the class
  1903  	if ctrl.csiMigratedPluginManager.IsMigrationEnabledForPlugin(class.Provisioner) {
  1904  		// CSI migration scenario - do not depend on in-tree plugin
  1905  		return nil, class, nil
  1906  	}
  1907  	plugin, err := ctrl.volumePluginMgr.FindProvisionablePluginByName(class.Provisioner)
  1908  	if err != nil {
  1909  		if !strings.HasPrefix(class.Provisioner, "kubernetes.io/") {
  1910  			// External provisioner is requested, do not report error
  1911  			return nil, class, nil
  1912  		}
  1913  		return nil, class, err
  1914  	}
  1915  	return plugin, class, nil
  1916  }
  1917  
  1918  // findDeletablePlugin finds a deleter plugin for a given volume. It returns
  1919  // either the deleter plugin or nil when an external deleter is requested.
  1920  func (ctrl *PersistentVolumeController) findDeletablePlugin(volume *v1.PersistentVolume) (vol.DeletableVolumePlugin, error) {
  1921  	// Find a plugin. Try to find the same plugin that provisioned the volume
  1922  	var plugin vol.DeletableVolumePlugin
  1923  	if metav1.HasAnnotation(volume.ObjectMeta, storagehelpers.AnnDynamicallyProvisioned) {
  1924  		provisionPluginName := volume.Annotations[storagehelpers.AnnDynamicallyProvisioned]
  1925  		if provisionPluginName != "" {
  1926  			plugin, err := ctrl.volumePluginMgr.FindDeletablePluginByName(provisionPluginName)
  1927  			if err != nil {
  1928  				if !strings.HasPrefix(provisionPluginName, "kubernetes.io/") {
  1929  					// External provisioner is requested, do not report error
  1930  					return nil, nil
  1931  				}
  1932  				return nil, err
  1933  			}
  1934  			return plugin, nil
  1935  		}
  1936  	}
  1937  
  1938  	if utilfeature.DefaultFeatureGate.Enabled(features.HonorPVReclaimPolicy) {
  1939  		if metav1.HasAnnotation(volume.ObjectMeta, storagehelpers.AnnMigratedTo) {
  1940  			// CSI migration scenario - do not depend on in-tree plugin
  1941  			return nil, nil
  1942  		}
  1943  
  1944  		if volume.Spec.CSI != nil {
  1945  			// CSI volume source scenario - external provisioner is requested
  1946  			return nil, nil
  1947  		}
  1948  	}
  1949  
  1950  	// The plugin that provisioned the volume was not found or the volume
  1951  	// was not dynamically provisioned. Try to find a plugin by spec.
  1952  	spec := vol.NewSpecFromPersistentVolume(volume, false)
  1953  	plugin, err := ctrl.volumePluginMgr.FindDeletablePluginBySpec(spec)
  1954  	if err != nil {
  1955  		// No deleter found. Emit an event and mark the volume Failed.
  1956  		return nil, fmt.Errorf("error getting deleter volume plugin for volume %q: %w", volume.Name, err)
  1957  	}
  1958  	return plugin, nil
  1959  }
  1960  
  1961  // obtain provisioner/deleter name for a volume
  1962  func (ctrl *PersistentVolumeController) getProvisionerNameFromVolume(volume *v1.PersistentVolume) string {
  1963  	plugin, err := ctrl.findDeletablePlugin(volume)
  1964  	if err != nil {
  1965  		return "N/A"
  1966  	}
  1967  	if plugin != nil {
  1968  		return plugin.GetPluginName()
  1969  	}
  1970  	// If reached here, Either an external provisioner was used for provisioning
  1971  	// or a plugin has been migrated to CSI.
  1972  	// If an external provisioner was used, i.e., plugin == nil, instead of using
  1973  	// the AnnDynamicallyProvisioned annotation value, use the storageClass's Provisioner
  1974  	// field to avoid explosion of the metric in the cases like local storage provisioner
  1975  	// tagging a volume with arbitrary provisioner names
  1976  	storageClass := storagehelpers.GetPersistentVolumeClass(volume)
  1977  	class, err := ctrl.classLister.Get(storageClass)
  1978  	if err != nil {
  1979  		return "N/A"
  1980  	}
  1981  	if ctrl.csiMigratedPluginManager.IsMigrationEnabledForPlugin(class.Provisioner) {
  1982  		provisionerName, err := ctrl.translator.GetCSINameFromInTreeName(class.Provisioner)
  1983  		if err != nil {
  1984  			return "N/A"
  1985  		}
  1986  		return provisionerName
  1987  	}
  1988  	return class.Provisioner
  1989  }
  1990  
  1991  // obtain plugin/external provisioner name from plugin and storage class for timestamp logging purposes
  1992  func (ctrl *PersistentVolumeController) getProvisionerName(plugin vol.ProvisionableVolumePlugin, storageClass *storage.StorageClass) string {
  1993  	// non CSI-migrated in-tree plugin, returns the plugin's name
  1994  	if plugin != nil {
  1995  		return plugin.GetPluginName()
  1996  	}
  1997  	if ctrl.csiMigratedPluginManager.IsMigrationEnabledForPlugin(storageClass.Provisioner) {
  1998  		// get the name of the CSI plugin that the in-tree storage class
  1999  		// provisioner has migrated to
  2000  		provisionerName, err := ctrl.translator.GetCSINameFromInTreeName(storageClass.Provisioner)
  2001  		if err != nil {
  2002  			return "N/A"
  2003  		}
  2004  		return provisionerName
  2005  	}
  2006  	return storageClass.Provisioner
  2007  }