This job view page is being replaced by Spyglass soon. Check out the new job view.
PRnilo19: Cherry pick of #103470: fix: return empty VMAS name if using standalone VM
ResultFAILURE
Tests 2 failed / 1937 succeeded
Started2021-07-16 20:54
Elapsed32m50s
Revisiond07de023fc519cce5858ffee9e3403fa7055de9a
Refs 103600

Test Failures


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

bazel test //pkg/controller/volume/attachdetach/go_default_test:run_2_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/controller/volume/attachdetach:go_default_test
-----------------------------------------------------------------------------
I0716 21:19:05.328213  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:05.434425  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:05.444008  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:05.444345  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:05.444489  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:05.445092  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:05.445317  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:05.445427  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:05.446219  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:05.446357  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:05.446494  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:05.447490  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:05.447676  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:05.447790  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:05.448860  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:05.449072  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:05.449206  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:05.449260  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:05.450251  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:05.450567  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:05.451212  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:05.451633  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:05.451898  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:05.452075  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.442407  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:07.543272  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:07.551508  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:07.551749  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:07.551890  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:07.553146  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:07.553335  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:07.553463  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:07.554700  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:07.554868  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:07.555473  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:07.556206  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:07.556311  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:07.556435  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:07.557694  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:07.557796  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:07.557911  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:07.558134  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:07.558543  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:07.558777  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.559115  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:07.559106  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.559204  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:07.559455  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.559667  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.559855  236264 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0716 21:19:07.560042  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.552109  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:09.653386  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:09.660599  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:09.660801  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:09.660917  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:09.662006  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:09.662226  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:09.662381  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:09.663441  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:09.663616  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:09.663754  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:09.664840  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:09.665005  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:09.665133  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:09.666240  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:09.666319  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:09.666428  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:09.666600  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:09.666816  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:09.667331  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:09.667631  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:09.667762  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.667992  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.668186  236264 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0716 21:19:09.668366  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.668513  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.668645  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.658599  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:11.759298  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:11.764525  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:11.764693  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:11.764800  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:11.765705  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:11.765815  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:11.765930  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:11.767052  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:11.767248  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:11.767365  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:11.768185  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:11.768399  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:11.768517  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:11.769335  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:11.769533  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:11.769651  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:11.769724  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:11.769940  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:11.770413  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0716 21:19:11.770568  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:11.770845  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0716 21:19:11.770864  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.771103  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:11.771141  236264 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0716 21:19:11.771365  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.771556  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.771729  236264 event.go:291] "Event occurred" object="mynamespace/newpod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName3\" "
I0716 21:19:11.771916  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.772105  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.766322  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:13.868951  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:13.876424  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:13.876681  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:13.876845  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:13.877872  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:13.877989  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:13.878162  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:13.879372  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:13.879581  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:13.879713  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:13.880768  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:13.880862  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:13.880985  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:13.882192  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:13.882466  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:13.882524  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:13.882603  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:13.882853  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0716 21:19:13.883202  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0716 21:19:13.883432  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.883657  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.883742  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:13.883858  236264 event.go:291] "Event occurred" object="mynamespace/pod1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"vol1\" "
I0716 21:19:13.884083  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.884295  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.884467  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.877384  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:14.978056  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:14.986069  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:14.986337  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:14.986490  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:14.987667  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:14.987930  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:14.988105  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:14.989173  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:14.989379  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:14.989513  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:14.990620  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:14.990769  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:14.990898  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:14.992144  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:14.992238  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:14.992373  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:14.992589  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:14.993166  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.993488  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.993548  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:14.993719  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.993948  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.994174  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:15.897840  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:15.898036  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:15.898349  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:15.983466  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:16.086213  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:16.093670  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:16.093914  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:16.094031  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:16.095138  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:16.095273  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:16.095372  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:16.096507  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:16.096599  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:16.096692  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:16.097830  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:16.097998  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:16.098135  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:16.099162  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:16.099251  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:16.099365  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:16.099615  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:16.104434  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:16.104925  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:16.105072  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:16.105199  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:16.105307  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:16.105421  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:17.004760  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:17.004995  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:17.005146  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:17.092002  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:17.192658  236264 shared_informer.go:247] Caches are synced for attach detach 
W0716 21:19:17.194979  236264 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
W0716 21:19:17.195360  236264 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
W0716 21:19:17.195455  236264 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
I0716 21:19:17.199101  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:17.208241  236264 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" 
I0716 21:19:17.208605  236264 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" 
E0716 21:19:17.208995  236264 csi_attacher.go:455] [attachment.ID=csi-77bd5b88d32d48e5a31f0073211a7dd54ed0066f008e12364f4b6ecb61dc7370] watch channel had been closed
E0716 21:19:17.209615  236264 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-07-16 21:19:17.709335506 +0000 UTC m=+12.556701561 (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"
E0716 21:19:17.210297  236264 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
E0716 21:19:17.219883  236264 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
E0716 21:19:17.221517  236264 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
E0716 21:19:17.223060  236264 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
I0716 21:19:17.225846  236264 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" 
==================
WARNING: DATA RACE
Write at 0x00c00068cfa8 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 0x00c00068cfa8 by goroutine 119:
  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 119 (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
==================
E0716 21:19:17.227584  236264 csi_attacher.go:455] [attachment.ID=csi-4ff6fd4b10c02f804e7435dffeb62054338b590749cdaacf18e198ee0ab6dd66] watch channel had been closed
I0716 21:19:17.229237  236264 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"
E0716 21:19:17.229857  236264 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-07-16 21:19:17.729360804 +0000 UTC m=+12.576726855 (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"
I0716 21:19:17.229870  236264 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"
I0716 21:19:17.230271  236264 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"
I0716 21:19:17.231567  236264 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"
I0716 21:19:17.231795  236264 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"
I0716 21:19:17.299618  236264 shared_informer.go:247] Caches are synced for attach detach 
W0716 21:19:17.302040  236264 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
W0716 21:19:17.302422  236264 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
W0716 21:19:17.302620  236264 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
--- FAIL: Test_ADC_VolumeAttachmentRecovery (3.54s)
    --- 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
W0716 21:19:17.302993  236264 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
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


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

bazel test //pkg/controller/volume/attachdetach/go_default_test:run_2_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/controller/volume/attachdetach:go_default_test
-----------------------------------------------------------------------------
I0716 21:19:05.328213  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:05.434425  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:05.444008  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:05.444345  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:05.444489  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:05.445092  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:05.445317  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:05.445427  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:05.446219  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:05.446357  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:05.446494  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:05.447490  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:05.447676  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:05.447790  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:05.448860  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:05.449072  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:05.449206  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:05.449260  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:05.450251  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:05.450567  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:05.451212  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:05.451633  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:05.451898  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:05.452075  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.442407  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:07.543272  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:07.551508  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:07.551749  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:07.551890  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:07.553146  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:07.553335  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:07.553463  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:07.554700  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:07.554868  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:07.555473  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:07.556206  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:07.556311  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:07.556435  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:07.557694  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:07.557796  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:07.557911  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:07.558134  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:07.558543  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:07.558777  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.559115  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:07.559106  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.559204  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:07.559455  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.559667  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:07.559855  236264 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0716 21:19:07.560042  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.552109  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:09.653386  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:09.660599  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:09.660801  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:09.660917  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:09.662006  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:09.662226  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:09.662381  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:09.663441  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:09.663616  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:09.663754  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:09.664840  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:09.665005  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:09.665133  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:09.666240  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:09.666319  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:09.666428  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:09.666600  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:09.666816  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:09.667331  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:09.667631  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:09.667762  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.667992  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.668186  236264 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0716 21:19:09.668366  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.668513  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:09.668645  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.658599  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:11.759298  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:11.764525  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:11.764693  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:11.764800  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:11.765705  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:11.765815  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:11.765930  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:11.767052  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:11.767248  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:11.767365  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:11.768185  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:11.768399  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:11.768517  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:11.769335  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:11.769533  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:11.769651  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:11.769724  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:11.769940  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:11.770413  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0716 21:19:11.770568  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:19:11.770845  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0716 21:19:11.770864  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.771103  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:11.771141  236264 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0716 21:19:11.771365  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.771556  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.771729  236264 event.go:291] "Event occurred" object="mynamespace/newpod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName3\" "
I0716 21:19:11.771916  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:11.772105  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.766322  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:13.868951  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:13.876424  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:13.876681  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:13.876845  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:13.877872  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:13.877989  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:13.878162  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:13.879372  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:13.879581  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:13.879713  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:13.880768  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:13.880862  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:13.880985  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:13.882192  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:13.882466  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:13.882524  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:13.882603  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:13.882853  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0716 21:19:13.883202  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0716 21:19:13.883432  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.883657  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.883742  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:13.883858  236264 event.go:291] "Event occurred" object="mynamespace/pod1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"vol1\" "
I0716 21:19:13.884083  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.884295  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:13.884467  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.877384  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:14.978056  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:14.986069  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:14.986337  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:14.986490  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:14.987667  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:14.987930  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:14.988105  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:14.989173  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:14.989379  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:14.989513  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:14.990620  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:14.990769  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:14.990898  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:14.992144  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:14.992238  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:14.992373  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:14.992589  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:14.993166  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.993488  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.993548  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:14.993719  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.993948  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:14.994174  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:15.897840  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:15.898036  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:15.898349  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:15.983466  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:16.086213  236264 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:19:16.093670  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:16.093914  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:16.094031  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:19:16.095138  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:16.095273  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:16.095372  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:19:16.096507  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:16.096599  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:16.096692  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:19:16.097830  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:16.097998  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:16.098135  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:19:16.099162  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:16.099251  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:16.099365  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:19:16.099615  236264 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:16.104434  236264 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:19:16.104925  236264 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:16.105072  236264 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:16.105199  236264 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:16.105307  236264 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:16.105421  236264 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0716 21:19:17.004760  236264 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:17.004995  236264 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:17.005146  236264 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:19:17.092002  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:17.192658  236264 shared_informer.go:247] Caches are synced for attach detach 
W0716 21:19:17.194979  236264 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
W0716 21:19:17.195360  236264 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
W0716 21:19:17.195455  236264 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
I0716 21:19:17.199101  236264 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:19:17.208241  236264 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" 
I0716 21:19:17.208605  236264 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" 
E0716 21:19:17.208995  236264 csi_attacher.go:455] [attachment.ID=csi-77bd5b88d32d48e5a31f0073211a7dd54ed0066f008e12364f4b6ecb61dc7370] watch channel had been closed
E0716 21:19:17.209615  236264 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-07-16 21:19:17.709335506 +0000 UTC m=+12.556701561 (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"
E0716 21:19:17.210297  236264 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
E0716 21:19:17.219883  236264 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
E0716 21:19:17.221517  236264 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
E0716 21:19:17.223060  236264 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
I0716 21:19:17.225846  236264 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" 
==================
WARNING: DATA RACE
Write at 0x00c00068cfa8 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 0x00c00068cfa8 by goroutine 119:
  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 119 (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
==================
E0716 21:19:17.227584  236264 csi_attacher.go:455] [attachment.ID=csi-4ff6fd4b10c02f804e7435dffeb62054338b590749cdaacf18e198ee0ab6dd66] watch channel had been closed
I0716 21:19:17.229237  236264 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"
E0716 21:19:17.229857  236264 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-07-16 21:19:17.729360804 +0000 UTC m=+12.576726855 (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"
I0716 21:19:17.229870  236264 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"
I0716 21:19:17.230271  236264 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"
I0716 21:19:17.231567  236264 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"
I0716 21:19:17.231795  236264 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"
I0716 21:19:17.299618  236264 shared_informer.go:247] Caches are synced for attach detach 
W0716 21:19:17.302040  236264 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
W0716 21:19:17.302422  236264 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
W0716 21:19:17.302620  236264 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
--- FAIL: Test_ADC_VolumeAttachmentRecovery (3.54s)
    --- 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
W0716 21:19:17.302993  236264 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
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


Show 1937 Passed Tests