This job view page is being replaced by Spyglass soon. Check out the new job view.
PRgnufied: Automated cherry pick of #102665: Add explicit capability for online volume expansion
ResultFAILURE
Tests 3 failed / 1936 succeeded
Started2021-07-10 03:45
Elapsed30m4s
Revision023c9f0d9ba1df6eedebb18ff31e578a302d1ce9
Refs 103164

Test Failures


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

bazel test //pkg/controller/volume/attachdetach/go_default_test:run_2_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/controller/volume/attachdetach:go_default_test
-----------------------------------------------------------------------------
I0710 04:00:11.450964  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:11.558320  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:11.570934  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:11.571096  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:11.571453  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:11.574680  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:11.574796  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:11.575382  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:11.580768  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:11.580882  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:11.581374  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:11.602021  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:11.602208  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:11.602337  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:11.603518  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:11.603622  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:11.609007  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:11.610416  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:11.610876  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.611093  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.611259  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.611435  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.611609  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.621241  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:13.567527  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:13.668206  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:13.675640  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:13.675758  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:13.676079  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:13.677395  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:13.677523  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:13.677731  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:13.679101  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:13.679215  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:13.679464  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:13.680857  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:13.680966  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:13.681215  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:13.682658  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:13.682758  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:13.685355  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:13.686613  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:13.699450  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.699668  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.699857  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.700016  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.700173  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.700371  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:13.701002  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:13.701328  145234 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0710 04:00:13.701529  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:15.673783  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:15.779682  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:15.787396  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:15.787540  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:15.787744  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:15.789146  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:15.789267  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:15.789542  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:15.790825  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:15.790928  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:15.791226  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:15.792525  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:15.792632  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:15.811007  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:15.818228  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:15.818360  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:15.827305  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:15.828623  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:15.829319  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.829539  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.829713  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.829870  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.830035  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.830482  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:15.831018  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:15.831458  145234 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0710 04:00:15.831547  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:17.785767  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:17.904488  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:17.912545  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:17.912674  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:17.912974  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:17.914448  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:17.914567  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:17.914746  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:17.916143  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:17.916251  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:17.916525  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:17.917894  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:17.918004  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:17.918255  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:17.919729  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:17.919869  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:17.927301  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:17.928788  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:17.929321  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.929514  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.929686  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.929862  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.930026  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.930606  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:17.931106  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:17.931432  145234 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0710 04:00:17.931720  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:17.932181  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0710 04:00:17.932572  145234 event.go:291] "Event occurred" object="mynamespace/newpod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName3\" "
I0710 04:00:17.936993  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0710 04:00:19.910795  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:20.012409  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:20.031249  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:20.031373  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:20.031489  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:20.038100  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:20.038230  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:20.038521  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:20.047228  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:20.046718  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:20.047364  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:20.051918  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:20.052008  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:20.052118  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:20.062857  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:20.062930  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:20.063036  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:20.063145  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:20.063403  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0710 04:00:20.064387  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.068478  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:20.068864  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.069283  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.069525  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.069712  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.128720  145234 event.go:291] "Event occurred" object="mynamespace/pod1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"vol1\" "
I0710 04:00:20.129063  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0710 04:00:21.023674  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:21.126241  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:21.143528  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:21.143798  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:21.144314  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:21.150027  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:21.150226  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:21.150603  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:21.164051  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:21.164181  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:21.164368  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:21.168917  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:21.169216  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:21.169685  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:21.176542  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:21.176770  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:21.185535  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:21.187596  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.188244  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.199265  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.199978  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:21.200524  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.200818  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.201488  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:22.107865  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:22.108433  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:22.108610  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:22.135936  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:22.236918  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:22.248158  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:22.248380  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:22.248704  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:22.252390  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:22.252581  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:22.253021  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:22.255070  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:22.255279  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:22.267406  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:22.269686  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:22.269874  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:22.299135  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:22.301506  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:22.301785  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:22.302166  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:22.304982  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:22.305709  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.305997  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.306254  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.306526  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.306745  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.307885  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:23.219777  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:23.220564  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:23.220797  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:23.250675  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:23.354393  145234 shared_informer.go:247] Caches are synced for attach detach 
W0710 04:00:23.358841  145234 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolume ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0710 04:00:23.359225  145234 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.Pod ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0710 04:00:23.359961  145234 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
E0710 04:00:23.372535  145234 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
E0710 04:00:23.374904  145234 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
E0710 04:00:23.380446  145234 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
E0710 04:00:23.382624  145234 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
I0710 04:00:23.384837  145234 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" 
I0710 04:00:23.385232  145234 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" 
E0710 04:00:23.385836  145234 csi_attacher.go:455] [attachment.ID=csi-4ff6fd4b10c02f804e7435dffeb62054338b590749cdaacf18e198ee0ab6dd66] watch channel had been closed
E0710 04:00:23.410589  145234 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-10 04:00:23.88690694 +0000 UTC m=+12.878880830 (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"
I0710 04:00:23.411181  145234 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"
I0710 04:00:23.411547  145234 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"
I0710 04:00:23.411634  145234 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" 
I0710 04:00:23.411860  145234 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"
E0710 04:00:23.412061  145234 csi_attacher.go:455] [attachment.ID=csi-77bd5b88d32d48e5a31f0073211a7dd54ed0066f008e12364f4b6ecb61dc7370] watch channel had been closed
I0710 04:00:23.412213  145234 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"
I0710 04:00:23.412555  145234 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"
==================
WARNING: DATA RACE
Write at 0x000003366eb8 by goroutine 176:
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/testing.CreateTestClient()
      pkg/controller/volume/attachdetach/testing/testvolumespec.go:176 +0xb84
  k8s.io/kubernetes/pkg/controller/volume/attachdetach.volumeAttachmentRecoveryTestCase()
      pkg/controller/volume/attachdetach/attach_detach_controller_test.go:430 +0x5d
  k8s.io/kubernetes/pkg/controller/volume/attachdetach.Test_ADC_VolumeAttachmentRecovery.func1()
      pkg/controller/volume/attachdetach/attach_detach_controller_test.go:424 +0xd7
  testing.tRunner()
      GOROOT/src/testing/testing.go:1123 +0x202

Previous read at 0x000003366eb8 by goroutine 153:
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/testing.CreateTestClient.func7()
      pkg/controller/volume/attachdetach/testing/testvolumespec.go:185 +0x106
E0710 04:00:23.412809  145234 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-10 04:00:23.912489734 +0000 UTC m=+12.904463653 (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"
  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

Goroutine 176 (running) created at:
  testing.(*T).Run()
      GOROOT/src/testing/testing.go:1168 +0x5bb
  k8s.io/kubernetes/pkg/controller/volume/attachdetach.Test_ADC_VolumeAttachmentRecovery()
      pkg/controller/volume/attachdetach/attach_detach_controller_test.go:423 +0x49c
  testing.tRunner()
      GOROOT/src/testing/testing.go:1123 +0x202

Goroutine 153 (finished) 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
==================
I0710 04:00:23.417179  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:23.517785  145234 shared_informer.go:247] Caches are synced for attach detach 
--- FAIL: Test_ADC_VolumeAttachmentRecovery (3.61s)
    --- FAIL: Test_ADC_VolumeAttachmentRecovery/Deleted_Pod_with_migrated_PV (0.16s)
        testing.go:1038: race detected during execution of test
    testing.go:1038: race detected during execution of test
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


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

bazel test //pkg/controller/volume/attachdetach/go_default_test:run_2_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/controller/volume/attachdetach:go_default_test
-----------------------------------------------------------------------------
I0710 04:00:11.450964  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:11.558320  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:11.570934  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:11.571096  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:11.571453  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:11.574680  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:11.574796  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:11.575382  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:11.580768  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:11.580882  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:11.581374  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:11.602021  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:11.602208  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:11.602337  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:11.603518  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:11.603622  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:11.609007  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:11.610416  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:11.610876  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.611093  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.611259  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.611435  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.611609  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:11.621241  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:13.567527  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:13.668206  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:13.675640  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:13.675758  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:13.676079  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:13.677395  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:13.677523  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:13.677731  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:13.679101  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:13.679215  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:13.679464  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:13.680857  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:13.680966  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:13.681215  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:13.682658  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:13.682758  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:13.685355  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:13.686613  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:13.699450  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.699668  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.699857  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.700016  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.700173  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:13.700371  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:13.701002  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:13.701328  145234 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0710 04:00:13.701529  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:15.673783  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:15.779682  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:15.787396  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:15.787540  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:15.787744  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:15.789146  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:15.789267  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:15.789542  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:15.790825  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:15.790928  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:15.791226  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:15.792525  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:15.792632  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:15.811007  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:15.818228  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:15.818360  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:15.827305  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:15.828623  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:15.829319  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.829539  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.829713  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.829870  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.830035  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:15.830482  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:15.831018  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:15.831458  145234 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0710 04:00:15.831547  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:17.785767  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:17.904488  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:17.912545  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:17.912674  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:17.912974  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:17.914448  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:17.914567  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:17.914746  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:17.916143  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:17.916251  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:17.916525  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:17.917894  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:17.918004  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:17.918255  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:17.919729  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:17.919869  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:17.927301  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:17.928788  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:17.929321  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.929514  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.929686  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.929862  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.930026  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:17.930606  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:17.931106  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:17.931432  145234 event.go:291] "Event occurred" object="mynamespace/newpod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName2\" "
I0710 04:00:17.931720  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName2" (UniqueName: "kubernetes.io/testPlugin/volumeName2") from node "mynode-1" 
I0710 04:00:17.932181  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0710 04:00:17.932572  145234 event.go:291] "Event occurred" object="mynamespace/newpod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName3\" "
I0710 04:00:17.936993  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName3" (UniqueName: "kubernetes.io/testPlugin/volumeName3") from node "mynode-1" 
I0710 04:00:19.910795  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:20.012409  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:20.031249  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:20.031373  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:20.031489  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:20.038100  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:20.038230  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:20.038521  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:20.047228  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:20.046718  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:20.047364  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:20.051918  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:20.052008  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:20.052118  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:20.062857  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:20.062930  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:20.063036  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:20.063145  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:20.063403  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0710 04:00:20.064387  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.068478  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:20.068864  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.069283  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.069525  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.069712  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:20.128720  145234 event.go:291] "Event occurred" object="mynamespace/pod1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"vol1\" "
I0710 04:00:20.129063  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "vol1" (UniqueName: "kubernetes.io/testPlugin/vol1") from node "mynode-1" 
I0710 04:00:21.023674  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:21.126241  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:21.143528  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:21.143798  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:21.144314  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:21.150027  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:21.150226  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:21.150603  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:21.164051  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:21.164181  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:21.164368  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:21.168917  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:21.169216  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:21.169685  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:21.176542  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:21.176770  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:21.185535  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:21.187596  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.188244  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.199265  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.199978  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:21.200524  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.200818  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:21.201488  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:22.107865  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:22.108433  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:22.108610  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:22.135936  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:22.236918  145234 shared_informer.go:247] Caches are synced for attach detach 
I0710 04:00:22.248158  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:22.248380  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:22.248704  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-4" 
I0710 04:00:22.252390  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:22.252581  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:22.253021  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode" 
I0710 04:00:22.255070  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:22.255279  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:22.267406  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-1" 
I0710 04:00:22.269686  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:22.269874  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:22.299135  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-2" 
I0710 04:00:22.301506  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:22.301785  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:22.302166  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "nil" (UniqueName: "kubernetes.io/testPlugin/lostVolumeName") on node "mynode-3" 
I0710 04:00:22.304982  145234 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:22.305709  145234 event.go:291] "Event occurred" object="mynamespace/mypod-2" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.305997  145234 event.go:291] "Event occurred" object="mynamespace/mypod-3" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.306254  145234 event.go:291] "Event occurred" object="mynamespace/mypod-4" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.306526  145234 event.go:291] "Event occurred" object="mynamespace/mypod-1" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.306745  145234 event.go:291] "Event occurred" object="mynamespace/mypod-0" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"volumeName\" "
I0710 04:00:22.307885  145234 reconciler.go:295] attacherDetacher.AttachVolume started for volume "volumeName" (UniqueName: "kubernetes.io/testPlugin/volumeName") from node "mynode" 
I0710 04:00:23.219777  145234 reconciler.go:219] attacherDetacher.DetachVolume started for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:23.220564  145234 operation_generator.go:1409] Verified volume is safe to detach for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:23.220797  145234 operation_generator.go:470] DetachVolume.Detach succeeded for volume "pv1" (UniqueName: "kubernetes.io/testPlugin/vol1") on node "mynode-1" 
I0710 04:00:23.250675  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:23.354393  145234 shared_informer.go:247] Caches are synced for attach detach 
W0710 04:00:23.358841  145234 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.PersistentVolume ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0710 04:00:23.359225  145234 reflector.go:436] k8s.io/client-go/informers/factory.go:134: watch of *v1.Pod ended with: very short watch: k8s.io/client-go/informers/factory.go:134: Unexpected watch close - watch lasted less than a second and no items received
W0710 04:00:23.359961  145234 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
E0710 04:00:23.372535  145234 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
E0710 04:00:23.374904  145234 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
E0710 04:00:23.380446  145234 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
E0710 04:00:23.382624  145234 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
I0710 04:00:23.384837  145234 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" 
I0710 04:00:23.385232  145234 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" 
E0710 04:00:23.385836  145234 csi_attacher.go:455] [attachment.ID=csi-4ff6fd4b10c02f804e7435dffeb62054338b590749cdaacf18e198ee0ab6dd66] watch channel had been closed
E0710 04:00:23.410589  145234 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-10 04:00:23.88690694 +0000 UTC m=+12.878880830 (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"
I0710 04:00:23.411181  145234 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"
I0710 04:00:23.411547  145234 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"
I0710 04:00:23.411634  145234 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" 
I0710 04:00:23.411860  145234 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"
E0710 04:00:23.412061  145234 csi_attacher.go:455] [attachment.ID=csi-77bd5b88d32d48e5a31f0073211a7dd54ed0066f008e12364f4b6ecb61dc7370] watch channel had been closed
I0710 04:00:23.412213  145234 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"
I0710 04:00:23.412555  145234 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"
==================
WARNING: DATA RACE
Write at 0x000003366eb8 by goroutine 176:
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/testing.CreateTestClient()
      pkg/controller/volume/attachdetach/testing/testvolumespec.go:176 +0xb84
  k8s.io/kubernetes/pkg/controller/volume/attachdetach.volumeAttachmentRecoveryTestCase()
      pkg/controller/volume/attachdetach/attach_detach_controller_test.go:430 +0x5d
  k8s.io/kubernetes/pkg/controller/volume/attachdetach.Test_ADC_VolumeAttachmentRecovery.func1()
      pkg/controller/volume/attachdetach/attach_detach_controller_test.go:424 +0xd7
  testing.tRunner()
      GOROOT/src/testing/testing.go:1123 +0x202

Previous read at 0x000003366eb8 by goroutine 153:
  k8s.io/kubernetes/pkg/controller/volume/attachdetach/testing.CreateTestClient.func7()
      pkg/controller/volume/attachdetach/testing/testvolumespec.go:185 +0x106
E0710 04:00:23.412809  145234 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-10 04:00:23.912489734 +0000 UTC m=+12.904463653 (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"
  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

Goroutine 176 (running) created at:
  testing.(*T).Run()
      GOROOT/src/testing/testing.go:1168 +0x5bb
  k8s.io/kubernetes/pkg/controller/volume/attachdetach.Test_ADC_VolumeAttachmentRecovery()
      pkg/controller/volume/attachdetach/attach_detach_controller_test.go:423 +0x49c
  testing.tRunner()
      GOROOT/src/testing/testing.go:1123 +0x202

Goroutine 153 (finished) 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
==================
I0710 04:00:23.417179  145234 shared_informer.go:240] Waiting for caches to sync for attach detach
I0710 04:00:23.517785  145234 shared_informer.go:247] Caches are synced for attach detach 
--- FAIL: Test_ADC_VolumeAttachmentRecovery (3.61s)
    --- FAIL: Test_ADC_VolumeAttachmentRecovery/Deleted_Pod_with_migrated_PV (0.16s)
        testing.go:1038: race detected during execution of test
    testing.go:1038: race detected during execution of test
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


//pkg/kubelet/cm/devicemanager/go_default_test:run_2_of_2 0.00s

bazel test //pkg/kubelet/cm/devicemanager/go_default_test:run_2_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/kubelet/cm/devicemanager:go_default_test
-----------------------------------------------------------------------------
I0710 03:56:01.474909  112498 device_plugin_stub.go:142] Starting to serve on /tmp/mock1625889361470334745.sock
I0710 03:56:01.478605  112498 device_plugin_stub.go:142] Starting to serve on /tmp/mock1625889361476971289.sock
I0710 03:56:01.482485  112498 device_plugin_stub.go:238] ListAndWatch
E0710 03:56:01.483631  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin mock with error rpc error: code = Unavailable desc = transport is closing
I0710 03:56:01.485198  112498 device_plugin_stub.go:142] Starting to serve on /tmp/mock1625889361483746875.sock
I0710 03:56:01.488905  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:01.489913  112498 device_plugin_stub.go:272] Allocate, &AllocateRequest{ContainerRequests:[]*ContainerAllocateRequest{&ContainerAllocateRequest{DevicesIDs:[ADeviceId],},},}
E0710 03:56:01.490979  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin mock with error rpc error: code = Unavailable desc = transport is closing
I0710 03:56:01.492772  112498 device_plugin_stub.go:142] Starting to serve on /tmp/mock1625889361491177676.sock
I0710 03:56:01.495311  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:01.496329  112498 device_plugin_stub.go:259] GetPreferredAllocation, &PreferredAllocationRequest{ContainerRequests:[]*ContainerPreferredAllocationRequest{&ContainerPreferredAllocationRequest{AvailableDeviceIDs:[],MustIncludeDeviceIDs:[],AllocationSize:-1,},},}
E0710 03:56:01.497205  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin mock with error rpc error: code = Unavailable desc = transport is closing
I0710 03:56:01.497524  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
I0710 03:56:01.497907  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
W0710 03:56:01.498087  112498 manager.go:594] Failed to retrieve checkpoint for "kubelet_internal_checkpoint": checkpoint is not found
I0710 03:56:01.499792  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin147345814/device-plugin.sock
I0710 03:56:01.500571  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
W0710 03:56:01.500720  112498 manager.go:594] Failed to retrieve checkpoint for "kubelet_internal_checkpoint": checkpoint is not found
I0710 03:56:01.501734  112498 plugin_manager.go:114] Starting Kubelet Plugin Manager
I0710 03:56:01.505870  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin201016317/device-plugin.sock
E0710 03:56:01.508548  112498 goroutinemap.go:150] Operation for "/tmp/device_plugin201016317/server.sock" failed. No retries permitted until 2021-07-10 03:56:02.008391853 +0000 UTC m=+0.625455182 (durationBeforeRetry 500ms). Error: "RegisterPlugin error -- failed to get plugin info using RPC GetInfo at socket /tmp/device_plugin201016317/server.sock, err: rpc error: code = Unavailable desc = transport is closing"
I0710 03:56:01.508694  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
E0710 03:56:01.508946  112498 goroutinemap.go:150] Operation for "/tmp/device_plugin201016317/device-plugin.sock" failed. No retries permitted until 2021-07-10 03:56:02.008767071 +0000 UTC m=+0.625830385 (durationBeforeRetry 500ms). Error: "RegisterPlugin error -- failed to get plugin info using RPC GetInfo at socket /tmp/device_plugin201016317/device-plugin.sock, err: rpc error: code = Unavailable desc = transport is closing"
W0710 03:56:01.508942  112498 manager.go:594] Failed to retrieve checkpoint for "kubelet_internal_checkpoint": checkpoint is not found
I0710 03:56:01.510829  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock
I0710 03:56:01.510894  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:01.512984  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:01.516039  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:01.593167  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock.new
I0710 03:56:01.593267  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:01.595539  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:01.599885  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:01.658409  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock.third
I0710 03:56:01.658529  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:01.660998  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:01.663819  112498 device_plugin_stub.go:238] ListAndWatch
E0710 03:56:01.707221  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
E0710 03:56:01.707739  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
I0710 03:56:01.708139  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
E0710 03:56:01.708313  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
I0710 03:56:01.710698  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock
I0710 03:56:01.710761  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:01.712866  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:01.717342  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:01.834192  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock.new
I0710 03:56:01.834271  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:01.836499  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:01.840012  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:02.041532  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock.third
I0710 03:56:02.041612  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:02.043831  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:02.047292  112498 device_plugin_stub.go:238] ListAndWatch
E0710 03:56:02.338552  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
E0710 03:56:02.339470  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
E0710 03:56:02.339919  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Canceled desc = grpc: the client connection is closing
I0710 03:56:02.339956  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
I0710 03:56:02.342276  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock
I0710 03:56:02.342334  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:02.344639  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:02.347388  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:02.599574  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock.new
I0710 03:56:02.599674  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:02.602623  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:02.605939  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:02.892243  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock.third
I0710 03:56:02.892325  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:02.895752  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:02.898453  112498 device_plugin_stub.go:238] ListAndWatch
E0710 03:56:03.002842  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Canceled desc = grpc: the client connection is closing
I0710 03:56:03.003003  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
E0710 03:56:03.006177  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
E0710 03:56:03.006879  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
I0710 03:56:03.007510  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock
I0710 03:56:03.100560  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:03.103196  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:03.105999  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:03.322503  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock.new
I0710 03:56:03.322590  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:03.324628  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:03.330351  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:03.406048  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin775265592/device-plugin.sock.third
I0710 03:56:03.406130  112498 device_plugin_stub.go:191] Deprecation file not found. Invoke registration
I0710 03:56:03.417394  112498 manager.go:408] Got registration request from device plugin with resource name "fake-domain/resource"
I0710 03:56:03.420203  112498 device_plugin_stub.go:238] ListAndWatch
E0710 03:56:03.425548  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
E0710 03:56:03.426364  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
E0710 03:56:03.426380  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Unavailable desc = transport is closing
I0710 03:56:03.427349  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
W0710 03:56:03.427569  112498 manager.go:594] Failed to retrieve checkpoint for "kubelet_internal_checkpoint": checkpoint is not found
I0710 03:56:03.429620  112498 plugin_manager.go:114] Starting Kubelet Plugin Manager
I0710 03:56:03.431900  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin296088931/device-plugin.sock
I0710 03:56:03.433749  112498 device_plugin_stub.go:164] GetInfo
E0710 03:56:03.439738  112498 goroutinemap.go:150] Operation for "/tmp/device_plugin296088931/server.sock" failed. No retries permitted until 2021-07-10 03:56:03.93963992 +0000 UTC m=+2.556703259 (durationBeforeRetry 500ms). Error: "RegisterPlugin error -- failed to get plugin info using RPC GetInfo at socket /tmp/device_plugin296088931/server.sock, err: rpc error: code = Unimplemented desc = unknown service pluginregistration.Registration"
I0710 03:56:03.446692  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:03.452119  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin296088931/device-plugin.sock.new
E0710 03:56:04.431632  112498 endpoint.go:107] listAndWatch ended unexpectedly for device plugin fake-domain/resource with error rpc error: code = Canceled desc = grpc: the client connection is closing
I0710 03:56:04.434204  112498 device_plugin_stub.go:164] GetInfo
E0710 03:56:04.434416  112498 goroutinemap.go:150] Operation for "/tmp/device_plugin296088931/server.sock" failed. No retries permitted until 2021-07-10 03:56:05.434249896 +0000 UTC m=+4.051313230 (durationBeforeRetry 1s). Error: "RegisterPlugin error -- failed to get plugin info using RPC GetInfo at socket /tmp/device_plugin296088931/server.sock, err: rpc error: code = Unimplemented desc = unknown service pluginregistration.Registration"
I0710 03:56:04.438654  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:04.444622  112498 device_plugin_stub.go:142] Starting to serve on /tmp/device_plugin296088931/device-plugin.sock.third
I0710 03:56:05.436760  112498 device_plugin_stub.go:164] GetInfo
I0710 03:56:05.436912  112498 device_plugin_stub.go:164] GetInfo
I0710 03:56:05.444624  112498 device_plugin_stub.go:238] ListAndWatch
I0710 03:56:05.446433  112498 device_plugin_stub.go:238] ListAndWatch
--- FAIL: TestDevicePluginReRegistrationProbeMode (2.02s)
    manager_test.go:223: 
        	Error Trace:	manager_test.go:223
        	Error:      	Not equal: 
        	            	expected: 1
        	            	actual  : 2
        	Test:       	TestDevicePluginReRegistrationProbeMode
        	Messages:   	Devices of previous registered should be removed
I0710 03:56:05.450340  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
E0710 03:56:05.465927  112498 manager.go:544] unexpected: unhealthyDevices and endpoints are out of sync
I0710 03:56:05.479853  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
I0710 03:56:05.480016  112498 fake_topology_manager.go:35] [fake topologymanager] GetAffinity pod: 4cae5799-1d4d-42ff-a497-bb8e40fe6a68 container name:  
I0710 03:56:05.480127  112498 fake_topology_manager.go:35] [fake topologymanager] GetAffinity pod: 4cae5799-1d4d-42ff-a497-bb8e40fe6a68 container name:  
I0710 03:56:05.485053  112498 fake_topology_manager.go:35] [fake topologymanager] GetAffinity pod: 7ffbfff5-bc59-4fea-9ff5-171cc5adab1e container name:  
I0710 03:56:05.489168  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
I0710 03:56:05.489387  112498 fake_topology_manager.go:35] [fake topologymanager] GetAffinity pod: 40c581f6-b288-4203-98a9-490b778256b0 container name:  fd5028b2-b547-4879-a190-29588f7025ee
I0710 03:56:05.492883  112498 fake_topology_manager.go:35] [fake topologymanager] GetAffinity pod: 40c581f6-b288-4203-98a9-490b778256b0 container name:  9ee791a1-eb12-4b2d-a712-a28f6bd28177
I0710 03:56:05.496719  112498 fake_topology_manager.go:35] [fake topologymanager] GetAffinity pod: 40c581f6-b288-4203-98a9-490b778256b0 container name:  75d0abf2-c013-4825-bfb7-03c8a1258009
I0710 03:56:05.501622  112498 fake_topology_manager.go:35] [fake topologymanager] GetAffinity pod: 40c581f6-b288-4203-98a9-490b778256b0 container name:  c21cb0aa-3a0a-49ae-bd5f-3e079ecce87a
I0710 03:56:05.508342  112498 fake_topology_manager.go:30] [fake topologymanager] NewFakeManager
I0710 03:56:05.508500  112498 fake_topology_manager.go:35] [fake topologymanager] GetAffinity pod: f5bd3d20-1139-47e6-89c8-2e38964d8686 container name:  
I0710 03:56:05.518115  112498 topology_hints.go:46] [devicemanager] Resource 'testdevice' does not have a topology preference
E0710 03:56:05.518781  112498 topology_hints.go:70] [devicemanager] Unable to generate topology hints: requested number of devices unavailable for 'testdevice': requested: 6, available: 4
I0710 03:56:05.518944  112498 topology_hints.go:61] [devicemanager] Regenerating TopologyHints for resource 'testdevice' already allocated to (pod _(fakePod), container fakeContainer)
E0710 03:56:05.519128  112498 topology_hints.go:57] [devicemanager] Resource 'testdevice' already allocated to (pod _(fakePod), container fakeContainer) with different number than request: requested: 4, allocated: 2
E0710 03:56:05.519270  112498 topology_hints.go:57] [devicemanager] Resource 'testdevice' already allocated to (pod _(fakePod), container fakeContainer) with different number than request: requested: 2, allocated: 4
I0710 03:56:05.528699  112498 topology_hints.go:96] [devicemanager] Resource 'testdevice' does not have a topology preference
I0710 03:56:05.529316  112498 topology_hints.go:111] [devicemanager] Regenerating TopologyHints for resource 'testdevice' already allocated to (pod _(fakePod))
E0710 03:56:05.529565  112498 topology_hints.go:119] [devicemanager] Unable to generate topology hints: requested number of devices unavailable for 'testdevice': requested: 6, available: 4
I0710 03:56:05.529697  112498 topology_hints.go:111] [devicemanager] Regenerating TopologyHints for resource 'testdevice' already allocated to (pod _(fakePod))
E0710 03:56:05.529836  112498 topology_hints.go:107] [devicemanager] Resource 'testdevice' already allocated to (pod _(fakePod)) with different number than request: requested: 4, allocated: 2
E0710 03:56:05.530913  112498 topology_hints.go:107] [devicemanager] Resource 'testdevice' already allocated to (pod _(fakePod)) with different number than request: requested: 2, allocated: 4
FAIL

				from junit_bazel.xml

Filter through log files | View test history on testgrid


Show 1936 Passed Tests