This job view page is being replaced by Spyglass soon. Check out the new job view.
PRfeiskyer: Automated cherry pick of #104384: fix: skip case sensitivity when checking Azure NSG rules #104382: fix: ensure InstanceShutdownByProviderID return false for
ResultFAILURE
Tests 2 failed / 1937 succeeded
Started2021-09-09 09:09
Elapsed31m18s
Revisionc8718b98f5c92f4d34d65c0d2b7c70f454efdd22
Refs 104448

Test Failures


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

bazel test //pkg/kubelet/volumemanager/reconciler/go_default_test:run_2_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/kubelet/volumemanager/reconciler:go_default_test
-----------------------------------------------------------------------------
I0909 09:25:21.258911  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.264821  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.265442  175526 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.265516  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.265559  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.265703  175526 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I0909 09:25:21.266327  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I0909 09:25:21.266442  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:21.266534  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:21.367023  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.367094  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.367140  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.367466  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:21.368082  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:25:21.368193  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:21.368312  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:21.468724  175526 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.468805  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.468854  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.469009  175526 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I0909 09:25:21.469514  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I0909 09:25:21.469633  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:21.469738  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:21.578848  175526 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 ""
I0909 09:25:21.580073  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:21.582275  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:21.582456  175526 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" )
I0909 09:25:21.582860  175526 reconciler.go:333] operationExecutor.DetachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:21.583038  175526 operation_generator.go:470] DetachVolume.Detach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:21.672124  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.672193  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.672245  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.672502  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:21.673057  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:25:21.673186  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:21.673296  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:21.774260  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:21.774506  175526 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 ""
I0909 09:25:21.776716  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:21.776895  175526 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 ""
I0909 09:25:21.777899  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:21.778169  175526 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" )
I0909 09:25:21.778367  175526 reconciler.go:319] Volume detached for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:25:21.886589  175526 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I0909 09:25:21.886643  175526 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.886733  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.886793  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.889162  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I0909 09:25:21.889293  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.002441  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.002512  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.002561  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.005370  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:22.005754  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.006564  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:22.007166  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:25:22.007286  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.121452  175526 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.121523  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.121571  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.121830  175526 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I0909 09:25:22.122402  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I0909 09:25:22.122514  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.221445  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:22.221916  175526 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 ""
I0909 09:25:22.222427  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.223279  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.223713  175526 reconciler.go:333] operationExecutor.DetachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.223881  175526 operation_generator.go:470] DetachVolume.Detach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.333333  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.333401  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.333453  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.333735  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:22.334237  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:25:22.334366  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.480677  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:22.480825  175526 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 ""
I0909 09:25:22.481262  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.481410  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.481570  175526 reconciler.go:319] Volume detached for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:25:22.575574  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.575646  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.575702  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.576062  175526 operation_generator.go:1357] Controller attach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I0909 09:25:22.576610  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I0909 09:25:22.576721  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.576825  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:22.676073  175526 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.780818  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.780898  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.780950  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.781359  175526 operation_generator.go:1357] Controller attach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I0909 09:25:22.782119  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I0909 09:25:22.782228  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.884783  175526 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.988986  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.989071  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.989126  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.989459  175526 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"
I0909 09:25:22.990133  175526 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"
I0909 09:25:22.990368  175526 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"
I0909 09:25:22.990520  175526 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 ""
E0909 09:25:22.990767  175526 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
I0909 09:25:23.124042  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:25:23.124119  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:23.124177  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:23.137709  175526 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"
I0909 09:25:23.138480  175526 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"
I0909 09:25:23.138624  175526 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"
E0909 09:25:23.139062  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-mount-device-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:23.638849598 +0000 UTC m=+2.614769355 (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"
I0909 09:25:23.224152  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I0909 09:25:23.224369  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I0909 09:25:23.224773  175526 reconciler.go:319] Volume detached for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:25:23.337627  175526 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") 
I0909 09:25:23.337698  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:23.337759  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:23.338077  175526 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"
I0909 09:25:23.338657  175526 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"
I0909 09:25:23.338787  175526 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"
E0909 09:25:23.339179  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-mount-device-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:23.838975109 +0000 UTC m=+2.814894875 (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"
I0909 09:25:23.457189  175526 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"
I0909 09:25:23.544898  175526 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") 
I0909 09:25:23.544983  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:23.545045  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:23.545387  175526 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"
I0909 09:25:23.546050  175526 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"
I0909 09:25:23.546191  175526 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"
E0909 09:25:23.546602  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:24.046419325 +0000 UTC m=+3.022339073 (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"
I0909 09:25:24.057327  175526 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"
I0909 09:25:24.057942  175526 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"
E0909 09:25:24.060536  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:25.059313569 +0000 UTC m=+4.035233323 (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"
I0909 09:25:25.059672  175526 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"
I0909 09:25:25.059817  175526 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"
E0909 09:25:25.060223  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:27.060021295 +0000 UTC m=+6.035941043 (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"
I0909 09:25:27.069587  175526 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"
I0909 09:25:27.069740  175526 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"
E0909 09:25:27.070164  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:31.069962678 +0000 UTC m=+10.045882442 (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"
I0909 09:25:31.070871  175526 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"
I0909 09:25:31.071067  175526 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"
E0909 09:25:31.071557  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:39.071297902 +0000 UTC m=+18.047217650 (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"
I0909 09:25:33.659021  175526 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"
I0909 09:25:33.759914  175526 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") 
I0909 09:25:33.761572  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:33.761642  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:33.761947  175526 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"
I0909 09:25:33.762550  175526 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"
I0909 09:25:33.762679  175526 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"
I0909 09:25:33.860438  175526 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"
I0909 09:25:33.860584  175526 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"
E0909 09:25:33.860980  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:34.360774315 +0000 UTC m=+13.336694062 (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"
I0909 09:25:34.386178  175526 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"
I0909 09:25:34.386345  175526 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"
E0909 09:25:34.386938  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:35.386752481 +0000 UTC m=+14.362672231 (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"
I0909 09:25:35.403001  175526 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"
I0909 09:25:35.403157  175526 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"
E0909 09:25:35.403562  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:37.403342411 +0000 UTC m=+16.379262174 (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"
I0909 09:25:37.403676  175526 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"
I0909 09:25:37.403854  175526 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"
E0909 09:25:37.404227  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:41.404034452 +0000 UTC m=+20.379954212 (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"
I0909 09:25:41.410415  175526 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"
I0909 09:25:41.410572  175526 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"
E0909 09:25:41.410932  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:49.410755066 +0000 UTC m=+28.386674814 (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"
I0909 09:25:43.864833  175526 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") 
I0909 09:25:43.865134  175526 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 ""
I0909 09:25:43.865651  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I0909 09:25:43.865884  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I0909 09:25:43.866083  175526 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"
I0909 09:25:43.967345  175526 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") 
I0909 09:25:43.967427  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:43.967489  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:43.973440  175526 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"
I0909 09:25:43.974354  175526 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"
I0909 09:25:43.974514  175526 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"
I0909 09:25:43.976504  175526 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"
I0909 09:25:43.976644  175526 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"
E0909 09:25:43.977043  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:44.476843886 +0000 UTC m=+23.452763635 (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"
I0909 09:25:44.485182  175526 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"
I0909 09:25:44.485353  175526 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"
E0909 09:25:44.487005  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:45.485632979 +0000 UTC m=+24.461552736 (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"
I0909 09:25:45.497540  175526 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"
I0909 09:25:45.497702  175526 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"
E0909 09:25:45.498109  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:47.497910056 +0000 UTC m=+26.473829805 (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"
I0909 09:25:47.499783  175526 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"
I0909 09:25:47.500719  175526 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"
E0909 09:25:47.505175  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:51.502443522 +0000 UTC m=+30.478363281 (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"
I0909 09:25:51.514936  175526 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"
I0909 09:25:51.527800  175526 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"
E0909 09:25:51.529776  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:59.529545568 +0000 UTC m=+38.505465321 (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"
I0909 09:25:54.094223  175526 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") 
I0909 09:25:54.094543  175526 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 ""
I0909 09:25:54.100425  175526 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" 
I0909 09:25:54.106681  175526 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" 
I0909 09:25:54.125399  175526 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"
I0909 09:25:54.204193  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:25:54.204265  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:54.204340  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:54.204790  175526 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"
I0909 09:25:54.234031  175526 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"
I0909 09:25:54.234566  175526 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"
E0909 09:25:54.261037  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-mount-device-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:54.73696743 +0000 UTC m=+33.712887226 (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"
I0909 09:25:54.329724  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I0909 09:25:54.329180  175526 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" )
I0909 09:25:54.330560  175526 reconciler.go:319] Volume detached for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:25:54.417532  175526 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") 
I0909 09:25:54.417661  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:54.417720  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:54.418795  175526 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"
I0909 09:25:54.419585  175526 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"
I0909 09:25:54.419811  175526 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"
E0909 09:25:54.420420  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-mount-device-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:54.920108445 +0000 UTC m=+33.896028192 (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"
I0909 09:25:54.523120  175526 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"
I0909 09:25:54.655955  175526 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") 
I0909 09:25:54.656036  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:54.656089  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:54.656641  175526 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"
I0909 09:25:54.657186  175526 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"
I0909 09:25:54.657318  175526 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"
E0909 09:25:54.657712  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:55.157524114 +0000 UTC m=+34.133443862 (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"
I0909 09:25:55.164925  175526 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"
I0909 09:25:55.165092  175526 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"
E0909 09:25:55.165518  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:56.16531953 +0000 UTC m=+35.141239279 (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"
I0909 09:25:56.173217  175526 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"
I0909 09:25:56.173406  175526 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"
E0909 09:25:56.173890  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:58.173680482 +0000 UTC m=+37.149600253 (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"
I0909 09:25:58.200929  175526 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"
I0909 09:25:58.201088  175526 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"
E0909 09:25:58.201489  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:02.201291084 +0000 UTC m=+41.177210833 (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"
I0909 09:26:02.203859  175526 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"
I0909 09:26:02.204055  175526 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"
E0909 09:26:02.213330  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:10.205629631 +0000 UTC m=+49.181549389 (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"
I0909 09:26:04.776763  175526 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"
I0909 09:26:04.880704  175526 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") 
I0909 09:26:04.881895  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:04.881946  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:04.882072  175526 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"
I0909 09:26:04.884746  175526 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"
I0909 09:26:04.884892  175526 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"
I0909 09:26:04.885019  175526 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 ""
I0909 09:26:04.887169  175526 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"
I0909 09:26:04.887324  175526 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"
I0909 09:26:04.986186  175526 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"
I0909 09:26:04.986344  175526 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"
I0909 09:26:14.983521  175526 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") 
I0909 09:26:14.983761  175526 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 ""
I0909 09:26:14.984411  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I0909 09:26:14.984683  175526 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" )
I0909 09:26:14.984946  175526 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"
I0909 09:26:15.095971  175526 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") 
I0909 09:26:15.096056  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:15.096110  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:15.096914  175526 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"
I0909 09:26:15.097552  175526 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"
I0909 09:26:15.097687  175526 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"
I0909 09:26:15.097805  175526 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 ""
I0909 09:26:15.195615  175526 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"
I0909 09:26:15.195776  175526 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"
I0909 09:26:25.197238  175526 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") 
I0909 09:26:25.196537  175526 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 ""
I0909 09:26:25.200082  175526 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") 
I0909 09:26:25.199640  175526 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 ""
I0909 09:26:25.201805  175526 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" 
I0909 09:26:25.202722  175526 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" )
I0909 09:26:25.203222  175526 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"
I0909 09:26:25.303128  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:26:25.303210  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:25.303271  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:25.303695  175526 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"
I0909 09:26:25.304897  175526 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"
I0909 09:26:25.305033  175526 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"
E0909 09:26:25.305402  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:25.805228258 +0000 UTC m=+64.781148083 (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"
I0909 09:26:25.415794  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I0909 09:26:25.416223  175526 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 ""
I0909 09:26:25.416741  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I0909 09:26:25.416939  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I0909 09:26:25.417140  175526 reconciler.go:319] Volume detached for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:26:25.517869  175526 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"
I0909 09:26:25.520638  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:26:25.520805  175526 reconciler.go:319] Volume detached for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" DevicePath "fake/path"
I0909 09:26:25.520842  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:25.521312  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:25.623261  175526 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") 
I0909 09:26:25.623343  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:25.623395  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:25.623662  175526 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"
I0909 09:26:25.624567  175526 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"
I0909 09:26:25.624706  175526 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"
E0909 09:26:25.625080  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:26.124903489 +0000 UTC m=+65.100823238 (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"
I0909 09:26:26.132613  175526 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"
I0909 09:26:26.132774  175526 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"
E0909 09:26:26.133180  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:27.132984973 +0000 UTC m=+66.108904731 (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"
I0909 09:26:27.133475  175526 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"
I0909 09:26:27.133642  175526 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"
E0909 09:26:27.136428  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:29.13483134 +0000 UTC m=+68.110751101 (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"
I0909 09:26:29.157200  175526 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"
I0909 09:26:29.157360  175526 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"
E0909 09:26:29.160562  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:33.160325651 +0000 UTC m=+72.136245439 (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"
I0909 09:26:33.161147  175526 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"
I0909 09:26:33.187722  175526 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"
E0909 09:26:33.188168  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:41.187961333 +0000 UTC m=+80.163881093 (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"
I0909 09:26:35.733672  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I0909 09:26:35.733889  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I0909 09:26:35.734103  175526 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"
I0909 09:26:35.841926  175526 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") 
I0909 09:26:35.842010  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:35.842073  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:35.842547  175526 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"
I0909 09:26:35.843638  175526 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"
I0909 09:26:35.843784  175526 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"
I0909 09:26:35.970017  175526 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"
I0909 09:26:35.972977  175526 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"
E0909 09:26:35.973499  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:36.473234366 +0000 UTC m=+75.449154115 (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"
I0909 09:26:36.473885  175526 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"
I0909 09:26:36.474097  175526 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"
E0909 09:26:36.474523  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:37.474322746 +0000 UTC m=+76.450242491 (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"
I0909 09:26:37.474699  175526 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"
I0909 09:26:37.474915  175526 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"
E0909 09:26:37.475309  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:39.475125501 +0000 UTC m=+78.451045248 (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"
I0909 09:26:39.489400  175526 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"
I0909 09:26:39.558490  175526 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"
E0909 09:26:39.563945  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:43.561340986 +0000 UTC m=+82.537260738 (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"
I0909 09:26:43.571082  175526 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"
I0909 09:26:43.572212  175526 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"
E0909 09:26:43.587367  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:51.587149962 +0000 UTC m=+90.563069719 (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"
I0909 09:26:45.955195  175526 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") 
I0909 09:26:45.955341  175526 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 ""
I0909 09:26:45.955916  175526 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" 
I0909 09:26:45.956130  175526 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" 
I0909 09:26:45.956383  175526 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"
I0909 09:26:46.058282  175526 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") 
I0909 09:26:46.058354  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:46.058403  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:46.058894  175526 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"
I0909 09:26:46.059613  175526 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"
I0909 09:26:46.059745  175526 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"
I0909 09:26:46.173700  175526 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"
I0909 09:26:46.173878  175526 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"
E0909 09:26:46.174277  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:46.674095329 +0000 UTC m=+85.650015083 (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"
I0909 09:26:46.686230  175526 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"
I0909 09:26:46.686418  175526 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"
E0909 09:26:46.688110  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:47.687911998 +0000 UTC m=+86.663831758 (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"
I0909 09:26:47.697183  175526 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"
I0909 09:26:47.697964  175526 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"
E0909 09:26:47.699862  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:49.69925352 +0000 UTC m=+88.675173276 (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"
I0909 09:26:49.713150  175526 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"
I0909 09:26:49.713340  175526 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"
E0909 09:26:49.715158  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:53.714974896 +0000 UTC m=+92.690894647 (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"
I0909 09:26:53.727358  175526 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"
I0909 09:26:53.727542  175526 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"
E0909 09:26:53.727981  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:01.72778063 +0000 UTC m=+100.703700382 (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"
I0909 09:26:56.185206  175526 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") 
I0909 09:26:56.200456  175526 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 ""
I0909 09:26:56.209827  175526 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") 
I0909 09:26:56.210149  175526 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 ""
I0909 09:26:56.212920  175526 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" 
I0909 09:26:56.213122  175526 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" 
I0909 09:26:56.213411  175526 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"
I0909 09:26:56.289870  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:26:56.289950  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:56.290008  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:56.290242  175526 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"
I0909 09:26:56.290988  175526 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"
I0909 09:26:56.291185  175526 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"
I0909 09:26:56.291337  175526 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 ""
E0909 09:26:56.291757  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:56.791592239 +0000 UTC m=+95.767511987 (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"
I0909 09:26:56.428125  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I0909 09:26:56.428640  175526 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 ""
I0909 09:26:56.433316  175526 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 ""
I0909 09:26:56.433270  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I0909 09:26:56.439659  175526 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" )
I0909 09:26:56.441638  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I0909 09:26:56.488203  175526 reconciler.go:319] Volume detached for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:26:56.523940  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:26:56.545972  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:56.546070  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:56.533592  175526 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"
I0909 09:26:56.547113  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I0909 09:26:56.547257  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:26:56.547377  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") device mount path ""
E0909 09:26:56.547792  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:57.047623763 +0000 UTC m=+96.023543510 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"fail-setup-volume\" (UniqueName: \"fake-plugin/fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I0909 09:26:56.655657  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" 
I0909 09:26:56.656035  175526 operation_generator.go:891] UnmountDevice succeeded for volume "fail-setup-volume" %!(EXTRA string=UnmountDevice succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" )
I0909 09:26:56.656361  175526 reconciler.go:319] Volume detached for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:26:56.727485  175526 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") 
I0909 09:26:56.727559  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:56.727620  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:56.727852  175526 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"
I0909 09:26:56.736740  175526 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"
I0909 09:26:56.736886  175526 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"
I0909 09:26:56.737001  175526 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 ""
E0909 09:26:56.737433  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:57.237246765 +0000 UTC m=+96.213166512 (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"
I0909 09:26:57.266214  175526 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"
I0909 09:26:57.266669  175526 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"
E0909 09:26:57.267441  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:58.267003299 +0000 UTC m=+97.242923058 (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"
I0909 09:26:58.273449  175526 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"
I0909 09:26:58.279113  175526 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"
E0909 09:26:58.290132  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:00.281492922 +0000 UTC m=+99.257412687 (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"
I0909 09:27:00.281837  175526 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"
I0909 09:27:00.281986  175526 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"
E0909 09:27:00.282372  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:04.282189882 +0000 UTC m=+103.258109633 (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"
I0909 09:27:04.282746  175526 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"
I0909 09:27:04.282920  175526 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"
E0909 09:27:04.283633  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:12.283137284 +0000 UTC m=+111.259057263 (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"
I0909 09:27:06.835975  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I0909 09:27:06.836329  175526 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" )
I0909 09:27:06.836585  175526 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"
I0909 09:27:06.940440  175526 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") 
I0909 09:27:06.941198  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:27:06.941260  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:27:06.941040  175526 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"
I0909 09:27:06.944231  175526 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"
I0909 09:27:06.965500  175526 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"
I0909 09:27:06.965854  175526 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 ""
I0909 09:27:06.969529  175526 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"
I0909 09:27:06.969903  175526 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"
E0909 09:27:06.971177  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:07.470548635 +0000 UTC m=+106.446468393 (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"
I0909 09:27:07.472810  175526 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"
I0909 09:27:07.472982  175526 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"
E0909 09:27:07.473396  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:08.473190036 +0000 UTC m=+107.449109785 (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"
I0909 09:27:08.473751  175526 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"
I0909 09:27:08.473924  175526 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"
E0909 09:27:08.474403  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:10.474162084 +0000 UTC m=+109.450081876 (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"
I0909 09:27:10.474669  175526 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"
I0909 09:27:10.474833  175526 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"
E0909 09:27:10.475249  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:14.47504622 +0000 UTC m=+113.450965968 (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"
I0909 09:27:14.485389  175526 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"
I0909 09:27:14.485571  175526 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"
E0909 09:27:14.486008  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:22.485796402 +0000 UTC m=+121.461716148 (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"
I0909 09:27:17.055637  175526 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") 
I0909 09:27:17.055958  175526 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 ""
I0909 09:27:17.056707  175526 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" 
I0909 09:27:17.057023  175526 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" )
I0909 09:27:17.057407  175526 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"
I0909 09:27:17.156448  175526 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") 
I0909 09:27:17.156537  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:27:17.156592  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:27:17.157138  175526 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"
I0909 09:27:17.157990  175526 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"
I0909 09:27:17.158119  175526 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"
I0909 09:27:17.158243  175526 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 ""
I0909 09:27:17.257017  175526 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"
I0909 09:27:17.257184  175526 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"
E0909 09:27:17.257585  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:17.757396127 +0000 UTC m=+116.733315878 (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"
I0909 09:27:17.757886  175526 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"
I0909 09:27:17.758085  175526 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"
E0909 09:27:17.758522  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:18.75831292 +0000 UTC m=+117.734232672 (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"
I0909 09:27:18.758899  175526 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"
I0909 09:27:18.759087  175526 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"
E0909 09:27:18.759519  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:20.759324655 +0000 UTC m=+119.735244408 (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"
I0909 09:27:20.784589  175526 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"
I0909 09:27:20.784759  175526 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"
E0909 09:27:20.785347  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:24.785147176 +0000 UTC m=+123.761066922 (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"
I0909 09:27:24.785614  175526 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"
I0909 09:27:24.787758  175526 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"
E0909 09:27:24.788230  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:32.788032404 +0000 UTC m=+131.763952163 (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"
I0909 09:27:27.266607  175526 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") 
I0909 09:27:27.266853  175526 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 ""
I0909 09:27:27.267441  175526 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" 
I0909 09:27:27.267758  175526 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" )
I0909 09:27:27.268012  175526 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.07s)
    --- FAIL: Test_UncertainVolumeMountState/failed_operation_should_result_in_not-mounted_volume_[Block] (0.11s)
        reconciler_test.go:1544: Error verifying UnMountDeviceCallCount: No Unmapper have expected TearDownDeviceCallCount. Expected: <1>.
I0909 09:27:27.368676  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:27:27.370561  175526 reconciler.go:157] Reconciler: start to sync state
I0909 09:27:27.369008  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
E0909 09:27:27.370641  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:27:27.379987  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:27:27.381589  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:27:27.384003  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:27:27.477680  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:27:27.479704  175526 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 ""
I0909 09:27:27.480179  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:27:27.480291  175526 reconciler_test.go:1798] UnmountDevice called
I0909 09:27:27.480547  175526 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" )
I0909 09:27:27.481111  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:27:27.481229  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:27:27.481316  175526 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_2_of_2 0.00s

bazel test //pkg/kubelet/volumemanager/reconciler/go_default_test:run_2_of_2
exec ${PAGER:-/usr/bin/less} "$0" || exit 1
Executing tests from //pkg/kubelet/volumemanager/reconciler:go_default_test
-----------------------------------------------------------------------------
I0909 09:25:21.258911  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.264821  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.265442  175526 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.265516  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.265559  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.265703  175526 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I0909 09:25:21.266327  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I0909 09:25:21.266442  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:21.266534  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:21.367023  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.367094  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.367140  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.367466  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:21.368082  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:25:21.368193  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:21.368312  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:21.468724  175526 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.468805  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.468854  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.469009  175526 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I0909 09:25:21.469514  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I0909 09:25:21.469633  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:21.469738  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:21.578848  175526 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 ""
I0909 09:25:21.580073  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:21.582275  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:21.582456  175526 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" )
I0909 09:25:21.582860  175526 reconciler.go:333] operationExecutor.DetachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:21.583038  175526 operation_generator.go:470] DetachVolume.Detach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:21.672124  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.672193  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.672245  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.672502  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:21.673057  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:25:21.673186  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:21.673296  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:21.774260  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:21.774506  175526 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 ""
I0909 09:25:21.776716  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:21.776895  175526 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 ""
I0909 09:25:21.777899  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:21.778169  175526 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" )
I0909 09:25:21.778367  175526 reconciler.go:319] Volume detached for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:25:21.886589  175526 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I0909 09:25:21.886643  175526 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:21.886733  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:21.886793  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:21.889162  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I0909 09:25:21.889293  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.002441  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.002512  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.002561  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.005370  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:22.005754  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.006564  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:22.007166  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:25:22.007286  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.121452  175526 reconciler.go:244] operationExecutor.AttachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.121523  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.121571  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.121830  175526 operation_generator.go:360] AttachVolume.Attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") from node "mynodename" 
I0909 09:25:22.122402  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/vdb-test"
I0909 09:25:22.122514  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.221445  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:22.221916  175526 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 ""
I0909 09:25:22.222427  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.223279  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.223713  175526 reconciler.go:333] operationExecutor.DetachVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.223881  175526 operation_generator.go:470] DetachVolume.Detach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.333333  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.333401  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.333453  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.333735  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
I0909 09:25:22.334237  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:25:22.334366  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.480677  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:25:22.480825  175526 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 ""
I0909 09:25:22.481262  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.481410  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:25:22.481570  175526 reconciler.go:319] Volume detached for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:25:22.575574  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.575646  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.575702  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.576062  175526 operation_generator.go:1357] Controller attach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I0909 09:25:22.576610  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I0909 09:25:22.576721  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.576825  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:25:22.676073  175526 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.780818  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.780898  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.780950  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.781359  175526 operation_generator.go:1357] Controller attach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") device path: "fake/path"
I0909 09:25:22.782119  175526 operation_generator.go:973] MapVolume.WaitForAttach entering for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I0909 09:25:22.782228  175526 operation_generator.go:982] MapVolume.WaitForAttach succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:25:22.884783  175526 operation_generator.go:1683] MountVolume.NodeExpandVolume succeeded for volume "pv" (UniqueName: "fake-plugin/pv") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.988986  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-expansion-in-use" (UniqueName: "fake-plugin/fail-expansion-in-use") pod "pod1" (UID: "pod1uid") 
I0909 09:25:22.989071  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:22.989126  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:22.989459  175526 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"
I0909 09:25:22.990133  175526 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"
I0909 09:25:22.990368  175526 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"
I0909 09:25:22.990520  175526 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 ""
E0909 09:25:22.990767  175526 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
I0909 09:25:23.124042  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:25:23.124119  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:23.124177  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:23.137709  175526 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"
I0909 09:25:23.138480  175526 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"
I0909 09:25:23.138624  175526 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"
E0909 09:25:23.139062  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-mount-device-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:23.638849598 +0000 UTC m=+2.614769355 (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"
I0909 09:25:23.224152  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I0909 09:25:23.224369  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I0909 09:25:23.224773  175526 reconciler.go:319] Volume detached for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:25:23.337627  175526 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") 
I0909 09:25:23.337698  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:23.337759  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:23.338077  175526 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"
I0909 09:25:23.338657  175526 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"
I0909 09:25:23.338787  175526 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"
E0909 09:25:23.339179  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-mount-device-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:23.838975109 +0000 UTC m=+2.814894875 (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"
I0909 09:25:23.457189  175526 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"
I0909 09:25:23.544898  175526 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") 
I0909 09:25:23.544983  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:23.545045  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:23.545387  175526 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"
I0909 09:25:23.546050  175526 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"
I0909 09:25:23.546191  175526 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"
E0909 09:25:23.546602  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:24.046419325 +0000 UTC m=+3.022339073 (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"
I0909 09:25:24.057327  175526 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"
I0909 09:25:24.057942  175526 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"
E0909 09:25:24.060536  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:25.059313569 +0000 UTC m=+4.035233323 (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"
I0909 09:25:25.059672  175526 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"
I0909 09:25:25.059817  175526 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"
E0909 09:25:25.060223  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:27.060021295 +0000 UTC m=+6.035941043 (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"
I0909 09:25:27.069587  175526 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"
I0909 09:25:27.069740  175526 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"
E0909 09:25:27.070164  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:31.069962678 +0000 UTC m=+10.045882442 (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"
I0909 09:25:31.070871  175526 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"
I0909 09:25:31.071067  175526 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"
E0909 09:25:31.071557  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:39.071297902 +0000 UTC m=+18.047217650 (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"
I0909 09:25:33.659021  175526 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"
I0909 09:25:33.759914  175526 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") 
I0909 09:25:33.761572  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:33.761642  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:33.761947  175526 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"
I0909 09:25:33.762550  175526 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"
I0909 09:25:33.762679  175526 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"
I0909 09:25:33.860438  175526 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"
I0909 09:25:33.860584  175526 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"
E0909 09:25:33.860980  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:34.360774315 +0000 UTC m=+13.336694062 (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"
I0909 09:25:34.386178  175526 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"
I0909 09:25:34.386345  175526 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"
E0909 09:25:34.386938  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:35.386752481 +0000 UTC m=+14.362672231 (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"
I0909 09:25:35.403001  175526 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"
I0909 09:25:35.403157  175526 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"
E0909 09:25:35.403562  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:37.403342411 +0000 UTC m=+16.379262174 (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"
I0909 09:25:37.403676  175526 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"
I0909 09:25:37.403854  175526 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"
E0909 09:25:37.404227  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:41.404034452 +0000 UTC m=+20.379954212 (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"
I0909 09:25:41.410415  175526 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"
I0909 09:25:41.410572  175526 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"
E0909 09:25:41.410932  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:49.410755066 +0000 UTC m=+28.386674814 (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"
I0909 09:25:43.864833  175526 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") 
I0909 09:25:43.865134  175526 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 ""
I0909 09:25:43.865651  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I0909 09:25:43.865884  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I0909 09:25:43.866083  175526 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"
I0909 09:25:43.967345  175526 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") 
I0909 09:25:43.967427  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:43.967489  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:43.973440  175526 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"
I0909 09:25:43.974354  175526 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"
I0909 09:25:43.974514  175526 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"
I0909 09:25:43.976504  175526 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"
I0909 09:25:43.976644  175526 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"
E0909 09:25:43.977043  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:44.476843886 +0000 UTC m=+23.452763635 (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"
I0909 09:25:44.485182  175526 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"
I0909 09:25:44.485353  175526 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"
E0909 09:25:44.487005  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:45.485632979 +0000 UTC m=+24.461552736 (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"
I0909 09:25:45.497540  175526 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"
I0909 09:25:45.497702  175526 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"
E0909 09:25:45.498109  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:47.497910056 +0000 UTC m=+26.473829805 (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"
I0909 09:25:47.499783  175526 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"
I0909 09:25:47.500719  175526 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"
E0909 09:25:47.505175  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:51.502443522 +0000 UTC m=+30.478363281 (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"
I0909 09:25:51.514936  175526 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"
I0909 09:25:51.527800  175526 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"
E0909 09:25:51.529776  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:59.529545568 +0000 UTC m=+38.505465321 (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"
I0909 09:25:54.094223  175526 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") 
I0909 09:25:54.094543  175526 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 ""
I0909 09:25:54.100425  175526 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" 
I0909 09:25:54.106681  175526 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" 
I0909 09:25:54.125399  175526 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"
I0909 09:25:54.204193  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:25:54.204265  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:54.204340  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:54.204790  175526 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"
I0909 09:25:54.234031  175526 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"
I0909 09:25:54.234566  175526 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"
E0909 09:25:54.261037  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-mount-device-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:54.73696743 +0000 UTC m=+33.712887226 (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"
I0909 09:25:54.329724  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" 
I0909 09:25:54.329180  175526 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" )
I0909 09:25:54.330560  175526 reconciler.go:319] Volume detached for volume "timeout-mount-device-volume" (UniqueName: "fake-plugin/timeout-mount-device-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:25:54.417532  175526 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") 
I0909 09:25:54.417661  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:54.417720  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:54.418795  175526 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"
I0909 09:25:54.419585  175526 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"
I0909 09:25:54.419811  175526 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"
E0909 09:25:54.420420  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-mount-device-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:54.920108445 +0000 UTC m=+33.896028192 (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"
I0909 09:25:54.523120  175526 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"
I0909 09:25:54.655955  175526 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") 
I0909 09:25:54.656036  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:25:54.656089  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:25:54.656641  175526 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"
I0909 09:25:54.657186  175526 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"
I0909 09:25:54.657318  175526 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"
E0909 09:25:54.657712  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:55.157524114 +0000 UTC m=+34.133443862 (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"
I0909 09:25:55.164925  175526 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"
I0909 09:25:55.165092  175526 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"
E0909 09:25:55.165518  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:56.16531953 +0000 UTC m=+35.141239279 (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"
I0909 09:25:56.173217  175526 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"
I0909 09:25:56.173406  175526 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"
E0909 09:25:56.173890  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:25:58.173680482 +0000 UTC m=+37.149600253 (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"
I0909 09:25:58.200929  175526 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"
I0909 09:25:58.201088  175526 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"
E0909 09:25:58.201489  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:02.201291084 +0000 UTC m=+41.177210833 (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"
I0909 09:26:02.203859  175526 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"
I0909 09:26:02.204055  175526 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"
E0909 09:26:02.213330  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-mount-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:10.205629631 +0000 UTC m=+49.181549389 (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"
I0909 09:26:04.776763  175526 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"
I0909 09:26:04.880704  175526 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") 
I0909 09:26:04.881895  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:04.881946  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:04.882072  175526 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"
I0909 09:26:04.884746  175526 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"
I0909 09:26:04.884892  175526 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"
I0909 09:26:04.885019  175526 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 ""
I0909 09:26:04.887169  175526 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"
I0909 09:26:04.887324  175526 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"
I0909 09:26:04.986186  175526 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"
I0909 09:26:04.986344  175526 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"
I0909 09:26:14.983521  175526 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") 
I0909 09:26:14.983761  175526 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 ""
I0909 09:26:14.984411  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "success-and-timeout-device-name" (UniqueName: "fake-plugin/success-and-timeout-device-name") on node "mynodename" 
I0909 09:26:14.984683  175526 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" )
I0909 09:26:14.984946  175526 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"
I0909 09:26:15.095971  175526 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") 
I0909 09:26:15.096056  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:15.096110  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:15.096914  175526 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"
I0909 09:26:15.097552  175526 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"
I0909 09:26:15.097687  175526 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"
I0909 09:26:15.097805  175526 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 ""
I0909 09:26:15.195615  175526 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"
I0909 09:26:15.195776  175526 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"
I0909 09:26:25.197238  175526 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") 
I0909 09:26:25.196537  175526 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 ""
I0909 09:26:25.200082  175526 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") 
I0909 09:26:25.199640  175526 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 ""
I0909 09:26:25.201805  175526 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" 
I0909 09:26:25.202722  175526 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" )
I0909 09:26:25.203222  175526 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"
I0909 09:26:25.303128  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:26:25.303210  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:25.303271  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:25.303695  175526 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"
I0909 09:26:25.304897  175526 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"
I0909 09:26:25.305033  175526 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"
E0909 09:26:25.305402  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:25.805228258 +0000 UTC m=+64.781148083 (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"
I0909 09:26:25.415794  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I0909 09:26:25.416223  175526 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 ""
I0909 09:26:25.416741  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I0909 09:26:25.416939  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I0909 09:26:25.417140  175526 reconciler.go:319] Volume detached for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:26:25.517869  175526 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"
I0909 09:26:25.520638  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:26:25.520805  175526 reconciler.go:319] Volume detached for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" DevicePath "fake/path"
I0909 09:26:25.520842  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:25.521312  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:25.623261  175526 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") 
I0909 09:26:25.623343  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:25.623395  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:25.623662  175526 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"
I0909 09:26:25.624567  175526 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"
I0909 09:26:25.624706  175526 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"
E0909 09:26:25.625080  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:26.124903489 +0000 UTC m=+65.100823238 (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"
I0909 09:26:26.132613  175526 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"
I0909 09:26:26.132774  175526 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"
E0909 09:26:26.133180  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:27.132984973 +0000 UTC m=+66.108904731 (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"
I0909 09:26:27.133475  175526 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"
I0909 09:26:27.133642  175526 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"
E0909 09:26:27.136428  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:29.13483134 +0000 UTC m=+68.110751101 (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"
I0909 09:26:29.157200  175526 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"
I0909 09:26:29.157360  175526 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"
E0909 09:26:29.160562  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:33.160325651 +0000 UTC m=+72.136245439 (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"
I0909 09:26:33.161147  175526 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"
I0909 09:26:33.187722  175526 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"
E0909 09:26:33.188168  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:41.187961333 +0000 UTC m=+80.163881093 (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"
I0909 09:26:35.733672  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I0909 09:26:35.733889  175526 operation_generator.go:1282] UnmapDevice succeeded for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I0909 09:26:35.734103  175526 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"
I0909 09:26:35.841926  175526 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") 
I0909 09:26:35.842010  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:35.842073  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:35.842547  175526 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"
I0909 09:26:35.843638  175526 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"
I0909 09:26:35.843784  175526 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"
I0909 09:26:35.970017  175526 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"
I0909 09:26:35.972977  175526 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"
E0909 09:26:35.973499  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:36.473234366 +0000 UTC m=+75.449154115 (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"
I0909 09:26:36.473885  175526 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"
I0909 09:26:36.474097  175526 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"
E0909 09:26:36.474523  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:37.474322746 +0000 UTC m=+76.450242491 (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"
I0909 09:26:37.474699  175526 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"
I0909 09:26:37.474915  175526 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"
E0909 09:26:37.475309  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:39.475125501 +0000 UTC m=+78.451045248 (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"
I0909 09:26:39.489400  175526 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"
I0909 09:26:39.558490  175526 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"
E0909 09:26:39.563945  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:43.561340986 +0000 UTC m=+82.537260738 (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"
I0909 09:26:43.571082  175526 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"
I0909 09:26:43.572212  175526 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"
E0909 09:26:43.587367  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:51.587149962 +0000 UTC m=+90.563069719 (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"
I0909 09:26:45.955195  175526 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") 
I0909 09:26:45.955341  175526 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 ""
I0909 09:26:45.955916  175526 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" 
I0909 09:26:45.956130  175526 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" 
I0909 09:26:45.956383  175526 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"
I0909 09:26:46.058282  175526 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") 
I0909 09:26:46.058354  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:46.058403  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:46.058894  175526 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"
I0909 09:26:46.059613  175526 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"
I0909 09:26:46.059745  175526 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"
I0909 09:26:46.173700  175526 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"
I0909 09:26:46.173878  175526 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"
E0909 09:26:46.174277  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:46.674095329 +0000 UTC m=+85.650015083 (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"
I0909 09:26:46.686230  175526 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"
I0909 09:26:46.686418  175526 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"
E0909 09:26:46.688110  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:47.687911998 +0000 UTC m=+86.663831758 (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"
I0909 09:26:47.697183  175526 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"
I0909 09:26:47.697964  175526 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"
E0909 09:26:47.699862  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:49.69925352 +0000 UTC m=+88.675173276 (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"
I0909 09:26:49.713150  175526 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"
I0909 09:26:49.713340  175526 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"
E0909 09:26:49.715158  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:53.714974896 +0000 UTC m=+92.690894647 (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"
I0909 09:26:53.727358  175526 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"
I0909 09:26:53.727542  175526 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"
E0909 09:26:53.727981  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:01.72778063 +0000 UTC m=+100.703700382 (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"
I0909 09:26:56.185206  175526 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") 
I0909 09:26:56.200456  175526 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 ""
I0909 09:26:56.209827  175526 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") 
I0909 09:26:56.210149  175526 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 ""
I0909 09:26:56.212920  175526 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" 
I0909 09:26:56.213122  175526 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" 
I0909 09:26:56.213411  175526 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"
I0909 09:26:56.289870  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:26:56.289950  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:56.290008  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:56.290242  175526 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"
I0909 09:26:56.290988  175526 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"
I0909 09:26:56.291185  175526 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"
I0909 09:26:56.291337  175526 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 ""
E0909 09:26:56.291757  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:56.791592239 +0000 UTC m=+95.767511987 (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"
I0909 09:26:56.428125  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I0909 09:26:56.428640  175526 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 ""
I0909 09:26:56.433316  175526 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 ""
I0909 09:26:56.433270  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") pod "pod1uid" (UID: "pod1uid") 
I0909 09:26:56.439659  175526 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" )
I0909 09:26:56.441638  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" 
I0909 09:26:56.488203  175526 reconciler.go:319] Volume detached for volume "timeout-setup-volume" (UniqueName: "fake-plugin/timeout-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:26:56.523940  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") 
I0909 09:26:56.545972  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:56.546070  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:56.533592  175526 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"
I0909 09:26:56.547113  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "fake/path"
I0909 09:26:56.547257  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:26:56.547377  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") pod "pod1" (UID: "pod1uid") device mount path ""
E0909 09:26:56.547792  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:57.047623763 +0000 UTC m=+96.023543510 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"fail-setup-volume\" (UniqueName: \"fake-plugin/fail-setup-volume\") pod \"pod1\" (UID: \"pod1uid\") : mounting volume failed"
I0909 09:26:56.655657  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" 
I0909 09:26:56.656035  175526 operation_generator.go:891] UnmountDevice succeeded for volume "fail-setup-volume" %!(EXTRA string=UnmountDevice succeeded for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" )
I0909 09:26:56.656361  175526 reconciler.go:319] Volume detached for volume "fail-setup-volume" (UniqueName: "fake-plugin/fail-setup-volume") on node "mynodename" DevicePath "/dev/sdb"
I0909 09:26:56.727485  175526 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") 
I0909 09:26:56.727559  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:26:56.727620  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:26:56.727852  175526 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"
I0909 09:26:56.736740  175526 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"
I0909 09:26:56.736886  175526 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"
I0909 09:26:56.737001  175526 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 ""
E0909 09:26:56.737433  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:57.237246765 +0000 UTC m=+96.213166512 (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"
I0909 09:26:57.266214  175526 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"
I0909 09:26:57.266669  175526 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"
E0909 09:26:57.267441  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:26:58.267003299 +0000 UTC m=+97.242923058 (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"
I0909 09:26:58.273449  175526 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"
I0909 09:26:58.279113  175526 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"
E0909 09:26:58.290132  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:00.281492922 +0000 UTC m=+99.257412687 (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"
I0909 09:27:00.281837  175526 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"
I0909 09:27:00.281986  175526 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"
E0909 09:27:00.282372  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:04.282189882 +0000 UTC m=+103.258109633 (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"
I0909 09:27:04.282746  175526 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"
I0909 09:27:04.282920  175526 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"
E0909 09:27:04.283633  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/timeout-and-fail-setup-volume podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:12.283137284 +0000 UTC m=+111.259057263 (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"
I0909 09:27:06.835975  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "timeout-and-fail-setup-volume" (UniqueName: "fake-plugin/timeout-and-fail-setup-volume") on node "mynodename" 
I0909 09:27:06.836329  175526 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" )
I0909 09:27:06.836585  175526 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"
I0909 09:27:06.940440  175526 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") 
I0909 09:27:06.941198  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:27:06.941260  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:27:06.941040  175526 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"
I0909 09:27:06.944231  175526 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"
I0909 09:27:06.965500  175526 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"
I0909 09:27:06.965854  175526 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 ""
I0909 09:27:06.969529  175526 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"
I0909 09:27:06.969903  175526 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"
E0909 09:27:06.971177  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:07.470548635 +0000 UTC m=+106.446468393 (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"
I0909 09:27:07.472810  175526 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"
I0909 09:27:07.472982  175526 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"
E0909 09:27:07.473396  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:08.473190036 +0000 UTC m=+107.449109785 (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"
I0909 09:27:08.473751  175526 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"
I0909 09:27:08.473924  175526 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"
E0909 09:27:08.474403  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:10.474162084 +0000 UTC m=+109.450081876 (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"
I0909 09:27:10.474669  175526 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"
I0909 09:27:10.474833  175526 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"
E0909 09:27:10.475249  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:14.47504622 +0000 UTC m=+113.450965968 (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"
I0909 09:27:14.485389  175526 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"
I0909 09:27:14.485571  175526 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"
E0909 09:27:14.486008  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-timeout-setup-volume-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:22.485796402 +0000 UTC m=+121.461716148 (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"
I0909 09:27:17.055637  175526 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") 
I0909 09:27:17.055958  175526 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 ""
I0909 09:27:17.056707  175526 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" 
I0909 09:27:17.057023  175526 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" )
I0909 09:27:17.057407  175526 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"
I0909 09:27:17.156448  175526 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") 
I0909 09:27:17.156537  175526 reconciler.go:157] Reconciler: start to sync state
E0909 09:27:17.156592  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:27:17.157138  175526 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"
I0909 09:27:17.157990  175526 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"
I0909 09:27:17.158119  175526 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"
I0909 09:27:17.158243  175526 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 ""
I0909 09:27:17.257017  175526 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"
I0909 09:27:17.257184  175526 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"
E0909 09:27:17.257585  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:17.757396127 +0000 UTC m=+116.733315878 (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"
I0909 09:27:17.757886  175526 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"
I0909 09:27:17.758085  175526 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"
E0909 09:27:17.758522  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:18.75831292 +0000 UTC m=+117.734232672 (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"
I0909 09:27:18.758899  175526 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"
I0909 09:27:18.759087  175526 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"
E0909 09:27:18.759519  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:20.759324655 +0000 UTC m=+119.735244408 (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"
I0909 09:27:20.784589  175526 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"
I0909 09:27:20.784759  175526 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"
E0909 09:27:20.785347  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:24.785147176 +0000 UTC m=+123.761066922 (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"
I0909 09:27:24.785614  175526 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"
I0909 09:27:24.787758  175526 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"
E0909 09:27:24.788230  175526 nestedpendingoperations.go:301] Operation for "{volumeName:fake-plugin/success-and-failed-setup-device-name podName: nodeName:}" failed. No retries permitted until 2021-09-09 09:27:32.788032404 +0000 UTC m=+131.763952163 (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"
I0909 09:27:27.266607  175526 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") 
I0909 09:27:27.266853  175526 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 ""
I0909 09:27:27.267441  175526 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" 
I0909 09:27:27.267758  175526 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" )
I0909 09:27:27.268012  175526 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.07s)
    --- FAIL: Test_UncertainVolumeMountState/failed_operation_should_result_in_not-mounted_volume_[Block] (0.11s)
        reconciler_test.go:1544: Error verifying UnMountDeviceCallCount: No Unmapper have expected TearDownDeviceCallCount. Expected: <1>.
I0909 09:27:27.368676  175526 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") 
I0909 09:27:27.370561  175526 reconciler.go:157] Reconciler: start to sync state
I0909 09:27:27.369008  175526 operation_generator.go:1357] Controller attach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device path: "/fake/path"
E0909 09:27:27.370641  175526 reconciler.go:389] Cannot get volumes from disk open fake-dir: no such file or directory
I0909 09:27:27.379987  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/fake/path"
I0909 09:27:27.381589  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:27:27.384003  175526 operation_generator.go:594] MountVolume.MountDevice succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") device mount path ""
I0909 09:27:27.477680  175526 reconciler.go:196] operationExecutor.UnmountVolume started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1uid" (UID: "pod1uid") 
I0909 09:27:27.479704  175526 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 ""
I0909 09:27:27.480179  175526 reconciler.go:312] operationExecutor.UnmountDevice started for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") on node "mynodename" 
I0909 09:27:27.480291  175526 reconciler_test.go:1798] UnmountDevice called
I0909 09:27:27.480547  175526 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" )
I0909 09:27:27.481111  175526 operation_generator.go:556] MountVolume.WaitForAttach entering for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:27:27.481229  175526 operation_generator.go:565] MountVolume.WaitForAttach succeeded for volume "volume-name" (UniqueName: "fake-plugin/fake-device1") pod "pod1" (UID: "pod1uid") DevicePath "/dev/sdb"
I0909 09:27:27.481316  175526 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