pull-azurefile-csi-driver-sanity #1608290585578311680 Results

Error lines from build-log.txt

Raw build-log.txt
... skipping 92 lines ...
Git Commit: d0762f814988fe4c48e44193a2223cef40b75409
Go Version: go1.19.4
Platform: linux/amd64

Streaming logs below:
I1229 02:39:00.042140   11009 azurefile.go:299] driver userAgent: file.csi.azure.com/e2e-d0762f814988fe4c48e44193a2223cef40b75409
W1229 02:39:00.042328   11009 azure.go:73] get kubeconfig() failed with error: open /var/run/secrets/kubernetes.io/serviceaccount/token: no such file or directory
I1229 02:39:00.042369   11009 azure.go:92] could not read cloud config from secret kube-system/azure-cloud-provider
I1229 02:39:00.042380   11009 azure.go:95] AZURE_CREDENTIAL_FILE env var set as /tmp/azure.json
I1229 02:39:00.042410   11009 azure.go:110] read cloud config from file: /tmp/azure.json successfully
I1229 02:39:00.043174   11009 azure_auth.go:245] Using AzurePublicCloud environment
I1229 02:39:00.043236   11009 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I1229 02:39:00.043329   11009 azure.go:775] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 60 lines ...
  Begin Captured GinkgoWriter Output >>
    STEP: connecting to CSI driver 12/29/22 02:39:01.027
    STEP: creating mount and staging directories 12/29/22 02:39:01.03
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodePublishVolume
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:379
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.039
STEP: creating mount and staging directories 12/29/22 02:39:01.039
I1229 02:39:01.040241   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:01.040259   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.040298   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:01.040828   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.041945   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:01.041961   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.041993   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.042680   11009 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I1229 02:39:01.042699   11009 utils.go:77] GRPC request: {}
E1229 02:39:01.042866   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume capability missing in request
------------------------------
• [0.003 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodePublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:378
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:379

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.039
    STEP: creating mount and staging directories 12/29/22 02:39:01.039
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodePublishVolume
  should fail when no target path is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:393
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.043
STEP: creating mount and staging directories 12/29/22 02:39:01.043
I1229 02:39:01.043926   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:01.043949   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.043998   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:01.044439   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.045819   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:01.045834   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.045903   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.046816   11009 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I1229 02:39:01.046832   11009 utils.go:77] GRPC request: {"volume_id":"fake-vol-id-9cfc3e1c-2"}
E1229 02:39:01.046893   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume capability missing in request
------------------------------
• [0.004 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodePublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:378
    should fail when no target path is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:393

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.043
    STEP: creating mount and staging directories 12/29/22 02:39:01.043
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodePublishVolume
  should fail when no volume capability is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:408
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.047
STEP: creating mount and staging directories 12/29/22 02:39:01.047
I1229 02:39:01.048295   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:01.048313   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.048342   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:01.049101   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.050602   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:01.050620   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.050649   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.051169   11009 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I1229 02:39:01.051189   11009 utils.go:77] GRPC request: {"target_path":"/tmp/csi-mount/target","volume_id":"fake-vol-id-02041a9e-4"}
E1229 02:39:01.051305   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume capability missing in request
------------------------------
• [0.004 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodePublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:378
    should fail when no volume capability is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:408

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.047
    STEP: creating mount and staging directories 12/29/22 02:39:01.047
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeUnpublishVolume
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:427
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.051
STEP: creating mount and staging directories 12/29/22 02:39:01.052
I1229 02:39:01.052750   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:01.052782   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.052823   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:01.053463   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.054666   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:01.054771   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.054878   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.055502   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1229 02:39:01.055529   11009 utils.go:77] GRPC request: {}
E1229 02:39:01.055601   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
------------------------------
• [0.004 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeUnpublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:426
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:427

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.051
    STEP: creating mount and staging directories 12/29/22 02:39:01.052
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeUnpublishVolume
  should fail when no target path is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:439
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.056
STEP: creating mount and staging directories 12/29/22 02:39:01.056
I1229 02:39:01.057006   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:01.057023   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.057049   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:01.057646   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.058995   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:01.059008   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.059037   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.059602   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1229 02:39:01.059624   11009 utils.go:77] GRPC request: {"volume_id":"fake-vol-id-eb335d5d-d"}
E1229 02:39:01.059699   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Target path missing in request
------------------------------
• [0.004 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeUnpublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:426
    should fail when no target path is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:439

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.056
    STEP: creating mount and staging directories 12/29/22 02:39:01.056
  << End Captured GinkgoWriter Output
------------------------------
S
------------------------------
Node Service NodeStageVolume
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:525
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.06
STEP: creating mount and staging directories 12/29/22 02:39:01.06
I1229 02:39:01.061466   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:01.061487   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.061534   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:01.062162   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.063381   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:01.063402   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.063441   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.064469   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I1229 02:39:01.064487   11009 utils.go:77] GRPC request: {"publish_context":{"device":"/dev/mock"},"staging_target_path":"/tmp/csi-staging","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":1}}}
E1229 02:39:01.064603   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
------------------------------
• [0.004 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeStageVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:512
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:525

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.06
    STEP: creating mount and staging directories 12/29/22 02:39:01.06
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeStageVolume
  should fail when no staging target path is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:544
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.064
STEP: creating mount and staging directories 12/29/22 02:39:01.065
I1229 02:39:01.065556   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:01.065571   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.065599   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:01.066067   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.067140   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:01.067159   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.067196   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:01.067940   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I1229 02:39:01.067974   11009 utils.go:77] GRPC request: {"publish_context":{"device":"/dev/mock"},"volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":1}},"volume_id":"fake-vol-id-97e125b3-b"}
E1229 02:39:01.068104   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Staging target not provided
------------------------------
• [0.003 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeStageVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:512
    should fail when no staging target path is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:544

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.064
    STEP: creating mount and staging directories 12/29/22 02:39:01.065
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeStageVolume
  should fail when no volume capability is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:563
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.068
STEP: creating mount and staging directories 12/29/22 02:39:01.068
I1229 02:39:01.069449   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:01.069459   11009 utils.go:77] GRPC request: {}
I1229 02:39:01.069486   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 14 lines ...
I1229 02:39:22.777383   11009 controllerserver.go:479] create file share sanity-node-stage-nocaps-bfaa4970-4f36ee66 on storage account f7b785f85834b49478b6faa successfully
W1229 02:39:22.777422   11009 azurefile.go:952] could not create secret: kubeClient is nil
I1229 02:39:22.777501   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.594533043 request="azurefile_csi_driver_controller_create_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:22.777591   11009 utils.go:83] GRPC response: {"volume":{"volume_context":{"secretnamespace":"default"},"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default"}}
I1229 02:39:22.779232   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I1229 02:39:22.779255   11009 utils.go:77] GRPC request: {"publish_context":{"device":"/dev/mock"},"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default"}
E1229 02:39:22.779377   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume capability not provided
I1229 02:39:22.780189   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1229 02:39:22.780210   11009 utils.go:77] GRPC request: {"target_path":"/tmp/csi-mount/target","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default"}
I1229 02:39:22.780292   11009 nodeserver.go:132] NodeUnpublishVolume: unmounting volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default on /tmp/csi-mount/target
I1229 02:39:22.780303   11009 azure_common_linux.go:38] force unmount on /tmp/csi-mount/target
W1229 02:39:22.780401   11009 mount_helper_common.go:47] Warning: mount cleanup skipped because path does not exist: /tmp/csi-mount/target
I1229 02:39:22.780429   11009 nodeserver.go:136] NodeUnpublishVolume: unmount volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default on /tmp/csi-mount/target successfully
I1229 02:39:22.780441   11009 utils.go:83] GRPC response: {}
I1229 02:39:22.781576   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:22.781609   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default"}
I1229 02:39:22.781685   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:22.781723   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:22.781753   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:22.781770   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:22.784866   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:22.785894   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:22.785993   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default"}
I1229 02:39:23.056657   11009 azure_storage.go:69] share sanity-node-stage-nocaps-bfaa4970-4f36ee66 deleted
I1229 02:39:23.056740   11009 controllerserver.go:613] azure file(sanity-node-stage-nocaps-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:23.056770   11009 azurefile.go:849] remove tag(skip-matching) on account(f7b785f85834b49478b6faa) subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e), resourceGroup(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc)
I1229 02:39:23.262266   11009 util.go:124] Send.sendRequest got response with ContentLength -1, StatusCode 200 and responseBody length 1557
I1229 02:39:23.262784   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.476576057 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:23.262827   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [22.195 seconds]
Node Service [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:319
  NodeStageVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:512
    should fail when no volume capability is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:563

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:01.068
    STEP: creating mount and staging directories 12/29/22 02:39:01.068
    STEP: creating a single node writer volume 12/29/22 02:39:01.072
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc00056e0f0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-stage-nocaps-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Node Service NodeUnstageVolume
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:614
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.263
STEP: creating mount and staging directories 12/29/22 02:39:23.264
I1229 02:39:23.264582   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:23.264608   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.264682   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:23.265179   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:23.266639   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:23.266656   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.266700   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:23.267111   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:23.267126   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging"}
E1229 02:39:23.267163   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
------------------------------
• [0.003 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeUnstageVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:607
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:614

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.263
    STEP: creating mount and staging directories 12/29/22 02:39:23.264
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeUnstageVolume
  should fail when no staging target path is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:628
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.267
STEP: creating mount and staging directories 12/29/22 02:39:23.267
I1229 02:39:23.268010   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:23.268094   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.268154   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 2 lines ...
I1229 02:39:23.268674   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:23.270123   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:23.270147   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.270332   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:23.270953   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:23.271100   11009 utils.go:77] GRPC request: {"volume_id":"fake-vol-id-eedae487-4"}
E1229 02:39:23.271211   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Staging target not provided
------------------------------
• [0.004 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeUnstageVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:607
    should fail when no staging target path is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:628

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.267
    STEP: creating mount and staging directories 12/29/22 02:39:23.267
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeGetVolumeStats
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:650
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.271
STEP: creating mount and staging directories 12/29/22 02:39:23.271
I1229 02:39:23.272296   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:23.272364   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.272455   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
I1229 02:39:23.272898   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:23.272915   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.272948   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:23.274097   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:23.274113   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.274143   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
E1229 02:39:23.274757   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = NodeGetVolumeStats volume ID was empty
------------------------------
• [0.003 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeGetVolumeStats
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:643
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:650

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.271
    STEP: creating mount and staging directories 12/29/22 02:39:23.271
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeGetVolumeStats
  should fail when no volume path is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:664
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.275
STEP: creating mount and staging directories 12/29/22 02:39:23.275
I1229 02:39:23.276995   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:23.277088   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.277163   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
I1229 02:39:23.277876   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:23.277900   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.277936   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:23.279419   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:23.279438   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.279470   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
E1229 02:39:23.279966   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = NodeGetVolumeStats volume path was empty
------------------------------
• [0.005 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeGetVolumeStats
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:643
    should fail when no volume path is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:664

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.275
    STEP: creating mount and staging directories 12/29/22 02:39:23.275
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeGetVolumeStats
  should fail when volume is not found
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:678
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.28
STEP: creating mount and staging directories 12/29/22 02:39:23.28
I1229 02:39:23.281063   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:23.281086   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.281128   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
I1229 02:39:23.281539   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:23.281556   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.281606   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:23.282789   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:23.282899   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.283006   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
E1229 02:39:23.283494   11009 utils.go:81] GRPC error: rpc error: code = NotFound desc = path some/path does not exist
------------------------------
• [0.003 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeGetVolumeStats
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:643
    should fail when volume is not found
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:678

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.28
    STEP: creating mount and staging directories 12/29/22 02:39:23.28
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeGetVolumeStats
  should fail when volume does not exist on the specified path
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:693
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.283
STEP: creating mount and staging directories 12/29/22 02:39:23.284
I1229 02:39:23.284435   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:23.284451   11009 utils.go:77] GRPC request: {}
I1229 02:39:23.284488   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 34 lines ...
I1229 02:39:24.357256   11009 nodeserver.go:109] NodePublishVolume: mounting /tmp/csi-staging at /tmp/csi-mount/target with mountOptions: [bind]
I1229 02:39:24.357310   11009 mount_linux.go:220] Mounting cmd (mount) with arguments ( -o bind /tmp/csi-staging /tmp/csi-mount/target)
I1229 02:39:24.359442   11009 mount_linux.go:220] Mounting cmd (mount) with arguments ( -o bind,remount /tmp/csi-staging /tmp/csi-mount/target)
I1229 02:39:24.362244   11009 nodeserver.go:116] NodePublishVolume: mount /tmp/csi-staging at /tmp/csi-mount/target successfully
I1229 02:39:24.362276   11009 utils.go:83] GRPC response: {}
STEP: Get node volume stats 12/29/22 02:39:24.362
E1229 02:39:24.363122   11009 utils.go:81] GRPC error: rpc error: code = NotFound desc = path some/path does not exist
I1229 02:39:24.363676   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1229 02:39:24.363702   11009 utils.go:77] GRPC request: {"target_path":"/tmp/csi-mount/target","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-get-volume-stats-bfaa4970-4f36ee66###default"}
I1229 02:39:24.363788   11009 nodeserver.go:132] NodeUnpublishVolume: unmounting volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-node-get-volume-stats-bfaa4970-4f36ee66###default on /tmp/csi-mount/target
I1229 02:39:24.363799   11009 azure_common_linux.go:38] force unmount on /tmp/csi-mount/target
I1229 02:39:24.363827   11009 mount_helper_common.go:56] unmounting "/tmp/csi-mount/target" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:24.363841   11009 mount_linux.go:779] Unmounting /tmp/csi-mount/target
... skipping 48 lines ...
------------------------------
• [1.836 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeGetVolumeStats
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:643
    should fail when volume does not exist on the specified path
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:693

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:23.283
    STEP: creating mount and staging directories 12/29/22 02:39:23.284
    STEP: creating a single node writer volume for expansion 12/29/22 02:39:23.287
... skipping 2 lines ...
    STEP: node staging volume 12/29/22 02:39:23.81
    STEP: publishing the volume on a node 12/29/22 02:39:24.351
    STEP: Get node volume stats 12/29/22 02:39:24.362
  << End Captured GinkgoWriter Output
------------------------------
Node Service NodeExpandVolume
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:740
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:25.12
STEP: creating mount and staging directories 12/29/22 02:39:25.12
I1229 02:39:25.121083   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:25.121136   11009 utils.go:77] GRPC request: {}
I1229 02:39:25.121233   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 6 lines ...
------------------------------
S [SKIPPED] [0.004 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeExpandVolume [BeforeEach]
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:733
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:740

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:25.12
    STEP: creating mount and staging directories 12/29/22 02:39:25.12
  << End Captured GinkgoWriter Output

  NodeExpandVolume not supported
  In [BeforeEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:735
------------------------------
Node Service NodeExpandVolume
  should fail when no volume path is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:755
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:25.125
STEP: creating mount and staging directories 12/29/22 02:39:25.125
I1229 02:39:25.126422   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:25.126520   11009 utils.go:77] GRPC request: {}
I1229 02:39:25.126614   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 6 lines ...
------------------------------
S [SKIPPED] [0.005 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeExpandVolume [BeforeEach]
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:733
    should fail when no volume path is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:755

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:25.125
    STEP: creating mount and staging directories 12/29/22 02:39:25.125
  << End Captured GinkgoWriter Output

  NodeExpandVolume not supported
  In [BeforeEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:735
------------------------------
Node Service NodeExpandVolume
  should fail when volume is not found
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:774
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:25.13
STEP: creating mount and staging directories 12/29/22 02:39:25.13
I1229 02:39:25.130769   11009 utils.go:76] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1229 02:39:25.130791   11009 utils.go:77] GRPC request: {}
I1229 02:39:25.130825   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}}]}
... skipping 6 lines ...
------------------------------
S [SKIPPED] [0.004 seconds]
Node Service
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  NodeExpandVolume [BeforeEach]
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:733
    should fail when volume is not found
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:774

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:25.13
    STEP: creating mount and staging directories 12/29/22 02:39:25.13
  << End Captured GinkgoWriter Output
... skipping 257 lines ...
    STEP: publishing the volume on a node 12/29/22 02:39:28.547
    STEP: publishing the volume on a node 12/29/22 02:39:28.696
    STEP: Get node volume stats 12/29/22 02:39:28.845
  << End Captured GinkgoWriter Output
------------------------------
ExpandVolume [Controller Server]
  should fail if no volume id is given
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1528
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.539
STEP: creating mount and staging directories 12/29/22 02:39:29.539
I1229 02:39:29.540347   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:29.540405   11009 utils.go:77] GRPC request: {}
I1229 02:39:29.540466   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:29.541363   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerExpandVolume
I1229 02:39:29.541386   11009 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":11811160064}}
E1229 02:39:29.541505   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
------------------------------
• [0.002 seconds]
ExpandVolume [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  should fail if no volume id is given
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1528

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.539
    STEP: creating mount and staging directories 12/29/22 02:39:29.539
  << End Captured GinkgoWriter Output
------------------------------
ExpandVolume [Controller Server]
  should fail if no capacity range is given
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1545
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.541
STEP: creating mount and staging directories 12/29/22 02:39:29.541
I1229 02:39:29.542338   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:29.542360   11009 utils.go:77] GRPC request: {}
I1229 02:39:29.542403   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:29.542986   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerExpandVolume
I1229 02:39:29.543000   11009 utils.go:77] GRPC request: {}
E1229 02:39:29.543052   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
------------------------------
• [0.002 seconds]
ExpandVolume [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  should fail if no capacity range is given
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1545

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.541
    STEP: creating mount and staging directories 12/29/22 02:39:29.541
  << End Captured GinkgoWriter Output
... skipping 72 lines ...
  << End Captured GinkgoWriter Output

  ListVolumes not supported
  In [BeforeEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:178
------------------------------
Controller Service [Controller Server] ListVolumes
  should fail when an invalid starting_token is passed
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:194
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.548
STEP: creating mount and staging directories 12/29/22 02:39:29.548
I1229 02:39:29.548966   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:29.548983   11009 utils.go:77] GRPC request: {}
I1229 02:39:29.549025   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
------------------------------
S [SKIPPED] [0.001 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ListVolumes [BeforeEach]
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:176
    should fail when an invalid starting_token is passed
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:194

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.548
    STEP: creating mount and staging directories 12/29/22 02:39:29.548
  << End Captured GinkgoWriter Output
... skipping 28 lines ...
------------------------------
P [PENDING]
Controller Service [Controller Server] ListVolumes pagination should detect volumes added between pages and accept tokens when the last volume from a page is deleted
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:268
------------------------------
Controller Service [Controller Server] CreateVolume
  should fail when no name is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:376
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.551
STEP: creating mount and staging directories 12/29/22 02:39:29.551
I1229 02:39:29.551777   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:29.551831   11009 utils.go:77] GRPC request: {}
I1229 02:39:29.551877   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:29.552420   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I1229 02:39:29.552435   11009 utils.go:77] GRPC request: {}
E1229 02:39:29.552496   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Name must be provided
------------------------------
• [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    should fail when no name is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:376

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.551
    STEP: creating mount and staging directories 12/29/22 02:39:29.551
  << End Captured GinkgoWriter Output
------------------------------
Controller Service [Controller Server] CreateVolume
  should fail when no volume capabilities are provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:391
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.553
STEP: creating mount and staging directories 12/29/22 02:39:29.553
I1229 02:39:29.553696   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:29.553718   11009 utils.go:77] GRPC request: {}
I1229 02:39:29.553810   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:29.554262   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I1229 02:39:29.554286   11009 utils.go:77] GRPC request: {"name":"sanity-controller-create-no-volume-capabilities-BFAA4970-4F36EE66"}
E1229 02:39:29.554358   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: CreateVolume Volume capabilities must be provided
------------------------------
• [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    should fail when no volume capabilities are provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:391

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.553
    STEP: creating mount and staging directories 12/29/22 02:39:29.553
  << End Captured GinkgoWriter Output
... skipping 24 lines ...
I1229 02:39:30.075423   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:30.075444   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-no-capacity-bfaa4970-4f36ee66###default"}
I1229 02:39:30.075534   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-no-capacity-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:30.075542   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:30.075564   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:30.075580   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:30.079023   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:30.079616   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:30.079639   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-no-capacity-bfaa4970-4f36ee66###default"}
I1229 02:39:30.355498   11009 azure_storage.go:69] share sanity-controller-create-single-no-capacity-bfaa4970-4f36ee66 deleted
I1229 02:39:30.355542   11009 controllerserver.go:613] azure file(sanity-controller-create-single-no-capacity-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-no-capacity-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:30.355596   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.2753552 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-no-capacity-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:30.355615   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [0.801 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    should return appropriate values SingleNodeWriter NoCapacity
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:409

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:29.555
    STEP: creating mount and staging directories 12/29/22 02:39:29.555
    STEP: creating a volume 12/29/22 02:39:29.557
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc000502110>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-no-capacity-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Controller Service [Controller Server] CreateVolume
... skipping 22 lines ...
I1229 02:39:30.888102   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:30.888120   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-with-capacity-bfaa4970-4f36ee66###default"}
I1229 02:39:30.888173   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-with-capacity-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:30.888179   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:30.888198   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:30.888214   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:30.891036   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:30.891527   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:30.891546   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-with-capacity-bfaa4970-4f36ee66###default"}
I1229 02:39:31.219532   11009 azure_storage.go:69] share sanity-controller-create-single-with-capacity-bfaa4970-4f36ee66 deleted
I1229 02:39:31.219568   11009 controllerserver.go:613] azure file(sanity-controller-create-single-with-capacity-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-with-capacity-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:31.219612   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.327973396 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-with-capacity-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:31.219631   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [0.864 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    should return appropriate values SingleNodeWriter WithCapacity 1Gi
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:430

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:30.356
    STEP: creating mount and staging directories 12/29/22 02:39:30.356
    STEP: creating a volume 12/29/22 02:39:30.358
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc000502ef0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-single-with-capacity-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Controller Service [Controller Server] CreateVolume
  should not fail when requesting to create a volume with already existing name and same capacity
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:460
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:31.22
STEP: creating mount and staging directories 12/29/22 02:39:31.22
I1229 02:39:31.221414   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:31.221438   11009 utils.go:77] GRPC request: {}
I1229 02:39:31.221506   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
... skipping 22 lines ...
I1229 02:39:32.403503   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:32.403552   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default"}
I1229 02:39:32.403624   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:32.403633   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:32.403658   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:32.403674   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:32.407432   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:32.408214   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:32.408233   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default"}
I1229 02:39:32.714058   11009 azure_storage.go:69] share sanity-controller-create-twice-bfaa4970-4f36ee66 deleted
I1229 02:39:32.714098   11009 controllerserver.go:613] azure file(sanity-controller-create-twice-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default) is deleted successfully
... skipping 9 lines ...
I1229 02:39:32.716053   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:32.716075   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default"}
I1229 02:39:32.716140   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:32.716157   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:32.716181   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:32.716203   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:32.719131   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:32.719609   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:32.719642   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default"}
I1229 02:39:32.997902   11009 azure_storage.go:69] share sanity-controller-create-twice-bfaa4970-4f36ee66 deleted
I1229 02:39:32.997954   11009 controllerserver.go:613] azure file(sanity-controller-create-twice-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:32.997998   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.278226094 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:32.998027   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [1.778 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    should not fail when requesting to create a volume with already existing name and same capacity
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:460

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:31.22
    STEP: creating mount and staging directories 12/29/22 02:39:31.22
    STEP: creating a volume 12/29/22 02:39:31.221
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:2, cap:2>: [
          <*errors.errorString | 0xc00031c0f0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc000503930>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Controller Service [Controller Server] CreateVolume
  should fail when requesting to create a volume with already existing name and different capacity
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:501
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:32.999
STEP: creating mount and staging directories 12/29/22 02:39:32.999
I1229 02:39:32.999718   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:32.999737   11009 utils.go:77] GRPC request: {}
I1229 02:39:32.999795   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
... skipping 4 lines ...
I1229 02:39:33.891567   11009 controllerserver.go:479] create file share sanity-controller-create-twice-different-bfaa4970-4f36ee66 on storage account f7b785f85834b49478b6faa successfully
W1229 02:39:33.891611   11009 azurefile.go:952] could not create secret: kubeClient is nil
I1229 02:39:33.891655   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.632935746 request="azurefile_csi_driver_controller_create_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:33.891676   11009 utils.go:83] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"secretnamespace":"default"},"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default"}}
I1229 02:39:33.892421   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I1229 02:39:33.892442   11009 utils.go:77] GRPC request: {"capacity_range":{"limit_bytes":21474836480,"required_bytes":21474836480},"name":"sanity-controller-create-twice-different-BFAA4970-4F36EE66","volume_capabilities":[{"AccessType":{"Mount":{}},"access_mode":{"mode":1}}]}
E1229 02:39:34.100489   11009 utils.go:81] GRPC error: rpc error: code = AlreadyExists desc = request file share(sanity-controller-create-twice-different-bfaa4970-4f36ee66) already exists, but its capacity 10 is smaller than 20
I1229 02:39:34.101181   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1229 02:39:34.101346   11009 utils.go:77] GRPC request: {"target_path":"/tmp/csi-mount/target","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default"}
I1229 02:39:34.101510   11009 nodeserver.go:132] NodeUnpublishVolume: unmounting volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default on /tmp/csi-mount/target
I1229 02:39:34.101534   11009 azure_common_linux.go:38] force unmount on /tmp/csi-mount/target
W1229 02:39:34.101601   11009 mount_helper_common.go:47] Warning: mount cleanup skipped because path does not exist: /tmp/csi-mount/target
I1229 02:39:34.101613   11009 nodeserver.go:136] NodeUnpublishVolume: unmount volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default on /tmp/csi-mount/target successfully
I1229 02:39:34.101622   11009 utils.go:83] GRPC response: {}
I1229 02:39:34.102481   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:34.102502   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default"}
I1229 02:39:34.102551   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:34.102558   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:34.102579   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:34.102591   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:34.105638   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:34.106136   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:34.106154   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default"}
I1229 02:39:34.450146   11009 azure_storage.go:69] share sanity-controller-create-twice-different-bfaa4970-4f36ee66 deleted
I1229 02:39:34.450184   11009 controllerserver.go:613] azure file(sanity-controller-create-twice-different-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:34.450226   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.343959022 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:34.450243   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [1.452 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    should fail when requesting to create a volume with already existing name and different capacity
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:501

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:32.999
    STEP: creating mount and staging directories 12/29/22 02:39:32.999
    STEP: creating a volume 12/29/22 02:39:33
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc0005faf00>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-create-twice-different-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Controller Service [Controller Server] CreateVolume
  should not fail when creating volume with maximum-length name
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:545
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:34.451
STEP: creating mount and staging directories 12/29/22 02:39:34.451
I1229 02:39:34.451917   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:34.451936   11009 utils.go:77] GRPC request: {}
I1229 02:39:34.451990   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
... skipping 15 lines ...
I1229 02:39:34.966308   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:34.966328   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa###default"}
I1229 02:39:34.966386   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa###default on /tmp/csi-staging
I1229 02:39:34.966393   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:34.966416   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:34.966441   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:34.969258   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:34.969820   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:34.969836   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa###default"}
I1229 02:39:35.244777   11009 azure_storage.go:69] share aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa deleted
I1229 02:39:35.244817   11009 controllerserver.go:613] azure file(aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa###default) is deleted successfully
I1229 02:39:35.244867   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.274913615 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa###default" result_code="succeeded"
I1229 02:39:35.244887   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [0.797 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    should not fail when creating volume with maximum-length name
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:545

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:34.451
    STEP: creating mount and staging directories 12/29/22 02:39:34.451
    STEP: creating a volume 12/29/22 02:39:34.452
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc000503f10>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Controller Service [Controller Server] CreateVolume
... skipping 38 lines ...
I1229 02:39:36.778741   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:36.778761   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-vol-from-snap-bfaa4970-4f36ee66###default"}
I1229 02:39:36.778811   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-vol-from-snap-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:36.778818   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:36.778838   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:36.778852   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:36.781808   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:36.782388   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:36.782405   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-vol-from-snap-bfaa4970-4f36ee66###default"}
I1229 02:39:37.058361   11009 azure_storage.go:69] share sanity-controller-vol-from-snap-bfaa4970-4f36ee66 deleted
I1229 02:39:37.058456   11009 controllerserver.go:613] azure file(sanity-controller-vol-from-snap-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-vol-from-snap-bfaa4970-4f36ee66###default) is deleted successfully
... skipping 15 lines ...
I1229 02:39:37.327684   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:37.327705   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-source-vol-bfaa4970-4f36ee66###default"}
I1229 02:39:37.327757   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-source-vol-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:37.327765   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:37.327791   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:37.327799   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:37.330558   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:37.331229   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:37.331250   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-source-vol-bfaa4970-4f36ee66###default"}
I1229 02:39:37.647089   11009 azure_storage.go:69] share sanity-controller-source-vol-bfaa4970-4f36ee66 deleted
I1229 02:39:37.647129   11009 controllerserver.go:613] azure file(sanity-controller-source-vol-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-source-vol-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:37.647180   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.315672539 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-source-vol-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:37.647196   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [2.400 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    should create volume from an existing source snapshot
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:572
... skipping 2 lines ...
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:35.248
    STEP: creating mount and staging directories 12/29/22 02:39:35.248
    STEP: creating a snapshot 12/29/22 02:39:35.25
    STEP: creating a volume from source snapshot 12/29/22 02:39:36.277
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:2, cap:2>: [
          <*errors.errorString | 0xc0003cb210>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-vol-from-snap-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc0005fa1f0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-source-vol-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
S
... skipping 24 lines ...
  << End Captured GinkgoWriter Output

  Volume Cloning not supported
  In [It] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:619
------------------------------
Controller Service [Controller Server] CreateVolume
  should fail when the volume source volume is not found
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:641
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:37.651
STEP: creating mount and staging directories 12/29/22 02:39:37.651
I1229 02:39:37.651709   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:37.651729   11009 utils.go:77] GRPC request: {}
I1229 02:39:37.651772   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
... skipping 3 lines ...
------------------------------
S [SKIPPED] [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  CreateVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:369
    [It] should fail when the volume source volume is not found
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:641

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:37.651
    STEP: creating mount and staging directories 12/29/22 02:39:37.651
  << End Captured GinkgoWriter Output

  Volume Cloning not supported
  In [It] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:643
------------------------------
Controller Service [Controller Server] DeleteVolume
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:671
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:37.653
STEP: creating mount and staging directories 12/29/22 02:39:37.653
I1229 02:39:37.654089   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:37.654111   11009 utils.go:77] GRPC request: {}
I1229 02:39:37.654164   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:37.654822   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:37.654881   11009 utils.go:77] GRPC request: {}
E1229 02:39:37.654957   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
------------------------------
• [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  DeleteVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:664
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:671

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:37.653
    STEP: creating mount and staging directories 12/29/22 02:39:37.653
  << End Captured GinkgoWriter Output
... skipping 5 lines ...
STEP: creating mount and staging directories 12/29/22 02:39:37.655
I1229 02:39:37.655836   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:37.655856   11009 utils.go:77] GRPC request: {}
I1229 02:39:37.655903   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:37.656459   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:37.656480   11009 utils.go:77] GRPC request: {"volume_id":"fake-vol-id"}
E1229 02:39:37.656564   11009 controllerserver.go:578] GetFileShareInfo(fake-vol-id) in DeleteVolume failed with error: error parsing volume id: "fake-vol-id", should at least contain two #
I1229 02:39:37.656588   11009 utils.go:83] GRPC response: {}
------------------------------
• [0.001 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  DeleteVolume
... skipping 43 lines ...
    STEP: creating mount and staging directories 12/29/22 02:39:37.657
    STEP: creating a volume 12/29/22 02:39:37.657
    STEP: deleting a volume 12/29/22 02:39:38.152
  << End Captured GinkgoWriter Output
------------------------------
Controller Service [Controller Server] ValidateVolumeCapabilities
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:734
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:38.48
STEP: creating mount and staging directories 12/29/22 02:39:38.48
I1229 02:39:38.481466   11009 utils.go:76] GRPC call: /csi.v1.Controller/ValidateVolumeCapabilities
I1229 02:39:38.481493   11009 utils.go:77] GRPC request: {}
E1229 02:39:38.481620   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID not provided
------------------------------
• [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ValidateVolumeCapabilities
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:733
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:734

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:38.48
    STEP: creating mount and staging directories 12/29/22 02:39:38.48
  << End Captured GinkgoWriter Output
------------------------------
Controller Service [Controller Server] ValidateVolumeCapabilities
  should fail when no volume capabilities are provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:748
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:38.482
STEP: creating mount and staging directories 12/29/22 02:39:38.482
STEP: creating a single node writer volume 12/29/22 02:39:38.483
I1229 02:39:38.484031   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I1229 02:39:38.484059   11009 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":10737418240},"name":"sanity-controller-validate-nocaps-BFAA4970-4F36EE66","volume_capabilities":[{"AccessType":{"Mount":{}},"access_mode":{"mode":1}}]}
I1229 02:39:38.659005   11009 controllerserver.go:457] begin to create file share(sanity-controller-validate-nocaps-bfaa4970-4f36ee66) on account(f7b785f85834b49478b6faa) type() subID() rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) location() size(10) protocol(SMB)
I1229 02:39:38.947964   11009 controllerserver.go:479] create file share sanity-controller-validate-nocaps-bfaa4970-4f36ee66 on storage account f7b785f85834b49478b6faa successfully
W1229 02:39:38.948009   11009 azurefile.go:952] could not create secret: kubeClient is nil
I1229 02:39:38.948049   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.289053224 request="azurefile_csi_driver_controller_create_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:38.948070   11009 utils.go:83] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"secretnamespace":"default"},"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default"}}
I1229 02:39:38.948696   11009 utils.go:76] GRPC call: /csi.v1.Controller/ValidateVolumeCapabilities
I1229 02:39:38.948714   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default"}
E1229 02:39:38.948787   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume capabilities not provided
I1229 02:39:38.949285   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1229 02:39:38.949305   11009 utils.go:77] GRPC request: {"target_path":"/tmp/csi-mount/target","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default"}
I1229 02:39:38.949387   11009 nodeserver.go:132] NodeUnpublishVolume: unmounting volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default on /tmp/csi-mount/target
I1229 02:39:38.949398   11009 azure_common_linux.go:38] force unmount on /tmp/csi-mount/target
W1229 02:39:38.949475   11009 mount_helper_common.go:47] Warning: mount cleanup skipped because path does not exist: /tmp/csi-mount/target
I1229 02:39:38.949485   11009 nodeserver.go:136] NodeUnpublishVolume: unmount volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default on /tmp/csi-mount/target successfully
I1229 02:39:38.949503   11009 utils.go:83] GRPC response: {}
I1229 02:39:38.950185   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:38.950211   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default"}
I1229 02:39:38.950281   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:38.950301   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:38.950326   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:38.950339   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:38.953156   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:38.953536   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:38.953559   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default"}
I1229 02:39:39.257211   11009 azure_storage.go:69] share sanity-controller-validate-nocaps-bfaa4970-4f36ee66 deleted
I1229 02:39:39.257255   11009 controllerserver.go:613] azure file(sanity-controller-validate-nocaps-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:39.257295   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.303622359 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:39.257312   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [0.775 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  ValidateVolumeCapabilities
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:733
    should fail when no volume capabilities are provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:748

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:38.482
    STEP: creating mount and staging directories 12/29/22 02:39:38.482
    STEP: creating a single node writer volume 12/29/22 02:39:38.483
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc00031d460>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-nocaps-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Controller Service [Controller Server] ValidateVolumeCapabilities
... skipping 23 lines ...
I1229 02:39:39.959005   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:39.959019   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-bfaa4970-4f36ee66###default"}
I1229 02:39:39.959066   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:39.959075   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:39.959093   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:39.959101   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:39.962133   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:39.962865   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:39.962885   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-bfaa4970-4f36ee66###default"}
I1229 02:39:40.261518   11009 azure_storage.go:69] share sanity-controller-validate-bfaa4970-4f36ee66 deleted
I1229 02:39:40.261566   11009 controllerserver.go:613] azure file(sanity-controller-validate-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:40.261608   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.298600539 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:40.261624   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [1.006 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  ValidateVolumeCapabilities
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:733
    should return appropriate values (no optional values added)
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:783
... skipping 2 lines ...
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:39.258
    STEP: creating mount and staging directories 12/29/22 02:39:39.258
    STEP: creating a single node writer volume 12/29/22 02:39:39.258
    STEP: validating volume capabilities 12/29/22 02:39:39.745
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc0005fa6e0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-validate-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Controller Service [Controller Server] ValidateVolumeCapabilities
  should fail when the requested volume does not exist
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:825
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.264
STEP: creating mount and staging directories 12/29/22 02:39:40.264
I1229 02:39:40.265176   11009 utils.go:76] GRPC call: /csi.v1.Controller/ValidateVolumeCapabilities
I1229 02:39:40.265203   11009 utils.go:77] GRPC request: {"volume_capabilities":[{"AccessType":{"Mount":{}},"access_mode":{"mode":1}}],"volume_id":"fake-vol-id-d15c63aa-b"}
W1229 02:39:40.265352   11009 azurefile.go:595] parsing volumeID(fake-vol-id-d15c63aa-b) return with error: error parsing volume id: "fake-vol-id-d15c63aa-b", should at least contain two #
E1229 02:39:40.265368   11009 utils.go:81] GRPC error: rpc error: code = NotFound desc = get account info from(fake-vol-id-d15c63aa-b) failed with error: <nil>
------------------------------
• [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ValidateVolumeCapabilities
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:733
    should fail when the requested volume does not exist
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:825

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.264
    STEP: creating mount and staging directories 12/29/22 02:39:40.264
  << End Captured GinkgoWriter Output
------------------------------
Controller Service [Controller Server] ControllerPublishVolume
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:852
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.265
STEP: creating mount and staging directories 12/29/22 02:39:40.265
I1229 02:39:40.266343   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:40.266356   11009 utils.go:77] GRPC request: {}
I1229 02:39:40.266400   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:40.267199   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1229 02:39:40.267217   11009 utils.go:77] GRPC request: {}
E1229 02:39:40.267308   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID not provided
------------------------------
• [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ControllerPublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:845
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:852

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.265
    STEP: creating mount and staging directories 12/29/22 02:39:40.265
  << End Captured GinkgoWriter Output
------------------------------
Controller Service [Controller Server] ControllerPublishVolume
  should fail when no node id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:867
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.267
STEP: creating mount and staging directories 12/29/22 02:39:40.267
I1229 02:39:40.268083   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:40.268109   11009 utils.go:77] GRPC request: {}
I1229 02:39:40.268169   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:40.268689   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1229 02:39:40.268704   11009 utils.go:77] GRPC request: {"volume_id":"fake-vol-id-c8805bca-e"}
E1229 02:39:40.268764   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume capability not provided
------------------------------
• [0.001 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ControllerPublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:845
    should fail when no node id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:867

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.267
    STEP: creating mount and staging directories 12/29/22 02:39:40.267
  << End Captured GinkgoWriter Output
------------------------------
Controller Service [Controller Server] ControllerPublishVolume
  should fail when no volume capability is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:883
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.269
STEP: creating mount and staging directories 12/29/22 02:39:40.269
I1229 02:39:40.269542   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:40.269558   11009 utils.go:77] GRPC request: {}
I1229 02:39:40.269589   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:40.269969   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1229 02:39:40.269984   11009 utils.go:77] GRPC request: {"node_id":"fake-node-id-bf31d3ea-4","volume_id":"fake-vol-id-fb3a9785-1"}
E1229 02:39:40.270047   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume capability not provided
------------------------------
• [0.001 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ControllerPublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:845
    should fail when no volume capability is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:883

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.269
    STEP: creating mount and staging directories 12/29/22 02:39:40.269
  << End Captured GinkgoWriter Output
------------------------------
Controller Service [Controller Server] ControllerPublishVolume
  should fail when publishing more volumes than the node max attach limit
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:900
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.27
STEP: creating mount and staging directories 12/29/22 02:39:40.27
I1229 02:39:40.270744   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:40.270759   11009 utils.go:77] GRPC request: {}
I1229 02:39:40.270869   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
------------------------------
S [SKIPPED] [0.001 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ControllerPublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:845
    [It] should fail when publishing more volumes than the node max attach limit
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:900

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.27
    STEP: creating mount and staging directories 12/29/22 02:39:40.27
  << End Captured GinkgoWriter Output

  testnodevolumeattachlimit not enabled
  In [It] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:902
------------------------------
SS
------------------------------
Controller Service [Controller Server] ControllerPublishVolume
  should fail when the volume is already published but is incompatible
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1001
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.271
STEP: creating mount and staging directories 12/29/22 02:39:40.271
I1229 02:39:40.272076   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:40.272088   11009 utils.go:77] GRPC request: {}
I1229 02:39:40.272128   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
... skipping 3 lines ...
------------------------------
S [SKIPPED] [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ControllerPublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:845
    [It] should fail when the volume is already published but is incompatible
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1001

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:40.271
    STEP: creating mount and staging directories 12/29/22 02:39:40.271
  << End Captured GinkgoWriter Output
... skipping 84 lines ...
I1229 02:39:40.801666   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:40.801686   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:40.801752   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:40.801761   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:40.801789   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:40.801807   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:40.804696   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:40.805151   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:40.805177   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:40.805257   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:40.805264   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:41.113106   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:41.113127   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:41.113201   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:41.113217   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:41.113265   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:41.113282   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:41.116067   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:41.116516   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:41.116532   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:41.116613   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:41.116627   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:41.372137   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:41.372166   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:41.372271   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:41.372303   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:41.372357   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:41.372379   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:41.375189   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:41.375806   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:41.375860   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:41.376003   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:41.376042   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:41.702391   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:41.702409   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:41.702530   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:41.702537   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:41.702556   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:41.702565   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:41.705345   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:41.706192   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:41.706265   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:41.706682   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:41.706737   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:42.015341   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:42.015365   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:42.015434   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:42.015442   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:42.015466   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:42.015485   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:42.018192   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:42.018664   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:42.018680   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:42.018752   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:42.018759   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:42.307935   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:42.307952   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:42.308002   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:42.308008   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:42.308031   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:42.308044   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:42.311480   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:42.312049   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:42.312124   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:42.312429   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:42.312453   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:42.574660   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:42.574681   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:42.574750   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:42.574766   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:42.574790   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:42.574808   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:42.577807   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:42.578220   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:42.578238   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:42.578324   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:42.578336   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:42.858730   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:42.858794   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:42.858862   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:42.858876   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:42.858897   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:42.858912   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:42.861728   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:42.862153   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:42.862215   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:42.862307   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:42.862319   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:43.091383   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:43.091401   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:43.091459   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:43.091465   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:43.091486   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:43.091494   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:43.094361   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:43.094835   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:43.094920   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:43.095052   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:43.095064   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:43.492033   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:43.492152   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:43.492253   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:43.492262   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:43.492287   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:43.492347   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:43.495141   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:43.495733   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:43.495749   11009 utils.go:77] GRPC request: {"node_id":"sanity-test-node","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:43.495862   11009 controllerserver.go:773] skip ControllerUnpublishVolume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) since it's not vhd disk detach
I1229 02:39:43.495886   11009 utils.go:83] GRPC response: {}
... skipping 13 lines ...
I1229 02:39:44.198828   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:44.198850   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:44.198913   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default on /tmp/csi-staging
I1229 02:39:44.198932   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:44.198953   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:44.198968   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:44.201883   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:44.202283   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:44.202299   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default"}
I1229 02:39:44.374281   11009 azure_storage.go:69] share sanity-controller-publish-bfaa4970-4f36ee66 deleted
I1229 02:39:44.374320   11009 controllerserver.go:613] azure file(sanity-controller-publish-bfaa4970-4f36ee66) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default) is deleted successfully
I1229 02:39:44.374362   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.171894635 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default" result_code="succeeded"
I1229 02:39:44.374380   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [4.101 seconds]
Controller Service [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:119
  volume lifecycle
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1056
    should be idempotent
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1067
... skipping 12 lines ...
    STEP: calling controllerpublish on that volume 12/29/22 02:39:40.798
    STEP: calling controllerpublish on that volume 12/29/22 02:39:40.798
    STEP: calling controllerpublish on that volume 12/29/22 02:39:40.799
    STEP: calling controllerpublish on that volume 12/29/22 02:39:40.799
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:11, cap:16>: [
          <*errors.errorString | 0xc000502640>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc000502c30>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc0005fb560>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc000502ec0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc000503230>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc000503570>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc00016b1f0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc00016b340>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc000503c40>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#sanity-controller-publish-bfaa4970-4f36ee66###default failed: rpc error: code = Internal desc = failed to unmount staging...

  Gomega truncated this representation as it exceeds 'format.MaxLength'.
  Consider having the object provide a custom 'GomegaStringer' representation
  or adjust the parameters in Gomega's 'format' package.

  Learn more here: https://onsi.github.io/gomega/#adjusting-output

  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Controller Service [Controller Server] ControllerUnpublishVolume
  should fail when no volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1079
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:44.375
STEP: creating mount and staging directories 12/29/22 02:39:44.375
I1229 02:39:44.376280   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:44.376308   11009 utils.go:77] GRPC request: {}
I1229 02:39:44.376369   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:44.376986   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1229 02:39:44.377002   11009 utils.go:77] GRPC request: {}
E1229 02:39:44.377066   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Volume ID not provided
------------------------------
• [0.002 seconds]
Controller Service [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  ControllerUnpublishVolume
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1072
    should fail when no volume id is provided
    /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1079

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:44.375
    STEP: creating mount and staging directories 12/29/22 02:39:44.375
  << End Captured GinkgoWriter Output
------------------------------
DeleteSnapshot [Controller Server]
  should fail when no snapshot id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1366
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:44.377
STEP: creating mount and staging directories 12/29/22 02:39:44.377
I1229 02:39:44.377867   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:44.377882   11009 utils.go:77] GRPC request: {}
I1229 02:39:44.377910   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:44.378412   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteSnapshot
I1229 02:39:44.378473   11009 utils.go:77] GRPC request: {}
E1229 02:39:44.378551   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Snapshot ID must be provided
------------------------------
• [0.001 seconds]
DeleteSnapshot [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  should fail when no snapshot id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1366

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:44.377
    STEP: creating mount and staging directories 12/29/22 02:39:44.377
  << End Captured GinkgoWriter Output
... skipping 5 lines ...
STEP: creating mount and staging directories 12/29/22 02:39:44.379
I1229 02:39:44.379770   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:44.379788   11009 utils.go:77] GRPC request: {}
I1229 02:39:44.379819   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:44.380199   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteSnapshot
I1229 02:39:44.380216   11009 utils.go:77] GRPC request: {"snapshot_id":"reallyfakesnapshotid"}
I1229 02:39:44.380277   11009 controllerserver.go:918] failed to get share url with (reallyfakesnapshotid): error parsing volume id: "reallyfakesnapshotid", should at least contain two #, returning with success
I1229 02:39:44.380283   11009 utils.go:83] GRPC response: {}
------------------------------
• [0.001 seconds]
DeleteSnapshot [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  should succeed when an invalid snapshot id is used
... skipping 42 lines ...
I1229 02:39:46.097622   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:46.097685   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#deletesnapshot-volume-1###default"}
I1229 02:39:46.097847   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#deletesnapshot-volume-1###default on /tmp/csi-staging
I1229 02:39:46.097863   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:46.097883   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:46.097891   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:46.100644   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:46.101094   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:46.101261   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#deletesnapshot-volume-1###default"}
I1229 02:39:46.417860   11009 azure_storage.go:69] share deletesnapshot-volume-1 deleted
I1229 02:39:46.417920   11009 controllerserver.go:613] azure file(deletesnapshot-volume-1) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#deletesnapshot-volume-1###default) is deleted successfully
I1229 02:39:46.417970   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.316449698 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#deletesnapshot-volume-1###default" result_code="succeeded"
I1229 02:39:46.417990   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [2.038 seconds]
DeleteSnapshot [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1362
  should return appropriate values (no optional values added)
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1389

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:44.38
    STEP: creating mount and staging directories 12/29/22 02:39:44.38
    STEP: creating a volume 12/29/22 02:39:44.382
    STEP: creating a snapshot 12/29/22 02:39:45.082
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc000206ba0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#deletesnapshot-volume-1###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
Identity Service GetPluginCapabilities
... skipping 224 lines ...
  << End Captured GinkgoWriter Output

  ListSnapshots not supported
  In [BeforeEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1107
------------------------------
CreateSnapshot [Controller Server]
  should fail when no name is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1422
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:46.433
STEP: creating mount and staging directories 12/29/22 02:39:46.433
I1229 02:39:46.433828   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:46.433895   11009 utils.go:77] GRPC request: {}
I1229 02:39:46.434042   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:46.434715   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateSnapshot
I1229 02:39:46.434733   11009 utils.go:77] GRPC request: {"source_volume_id":"testId"}
E1229 02:39:46.434800   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = Snapshot name must be provided
------------------------------
• [0.002 seconds]
CreateSnapshot [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  should fail when no name is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1422

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:46.433
    STEP: creating mount and staging directories 12/29/22 02:39:46.433
  << End Captured GinkgoWriter Output
------------------------------
CreateSnapshot [Controller Server]
  should fail when no source volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1439
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:46.437
STEP: creating mount and staging directories 12/29/22 02:39:46.438
I1229 02:39:46.438894   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:46.438975   11009 utils.go:77] GRPC request: {}
I1229 02:39:46.439116   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
I1229 02:39:46.439755   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateSnapshot
I1229 02:39:46.439813   11009 utils.go:77] GRPC request: {"name":"name"}
E1229 02:39:46.439943   11009 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateSnapshot Source Volume ID must be provided
------------------------------
• [0.005 seconds]
CreateSnapshot [Controller Server]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:45
  should fail when no source volume id is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1439

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:46.437
    STEP: creating mount and staging directories 12/29/22 02:39:46.438
  << End Captured GinkgoWriter Output
... skipping 49 lines ...
I1229 02:39:48.484796   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:48.484812   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-1###default"}
I1229 02:39:48.484852   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-1###default on /tmp/csi-staging
I1229 02:39:48.484861   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:48.484886   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:48.484897   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:48.487784   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:48.488413   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:48.488438   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-1###default"}
I1229 02:39:48.748699   11009 azure_storage.go:69] share createsnapshot-volume-1 deleted
I1229 02:39:48.748746   11009 controllerserver.go:613] azure file(createsnapshot-volume-1) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-1###default) is deleted successfully
I1229 02:39:48.748789   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.260243069 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-1###default" result_code="succeeded"
I1229 02:39:48.748804   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [2.309 seconds]
CreateSnapshot [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1418
  should succeed when requesting to create a snapshot with already existing name and same source volume ID
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1456

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:46.44
    STEP: creating mount and staging directories 12/29/22 02:39:46.44
    STEP: creating a volume 12/29/22 02:39:46.441
    STEP: creating a snapshot 12/29/22 02:39:46.981
    STEP: creating a snapshot with the same name and source volume ID 12/29/22 02:39:47.496
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc0005fae90>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-1###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
CreateSnapshot [Controller Server]
  should fail when requesting to create a snapshot with already existing name and different source volume ID
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1470
STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:48.749
STEP: creating mount and staging directories 12/29/22 02:39:48.75
I1229 02:39:48.750500   11009 utils.go:76] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1229 02:39:48.750567   11009 utils.go:77] GRPC request: {}
I1229 02:39:48.750702   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
... skipping 19 lines ...
I1229 02:39:50.137274   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.291861639 request="azurefile_csi_driver_controller_create_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default" result_code="succeeded"
I1229 02:39:50.137291   11009 utils.go:83] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"secretnamespace":"default"},"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default"}}
STEP: creating a snapshot with the same name but different source volume ID 12/29/22 02:39:50.137
I1229 02:39:50.138025   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateSnapshot
I1229 02:39:50.138045   11009 utils.go:77] GRPC request: {"name":"CreateSnapshot-snapshot-2","source_volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default"}
I1229 02:39:50.577915   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.439741997 request="azurefile_csi_driver_controller_create_snapshot" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" source_resource_id="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default" snapshot_name="CreateSnapshot-snapshot-2" result_code="failed_csi_driver_controller_create_snapshot"
E1229 02:39:50.577956   11009 utils.go:81] GRPC error: rpc error: code = AlreadyExists desc = snapshot(CreateSnapshot-snapshot-2) already exists, while the current file share name(createsnapshot-volume-2) does not equal to createsnapshot-volume-3, SourceVolumeId(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default)
I1229 02:39:50.578637   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1229 02:39:50.578658   11009 utils.go:77] GRPC request: {"target_path":"/tmp/csi-mount/target","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default"}
I1229 02:39:50.578719   11009 nodeserver.go:132] NodeUnpublishVolume: unmounting volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default on /tmp/csi-mount/target
I1229 02:39:50.578731   11009 azure_common_linux.go:38] force unmount on /tmp/csi-mount/target
W1229 02:39:50.578786   11009 mount_helper_common.go:47] Warning: mount cleanup skipped because path does not exist: /tmp/csi-mount/target
I1229 02:39:50.578791   11009 nodeserver.go:136] NodeUnpublishVolume: unmount volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default on /tmp/csi-mount/target successfully
I1229 02:39:50.578797   11009 utils.go:83] GRPC response: {}
I1229 02:39:50.579711   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:50.579776   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default"}
I1229 02:39:50.579849   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default on /tmp/csi-staging
I1229 02:39:50.579868   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:50.579892   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:50.579900   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:50.582635   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:50.583255   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:50.583303   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default"}
I1229 02:39:50.840913   11009 azure_storage.go:69] share createsnapshot-volume-3 deleted
I1229 02:39:50.841019   11009 controllerserver.go:613] azure file(createsnapshot-volume-3) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default) is deleted successfully
... skipping 15 lines ...
I1229 02:39:51.357110   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:39:51.357138   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-2###default"}
I1229 02:39:51.357212   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-2###default on /tmp/csi-staging
I1229 02:39:51.357221   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:39:51.357259   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:39:51.357277   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:39:51.360095   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:39:51.360523   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:39:51.360539   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-2###default"}
I1229 02:39:51.652886   11009 azure_storage.go:69] share createsnapshot-volume-2 deleted
I1229 02:39:51.652950   11009 controllerserver.go:613] azure file(createsnapshot-volume-2) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-2###default) is deleted successfully
I1229 02:39:51.652992   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.292356961 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-2###default" result_code="succeeded"
I1229 02:39:51.653014   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [2.904 seconds]
CreateSnapshot [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1418
  should fail when requesting to create a snapshot with already existing name and different source volume ID
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1470

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:48.749
    STEP: creating mount and staging directories 12/29/22 02:39:48.75
    STEP: creating a snapshot 12/29/22 02:39:48.751
    STEP: creating a new source volume 12/29/22 02:39:49.637
    STEP: creating a snapshot with the same name but different source volume ID 12/29/22 02:39:50.137
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:2, cap:2>: [
          <*errors.errorString | 0xc00016a7f0>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
          <*errors.errorString | 0xc00031dd00>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-2###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------
CreateSnapshot [Controller Server]
... skipping 5 lines ...
I1229 02:39:51.654542   11009 utils.go:77] GRPC request: {}
I1229 02:39:51.654597   11009 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":9}}},{"Type":{"Rpc":{"type":13}}}]}
STEP: creating a volume 12/29/22 02:39:51.654
I1229 02:39:51.655478   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I1229 02:39:51.655503   11009 utils.go:77] GRPC request: {"capacity_range":{"limit_bytes":10737418240,"required_bytes":10737418240},"name":"CreateSnapshot-volume-3","volume_capabilities":[{"AccessType":{"Mount":{}},"access_mode":{"mode":1}}]}
I1229 02:39:51.864863   11009 controllerserver.go:457] begin to create file share(createsnapshot-volume-3) on account(f7b785f85834b49478b6faa) type() subID() rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) location() size(10) protocol(SMB)
W1229 02:39:52.752145   11009 azurefile.go:770] CreateFileShare(createsnapshot-volume-3) on account(f7b785f85834b49478b6faa) failed with error(storage.FileSharesClient#Create: Failure sending request: StatusCode=409 -- Original Error: autorest/azure: Service returned an error. Status=<nil> Code="ShareBeingDeleted" Message="The specified share is being deleted. Try operation later.\nRequestId:ef3e86cb-101a-0035-3d2e-1bf8bf000000\nTime:2022-12-29T02:39:52.6847337Z"), waiting for retrying
W1229 02:40:01.752448   11009 azurefile.go:770] CreateFileShare(createsnapshot-volume-3) on account(f7b785f85834b49478b6faa) failed with error(storage.FileSharesClient#Create: Failure sending request: StatusCode=409 -- Original Error: autorest/azure: Service returned an error. Status=<nil> Code="ShareBeingDeleted" Message="The specified share is being deleted. Try operation later.\nRequestId:ef3e86e5-101a-0035-452e-1bf8bf000000\nTime:2022-12-29T02:40:01.6845853Z"), waiting for retrying
W1229 02:40:17.238860   11009 azurefile.go:770] CreateFileShare(createsnapshot-volume-3) on account(f7b785f85834b49478b6faa) failed with error(storage.FileSharesClient#Create: Failure sending request: StatusCode=409 -- Original Error: autorest/azure: Service returned an error. Status=<nil> Code="ShareBeingDeleted" Message="The specified share is being deleted. Try operation later.\nRequestId:ef3e8702-101a-0035-512e-1bf8bf000000\nTime:2022-12-29T02:40:17.1577338Z"), waiting for retrying
I1229 02:40:36.154393   11009 controllerserver.go:479] create file share createsnapshot-volume-3 on storage account f7b785f85834b49478b6faa successfully
W1229 02:40:36.154528   11009 azurefile.go:952] could not create secret: kubeClient is nil
I1229 02:40:36.154587   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=44.289727968 request="azurefile_csi_driver_controller_create_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default" result_code="succeeded"
I1229 02:40:36.154627   11009 utils.go:83] GRPC response: {"volume":{"capacity_bytes":10737418240,"volume_context":{"secretnamespace":"default"},"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default"}}
STEP: creating a snapshot 12/29/22 02:40:36.155
I1229 02:40:36.155642   11009 utils.go:76] GRPC call: /csi.v1.Controller/CreateSnapshot
... skipping 29 lines ...
I1229 02:40:37.662920   11009 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1229 02:40:37.662945   11009 utils.go:77] GRPC request: {"staging_target_path":"/tmp/csi-staging","volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default"}
I1229 02:40:37.663020   11009 nodeserver.go:387] NodeUnstageVolume: CleanupMountPoint volume azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default on /tmp/csi-staging
I1229 02:40:37.663028   11009 azure_common_linux.go:38] force unmount on /tmp/csi-staging
I1229 02:40:37.663052   11009 mount_helper_common.go:56] unmounting "/tmp/csi-staging" (corruptedMount: false, mounterCanSkipMountPointChecks: true)
I1229 02:40:37.663063   11009 mount_linux.go:779] Unmounting /tmp/csi-staging
E1229 02:40:37.666397   11009 utils.go:81] GRPC error: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32
Unmounting arguments: /tmp/csi-staging
Output: umount: /tmp/csi-staging: not mounted.
I1229 02:40:37.666925   11009 utils.go:76] GRPC call: /csi.v1.Controller/DeleteVolume
I1229 02:40:37.666954   11009 utils.go:77] GRPC request: {"volume_id":"azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default"}
I1229 02:40:37.985131   11009 azure_storage.go:69] share createsnapshot-volume-3 deleted
I1229 02:40:37.985252   11009 controllerserver.go:613] azure file(createsnapshot-volume-3) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc) account(f7b785f85834b49478b6faa) volume(azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default) is deleted successfully
I1229 02:40:37.985322   11009 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.318124692 request="azurefile_csi_driver_controller_delete_volume" resource_group="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="file.csi.azure.com" volumeid="azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default" result_code="succeeded"
I1229 02:40:37.985340   11009 utils.go:83] GRPC response: {}
------------------------------
• [FAILED] [46.332 seconds]
CreateSnapshot [Controller Server] [AfterEach]
/home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1418
  should succeed when creating snapshot with maximum-length name
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1489

  Begin Captured GinkgoWriter Output >>
    STEP: reusing connection to CSI driver at unix:///tmp/csi.sock 12/29/22 02:39:51.653
    STEP: creating mount and staging directories 12/29/22 02:39:51.654
    STEP: creating a volume 12/29/22 02:39:51.654
    STEP: creating a snapshot 12/29/22 02:40:36.155
  << End Captured GinkgoWriter Output

  resource cleanup failed
  Expected
      <[]error | len:1, cap:1>: [
          <*errors.errorString | 0xc00016b090>{
              s: "NodeUnstageVolume for volume ID azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc#f7b785f85834b49478b6faa#createsnapshot-volume-3###default failed: rpc error: code = Internal desc = failed to unmount staging target /tmp/csi-staging: unmount failed: exit status 32\nUnmounting arguments: /tmp/csi-staging\nOutput: umount: /tmp/csi-staging: not mounted.\n",
          },
      ]
  to be empty
  In [AfterEach] at: /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
------------------------------


Summarizing 14 Failures:
  [FAIL] Node Service [AfterEach] NodeStageVolume should fail when no volume capability is provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] CreateVolume should return appropriate values SingleNodeWriter NoCapacity
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] CreateVolume should return appropriate values SingleNodeWriter WithCapacity 1Gi
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] CreateVolume should not fail when requesting to create a volume with already existing name and same capacity
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] CreateVolume should fail when requesting to create a volume with already existing name and different capacity
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] CreateVolume should not fail when creating volume with maximum-length name
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] CreateVolume should create volume from an existing source snapshot
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] ValidateVolumeCapabilities should fail when no volume capabilities are provided
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] ValidateVolumeCapabilities should return appropriate values (no optional values added)
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] Controller Service [Controller Server] [AfterEach] volume lifecycle should be idempotent
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] DeleteSnapshot [Controller Server] [AfterEach] should return appropriate values (no optional values added)
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] CreateSnapshot [Controller Server] [AfterEach] should succeed when requesting to create a snapshot with already existing name and same source volume ID
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] CreateSnapshot [Controller Server] [AfterEach] should fail when requesting to create a snapshot with already existing name and different source volume ID
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596
  [FAIL] CreateSnapshot [Controller Server] [AfterEach] should succeed when creating snapshot with maximum-length name
  /home/prow/go/src/github.com/kubernetes-csi/csi-test/vendor/github.com/onsi/ginkgo/v2/internal/suite.go:596

Ran 50 of 78 Specs in 96.959 seconds
FAIL! -- 36 Passed | 14 Failed | 1 Pending | 27 Skipped
[38;5;228mYou're using deprecated Ginkgo functionality:[0m
[38;5;228m=============================================[0m
  [38;5;11m--ginkgo.noColor is deprecated, use --ginkgo.no-color instead[0m
  [1mLearn more at:[0m [38;5;14m[4mhttps://onsi.github.io/ginkgo/MIGRATING_TO_V2#changed-command-line-flags[0m

[38;5;243mTo silence deprecations that can be silenced set the following environment variable:[0m
  [38;5;243mACK_GINKGO_DEPRECATIONS=2.1.4[0m

pkill -f azurefileplugin
Deleting CSI sanity test binary
    sanity_test.go:88: Sanity test failed exit status 1
2022/12/29 02:40:37 Deleting resource group azurefile-csi-driver-test-c7b3de7f-8721-11ed-ae83-12be54e47fdc
--- FAIL: TestSanity (171.94s)
FAIL
FAIL	sigs.k8s.io/azurefile-csi-driver/test/sanity	171.949s
FAIL
make: *** [Makefile:77: sanity-test] Error 1
+ EXIT_VALUE=2
+ set +o xtrace
PR	andyzhangx: fix: use force unmount to fix unmount NFS volume stuck issue
Result	FAILURE
Tests	0 failed / 0 succeeded
Started	2022-12-29 02:35
Elapsed	4m53s
Revision	831e68d5a6f655abb9f4b4ad3ef77026bda3e8bb
Refs	1146
kubernetes-sigs/azurefile-csi-driver PR #1146 pull-azurefile-csi-driver-sanity #1608290585578311680

No Test Failures!

Error lines from build-log.txt
