This job view page is being replaced by Spyglass soon. Check out the new job view.
PRmlavacca: Warning log callback in client-go
ResultFAILURE
Tests 2 failed / 1937 succeeded
Started2020-11-21 11:14
Elapsed32m51s
Revision2ec6c259f74e1c31ebda6c4ac2e24e2430df5ec4
Refs 95517

Test Failures


//pkg/kubelet/volumemanager/reconciler/go_default_test:run_1_of_2 0.00s

bazel test //pkg/kubelet/volumemanager/reconciler/go_default_test:run_1_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/kubelet/volumemanager/reconciler:go_default_test
-----------------------------------------------------------------------------
I1121 11:25:49.632863   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:49.633020   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:49.633824   83425 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:49.633897   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:49.633940   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:49.634171   83425 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I1121 11:25:49.635301   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I1121 11:25:49.635426   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.635519   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:49.734712   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:49.734788   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:49.734837   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:49.734971   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:25:49.737156   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:25:49.737308   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.737424   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:49.738545   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.738695   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.835544   83425 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:49.835612   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:49.835661   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:49.836018   83425 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I1121 11:25:49.836784   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I1121 11:25:49.836908   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.837050   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:49.935602   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:49.935822   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:49.936307   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:49.936456   83425 operation_generator.go:891] UnmountDevice succeeded for volume "volume-name" %!(EXTRA string=UnmountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" )
I1121 11:25:49.936947   83425 reconciler.go:333] operationExecutor.DetachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:49.937086   83425 operation_generator.go:470] DetachVolume.Detach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.036390   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.036489   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.036541   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.036934   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:25:50.037671   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:25:50.037790   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.037888   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:50.136400   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:50.136706   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:50.138593   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:50.138824   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:50.139291   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.139473   83425 operation_generator.go:891] UnmountDevice succeeded for volume "volume-name" %!(EXTRA string=UnmountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" )
I1121 11:25:50.139692   83425 reconciler.go:319] Volume detached for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:25:50.237933   83425 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.238006   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.238058   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.238256   83425 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I1121 11:25:50.238843   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I1121 11:25:50.238957   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.342296   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.342334   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:25:50.342379   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.342442   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.342993   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:25:50.343108   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.461125   83425 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.461200   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.461255   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.461612   83425 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I1121 11:25:50.462334   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I1121 11:25:50.462446   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.561067   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:50.561301   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:50.561736   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.561898   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.562270   83425 reconciler.go:333] operationExecutor.DetachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.562403   83425 operation_generator.go:470] DetachVolume.Detach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.669778   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.669854   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.669913   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.670110   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:25:50.670615   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:25:50.670727   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.773067   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:50.773205   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:50.773674   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.773848   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.774006   83425 reconciler.go:319] Volume detached for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:25:50.881801   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.881873   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.881933   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.882594   83425 operation_generator.go:1357] Controller attach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:50.883087   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:50.883182   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.883270   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:50.997104   83425 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.006489   83425 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.105199   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.105275   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.105332   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.105688   83425 operation_generator.go:1357] Controller attach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.106191   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.106297   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:51.207186   83425 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.325394   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.327864   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.327938   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.327993   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.328679   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.329800   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:51.329926   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") device mount path ""
E1121 11:25:51.330179   83425 operation_generator.go:1669] MountVolume.NodeExapndVolume failed with %!!(MISSING)v(MISSING) for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") : volume-in-use
I1121 11:25:51.333769   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.333947   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:51.334503   83425 operation_generator.go:1669] MountVolume.NodeExapndVolume failed with %!!(MISSING)v(MISSING) for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") : volume-in-use
I1121 11:25:51.426332   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.426397   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.426449   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.426680   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.427270   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.427396   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:51.427836   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-mount-device-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:51.92762814 +0000 UTC m=+2.395836802 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"timeout-mount-device-volume\" (UniqueName: \"fake-plugin/timeout-mount-device-volume\") pod \"pod1\" (UID: \"pod1uid\") : mount failed"
I1121 11:25:51.526397   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I1121 11:25:51.526595   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I1121 11:25:51.526817   83425 reconciler.go:319] Volume detached for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:25:51.628188   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.628264   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.628316   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.632877   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.633537   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.633667   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:51.634132   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-mount-device-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:52.133886242 +0000 UTC m=+2.602094913 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"fail-mount-device-volume-name\" (UniqueName: \"fake-plugin/fail-mount-device-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: fail-mount-device-volume-name"
I1121 11:25:51.738676   83425 reconciler.go:319] Volume detached for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") on node "mynodename" DevicePath "fake/path"
I1121 11:25:51.849168   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.849245   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.849513   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.849996   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.851115   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.852028   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:51.852586   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:52.352348818 +0000 UTC m=+2.820557488 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : timed out mounting error"
I1121 11:25:52.352747   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:52.352923   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:52.353396   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:53.353180838 +0000 UTC m=+3.821389509 (durationBeforeRetry 1s). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: timeout-and-fail-mount-device-name"
I1121 11:25:53.353664   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:53.353826   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:53.354228   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:55.354028075 +0000 UTC m=+5.822236739 (durationBeforeRetry 2s). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: timeout-and-fail-mount-device-name"
I1121 11:25:55.354382   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:55.354554   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:55.354993   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:59.354800078 +0000 UTC m=+9.823008770 (durationBeforeRetry 4s). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: timeout-and-fail-mount-device-name"
I1121 11:25:59.355519   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:59.355678   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:59.356185   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:07.355969117 +0000 UTC m=+17.824177790 (durationBeforeRetry 8s). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: timeout-and-fail-mount-device-name"
I1121 11:26:01.954397   83425 reconciler.go:319] Volume detached for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:02.091475   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:02.091551   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:02.091601   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:02.092111   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:02.092899   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:02.093037   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:02.193148   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:02.193299   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:02.193747   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:02.693501566 +0000 UTC m=+13.161710243 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:02.698413   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:02.698563   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:02.699080   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:03.698884116 +0000 UTC m=+14.167092798 (durationBeforeRetry 1s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:03.699559   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:03.699728   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:03.700119   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:05.699933951 +0000 UTC m=+16.168142635 (durationBeforeRetry 2s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:05.705591   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:05.705757   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:05.706137   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:09.705958769 +0000 UTC m=+20.174167448 (durationBeforeRetry 4s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:09.706370   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:09.706527   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:09.706892   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:17.706704351 +0000 UTC m=+28.174913024 (durationBeforeRetry 8s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:12.193051   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:12.193234   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/success-and-timeout-device-name" (OuterVolumeSpecName: "success-and-timeout-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-timeout-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:12.193695   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I1121 11:26:12.193896   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I1121 11:26:12.194103   83425 reconciler.go:319] Volume detached for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:12.294019   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:12.294107   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:12.294161   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:12.294457   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:12.295114   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:12.295246   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:12.407449   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:12.407623   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:12.409219   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:12.908182756 +0000 UTC m=+23.376391445 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:12.918042   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:12.918198   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:12.918919   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:13.918703484 +0000 UTC m=+24.386912155 (durationBeforeRetry 1s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:13.931291   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:13.931453   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:13.932258   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:15.931728604 +0000 UTC m=+26.399937280 (durationBeforeRetry 2s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:15.947551   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:15.947745   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:15.948154   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:19.947947991 +0000 UTC m=+30.416156659 (durationBeforeRetry 4s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:19.950636   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:19.950797   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:19.951303   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:27.951047931 +0000 UTC m=+38.419256605 (durationBeforeRetry 8s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:22.398631   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:22.398791   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/success-and-failed-mount-device-name" (OuterVolumeSpecName: "success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-mount-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:22.399464   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" 
I1121 11:26:22.399503   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" 
I1121 11:26:22.407988   83425 reconciler.go:319] Volume detached for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:22.496692   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:26:22.496765   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:22.496817   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:22.497046   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:22.497562   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:22.497707   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:22.498130   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-mount-device-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:22.997949753 +0000 UTC m=+33.466158439 (durationBeforeRetry 500ms). Error: "MountVolume.MountDevice failed for volume \"timeout-mount-device-volume\" (UniqueName: \"fake-plugin/timeout-mount-device-volume\") pod \"pod1\" (UID: \"pod1uid\") : mount failed"
I1121 11:26:22.597532   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I1121 11:26:22.597748   83425 operation_generator.go:891] UnmountDevice succeeded for volume "timeout-mount-device-volume" %!(EXTRA string=UnmountDevice succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" )
I1121 11:26:22.597999   83425 reconciler.go:319] Volume detached for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:22.699409   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:22.699477   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:22.699527   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:22.699934   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:22.700520   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:22.716566   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:22.717040   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-mount-device-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:23.216843358 +0000 UTC m=+33.685052037 (durationBeforeRetry 500ms). Error: "MountVolume.MountDevice failed for volume \"fail-mount-device-volume-name\" (UniqueName: \"fake-plugin/fail-mount-device-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:22.812716   83425 reconciler.go:319] Volume detached for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") on node "mynodename" DevicePath "fake/path"
I1121 11:26:22.921283   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:22.921370   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:22.921439   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:22.921705   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:22.922424   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:22.922561   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:22.922954   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:23.422764213 +0000 UTC m=+33.890972884 (durationBeforeRetry 500ms). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : timed out mounting error"
I1121 11:26:23.433030   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:23.433189   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:23.446327   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:24.446035849 +0000 UTC m=+34.914244540 (durationBeforeRetry 1s). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:24.450637   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:24.450841   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:24.451275   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:26.451058171 +0000 UTC m=+36.919266850 (durationBeforeRetry 2s). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:26.451859   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:26.452033   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:26.452538   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:30.452258929 +0000 UTC m=+40.920467595 (durationBeforeRetry 4s). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:30.470177   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:30.470344   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:30.470761   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:38.470565579 +0000 UTC m=+48.938774252 (durationBeforeRetry 8s). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:33.021337   83425 reconciler.go:319] Volume detached for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:33.127592   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:33.127687   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:33.127766   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:33.128661   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:33.131952   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:33.132159   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:33.132332   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:26:33.226781   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:33.236302   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:33.237265   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:33.237415   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:43.250551   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:43.250763   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-timeout-device-name" (OuterVolumeSpecName: "success-and-timeout-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-timeout-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:43.251296   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I1121 11:26:43.251496   83425 operation_generator.go:891] UnmountDevice succeeded for volume "success-and-timeout-device-name" %!(EXTRA string=UnmountDevice succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" )
I1121 11:26:43.251735   83425 reconciler.go:319] Volume detached for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:43.351381   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:43.351448   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:43.351501   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:43.351869   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:43.376243   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:43.376419   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:43.376562   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:26:43.487799   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:43.487963   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:53.469761   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:53.474921   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-failed-mount-device-name" (OuterVolumeSpecName: "success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-mount-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:53.475735   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:53.476703   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-failed-mount-device-name" (OuterVolumeSpecName: "success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-mount-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:53.493365   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" 
I1121 11:26:53.493934   83425 operation_generator.go:891] UnmountDevice succeeded for volume "success-and-failed-mount-device-name" %!(EXTRA string=UnmountDevice succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" )
I1121 11:26:53.494189   83425 reconciler.go:319] Volume detached for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:53.580080   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:26:53.580162   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:53.580217   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:53.580454   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:53.581035   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:53.581157   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:53.581524   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:54.0813423 +0000 UTC m=+64.549550974 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"timeout-setup-volume\" (UniqueName: \"fake-plugin/timeout-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:26:53.680094   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:53.681077   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/timeout-setup-volume" (OuterVolumeSpecName: "timeout-setup-volume") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "timeout-setup-volume". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:53.681601   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I1121 11:26:53.681962   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I1121 11:26:53.682169   83425 reconciler.go:319] Volume detached for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:53.782409   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:26:53.782483   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:53.782539   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:53.782893   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:53.784879   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:53.785019   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:53.785379   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:54.285204851 +0000 UTC m=+64.753413522 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"fail-setup-volume\" (UniqueName: \"fake-plugin/fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:26:53.902502   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" 
I1121 11:26:53.902754   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" 
I1121 11:26:53.902996   83425 reconciler.go:319] Volume detached for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:54.016856   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:26:54.016950   83425 reconciler.go:157] Reconciler: start to sync state
I1121 11:26:54.017034   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
E1121 11:26:54.017005   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:54.020668   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:54.022949   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:54.030817   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:54.526624164 +0000 UTC m=+64.994832853 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:26:54.530453   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:54.530625   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:54.548651   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:55.530843554 +0000 UTC m=+65.999052242 (durationBeforeRetry 1s). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:26:55.533285   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:55.534966   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:55.539624   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:57.535813008 +0000 UTC m=+68.004021699 (durationBeforeRetry 2s). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:26:57.538272   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:57.538433   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:57.538872   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:01.538642941 +0000 UTC m=+72.006851608 (durationBeforeRetry 4s). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:01.539865   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:01.540255   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:01.541415   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:09.540685127 +0000 UTC m=+80.008893795 (durationBeforeRetry 8s). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:04.121785   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I1121 11:27:04.122200   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I1121 11:27:04.127076   83425 reconciler.go:319] Volume detached for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:04.227368   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") 
I1121 11:27:04.227554   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:04.228445   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:04.229449   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:04.245771   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:04.245958   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:04.339386   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:04.339661   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:04.340235   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:04.839984094 +0000 UTC m=+75.308192768 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:04.871373   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:04.871546   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:04.871977   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:05.871768653 +0000 UTC m=+76.339977338 (durationBeforeRetry 1s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:05.889531   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:05.890663   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:05.913565   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:07.913237256 +0000 UTC m=+78.381445989 (durationBeforeRetry 2s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:07.920630   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:07.922517   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:07.937021   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:11.92334134 +0000 UTC m=+82.391550002 (durationBeforeRetry 4s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:11.932152   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:11.933065   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:11.933848   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:19.93328555 +0000 UTC m=+90.401494239 (durationBeforeRetry 8s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:14.328866   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:14.329018   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/success-and-timeout-setup-volume-name" (OuterVolumeSpecName: "success-and-timeout-setup-volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-timeout-setup-volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:14.341311   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" 
I1121 11:27:14.341621   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" 
I1121 11:27:14.341856   83425 reconciler.go:319] Volume detached for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:14.442259   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:27:14.442346   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:14.442404   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:14.443076   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:14.443875   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:14.444014   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:14.542348   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:14.542513   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:14.542942   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:15.042746757 +0000 UTC m=+85.510955433 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:15.043516   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:15.043681   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:15.050762   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:16.043883132 +0000 UTC m=+86.512091801 (durationBeforeRetry 1s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:16.047842   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:16.048014   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:16.048433   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:18.048232278 +0000 UTC m=+88.516440959 (durationBeforeRetry 2s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:18.052446   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:18.052649   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:18.053078   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:22.052881926 +0000 UTC m=+92.521090596 (durationBeforeRetry 4s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:22.090383   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:22.090552   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:22.090982   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:30.090771578 +0000 UTC m=+100.558980244 (durationBeforeRetry 8s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:24.577505   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:24.577655   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/success-and-failed-setup-device-name" (OuterVolumeSpecName: "success-and-failed-setup-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-setup-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:24.578365   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" 
I1121 11:27:24.581183   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" 
I1121 11:27:24.581449   83425 reconciler.go:319] Volume detached for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:24.690008   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:27:24.690088   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:24.690145   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:24.690527   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:24.691273   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:24.691406   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:24.691516   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") device mount path ""
E1121 11:27:24.691922   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:25.191753804 +0000 UTC m=+95.659962470 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"timeout-setup-volume\" (UniqueName: \"fake-plugin/timeout-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:24.813340   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/timeout-setup-volume" (OuterVolumeSpecName: "timeout-setup-volume") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "timeout-setup-volume". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:24.814545   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:24.817573   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I1121 11:27:24.817707   83425 operation_generator.go:891] UnmountDevice succeeded for volume "timeout-setup-volume" %!(EXTRA string=UnmountDevice succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" )
I1121 11:27:24.819516   83425 reconciler.go:319] Volume detached for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:24.923409   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:24.924644   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:27:24.930421   83425 reconciler.go:319] Volume detached for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" DevicePath "fake/path"
I1121 11:27:24.930482   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:24.937798   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:25.033731   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:27:25.033802   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:25.033846   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:25.034371   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:25.035199   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:25.035340   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:25.035460   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") device mount path ""
E1121 11:27:25.035863   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:25.535685461 +0000 UTC m=+96.003894143 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:25.578593   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:25.578742   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:25.579150   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:26.578978461 +0000 UTC m=+97.047187130 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:26.579561   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:26.579731   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:26.602487   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:28.602145511 +0000 UTC m=+99.070354193 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:28.602699   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:28.602862   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:28.603322   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:32.603086421 +0000 UTC m=+103.071295172 (durationBeforeRetry 4s). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:32.603832   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:32.604023   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:32.604418   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:40.604237628 +0000 UTC m=+111.072446298 (durationBeforeRetry 8s). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:35.136866   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I1121 11:27:35.137128   83425 operation_generator.go:891] UnmountDevice succeeded for volume "timeout-and-fail-setup-volume" %!(EXTRA string=UnmountDevice succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" )
I1121 11:27:35.137583   83425 reconciler.go:319] Volume detached for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:35.270540   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") 
I1121 11:27:35.270618   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:35.270677   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:35.271080   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:35.271685   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:35.271823   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:35.271946   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:27:35.386128   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:35.386325   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:35.387084   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:35.886544802 +0000 UTC m=+106.354753486 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:35.887113   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:35.887282   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:35.887677   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:36.887490899 +0000 UTC m=+107.355699582 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:36.889771   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:36.892634   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:36.897140   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:38.895979609 +0000 UTC m=+109.364188303 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:38.905461   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:38.905619   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:38.906031   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:42.905826094 +0000 UTC m=+113.374034770 (durationBeforeRetry 4s). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:42.917820   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:42.918000   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:42.918466   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:50.918241381 +0000 UTC m=+121.386450056 (durationBeforeRetry 8s). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:45.387566   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:45.387932   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-timeout-setup-volume-name" (OuterVolumeSpecName: "success-and-timeout-setup-volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-timeout-setup-volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:45.388418   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" 
I1121 11:27:45.388649   83425 operation_generator.go:891] UnmountDevice succeeded for volume "success-and-timeout-setup-volume-name" %!(EXTRA string=UnmountDevice succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" )
I1121 11:27:45.389054   83425 reconciler.go:319] Volume detached for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:45.521658   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:27:45.521761   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:45.521829   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:45.522616   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:45.523299   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:45.523457   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:45.523700   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:27:45.650360   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:45.650534   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:45.650937   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:46.150736242 +0000 UTC m=+116.618944917 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:46.169816   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:46.169990   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:46.170416   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:47.170220278 +0000 UTC m=+117.638428947 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:47.170760   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:47.170921   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:47.171318   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:49.171123406 +0000 UTC m=+119.639332082 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:49.176632   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:49.178936   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:49.184237   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:53.181618406 +0000 UTC m=+123.649827086 (durationBeforeRetry 4s). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:53.194773   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:53.194968   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:53.195408   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:28:01.195184989 +0000 UTC m=+131.663393638 (durationBeforeRetry 8s). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:55.700997   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:55.701497   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-failed-setup-device-name" (OuterVolumeSpecName: "success-and-failed-setup-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-setup-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:55.702092   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" 
I1121 11:27:55.702346   83425 operation_generator.go:891] UnmountDevice succeeded for volume "success-and-failed-setup-device-name" %!(EXTRA string=UnmountDevice succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" )
I1121 11:27:55.702801   83425 reconciler.go:319] Volume detached for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" DevicePath "/dev/sdb"
--- FAIL: Test_UncertainVolumeMountState (62.23s)
    --- FAIL: Test_UncertainVolumeMountState/failed_operation_should_result_in_not-mounted_volume_[Filesystem] (0.11s)
        reconciler_test.go:1523: Error verifying UnMountDeviceCallCount: Expected DeviceUnmount Call 1, got 0
I1121 11:27:55.805640   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:27:55.805714   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:55.805774   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:55.806180   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:27:55.807067   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:27:55.807195   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:55.807291   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:27:55.949309   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:55.949849   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:55.950300   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:27:55.950375   83425 reconciler_test.go:1798] UnmountDevice called
I1121 11:27:55.950563   83425 operation_generator.go:891] UnmountDevice succeeded for volume "volume-name" %!(EXTRA string=UnmountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" )
I1121 11:27:55.951282   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:55.951392   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:55.951489   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
FAIL

				from junit_bazel.xml

Find pod1 mentions in log files | View test history on testgrid


//pkg/kubelet/volumemanager/reconciler/go_default_test:run_1_of_2 0.00s

bazel test //pkg/kubelet/volumemanager/reconciler/go_default_test:run_1_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/kubelet/volumemanager/reconciler:go_default_test
-----------------------------------------------------------------------------
I1121 11:25:49.632863   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:49.633020   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:49.633824   83425 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:49.633897   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:49.633940   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:49.634171   83425 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I1121 11:25:49.635301   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I1121 11:25:49.635426   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.635519   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:49.734712   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:49.734788   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:49.734837   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:49.734971   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:25:49.737156   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:25:49.737308   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.737424   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:49.738545   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.738695   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.835544   83425 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:49.835612   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:49.835661   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:49.836018   83425 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I1121 11:25:49.836784   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I1121 11:25:49.836908   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:49.837050   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:49.935602   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:49.935822   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:49.936307   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:49.936456   83425 operation_generator.go:891] UnmountDevice succeeded for volume "volume-name" %!(EXTRA string=UnmountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" )
I1121 11:25:49.936947   83425 reconciler.go:333] operationExecutor.DetachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:49.937086   83425 operation_generator.go:470] DetachVolume.Detach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.036390   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.036489   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.036541   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.036934   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:25:50.037671   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:25:50.037790   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.037888   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:50.136400   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:50.136706   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:50.138593   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:50.138824   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:50.139291   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.139473   83425 operation_generator.go:891] UnmountDevice succeeded for volume "volume-name" %!(EXTRA string=UnmountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" )
I1121 11:25:50.139692   83425 reconciler.go:319] Volume detached for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:25:50.237933   83425 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.238006   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.238058   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.238256   83425 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I1121 11:25:50.238843   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I1121 11:25:50.238957   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.342296   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.342334   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:25:50.342379   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.342442   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.342993   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:25:50.343108   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.461125   83425 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.461200   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.461255   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.461612   83425 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I1121 11:25:50.462334   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I1121 11:25:50.462446   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.561067   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:50.561301   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:50.561736   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.561898   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.562270   83425 reconciler.go:333] operationExecutor.DetachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.562403   83425 operation_generator.go:470] DetachVolume.Detach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.669778   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.669854   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.669913   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.670110   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:25:50.670615   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:25:50.670727   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.773067   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:25:50.773205   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:25:50.773674   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.773848   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:25:50.774006   83425 reconciler.go:319] Volume detached for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:25:50.881801   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:50.881873   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:50.881933   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:50.882594   83425 operation_generator.go:1357] Controller attach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:50.883087   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:50.883182   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:50.883270   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:25:50.997104   83425 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.006489   83425 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.105199   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.105275   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.105332   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.105688   83425 operation_generator.go:1357] Controller attach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.106191   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.106297   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:51.207186   83425 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.325394   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.327864   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.327938   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.327993   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.328679   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.329800   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:51.329926   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") device mount path ""
E1121 11:25:51.330179   83425 operation_generator.go:1669] MountVolume.NodeExapndVolume failed with %!!(MISSING)v(MISSING) for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") : volume-in-use
I1121 11:25:51.333769   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.333947   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:51.334503   83425 operation_generator.go:1669] MountVolume.NodeExapndVolume failed with %!!(MISSING)v(MISSING) for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") : volume-in-use
I1121 11:25:51.426332   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.426397   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.426449   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.426680   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.427270   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.427396   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:51.427836   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-mount-device-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:51.92762814 +0000 UTC m=+2.395836802 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"timeout-mount-device-volume\" (UniqueName: \"fake-plugin/timeout-mount-device-volume\") pod \"pod1\" (UID: \"pod1uid\") : mount failed"
I1121 11:25:51.526397   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I1121 11:25:51.526595   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I1121 11:25:51.526817   83425 reconciler.go:319] Volume detached for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:25:51.628188   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.628264   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.628316   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.632877   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.633537   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.633667   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:51.634132   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-mount-device-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:52.133886242 +0000 UTC m=+2.602094913 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"fail-mount-device-volume-name\" (UniqueName: \"fake-plugin/fail-mount-device-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: fail-mount-device-volume-name"
I1121 11:25:51.738676   83425 reconciler.go:319] Volume detached for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") on node "mynodename" DevicePath "fake/path"
I1121 11:25:51.849168   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:25:51.849245   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:25:51.849513   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:25:51.849996   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:25:51.851115   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:25:51.852028   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:51.852586   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:52.352348818 +0000 UTC m=+2.820557488 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : timed out mounting error"
I1121 11:25:52.352747   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:52.352923   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:52.353396   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:53.353180838 +0000 UTC m=+3.821389509 (durationBeforeRetry 1s). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: timeout-and-fail-mount-device-name"
I1121 11:25:53.353664   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:53.353826   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:53.354228   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:55.354028075 +0000 UTC m=+5.822236739 (durationBeforeRetry 2s). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: timeout-and-fail-mount-device-name"
I1121 11:25:55.354382   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:55.354554   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:55.354993   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:25:59.354800078 +0000 UTC m=+9.823008770 (durationBeforeRetry 4s). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: timeout-and-fail-mount-device-name"
I1121 11:25:59.355519   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:25:59.355678   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:25:59.356185   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:07.355969117 +0000 UTC m=+17.824177790 (durationBeforeRetry 8s). Error: "MapVolume.SetUpDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: timeout-and-fail-mount-device-name"
I1121 11:26:01.954397   83425 reconciler.go:319] Volume detached for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:02.091475   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:02.091551   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:02.091601   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:02.092111   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:02.092899   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:02.093037   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:02.193148   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:02.193299   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:02.193747   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:02.693501566 +0000 UTC m=+13.161710243 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:02.698413   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:02.698563   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:02.699080   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:03.698884116 +0000 UTC m=+14.167092798 (durationBeforeRetry 1s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:03.699559   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:03.699728   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:03.700119   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:05.699933951 +0000 UTC m=+16.168142635 (durationBeforeRetry 2s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:05.705591   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:05.705757   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:05.706137   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:09.705958769 +0000 UTC m=+20.174167448 (durationBeforeRetry 4s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:09.706370   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:09.706527   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:09.706892   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:17.706704351 +0000 UTC m=+28.174913024 (durationBeforeRetry 8s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-timeout-device-name\" (UniqueName: \"fake-plugin/success-and-timeout-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting state"
I1121 11:26:12.193051   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:12.193234   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/success-and-timeout-device-name" (OuterVolumeSpecName: "success-and-timeout-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-timeout-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:12.193695   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I1121 11:26:12.193896   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I1121 11:26:12.194103   83425 reconciler.go:319] Volume detached for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:12.294019   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:12.294107   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:12.294161   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:12.294457   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:12.295114   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:12.295246   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:12.407449   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:12.407623   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:12.409219   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:12.908182756 +0000 UTC m=+23.376391445 (durationBeforeRetry 500ms). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:12.918042   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:12.918198   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:12.918919   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:13.918703484 +0000 UTC m=+24.386912155 (durationBeforeRetry 1s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:13.931291   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:13.931453   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:13.932258   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:15.931728604 +0000 UTC m=+26.399937280 (durationBeforeRetry 2s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:15.947551   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:15.947745   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:15.948154   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:19.947947991 +0000 UTC m=+30.416156659 (durationBeforeRetry 4s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:19.950636   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:19.950797   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:19.951303   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:27.951047931 +0000 UTC m=+38.419256605 (durationBeforeRetry 8s). Error: "MapVolume.SetUpDevice failed for volume \"success-and-failed-mount-device-name\" (UniqueName: \"fake-plugin/success-and-failed-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mapping disk: success-and-failed-mount-device-name"
I1121 11:26:22.398631   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:22.398791   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/success-and-failed-mount-device-name" (OuterVolumeSpecName: "success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-mount-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:22.399464   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" 
I1121 11:26:22.399503   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" 
I1121 11:26:22.407988   83425 reconciler.go:319] Volume detached for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:22.496692   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:26:22.496765   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:22.496817   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:22.497046   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:22.497562   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:22.497707   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:22.498130   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-mount-device-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:22.997949753 +0000 UTC m=+33.466158439 (durationBeforeRetry 500ms). Error: "MountVolume.MountDevice failed for volume \"timeout-mount-device-volume\" (UniqueName: \"fake-plugin/timeout-mount-device-volume\") pod \"pod1\" (UID: \"pod1uid\") : mount failed"
I1121 11:26:22.597532   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I1121 11:26:22.597748   83425 operation_generator.go:891] UnmountDevice succeeded for volume "timeout-mount-device-volume" %!(EXTRA string=UnmountDevice succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" )
I1121 11:26:22.597999   83425 reconciler.go:319] Volume detached for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:22.699409   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:22.699477   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:22.699527   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:22.699934   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:22.700520   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:22.716566   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:22.717040   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-mount-device-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:23.216843358 +0000 UTC m=+33.685052037 (durationBeforeRetry 500ms). Error: "MountVolume.MountDevice failed for volume \"fail-mount-device-volume-name\" (UniqueName: \"fake-plugin/fail-mount-device-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:22.812716   83425 reconciler.go:319] Volume detached for volume "fail-mount-device-volume-name" (UniqueName: "fake-plugin/fail-mount-device-volume-name") on node "mynodename" DevicePath "fake/path"
I1121 11:26:22.921283   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:22.921370   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:22.921439   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:22.921705   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:22.922424   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:22.922561   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:22.922954   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:23.422764213 +0000 UTC m=+33.890972884 (durationBeforeRetry 500ms). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : timed out mounting error"
I1121 11:26:23.433030   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:23.433189   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:23.446327   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:24.446035849 +0000 UTC m=+34.914244540 (durationBeforeRetry 1s). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:24.450637   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:24.450841   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:24.451275   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:26.451058171 +0000 UTC m=+36.919266850 (durationBeforeRetry 2s). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:26.451859   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:26.452033   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:26.452538   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:30.452258929 +0000 UTC m=+40.920467595 (durationBeforeRetry 4s). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:30.470177   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:30.470344   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:30.470761   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:38.470565579 +0000 UTC m=+48.938774252 (durationBeforeRetry 8s). Error: "MountVolume.MountDevice failed for volume \"timeout-and-fail-mount-device-name\" (UniqueName: \"fake-plugin/timeout-and-fail-mount-device-name\") pod \"pod1\" (UID: \"pod1uid\") : error mounting disk: /dev/sdb"
I1121 11:26:33.021337   83425 reconciler.go:319] Volume detached for volume "timeout-and-fail-mount-device-name" (UniqueName: "fake-plugin/timeout-and-fail-mount-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:33.127592   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:33.127687   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:33.127766   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:33.128661   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:33.131952   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:33.132159   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:33.132332   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:26:33.226781   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:33.236302   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:33.237265   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:33.237415   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:43.250551   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:43.250763   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-timeout-device-name" (OuterVolumeSpecName: "success-and-timeout-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-timeout-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:43.251296   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I1121 11:26:43.251496   83425 operation_generator.go:891] UnmountDevice succeeded for volume "success-and-timeout-device-name" %!(EXTRA string=UnmountDevice succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" )
I1121 11:26:43.251735   83425 reconciler.go:319] Volume detached for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:43.351381   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:26:43.351448   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:43.351501   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:43.351869   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:43.376243   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:43.376419   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:43.376562   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:26:43.487799   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:43.487963   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:53.469761   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:53.474921   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-failed-mount-device-name" (OuterVolumeSpecName: "success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-mount-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:53.475735   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:53.476703   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-failed-mount-device-name" (OuterVolumeSpecName: "success-and-failed-mount-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-mount-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:53.493365   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" 
I1121 11:26:53.493934   83425 operation_generator.go:891] UnmountDevice succeeded for volume "success-and-failed-mount-device-name" %!(EXTRA string=UnmountDevice succeeded for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" )
I1121 11:26:53.494189   83425 reconciler.go:319] Volume detached for volume "success-and-failed-mount-device-name" (UniqueName: "fake-plugin/success-and-failed-mount-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:53.580080   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:26:53.580162   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:53.580217   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:53.580454   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:53.581035   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:53.581157   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:53.581524   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:54.0813423 +0000 UTC m=+64.549550974 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"timeout-setup-volume\" (UniqueName: \"fake-plugin/timeout-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:26:53.680094   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I1121 11:26:53.681077   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/timeout-setup-volume" (OuterVolumeSpecName: "timeout-setup-volume") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "timeout-setup-volume". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:26:53.681601   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I1121 11:26:53.681962   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I1121 11:26:53.682169   83425 reconciler.go:319] Volume detached for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:53.782409   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:26:53.782483   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:26:53.782539   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:53.782893   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:26:53.784879   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:53.785019   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:53.785379   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:54.285204851 +0000 UTC m=+64.753413522 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"fail-setup-volume\" (UniqueName: \"fake-plugin/fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:26:53.902502   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" 
I1121 11:26:53.902754   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" 
I1121 11:26:53.902996   83425 reconciler.go:319] Volume detached for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:26:54.016856   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:26:54.016950   83425 reconciler.go:157] Reconciler: start to sync state
I1121 11:26:54.017034   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
E1121 11:26:54.017005   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:26:54.020668   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:26:54.022949   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:54.030817   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:54.526624164 +0000 UTC m=+64.994832853 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:26:54.530453   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:54.530625   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:54.548651   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:55.530843554 +0000 UTC m=+65.999052242 (durationBeforeRetry 1s). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:26:55.533285   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:55.534966   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:55.539624   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:26:57.535813008 +0000 UTC m=+68.004021699 (durationBeforeRetry 2s). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:26:57.538272   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:26:57.538433   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:26:57.538872   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:01.538642941 +0000 UTC m=+72.006851608 (durationBeforeRetry 4s). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:01.539865   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:01.540255   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:01.541415   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:09.540685127 +0000 UTC m=+80.008893795 (durationBeforeRetry 8s). Error: "MapVolume.MapPodDevice failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:04.121785   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I1121 11:27:04.122200   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I1121 11:27:04.127076   83425 reconciler.go:319] Volume detached for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:04.227368   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") 
I1121 11:27:04.227554   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:04.228445   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:04.229449   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:04.245771   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:04.245958   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:04.339386   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:04.339661   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:04.340235   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:04.839984094 +0000 UTC m=+75.308192768 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:04.871373   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:04.871546   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:04.871977   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:05.871768653 +0000 UTC m=+76.339977338 (durationBeforeRetry 1s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:05.889531   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:05.890663   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:05.913565   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:07.913237256 +0000 UTC m=+78.381445989 (durationBeforeRetry 2s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:07.920630   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:07.922517   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:07.937021   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:11.92334134 +0000 UTC m=+82.391550002 (durationBeforeRetry 4s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:11.932152   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:11.933065   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:11.933848   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:19.93328555 +0000 UTC m=+90.401494239 (durationBeforeRetry 8s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:14.328866   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:14.329018   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/success-and-timeout-setup-volume-name" (OuterVolumeSpecName: "success-and-timeout-setup-volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-timeout-setup-volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:14.341311   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" 
I1121 11:27:14.341621   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" 
I1121 11:27:14.341856   83425 reconciler.go:319] Volume detached for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:14.442259   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:27:14.442346   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:14.442404   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:14.443076   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:14.443875   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:14.444014   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:14.542348   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:14.542513   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:14.542942   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:15.042746757 +0000 UTC m=+85.510955433 (durationBeforeRetry 500ms). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:15.043516   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:15.043681   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:15.050762   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:16.043883132 +0000 UTC m=+86.512091801 (durationBeforeRetry 1s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:16.047842   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:16.048014   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:16.048433   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:18.048232278 +0000 UTC m=+88.516440959 (durationBeforeRetry 2s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:18.052446   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:18.052649   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:18.053078   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:22.052881926 +0000 UTC m=+92.521090596 (durationBeforeRetry 4s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:22.090383   83425 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:22.090552   83425 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:22.090982   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:30.090771578 +0000 UTC m=+100.558980244 (durationBeforeRetry 8s). Error: "MapVolume.MapPodDevice failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:24.577505   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:24.577655   83425 operation_generator.go:1170] UnmapVolume succeeded for volume "fake-plugin/success-and-failed-setup-device-name" (OuterVolumeSpecName: "success-and-failed-setup-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-setup-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:24.578365   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" 
I1121 11:27:24.581183   83425 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" 
I1121 11:27:24.581449   83425 reconciler.go:319] Volume detached for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:24.690008   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:27:24.690088   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:24.690145   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:24.690527   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:24.691273   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:24.691406   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:24.691516   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") device mount path ""
E1121 11:27:24.691922   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:25.191753804 +0000 UTC m=+95.659962470 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"timeout-setup-volume\" (UniqueName: \"fake-plugin/timeout-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:24.813340   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/timeout-setup-volume" (OuterVolumeSpecName: "timeout-setup-volume") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "timeout-setup-volume". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:24.814545   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:24.817573   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I1121 11:27:24.817707   83425 operation_generator.go:891] UnmountDevice succeeded for volume "timeout-setup-volume" %!(EXTRA string=UnmountDevice succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" )
I1121 11:27:24.819516   83425 reconciler.go:319] Volume detached for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:24.923409   83425 operation_generator.go:1357] Controller attach succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:24.924644   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:27:24.930421   83425 reconciler.go:319] Volume detached for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" DevicePath "fake/path"
I1121 11:27:24.930482   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:24.937798   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:25.033731   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I1121 11:27:25.033802   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:25.033846   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:25.034371   83425 operation_generator.go:1357] Controller attach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:25.035199   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:25.035340   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:25.035460   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") device mount path ""
E1121 11:27:25.035863   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:25.535685461 +0000 UTC m=+96.003894143 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:25.578593   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:25.578742   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:25.579150   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:26.578978461 +0000 UTC m=+97.047187130 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:26.579561   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:26.579731   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:26.602487   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:28.602145511 +0000 UTC m=+99.070354193 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:28.602699   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:28.602862   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:28.603322   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:32.603086421 +0000 UTC m=+103.071295172 (durationBeforeRetry 4s). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:32.603832   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:32.604023   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:32.604418   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:40.604237628 +0000 UTC m=+111.072446298 (durationBeforeRetry 8s). Error: "MountVolume.SetUp failed for volume \"timeout-and-fail-setup-volume\" (UniqueName: \"fake-plugin/timeout-and-fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:35.136866   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I1121 11:27:35.137128   83425 operation_generator.go:891] UnmountDevice succeeded for volume "timeout-and-fail-setup-volume" %!(EXTRA string=UnmountDevice succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" )
I1121 11:27:35.137583   83425 reconciler.go:319] Volume detached for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:35.270540   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") 
I1121 11:27:35.270618   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:35.270677   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:35.271080   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:35.271685   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:35.271823   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:35.271946   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:27:35.386128   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:35.386325   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:35.387084   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:35.886544802 +0000 UTC m=+106.354753486 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:35.887113   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:35.887282   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:35.887677   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:36.887490899 +0000 UTC m=+107.355699582 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:36.889771   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:36.892634   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:36.897140   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:38.895979609 +0000 UTC m=+109.364188303 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:38.905461   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:38.905619   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:38.906031   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:42.905826094 +0000 UTC m=+113.374034770 (durationBeforeRetry 4s). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:42.917820   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:42.918000   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:42.918466   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:50.918241381 +0000 UTC m=+121.386450056 (durationBeforeRetry 8s). Error: "MountVolume.SetUp failed for volume \"success-and-timeout-setup-volume-name\" (UniqueName: \"fake-plugin/success-and-timeout-setup-volume-name\") pod \"pod1\" (UID: \"pod1uid\") : time out on setup"
I1121 11:27:45.387566   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:45.387932   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-timeout-setup-volume-name" (OuterVolumeSpecName: "success-and-timeout-setup-volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-timeout-setup-volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:45.388418   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" 
I1121 11:27:45.388649   83425 operation_generator.go:891] UnmountDevice succeeded for volume "success-and-timeout-setup-volume-name" %!(EXTRA string=UnmountDevice succeeded for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" )
I1121 11:27:45.389054   83425 reconciler.go:319] Volume detached for volume "success-and-timeout-setup-volume-name" (UniqueName: "fake-plugin/success-and-timeout-setup-volume-name") on node "mynodename" DevicePath "/dev/sdb"
I1121 11:27:45.521658   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") 
I1121 11:27:45.521761   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:45.521829   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:45.522616   83425 operation_generator.go:1357] Controller attach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I1121 11:27:45.523299   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I1121 11:27:45.523457   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:45.523700   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:27:45.650360   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:45.650534   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:45.650937   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:46.150736242 +0000 UTC m=+116.618944917 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:46.169816   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:46.169990   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:46.170416   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:47.170220278 +0000 UTC m=+117.638428947 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:47.170760   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:47.170921   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:47.171318   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:49.171123406 +0000 UTC m=+119.639332082 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:49.176632   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:49.178936   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:49.184237   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:27:53.181618406 +0000 UTC m=+123.649827086 (durationBeforeRetry 4s). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:53.194773   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:53.194968   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
E1121 11:27:53.195408   83425 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2020-11-21 11:28:01.195184989 +0000 UTC m=+131.663393638 (durationBeforeRetry 8s). Error: "MountVolume.SetUp failed for volume \"success-and-failed-setup-device-name\" (UniqueName: \"fake-plugin/success-and-failed-setup-device-name\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I1121 11:27:55.700997   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:55.701497   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/success-and-failed-setup-device-name" (OuterVolumeSpecName: "success-and-failed-setup-device-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "success-and-failed-setup-device-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:55.702092   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" 
I1121 11:27:55.702346   83425 operation_generator.go:891] UnmountDevice succeeded for volume "success-and-failed-setup-device-name" %!(EXTRA string=UnmountDevice succeeded for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" )
I1121 11:27:55.702801   83425 reconciler.go:319] Volume detached for volume "success-and-failed-setup-device-name" (UniqueName: "fake-plugin/success-and-failed-setup-device-name") on node "mynodename" DevicePath "/dev/sdb"
--- FAIL: Test_UncertainVolumeMountState (62.23s)
    --- FAIL: Test_UncertainVolumeMountState/failed_operation_should_result_in_not-mounted_volume_[Filesystem] (0.11s)
        reconciler_test.go:1523: Error verifying UnMountDeviceCallCount: Expected DeviceUnmount Call 1, got 0
I1121 11:27:55.805640   83425 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I1121 11:27:55.805714   83425 reconciler.go:157] Reconciler: start to sync state
E1121 11:27:55.805774   83425 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I1121 11:27:55.806180   83425 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I1121 11:27:55.807067   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I1121 11:27:55.807195   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:55.807291   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I1121 11:27:55.949309   83425 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I1121 11:27:55.949849   83425 operation_generator.go:797] UnmountVolume.TearDown succeeded for volume "fake-plugin/fake-device1" (OuterVolumeSpecName: "volume-name") pod "pod1uid" (UID: "pod1uid"). InnerVolumeSpecName "volume-name". PluginName "fake-plugin", VolumeGidValue ""
I1121 11:27:55.950300   83425 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I1121 11:27:55.950375   83425 reconciler_test.go:1798] UnmountDevice called
I1121 11:27:55.950563   83425 operation_generator.go:891] UnmountDevice succeeded for volume "volume-name" %!(EXTRA string=UnmountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" )
I1121 11:27:55.951282   83425 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:55.951392   83425 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I1121 11:27:55.951489   83425 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
FAIL

				from junit_bazel.xml

Find pod1 mentions in log files | View test history on testgrid


Show 1937 Passed Tests