This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 2 failed / 1939 succeeded
Started2021-06-23 21:43
Elapsed32m18s
Revisionrelease-1.20

Test Failures


//pkg/controller/volume/attachdetach/go_default_test:run_1_of_2 0.00s

bazel test //pkg/controller/volume/attachdetach/go_default_test:run_1_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/controller/volume/attachdetach:go_default_test
-----------------------------------------------------------------------------
I0623 22:09:49.114173  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:49.224527  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:49.235834  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:49.236015  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:49.236499  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:49.238191  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:49.238318  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:49.238706  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:49.240403  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:49.240529  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:49.240884  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:49.242625  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:49.242751  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:49.242923  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:49.244460  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:49.244587  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:49.244743  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:49.245990  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.246367  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:49.246785  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.246969  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.247162  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.247353  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.247454  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:51.229934  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:51.334335  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:51.343055  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:51.343378  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:51.343557  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:51.344619  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:51.344846  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:51.344975  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:51.346058  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:51.346174  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:51.346302  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:51.347461  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:51.347910  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:51.348025  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:51.349048  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:51.349157  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:51.349399  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:51.349744  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:51.349977  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:51.354490  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:51.354656  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.354950  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.355134  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.355426  245902 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0623 22:09:51.355707  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.355941  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.354521  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:53.340006  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:53.443173  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:53.454843  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:53.455016  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:53.455157  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:53.456054  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:53.456174  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:53.456296  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:53.457368  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:53.457463  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:53.457618  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:53.458587  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:53.458795  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:53.458925  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:53.459888  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:53.459966  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:53.460130  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:53.461269  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:53.461927  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.462126  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.462296  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.462462  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.462622  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.464850  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:53.465578  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:53.465823  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:53.465840  245902 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0623 22:09:55.451594  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:55.558121  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:55.565445  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:55.565542  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:55.565694  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:55.566880  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:55.567076  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:55.567206  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:55.568084  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:55.568291  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:55.568432  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:55.569457  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:55.569677  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:55.569799  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:55.570753  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:55.570869  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:55.570993  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:55.571126  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:55.571348  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0623 22:09:55.571676  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:55.571839  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:55.572272  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0623 22:09:55.572446  245902 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0623 22:09:55.572744  245902 event.go:291] "Event occurred" object="mynamespace/newpod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName3\" "
I0623 22:09:55.572767  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:55.573079  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:55.573276  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:55.573454  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:55.573607  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:55.573743  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.564375  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:57.670311  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:57.680536  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:57.680791  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:57.680901  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:57.681900  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:57.682114  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:57.682212  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:57.683126  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:57.683247  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:57.683341  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:57.684346  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:57.684434  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:57.684520  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:57.685580  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:57.685754  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:57.685844  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:57.685942  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:57.686163  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0623 22:09:57.686628  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0623 22:09:57.687063  245902 event.go:291] "Event occurred" object="mynamespace/pod1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"vol1\" "
I0623 22:09:57.687222  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:57.687532  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.687711  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.687897  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.688050  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.688214  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.677067  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:58.781179  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:58.795734  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:58.795918  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:58.796891  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:58.798712  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:58.798871  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:58.800912  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:58.803023  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:58.803163  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:58.805446  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:58.806988  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:58.808420  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:58.808879  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:58.810114  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:58.810904  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:58.811032  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:58.811345  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:58.811794  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:58.812301  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.812588  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.817622  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.817785  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.817939  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.720018  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:09:59.720213  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:09:59.720354  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:09:59.790547  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:59.895405  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:59.901401  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:59.901635  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:59.901772  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:59.902592  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:59.902729  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:59.902840  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:59.903667  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:59.903769  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:59.903895  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:59.904808  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:59.905001  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:59.905139  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:59.905926  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:59.906075  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:59.906212  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:59.906271  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:59.907384  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:59.908209  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.908435  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.908775  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.908974  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.909130  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:10:00.812064  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:10:00.812272  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:10:00.812420  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:10:00.902369  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:10:01.003074  245902 shared_informer.go:247] Caches are synced for attach detach 
W0623 22:10:01.007960  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolume ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.008253  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.Pod ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.009798  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.CSINode ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.010331  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.VolumeAttachment ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.008498  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.CSIDriver ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.010661  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.Node ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
E0623 22:10:01.014947  245902 reconciler.go:228] attacherDetacher.DetachVolume failed to start for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" : DetachVolume.FindAttachablePluginByName failed for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" : no volume plugin matched name: kubernetes.io/testPlugin
I0623 22:10:01.016220  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
E0623 22:10:01.016443  245902 reconciler.go:228] attacherDetacher.DetachVolume failed to start for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" : DetachVolume.FindAttachablePluginByName failed for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" : no volume plugin matched name: kubernetes.io/testPlugin
E0623 22:10:01.020334  245902 reconciler.go:228] attacherDetacher.DetachVolume failed to start for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" : DetachVolume.FindAttachablePluginByName failed for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" : no volume plugin matched name: kubernetes.io/testPlugin
E0623 22:10:01.028303  245902 reconciler.go:228] attacherDetacher.DetachVolume failed to start for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" : DetachVolume.FindAttachablePluginByName failed for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" : no volume plugin matched name: kubernetes.io/testPlugin
I0623 22:10:01.032245  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/vol1") on node "mynode-1" 
I0623 22:10:01.032852  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "pd.csi.storage.gke.io-pdName" (UniqueName: "kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/pdName") from node "mynode" 
I0623 22:10:01.033184  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/vol1") on node "mynode-1" 
E0623 22:10:01.033577  245902 csi_attacher.go:455] [attachment.ID=csi-77bd5b88d32d48e5a31f0073211a7dd54ed0066f008e12364f4b6ecb61dc7370] watch channel had been closed
==================
WARNING: DATA RACE
Write at 0x00c000310598 by goroutine 184:
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/testing.CreateTestClient.func7()
      pkg/controller/volume/attachdetach/testing/testvolumespec.go:185 +0x207
  k8s.io/kubernetes/vendor/k8s.io/client-go/testing.(*SimpleReactor).React()
      staging/src/k8s.io/client-go/testing/fixture.go:521 +0x68
  k8s.io/kubernetes/vendor/k8s.io/client-go/testing.(*Fake).Invokes()
      staging/src/k8s.io/client-go/testing/fake.go:141 +0x327
  k8s.io/kubernetes/vendor/k8s.io/client-go/kubernetes/typed/storage/v1/fake.(*FakeVolumeAttachments).Create()
      staging/src/k8s.io/client-go/kubernetes/typed/storage/v1/fake/fake_volumeattachment.go:82 +0x246
  k8s.io/kubernetes/pkg/volume/csi.(*csiAttacher).Attach()
      pkg/volume/csi/csi_attacher.go:109 +0x5f3
  k8s.io/kubernetes/pkg/volume/util/operationexecutor.(*operationGenerator).GenerateAttachVolumeFunc.func1()
      pkg/volume/util/operationexecutor/operation_generator.go:335 +0x275
  k8s.io/kubernetes/pkg/volume/util/types.(*GeneratedOperations).Run()
      pkg/volume/util/types/types.go:54 +0x142
  k8s.io/kubernetes/pkg/volume/util/nestedpendingoperations.(*nestedPendingOperations).Run.func1()
      pkg/volume/util/nestedpendingoperations/nestedpendingoperations.go:183 +0x159

Previous read at 0x00c000310598 by goroutine 66:
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/testing.CreateTestClient.func6()
      pkg/controller/volume/attachdetach/testing/testvolumespec.go:179 +0x104
  k8s.io/kubernetes/vendor/k8s.io/client-go/testing.(*SimpleReactor).React()
      staging/src/k8s.io/client-go/testing/fixture.go:521 +0x68
  k8s.io/kubernetes/vendor/k8s.io/client-go/testing.(*Fake).Invokes()
      staging/src/k8s.io/client-go/testing/fake.go:141 +0x327
  k8s.io/kubernetes/vendor/k8s.io/client-go/kubernetes/typed/storage/v1/fake.(*FakeVolumeAttachments).List()
      staging/src/k8s.io/client-go/kubernetes/typed/storage/v1/fake/fake_volumeattachment.go:55 +0x273
  k8s.io/kubernetes/vendor/k8s.io/client-go/informers/storage/v1.NewFilteredVolumeAttachmentInformer.func1()
      staging/src/k8s.io/client-go/informers/storage/v1/volumeattachment.go:64 +0x23c
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*ListWatch).List()
      staging/src/k8s.io/client-go/tools/cache/listwatch.go:106 +0x97
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch.func1.1.2()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:277 +0xf4
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/pager.SimplePageFunc.func1()
      staging/src/k8s.io/client-go/tools/pager/pager.go:40 +0x97
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/pager.(*ListPager).List()
      staging/src/k8s.io/client-go/tools/pager/pager.go:91 +0x1e2
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch.func1.1()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:302 +0x2b7

Goroutine 184 (running) created at:
  k8s.io/kubernetes/pkg/volume/util/nestedpendingoperations.(*nestedPendingOperations).Run()
      pkg/volume/util/nestedpendingoperations/nestedpendingoperations.go:178 +0x5b2
  k8s.io/kubernetes/pkg/volume/util/operationexecutor.(*operationExecutor).AttachVolume()
      pkg/volume/util/operationexecutor/operation_executor.go:675 +0x348
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/reconciler.(*reconciler).attachDesiredVolumes()
      pkg/controller/volume/attachdetach/reconciler/reconciler.go:293 +0x639
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/reconciler.(*reconciler).reconcile()
      pkg/controller/volume/attachdetach/reconciler/reconciler.go:233 +0x1b9
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/reconciler.(*reconciler).reconciliationLoopFunc.func1()
      pkg/controller/volume/attachdetach/reconciler/reconciler.go:110 +0x5e
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:155 +0x75
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:156 +0xba
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:133 +0x114
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.Until()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:90 +0x89
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/reconciler.(*reconciler).Run()
      pkg/controller/volume/attachdetach/reconciler/reconciler.go:101 +0x2f

Goroutine 66 (finished) created at:
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch.func1()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:268 +0x36f
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:360 +0x2e4
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).Run.func1()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:221 +0x53
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:155 +0x75
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:156 +0xba
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).Run()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:220 +0x2c4
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).Run-fm()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:218 +0x4b
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.(*Group).StartWithChannel.func1()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:56 +0x45
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.(*Group).Start.func1()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:73 +0x6d
==================
E0623 22:10:01.034170  245902 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/vol1 podName: nodeName:mynode-1}" failed. No retries permitted until 2021-06-23 22:10:01.533870959 +0000 UTC m=+12.591183555 (durationBeforeRetry 500ms). Error: "DetachVolume.Detach failed for volume \"nil\" (UniqueName: \"kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/vol1\") on node \"mynode-1\" : volume attachment watch channel had been closed"
E0623 22:10:01.034323  245902 csi_attacher.go:455] [attachment.ID=csi-4ff6fd4b10c02f804e7435dffeb62054338b590749cdaacf18e198ee0ab6dd66] watch channel had been closed
I0623 22:10:01.035227  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
I0623 22:10:01.035705  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
E0623 22:10:01.035975  245902 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/pdName podName: nodeName:}" failed. No retries permitted until 2021-06-23 22:10:01.535683656 +0000 UTC m=+12.592996252 (durationBeforeRetry 500ms). Error: "AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" (UniqueName: \"kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/pdName\") from node \"mynode\" : volume attachment watch channel had been closed"
I0623 22:10:01.035979  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
I0623 22:10:01.036527  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
I0623 22:10:01.036811  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
I0623 22:10:01.116889  245902 shared_informer.go:247] Caches are synced for attach detach 
W0623 22:10:01.119181  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolume ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.119411  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.Pod ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.119454  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolumeClaim ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
--- FAIL: Test_ADC_VolumeAttachmentRecovery (3.56s)
    --- FAIL: Test_ADC_VolumeAttachmentRecovery/Deleted_Pod_with_migrated_PV (0.11s)
        testing.go:1038: race detected during execution of test
    testing.go:1038: race detected during execution of test
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


//pkg/controller/volume/attachdetach/go_default_test:run_1_of_2 0.00s

bazel test //pkg/controller/volume/attachdetach/go_default_test:run_1_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/controller/volume/attachdetach:go_default_test
-----------------------------------------------------------------------------
I0623 22:09:49.114173  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:49.224527  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:49.235834  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:49.236015  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:49.236499  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:49.238191  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:49.238318  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:49.238706  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:49.240403  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:49.240529  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:49.240884  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:49.242625  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:49.242751  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:49.242923  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:49.244460  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:49.244587  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:49.244743  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:49.245990  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.246367  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:49.246785  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.246969  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.247162  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.247353  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:49.247454  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:51.229934  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:51.334335  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:51.343055  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:51.343378  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:51.343557  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:51.344619  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:51.344846  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:51.344975  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:51.346058  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:51.346174  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:51.346302  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:51.347461  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:51.347910  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:51.348025  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:51.349048  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:51.349157  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:51.349399  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:51.349744  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:51.349977  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:51.354490  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:51.354656  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.354950  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.355134  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.355426  245902 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0623 22:09:51.355707  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.355941  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:51.354521  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:53.340006  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:53.443173  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:53.454843  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:53.455016  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:53.455157  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:53.456054  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:53.456174  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:53.456296  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:53.457368  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:53.457463  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:53.457618  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:53.458587  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:53.458795  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:53.458925  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:53.459888  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:53.459966  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:53.460130  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:53.461269  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:53.461927  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.462126  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.462296  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.462462  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.462622  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:53.464850  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:53.465578  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:53.465823  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:53.465840  245902 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0623 22:09:55.451594  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:55.558121  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:55.565445  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:55.565542  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:55.565694  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:55.566880  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:55.567076  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:55.567206  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:55.568084  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:55.568291  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:55.568432  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:55.569457  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:55.569677  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:55.569799  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:55.570753  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:55.570869  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:55.570993  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:55.571126  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:55.571348  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0623 22:09:55.571676  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:55.571839  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0623 22:09:55.572272  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0623 22:09:55.572446  245902 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0623 22:09:55.572744  245902 event.go:291] "Event occurred" object="mynamespace/newpod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName3\" "
I0623 22:09:55.572767  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:55.573079  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:55.573276  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:55.573454  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:55.573607  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:55.573743  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.564375  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:57.670311  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:57.680536  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:57.680791  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:57.680901  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:57.681900  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:57.682114  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:57.682212  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:57.683126  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:57.683247  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:57.683341  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:57.684346  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:57.684434  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:57.684520  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:57.685580  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:57.685754  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:57.685844  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:57.685942  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:57.686163  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0623 22:09:57.686628  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0623 22:09:57.687063  245902 event.go:291] "Event occurred" object="mynamespace/pod1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"vol1\" "
I0623 22:09:57.687222  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:57.687532  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.687711  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.687897  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.688050  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:57.688214  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.677067  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:58.781179  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:58.795734  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:58.795918  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:58.796891  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:58.798712  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:58.798871  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:58.800912  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:58.803023  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:58.803163  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:58.805446  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:58.806988  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:58.808420  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:58.808879  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:58.810114  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:58.810904  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:58.811032  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:58.811345  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:58.811794  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:58.812301  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.812588  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.817622  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.817785  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:58.817939  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.720018  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:09:59.720213  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:09:59.720354  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:09:59.790547  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:09:59.895405  245902 shared_informer.go:247] Caches are synced for attach detach 
I0623 22:09:59.901401  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:59.901635  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:59.901772  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0623 22:09:59.902592  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:59.902729  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:59.902840  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0623 22:09:59.903667  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:59.903769  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:59.903895  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0623 22:09:59.904808  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:59.905001  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:59.905139  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0623 22:09:59.905926  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:59.906075  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:59.906212  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0623 22:09:59.906271  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:59.907384  245902 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0623 22:09:59.908209  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.908435  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.908775  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.908974  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:09:59.909130  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0623 22:10:00.812064  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:10:00.812272  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:10:00.812420  245902 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0623 22:10:00.902369  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
I0623 22:10:01.003074  245902 shared_informer.go:247] Caches are synced for attach detach 
W0623 22:10:01.007960  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolume ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.008253  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.Pod ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.009798  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.CSINode ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.010331  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.VolumeAttachment ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.008498  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.CSIDriver ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.010661  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.Node ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
E0623 22:10:01.014947  245902 reconciler.go:228] attacherDetacher.DetachVolume failed to start for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" : DetachVolume.FindAttachablePluginByName failed for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" : no volume plugin matched name: kubernetes.io/testPlugin
I0623 22:10:01.016220  245902 shared_informer.go:240] Waiting for caches to sync for attach detach
E0623 22:10:01.016443  245902 reconciler.go:228] attacherDetacher.DetachVolume failed to start for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" : DetachVolume.FindAttachablePluginByName failed for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" : no volume plugin matched name: kubernetes.io/testPlugin
E0623 22:10:01.020334  245902 reconciler.go:228] attacherDetacher.DetachVolume failed to start for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" : DetachVolume.FindAttachablePluginByName failed for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" : no volume plugin matched name: kubernetes.io/testPlugin
E0623 22:10:01.028303  245902 reconciler.go:228] attacherDetacher.DetachVolume failed to start for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" : DetachVolume.FindAttachablePluginByName failed for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" : no volume plugin matched name: kubernetes.io/testPlugin
I0623 22:10:01.032245  245902 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/vol1") on node "mynode-1" 
I0623 22:10:01.032852  245902 reconciler.go:295] attacherDetacher.AttachVolume started for volume "pd.csi.storage.gke.io-pdName" (UniqueName: "kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/pdName") from node "mynode" 
I0623 22:10:01.033184  245902 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/vol1") on node "mynode-1" 
E0623 22:10:01.033577  245902 csi_attacher.go:455] [attachment.ID=csi-77bd5b88d32d48e5a31f0073211a7dd54ed0066f008e12364f4b6ecb61dc7370] watch channel had been closed
==================
WARNING: DATA RACE
Write at 0x00c000310598 by goroutine 184:
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/testing.CreateTestClient.func7()
      pkg/controller/volume/attachdetach/testing/testvolumespec.go:185 +0x207
  k8s.io/kubernetes/vendor/k8s.io/client-go/testing.(*SimpleReactor).React()
      staging/src/k8s.io/client-go/testing/fixture.go:521 +0x68
  k8s.io/kubernetes/vendor/k8s.io/client-go/testing.(*Fake).Invokes()
      staging/src/k8s.io/client-go/testing/fake.go:141 +0x327
  k8s.io/kubernetes/vendor/k8s.io/client-go/kubernetes/typed/storage/v1/fake.(*FakeVolumeAttachments).Create()
      staging/src/k8s.io/client-go/kubernetes/typed/storage/v1/fake/fake_volumeattachment.go:82 +0x246
  k8s.io/kubernetes/pkg/volume/csi.(*csiAttacher).Attach()
      pkg/volume/csi/csi_attacher.go:109 +0x5f3
  k8s.io/kubernetes/pkg/volume/util/operationexecutor.(*operationGenerator).GenerateAttachVolumeFunc.func1()
      pkg/volume/util/operationexecutor/operation_generator.go:335 +0x275
  k8s.io/kubernetes/pkg/volume/util/types.(*GeneratedOperations).Run()
      pkg/volume/util/types/types.go:54 +0x142
  k8s.io/kubernetes/pkg/volume/util/nestedpendingoperations.(*nestedPendingOperations).Run.func1()
      pkg/volume/util/nestedpendingoperations/nestedpendingoperations.go:183 +0x159

Previous read at 0x00c000310598 by goroutine 66:
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/testing.CreateTestClient.func6()
      pkg/controller/volume/attachdetach/testing/testvolumespec.go:179 +0x104
  k8s.io/kubernetes/vendor/k8s.io/client-go/testing.(*SimpleReactor).React()
      staging/src/k8s.io/client-go/testing/fixture.go:521 +0x68
  k8s.io/kubernetes/vendor/k8s.io/client-go/testing.(*Fake).Invokes()
      staging/src/k8s.io/client-go/testing/fake.go:141 +0x327
  k8s.io/kubernetes/vendor/k8s.io/client-go/kubernetes/typed/storage/v1/fake.(*FakeVolumeAttachments).List()
      staging/src/k8s.io/client-go/kubernetes/typed/storage/v1/fake/fake_volumeattachment.go:55 +0x273
  k8s.io/kubernetes/vendor/k8s.io/client-go/informers/storage/v1.NewFilteredVolumeAttachmentInformer.func1()
      staging/src/k8s.io/client-go/informers/storage/v1/volumeattachment.go:64 +0x23c
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*ListWatch).List()
      staging/src/k8s.io/client-go/tools/cache/listwatch.go:106 +0x97
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch.func1.1.2()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:277 +0xf4
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/pager.SimplePageFunc.func1()
      staging/src/k8s.io/client-go/tools/pager/pager.go:40 +0x97
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/pager.(*ListPager).List()
      staging/src/k8s.io/client-go/tools/pager/pager.go:91 +0x1e2
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch.func1.1()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:302 +0x2b7

Goroutine 184 (running) created at:
  k8s.io/kubernetes/pkg/volume/util/nestedpendingoperations.(*nestedPendingOperations).Run()
      pkg/volume/util/nestedpendingoperations/nestedpendingoperations.go:178 +0x5b2
  k8s.io/kubernetes/pkg/volume/util/operationexecutor.(*operationExecutor).AttachVolume()
      pkg/volume/util/operationexecutor/operation_executor.go:675 +0x348
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/reconciler.(*reconciler).attachDesiredVolumes()
      pkg/controller/volume/attachdetach/reconciler/reconciler.go:293 +0x639
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/reconciler.(*reconciler).reconcile()
      pkg/controller/volume/attachdetach/reconciler/reconciler.go:233 +0x1b9
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/reconciler.(*reconciler).reconciliationLoopFunc.func1()
      pkg/controller/volume/attachdetach/reconciler/reconciler.go:110 +0x5e
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:155 +0x75
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:156 +0xba
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:133 +0x114
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.Until()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:90 +0x89
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/reconciler.(*reconciler).Run()
      pkg/controller/volume/attachdetach/reconciler/reconciler.go:101 +0x2f

Goroutine 66 (finished) created at:
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch.func1()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:268 +0x36f
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:360 +0x2e4
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).Run.func1()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:221 +0x53
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:155 +0x75
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:156 +0xba
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).Run()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:220 +0x2c4
  k8s.io/kubernetes/vendor/k8s.io/client-go/tools/cache.(*Reflector).Run-fm()
      staging/src/k8s.io/client-go/tools/cache/reflector.go:218 +0x4b
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.(*Group).StartWithChannel.func1()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:56 +0x45
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.(*Group).Start.func1()
      staging/src/k8s.io/apimachinery/pkg/util/wait/wait.go:73 +0x6d
==================
E0623 22:10:01.034170  245902 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/vol1 podName: nodeName:mynode-1}" failed. No retries permitted until 2021-06-23 22:10:01.533870959 +0000 UTC m=+12.591183555 (durationBeforeRetry 500ms). Error: "DetachVolume.Detach failed for volume \"nil\" (UniqueName: \"kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/vol1\") on node \"mynode-1\" : volume attachment watch channel had been closed"
E0623 22:10:01.034323  245902 csi_attacher.go:455] [attachment.ID=csi-4ff6fd4b10c02f804e7435dffeb62054338b590749cdaacf18e198ee0ab6dd66] watch channel had been closed
I0623 22:10:01.035227  245902 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
I0623 22:10:01.035705  245902 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
E0623 22:10:01.035975  245902 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/pdName podName: nodeName:}" failed. No retries permitted until 2021-06-23 22:10:01.535683656 +0000 UTC m=+12.592996252 (durationBeforeRetry 500ms). Error: "AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" (UniqueName: \"kubernetes.io/csi/pd.csi.storage.gke.io^projects/UNSPECIFIED/zones/UNSPECIFIED/disks/pdName\") from node \"mynode\" : volume attachment watch channel had been closed"
I0623 22:10:01.035979  245902 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
I0623 22:10:01.036527  245902 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
I0623 22:10:01.036811  245902 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="AttachVolume.Attach failed for volume \"pd.csi.storage.gke.io-pdName\" : volume attachment watch channel had been closed"
I0623 22:10:01.116889  245902 shared_informer.go:247] Caches are synced for attach detach 
W0623 22:10:01.119181  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolume ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.119411  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.Pod ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0623 22:10:01.119454  245902 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolumeClaim ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
--- FAIL: Test_ADC_VolumeAttachmentRecovery (3.56s)
    --- FAIL: Test_ADC_VolumeAttachmentRecovery/Deleted_Pod_with_migrated_PV (0.11s)
        testing.go:1038: race detected during execution of test
    testing.go:1038: race detected during execution of test
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


Show 1939 Passed Tests