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 4 failed / 1936 succeeded
Started2021-07-16 21:30
Elapsed32m53s
Revisiond07de023fc519cce5858ffee9e3403fa7055de9a
Refs 103600

Test Failures


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

bazel test //pkg/controller/volume/attachdetach/go_default_test:run_1_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/controller/volume/attachdetach:go_default_test
-----------------------------------------------------------------------------
I0716 21:51:29.905327  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:30.008202  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:30.020451  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:30.020730  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:30.020905  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:30.022042  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:30.022313  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:30.022437  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:30.023612  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:30.023706  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:30.023833  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:30.025173  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:30.025270  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:30.025382  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:30.026747  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:30.026843  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:30.026957  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:30.027132  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:30.028038  219590 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:51:30.028568  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:30.028634  219590 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:51:30.028862  219590 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:51:30.029052  219590 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:51:30.029218  219590 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:51:32.013824  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:32.114953  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:32.125845  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:32.125985  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:32.128082  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:32.131132  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:32.131464  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:32.131490  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:32.131638  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:32.131902  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:32.132012  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:32.133008  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:32.133299  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:32.133429  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:32.134645  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:32.134919  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:32.135124  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:32.135645  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:32.136033  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:32.136147  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:32.137244  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:32.137663  219590 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:51:32.138654  219590 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:51:32.138848  219590 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:51:32.139026  219590 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:51:32.139212  219590 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:51:32.139400  219590 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:51:34.121409  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:34.222591  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:34.231560  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:34.231757  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:34.231935  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:34.233300  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:34.233620  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:34.233785  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:34.235021  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:34.235202  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:34.235342  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:34.236316  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:34.236477  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:34.236611  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:34.237537  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:34.237653  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:34.237808  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:34.237978  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:34.238211  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:34.238637  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:34.239237  219590 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:51:34.239291  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:34.239474  219590 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:51:34.239637  219590 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:51:34.239785  219590 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:51:34.239936  219590 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:51:34.240078  219590 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:51:36.228870  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:36.329548  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:36.337914  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:36.338556  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:36.338730  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:36.339632  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:36.339769  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:36.339918  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:36.341296  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:36.341462  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:36.341608  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:36.342925  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:36.343115  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:36.343238  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:36.344517  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:36.344614  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:36.344745  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:36.345381  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:36.345625  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:36.345746  219590 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:51:36.345879  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0716 21:51:36.346124  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:36.346284  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0716 21:51:36.346670  219590 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:51:36.347895  219590 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:51:36.347983  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:36.348134  219590 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:51:36.348426  219590 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:51:36.348624  219590 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:51:36.348929  219590 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:51:38.336589  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:38.438574  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:38.446057  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:38.446315  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:38.446446  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:38.447445  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:38.447505  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:38.447609  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:38.448874  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:38.449111  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:38.449268  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:38.450003  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:38.450172  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:38.450307  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:38.451224  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:38.451368  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:38.451520  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:38.451568  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:38.452019  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0716 21:51:38.452225  219590 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:51:38.452483  219590 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:51:38.452556  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0716 21:51:38.452898  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:38.452928  219590 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:51:38.453156  219590 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:51:38.453311  219590 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:51:38.453447  219590 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:51:39.446133  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:39.548155  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:39.554753  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:39.555166  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:39.555320  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:39.555971  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:39.556161  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:39.556301  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:39.557204  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:39.557332  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:39.557475  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:39.558540  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:39.558721  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:39.558849  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:39.559825  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:39.559990  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:39.560110  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:39.560178  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:39.560985  219590 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:51:39.561281  219590 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:51:39.561317  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:39.561489  219590 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:51:39.561668  219590 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:51:39.561803  219590 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:51:40.467654  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:40.467870  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:40.468014  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:40.553077  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:40.653691  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:40.661391  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:40.663097  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:40.664650  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:40.666252  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:40.666341  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:40.666458  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:40.666692  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:40.666762  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:40.666956  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:40.667027  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:40.667279  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:40.667362  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:40.667808  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:40.668170  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:40.669129  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:40.669257  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:40.669315  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:40.669325  219590 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:51:40.669609  219590 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:51:40.669792  219590 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:51:40.669931  219590 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:51:40.670042  219590 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:51:41.573044  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:41.573702  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:41.573837  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:41.659862  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:41.770574  219590 shared_informer.go:247] Caches are synced for attach detach 
W0716 21:51:41.773672  219590 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.CSINode ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0716 21:51:41.774542  219590 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:51:41.782837  219590 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" 
I0716 21:51:41.782875  219590 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" 
E0716 21:51:41.783178  219590 csi_attacher.go:455] [attachment.ID=csi-77bd5b88d32d48e5a31f0073211a7dd54ed0066f008e12364f4b6ecb61dc7370] watch channel had been closed
E0716 21:51:41.783611  219590 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:51:42.283406374 +0000 UTC m=+12.598503801 (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:51:41.784555  219590 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:51:41.788904  219590 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
I0716 21:51:41.789289  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
E0716 21:51:41.790813  219590 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:51:41.792436  219590 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:51:41.792890  219590 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 0x00c000124138 by goroutine 83:
  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 0x00c000124138 by goroutine 156:
  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 83 (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 156 (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:51:41.793873  219590 csi_attacher.go:455] [attachment.ID=csi-4ff6fd4b10c02f804e7435dffeb62054338b590749cdaacf18e198ee0ab6dd66] watch channel had been closed
I0716 21:51:41.795304  219590 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:51:41.795736  219590 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"
E0716 21:51:41.795930  219590 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:51:42.295495887 +0000 UTC m=+12.610593324 (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:51:41.795956  219590 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:51:41.796370  219590 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:51:41.796617  219590 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"
I0716 21:51:41.889839  219590 shared_informer.go:247] Caches are synced for attach detach 
W0716 21:51:41.892464  219590 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
W0716 21:51:41.892723  219590 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolumeClaim ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
--- FAIL: Test_ADC_VolumeAttachmentRecovery (3.56s)
    --- FAIL: Test_ADC_VolumeAttachmentRecovery/Deleted_Pod_with_migrated_PV (0.12s)
        testing.go:1038: race detected during execution of test
    testing.go:1038: race detected during execution of test
W0716 21:51:41.892953  219590 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.CSINode ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0716 21:51:41.892973  219590 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_1_of_2 0.00s

bazel test //pkg/controller/volume/attachdetach/go_default_test:run_1_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/controller/volume/attachdetach:go_default_test
-----------------------------------------------------------------------------
I0716 21:51:29.905327  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:30.008202  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:30.020451  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:30.020730  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:30.020905  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:30.022042  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:30.022313  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:30.022437  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:30.023612  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:30.023706  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:30.023833  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:30.025173  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:30.025270  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:30.025382  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:30.026747  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:30.026843  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:30.026957  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:30.027132  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:30.028038  219590 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:51:30.028568  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:30.028634  219590 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:51:30.028862  219590 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:51:30.029052  219590 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:51:30.029218  219590 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:51:32.013824  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:32.114953  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:32.125845  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:32.125985  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:32.128082  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:32.131132  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:32.131464  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:32.131490  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:32.131638  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:32.131902  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:32.132012  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:32.133008  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:32.133299  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:32.133429  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:32.134645  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:32.134919  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:32.135124  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:32.135645  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:32.136033  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:32.136147  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:32.137244  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:32.137663  219590 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:51:32.138654  219590 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:51:32.138848  219590 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:51:32.139026  219590 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:51:32.139212  219590 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:51:32.139400  219590 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:51:34.121409  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:34.222591  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:34.231560  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:34.231757  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:34.231935  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:34.233300  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:34.233620  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:34.233785  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:34.235021  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:34.235202  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:34.235342  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:34.236316  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:34.236477  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:34.236611  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:34.237537  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:34.237653  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:34.237808  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:34.237978  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:34.238211  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:34.238637  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:34.239237  219590 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:51:34.239291  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:34.239474  219590 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:51:34.239637  219590 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:51:34.239785  219590 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:51:34.239936  219590 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:51:34.240078  219590 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:51:36.228870  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:36.329548  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:36.337914  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:36.338556  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:36.338730  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:36.339632  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:36.339769  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:36.339918  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:36.341296  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:36.341462  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:36.341608  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:36.342925  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:36.343115  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:36.343238  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:36.344517  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:36.344614  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:36.344745  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:36.345381  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:36.345625  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0716 21:51:36.345746  219590 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:51:36.345879  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0716 21:51:36.346124  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:36.346284  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0716 21:51:36.346670  219590 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:51:36.347895  219590 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:51:36.347983  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:36.348134  219590 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:51:36.348426  219590 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:51:36.348624  219590 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:51:36.348929  219590 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:51:38.336589  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:38.438574  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:38.446057  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:38.446315  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:38.446446  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:38.447445  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:38.447505  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:38.447609  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:38.448874  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:38.449111  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:38.449268  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:38.450003  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:38.450172  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:38.450307  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:38.451224  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:38.451368  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:38.451520  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:38.451568  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:38.452019  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0716 21:51:38.452225  219590 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:51:38.452483  219590 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:51:38.452556  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0716 21:51:38.452898  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:38.452928  219590 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:51:38.453156  219590 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:51:38.453311  219590 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:51:38.453447  219590 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:51:39.446133  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:39.548155  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:39.554753  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:39.555166  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:39.555320  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:39.555971  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:39.556161  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:39.556301  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:39.557204  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:39.557332  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:39.557475  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:39.558540  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:39.558721  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:39.558849  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:39.559825  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:39.559990  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:39.560110  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:39.560178  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:39.560985  219590 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:51:39.561281  219590 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:51:39.561317  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:39.561489  219590 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:51:39.561668  219590 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:51:39.561803  219590 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:51:40.467654  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:40.467870  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:40.468014  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:40.553077  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:40.653691  219590 shared_informer.go:247] Caches are synced for attach detach 
I0716 21:51:40.661391  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:40.663097  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:40.664650  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:40.666252  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:40.666341  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:40.666458  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0716 21:51:40.666692  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:40.666762  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0716 21:51:40.666956  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:40.667027  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0716 21:51:40.667279  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:40.667362  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0716 21:51:40.667808  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:40.668170  219590 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:40.669129  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:40.669257  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0716 21:51:40.669315  219590 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0716 21:51:40.669325  219590 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:51:40.669609  219590 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:51:40.669792  219590 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:51:40.669931  219590 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:51:40.670042  219590 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:51:41.573044  219590 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:41.573702  219590 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:41.573837  219590 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0716 21:51:41.659862  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
I0716 21:51:41.770574  219590 shared_informer.go:247] Caches are synced for attach detach 
W0716 21:51:41.773672  219590 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.CSINode ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0716 21:51:41.774542  219590 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:51:41.782837  219590 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" 
I0716 21:51:41.782875  219590 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" 
E0716 21:51:41.783178  219590 csi_attacher.go:455] [attachment.ID=csi-77bd5b88d32d48e5a31f0073211a7dd54ed0066f008e12364f4b6ecb61dc7370] watch channel had been closed
E0716 21:51:41.783611  219590 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:51:42.283406374 +0000 UTC m=+12.598503801 (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:51:41.784555  219590 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:51:41.788904  219590 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
I0716 21:51:41.789289  219590 shared_informer.go:240] Waiting for caches to sync for attach detach
E0716 21:51:41.790813  219590 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:51:41.792436  219590 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:51:41.792890  219590 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 0x00c000124138 by goroutine 83:
  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 0x00c000124138 by goroutine 156:
  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 83 (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 156 (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:51:41.793873  219590 csi_attacher.go:455] [attachment.ID=csi-4ff6fd4b10c02f804e7435dffeb62054338b590749cdaacf18e198ee0ab6dd66] watch channel had been closed
I0716 21:51:41.795304  219590 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:51:41.795736  219590 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"
E0716 21:51:41.795930  219590 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:51:42.295495887 +0000 UTC m=+12.610593324 (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:51:41.795956  219590 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:51:41.796370  219590 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:51:41.796617  219590 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"
I0716 21:51:41.889839  219590 shared_informer.go:247] Caches are synced for attach detach 
W0716 21:51:41.892464  219590 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
W0716 21:51:41.892723  219590 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolumeClaim ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
--- FAIL: Test_ADC_VolumeAttachmentRecovery (3.56s)
    --- FAIL: Test_ADC_VolumeAttachmentRecovery/Deleted_Pod_with_migrated_PV (0.12s)
        testing.go:1038: race detected during execution of test
    testing.go:1038: race detected during execution of test
W0716 21:51:41.892953  219590 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.CSINode ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0716 21:51:41.892973  219590 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


//staging/src/k8s.io/legacy-cloud-providers/vsphere/go_default_test:run_1_of_2 0.00s

bazel test //staging/src/k8s.io/legacy-cloud-providers/vsphere/go_default_test:run_1_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //staging/src/k8s.io/legacy-cloud-providers/vsphere:go_default_test
-----------------------------------------------------------------------------
E0716 21:48:03.061277  175147 credentialmanager.go:96] Cannot get secret vsconf in namespace kube-system. error: "secret \"vsconf\" not found"
W0716 21:48:03.061365  175147 credentialmanager.go:77] secret "vsconf" not found in namespace "kube-system"
E0716 21:48:03.061805  175147 credentialmanager.go:96] Cannot get secret vsconf in namespace kube-system. error: "secret \"vsconf\" not found"
W0716 21:48:03.061862  175147 credentialmanager.go:77] secret "vsconf" not found in namespace "kube-system"
E0716 21:48:03.061906  175147 credentialmanager.go:84] credentials not found for server "0.0.0.0"
E0716 21:48:03.062554  175147 credentialmanager.go:84] credentials not found for server "1.1.1.1"
E0716 21:48:03.063709  175147 credentialmanager.go:158] Unknown secret key 10.20.30.40.usernam
E0716 21:48:03.063800  175147 credentialmanager.go:164] Username/Password is missing for server 10.20.30.40
E0716 21:48:03.063889  175147 credentialmanager.go:164] Username/Password is missing for server 10.20.30.40
E0716 21:48:03.064014  175147 credentialmanager.go:158] Unknown secret key 10.20.30.40
W0716 21:48:03.131193  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:03.153104  175147 connection.go:169] No active session, cannot logout
E0716 21:48:03.166699  175147 connection.go:169] No active session, cannot logout
W0716 21:48:03.197691  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:03.296622  175147 connection.go:169] No active session, cannot logout
E0716 21:48:03.296700  175147 connection.go:169] No active session, cannot logout
W0716 21:48:03.346123  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:03.402298  175147 connection.go:169] No active session, cannot logout
E0716 21:48:03.402427  175147 connection.go:169] No active session, cannot logout
W0716 21:48:03.442186  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
I0716 21:48:03.555613  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
I0716 21:48:03.675885  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:03.807239  175147 vsphere.go:1693] Get zone for node ca1da1bc-e67c-11eb-b406-dac77dad41a3: vSphere region category "k8s-region" does not match any tags for node ca1da1bc-e67c-11eb-b406-dac77dad41a3 [11e1cea9-f36e-4e09-9973-53d76f1f7ac3]
I0716 21:48:03.830562  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:03.948331  175147 vsphere.go:1666] Found "k8s-region" tag (k8s-region-US) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to HostSystem:host-20
E0716 21:48:03.959949  175147 vsphere.go:1693] Get zone for node ca1da1bc-e67c-11eb-b406-dac77dad41a3: vSphere zone category "k8s-zone" does not match any tags for node ca1da1bc-e67c-11eb-b406-dac77dad41a3 [11e1cea9-f36e-4e09-9973-53d76f1f7ac3]
I0716 21:48:03.985935  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:04.125532  175147 vsphere.go:1666] Found "k8s-region" tag (k8s-region-US) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to HostSystem:host-20
E0716 21:48:04.128755  175147 vsphere.go:1666] Found "k8s-zone" tag (k8s-zone-US-CA1) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to HostSystem:host-20
I0716 21:48:04.171555  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:04.288841  175147 vsphere.go:1693] Get zone for node ca1da1bc-e67c-11eb-b406-dac77dad41a3: vSphere region category "k8s-region" does not match any tags for node ca1da1bc-e67c-11eb-b406-dac77dad41a3 [11e1cea9-f36e-4e09-9973-53d76f1f7ac3]
I0716 21:48:04.315518  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:04.441445  175147 vsphere.go:1666] Found "k8s-zone" tag (k8s-zone-US-CA1) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to ComputeResource:computeresource-22
E0716 21:48:04.448788  175147 vsphere.go:1666] Found "k8s-region" tag (k8s-region-US) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to Datacenter:datacenter-2
E0716 21:48:04.505515  175147 connection.go:169] No active session, cannot logout
W0716 21:48:04.509086  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.412016  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.414587  175147 vsphere.go:339] Global.User and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.414650  175147 vsphere.go:343] Global.Password and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.415734  175147 vsphere.go:343] Global.Password and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.416808  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.417910  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:05.417968  175147 vsphere.go:354] Global.User is empty!
W0716 21:48:05.418929  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:05.418998  175147 vsphere.go:358] Global.Password is empty!
W0716 21:48:05.419887  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:05.419934  175147 vsphere.go:354] Global.User is empty!
W0716 21:48:05.421023  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.422509  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.427103  175147 vsphere.go:443] vcConfig.Password for server 0.0.0.0 and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.428261  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.429770  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.431541  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.508129  175147 vsphere.go:339] Global.User and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.508212  175147 vsphere.go:343] Global.Password and Secret info provided. VCP will use secret to get credentials
E0716 21:48:05.510623  175147 connection.go:169] No active session, cannot logout
--- FAIL: TestSecretUpdated (0.10s)
    --- FAIL: TestSecretUpdated/Secret_with_a_different_data (0.01s)
        vsphere_test.go:1252: Unexpected log error messages for secrets:
            Old:
            	&Secret{ObjectMeta:{vccreds  kube-system    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Data:map[string][]byte{vcenter.0.0.0.0.password: [116 101 115 116 45 117 115 101 114 110 97 109 101],vcenter.0.0.0.0.username: [116 101 115 116 45 112 97 115 115 119 111 114 100],},Type:,StringData:map[string]string{},Immutable:nil,}
            
            New:
            	&Secret{ObjectMeta:{vccreds  kube-system    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Data:map[string][]byte{vcenter.0.0.0.0.password: [46 46 46],vcenter.0.0.0.0.username: [46 46 46],},Type:,StringData:map[string]string{},Immutable:nil,}
            Message:E0716 21:48:05.510623  175147 connection.go:169] No active session, cannot logout
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


//staging/src/k8s.io/legacy-cloud-providers/vsphere/go_default_test:run_1_of_2 0.00s

bazel test //staging/src/k8s.io/legacy-cloud-providers/vsphere/go_default_test:run_1_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //staging/src/k8s.io/legacy-cloud-providers/vsphere:go_default_test
-----------------------------------------------------------------------------
E0716 21:48:03.061277  175147 credentialmanager.go:96] Cannot get secret vsconf in namespace kube-system. error: "secret \"vsconf\" not found"
W0716 21:48:03.061365  175147 credentialmanager.go:77] secret "vsconf" not found in namespace "kube-system"
E0716 21:48:03.061805  175147 credentialmanager.go:96] Cannot get secret vsconf in namespace kube-system. error: "secret \"vsconf\" not found"
W0716 21:48:03.061862  175147 credentialmanager.go:77] secret "vsconf" not found in namespace "kube-system"
E0716 21:48:03.061906  175147 credentialmanager.go:84] credentials not found for server "0.0.0.0"
E0716 21:48:03.062554  175147 credentialmanager.go:84] credentials not found for server "1.1.1.1"
E0716 21:48:03.063709  175147 credentialmanager.go:158] Unknown secret key 10.20.30.40.usernam
E0716 21:48:03.063800  175147 credentialmanager.go:164] Username/Password is missing for server 10.20.30.40
E0716 21:48:03.063889  175147 credentialmanager.go:164] Username/Password is missing for server 10.20.30.40
E0716 21:48:03.064014  175147 credentialmanager.go:158] Unknown secret key 10.20.30.40
W0716 21:48:03.131193  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:03.153104  175147 connection.go:169] No active session, cannot logout
E0716 21:48:03.166699  175147 connection.go:169] No active session, cannot logout
W0716 21:48:03.197691  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:03.296622  175147 connection.go:169] No active session, cannot logout
E0716 21:48:03.296700  175147 connection.go:169] No active session, cannot logout
W0716 21:48:03.346123  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:03.402298  175147 connection.go:169] No active session, cannot logout
E0716 21:48:03.402427  175147 connection.go:169] No active session, cannot logout
W0716 21:48:03.442186  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
I0716 21:48:03.555613  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
I0716 21:48:03.675885  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:03.807239  175147 vsphere.go:1693] Get zone for node ca1da1bc-e67c-11eb-b406-dac77dad41a3: vSphere region category "k8s-region" does not match any tags for node ca1da1bc-e67c-11eb-b406-dac77dad41a3 [11e1cea9-f36e-4e09-9973-53d76f1f7ac3]
I0716 21:48:03.830562  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:03.948331  175147 vsphere.go:1666] Found "k8s-region" tag (k8s-region-US) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to HostSystem:host-20
E0716 21:48:03.959949  175147 vsphere.go:1693] Get zone for node ca1da1bc-e67c-11eb-b406-dac77dad41a3: vSphere zone category "k8s-zone" does not match any tags for node ca1da1bc-e67c-11eb-b406-dac77dad41a3 [11e1cea9-f36e-4e09-9973-53d76f1f7ac3]
I0716 21:48:03.985935  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:04.125532  175147 vsphere.go:1666] Found "k8s-region" tag (k8s-region-US) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to HostSystem:host-20
E0716 21:48:04.128755  175147 vsphere.go:1666] Found "k8s-zone" tag (k8s-zone-US-CA1) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to HostSystem:host-20
I0716 21:48:04.171555  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:04.288841  175147 vsphere.go:1693] Get zone for node ca1da1bc-e67c-11eb-b406-dac77dad41a3: vSphere region category "k8s-region" does not match any tags for node ca1da1bc-e67c-11eb-b406-dac77dad41a3 [11e1cea9-f36e-4e09-9973-53d76f1f7ac3]
I0716 21:48:04.315518  175147 datacenter.go:99] VirtualMachine:vm-53 host is HostSystem:host-20
E0716 21:48:04.441445  175147 vsphere.go:1666] Found "k8s-zone" tag (k8s-zone-US-CA1) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to ComputeResource:computeresource-22
E0716 21:48:04.448788  175147 vsphere.go:1666] Found "k8s-region" tag (k8s-region-US) for 11e1cea9-f36e-4e09-9973-53d76f1f7ac3 attached to Datacenter:datacenter-2
E0716 21:48:04.505515  175147 connection.go:169] No active session, cannot logout
W0716 21:48:04.509086  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.412016  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.414587  175147 vsphere.go:339] Global.User and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.414650  175147 vsphere.go:343] Global.Password and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.415734  175147 vsphere.go:343] Global.Password and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.416808  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.417910  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:05.417968  175147 vsphere.go:354] Global.User is empty!
W0716 21:48:05.418929  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:05.418998  175147 vsphere.go:358] Global.Password is empty!
W0716 21:48:05.419887  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
E0716 21:48:05.419934  175147 vsphere.go:354] Global.User is empty!
W0716 21:48:05.421023  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.422509  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.427103  175147 vsphere.go:443] vcConfig.Password for server 0.0.0.0 and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.428261  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.429770  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.431541  175147 vsphere.go:332] SecretName and/or SecretNamespace is not provided. VCP will use username and password from config file
W0716 21:48:05.508129  175147 vsphere.go:339] Global.User and Secret info provided. VCP will use secret to get credentials
W0716 21:48:05.508212  175147 vsphere.go:343] Global.Password and Secret info provided. VCP will use secret to get credentials
E0716 21:48:05.510623  175147 connection.go:169] No active session, cannot logout
--- FAIL: TestSecretUpdated (0.10s)
    --- FAIL: TestSecretUpdated/Secret_with_a_different_data (0.01s)
        vsphere_test.go:1252: Unexpected log error messages for secrets:
            Old:
            	&Secret{ObjectMeta:{vccreds  kube-system    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Data:map[string][]byte{vcenter.0.0.0.0.password: [116 101 115 116 45 117 115 101 114 110 97 109 101],vcenter.0.0.0.0.username: [116 101 115 116 45 112 97 115 115 119 111 114 100],},Type:,StringData:map[string]string{},Immutable:nil,}
            
            New:
            	&Secret{ObjectMeta:{vccreds  kube-system    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Data:map[string][]byte{vcenter.0.0.0.0.password: [46 46 46],vcenter.0.0.0.0.username: [46 46 46],},Type:,StringData:map[string]string{},Immutable:nil,}
            Message:E0716 21:48:05.510623  175147 connection.go:169] No active session, cannot logout
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


Show 1936 Passed Tests