This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: test: run k8s 1.24 external e2e test
ResultFAILURE
Tests 1 failed / 13 succeeded
Started2022-05-07 07:24
Elapsed32m8s
Revision70d38bbb09178d7d3c95bed995df44431b6b3e6c
Refs 1014
job-versionv1.25.0-alpha.0.340+9d0bb09fae6a6a
kubetest-version
revisionv1.25.0-alpha.0.340+9d0bb09fae6a6a

Test Failures


kubetest Test 19m57s

error during make e2e-test: exit status 2
				from junit_runner.xml

Filter through log files | View test history on testgrid


Show 13 Passed Tests

Error lines from build-log.txt

... skipping 221 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11156  100 11156    0     0   213k      0 --:--:-- --:--:-- --:--:--  213k
Downloading https://get.helm.sh/helm-v3.8.2-linux-amd64.tar.gz
Verifying checksum... Done.
Preparing to install helm into /usr/local/bin
helm installed into /usr/local/bin/helm
docker pull k8sprow.azurecr.io/azurefile-csi:e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 || make container-all push-manifest
Error response from daemon: manifest for k8sprow.azurecr.io/azurefile-csi:e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 not found: manifest unknown: manifest tagged by "e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6" is not found
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver'
CGO_ENABLED=0 GOOS=windows go build -a -ldflags "-X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.driverVersion=e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.gitCommit=3273d65a31e38c7a128a9fa367eba2609e4079b6 -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.buildDate=2022-05-07T07:28:29Z -s -w -extldflags '-static'" -mod vendor -o _output/amd64/azurefileplugin.exe ./pkg/azurefileplugin
docker buildx rm container-builder || true
error: no builder "container-builder" found
docker buildx create --use --name=container-builder
container-builder
# enable qemu for arm64 build
# https://github.com/docker/buildx/issues/464#issuecomment-741507760
docker run --privileged --rm tonistiigi/binfmt --uninstall qemu-aarch64
Unable to find image 'tonistiigi/binfmt:latest' locally
... skipping 1791 lines ...
                    type: string
                type: object
                oneOf:
                - required: ["persistentVolumeClaimName"]
                - required: ["volumeSnapshotContentName"]
              volumeSnapshotClassName:
                description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.'
                type: string
            required:
            - source
            type: object
          status:
            description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.
... skipping 2 lines ...
                description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.'
                type: string
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown.
                format: date-time
                type: string
              error:
                description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                type: string
                description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$
                x-kubernetes-int-or-string: true
            type: object
        required:
        - spec
        type: object
... skipping 60 lines ...
                    type: string
                  volumeSnapshotContentName:
                    description: volumeSnapshotContentName specifies the name of a pre-existing VolumeSnapshotContent object representing an existing volume snapshot. This field should be set if the snapshot already exists and only needs a representation in Kubernetes. This field is immutable.
                    type: string
                type: object
              volumeSnapshotClassName:
                description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.'
                type: string
            required:
            - source
            type: object
          status:
            description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.
... skipping 2 lines ...
                description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.'
                type: string
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown.
                format: date-time
                type: string
              error:
                description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                type: string
                description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$
                x-kubernetes-int-or-string: true
            type: object
        required:
        - spec
        type: object
... skipping 254 lines ...
            description: status represents the current information of a snapshot.
            properties:
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC.
                format: int64
                type: integer
              error:
                description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                format: int64
                minimum: 0
                type: integer
              snapshotHandle:
                description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress.
                type: string
            type: object
        required:
        - spec
        type: object
    served: true
... skipping 108 lines ...
            description: status represents the current information of a snapshot.
            properties:
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC.
                format: int64
                type: integer
              error:
                description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                format: int64
                minimum: 0
                type: integer
              snapshotHandle:
                description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress.
                type: string
            type: object
        required:
        - spec
        type: object
    served: true
... skipping 938 lines ...
          image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.4.0"
          args:
            - "-csi-address=$(ADDRESS)"
            - "-v=2"
            - "-leader-election"
            - "--leader-election-namespace=kube-system"
            - '-handle-volume-inuse-error=false'
            - '-timeout=120s'
            - '-feature-gates=RecoverVolumeExpansionFailure=true'
          env:
            - name: ADDRESS
              value: /csi/csi.sock
          imagePullPolicy: IfNotPresent
... skipping 308 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:258

    Driver test.csi.azure.com doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 549 lines ...

    test/e2e/storage/testsuites/provisioning.go:111
------------------------------
SSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:269

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
... skipping 2 lines ...
STEP: Building a namespace api object, basename provisioning
W0507 07:38:11.923510   35577 warnings.go:70] policy/v1beta1 PodSecurityPolicy is deprecated in v1.21+, unavailable in v1.25+
May  7 07:38:11.923: INFO: Found PodSecurityPolicies; testing pod creation to see if PodSecurityPolicy is enabled
May  7 07:38:11.960: INFO: No PSP annotation exists on dry run pod; assuming PodSecurityPolicy is disabled
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:269
May  7 07:38:12.089: INFO: Creating resource for dynamic PV
May  7 07:38:12.089: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-6812-e2e-scds4qq
STEP: creating a claim
May  7 07:38:12.126: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
... skipping 7 lines ...
May  7 07:38:24.406: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found but phase is Pending instead of Bound.
May  7 07:38:26.441: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found but phase is Pending instead of Bound.
May  7 07:38:28.474: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found but phase is Pending instead of Bound.
May  7 07:38:30.508: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found but phase is Pending instead of Bound.
May  7 07:38:32.542: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found and phase=Bound (20.378175722s)
STEP: Creating pod pod-subpath-test-dynamicpv-dkq2
STEP: Checking for subpath error in container status
May  7 07:38:40.720: INFO: Deleting pod "pod-subpath-test-dynamicpv-dkq2" in namespace "provisioning-6812"
May  7 07:38:40.755: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-dkq2" to be fully deleted
STEP: Deleting pod
May  7 07:38:42.821: INFO: Deleting pod "pod-subpath-test-dynamicpv-dkq2" in namespace "provisioning-6812"
STEP: Deleting pvc
May  7 07:38:42.854: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comzdckn"
... skipping 9 lines ...

• [SLOW TEST:36.334 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:269
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]","total":35,"completed":1,"skipped":40,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:38:48.149: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 24 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (immediate binding)] topology
  test/e2e/storage/framework/testsuite.go:50
    should fail to schedule a pod which has topologies that conflict with AllowedTopologies [BeforeEach]
    test/e2e/storage/testsuites/topology.go:194

    Driver "test.csi.azure.com" does not support topology - skipping

    test/e2e/storage/testsuites/topology.go:93
------------------------------
... skipping 5 lines ...
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May  7 07:38:48.214: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
May  7 07:38:48.447: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
[AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:188
May  7 07:38:48.448: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-5219" for this suite.


S [SKIPPING] [0.301 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [Measurement]
    test/e2e/storage/testsuites/volumemode.go:299

    Driver "test.csi.azure.com" does not provide raw block - skipping

    test/e2e/storage/testsuites/volumes.go:114
------------------------------
... skipping 18 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (block volmode)] volumeMode 
  should fail in binding dynamic provisioned PV to PVC [Slow][LinuxOnly]
  test/e2e/storage/testsuites/volumemode.go:260

[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May  7 07:38:48.564: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail in binding dynamic provisioned PV to PVC [Slow][LinuxOnly]
  test/e2e/storage/testsuites/volumemode.go:260
STEP: Creating sc
STEP: Creating pv and pvc
STEP: Deleting pvc
May  7 07:38:48.978: INFO: Deleting PersistentVolumeClaim "pvc-zdhsx"
STEP: Deleting sc
[AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:188
May  7 07:38:49.047: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-7633" for this suite.

•
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (block volmode)] volumeMode should fail in binding dynamic provisioned PV to PVC [Slow][LinuxOnly]","total":35,"completed":2,"skipped":209,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:38:49.225: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 130 lines ...
May  7 07:38:27.288: INFO: PersistentVolumeClaim test.csi.azure.com7zmwh found but phase is Pending instead of Bound.
May  7 07:38:29.323: INFO: PersistentVolumeClaim test.csi.azure.com7zmwh found but phase is Pending instead of Bound.
May  7 07:38:31.359: INFO: PersistentVolumeClaim test.csi.azure.com7zmwh found but phase is Pending instead of Bound.
May  7 07:38:33.394: INFO: PersistentVolumeClaim test.csi.azure.com7zmwh found and phase=Bound (20.386133363s)
STEP: Creating pod pod-subpath-test-dynamicpv-89ss
STEP: Creating a pod to test multi_subpath
May  7 07:38:33.496: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-89ss" in namespace "provisioning-4020" to be "Succeeded or Failed"
May  7 07:38:33.532: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 35.370591ms
May  7 07:38:35.566: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069932271s
May  7 07:38:37.601: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 4.104848032s
May  7 07:38:39.637: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 6.140143543s
May  7 07:38:41.672: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 8.175979558s
May  7 07:38:43.707: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.210125353s
STEP: Saw pod success
May  7 07:38:43.707: INFO: Pod "pod-subpath-test-dynamicpv-89ss" satisfied condition "Succeeded or Failed"
May  7 07:38:43.741: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000001 pod pod-subpath-test-dynamicpv-89ss container test-container-subpath-dynamicpv-89ss: <nil>
STEP: delete the pod
May  7 07:38:44.334: INFO: Waiting for pod pod-subpath-test-dynamicpv-89ss to disappear
May  7 07:38:44.368: INFO: Pod pod-subpath-test-dynamicpv-89ss no longer exists
STEP: Deleting pod
May  7 07:38:44.368: INFO: Deleting pod "pod-subpath-test-dynamicpv-89ss" in namespace "provisioning-4020"
... skipping 14 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support creating multiple subpath from same volumes [Slow]
    test/e2e/storage/testsuites/subpath.go:296
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support creating multiple subpath from same volumes [Slow]","total":37,"completed":1,"skipped":120,"failed":0}

SSSSSSS
------------------------------
[BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
  test/e2e/storage/framework/testsuite.go:51
May  7 07:38:49.656: INFO: Driver "test.csi.azure.com" does not support volume type "CSIInlineVolume" - skipping
... skipping 184 lines ...
May  7 07:38:24.418: INFO: PersistentVolumeClaim test.csi.azure.comss72b found but phase is Pending instead of Bound.
May  7 07:38:26.452: INFO: PersistentVolumeClaim test.csi.azure.comss72b found but phase is Pending instead of Bound.
May  7 07:38:28.486: INFO: PersistentVolumeClaim test.csi.azure.comss72b found but phase is Pending instead of Bound.
May  7 07:38:30.521: INFO: PersistentVolumeClaim test.csi.azure.comss72b found but phase is Pending instead of Bound.
May  7 07:38:32.555: INFO: PersistentVolumeClaim test.csi.azure.comss72b found and phase=Bound (20.386073035s)
STEP: Creating pod to format volume volume-prep-provisioning-9552
May  7 07:38:32.673: INFO: Waiting up to 5m0s for pod "volume-prep-provisioning-9552" in namespace "provisioning-9552" to be "Succeeded or Failed"
May  7 07:38:32.720: INFO: Pod "volume-prep-provisioning-9552": Phase="Pending", Reason="", readiness=false. Elapsed: 46.163857ms
May  7 07:38:34.755: INFO: Pod "volume-prep-provisioning-9552": Phase="Pending", Reason="", readiness=false. Elapsed: 2.081283032s
May  7 07:38:36.789: INFO: Pod "volume-prep-provisioning-9552": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.115485431s
STEP: Saw pod success
May  7 07:38:36.789: INFO: Pod "volume-prep-provisioning-9552" satisfied condition "Succeeded or Failed"
May  7 07:38:36.789: INFO: Deleting pod "volume-prep-provisioning-9552" in namespace "provisioning-9552"
May  7 07:38:36.828: INFO: Wait up to 5m0s for pod "volume-prep-provisioning-9552" to be fully deleted
STEP: Creating pod pod-subpath-test-dynamicpv-5hcf
STEP: Checking for subpath error in container status
May  7 07:38:44.966: INFO: Deleting pod "pod-subpath-test-dynamicpv-5hcf" in namespace "provisioning-9552"
May  7 07:38:45.007: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-5hcf" to be fully deleted
STEP: Deleting pod
May  7 07:38:45.040: INFO: Deleting pod "pod-subpath-test-dynamicpv-5hcf" in namespace "provisioning-9552"
STEP: Deleting pvc
May  7 07:38:45.074: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comss72b"
... skipping 12 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should verify container cannot write to subpath readonly volumes [Slow]
    test/e2e/storage/testsuites/subpath.go:425
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should verify container cannot write to subpath readonly volumes [Slow]","total":36,"completed":1,"skipped":39,"failed":0}

S
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:38:50.316: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 59 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
May  7 07:38:50.068: INFO: Creating resource for dynamic PV
May  7 07:38:50.068: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-1997-e2e-scv8ts7
STEP: [init] starting a pod to use the claim
May  7 07:38:50.140: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-d9bhj" in namespace "snapshotting-1997" to be "Succeeded or Failed"
May  7 07:38:50.176: INFO: Pod "pvc-snapshottable-tester-d9bhj": Phase="Pending", Reason="", readiness=false. Elapsed: 35.588744ms
May  7 07:38:52.210: INFO: Pod "pvc-snapshottable-tester-d9bhj": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069858016s
May  7 07:38:54.244: INFO: Pod "pvc-snapshottable-tester-d9bhj": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.104308051s
STEP: Saw pod success
May  7 07:38:54.244: INFO: Pod "pvc-snapshottable-tester-d9bhj" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
May  7 07:38:54.279: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
May  7 07:38:54.280: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-d9bhj-my-volume] to have phase Bound
May  7 07:38:54.314: INFO: PersistentVolumeClaim pvc-snapshottable-tester-d9bhj-my-volume found and phase=Bound (33.602367ms)
STEP: [init] checking the PV
... skipping 57 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:280

    Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 8 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:258

    Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 164 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":34,"completed":1,"skipped":129,"failed":0}

SSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:38:58.711: INFO: Driver test.csi.azure.com doesn't support ext4 -- skipping
... skipping 117 lines ...
May  7 07:38:50.012: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:38:50.049: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comnmnbt] to have phase Bound
May  7 07:38:50.082: INFO: PersistentVolumeClaim test.csi.azure.comnmnbt found but phase is Pending instead of Bound.
May  7 07:38:52.123: INFO: PersistentVolumeClaim test.csi.azure.comnmnbt found and phase=Bound (2.073542902s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
May  7 07:38:52.256: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-2sqpb" in namespace "snapshotting-6746" to be "Succeeded or Failed"
May  7 07:38:52.289: INFO: Pod "pvc-snapshottable-tester-2sqpb": Phase="Pending", Reason="", readiness=false. Elapsed: 33.093749ms
May  7 07:38:54.326: INFO: Pod "pvc-snapshottable-tester-2sqpb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.069341535s
STEP: Saw pod success
May  7 07:38:54.326: INFO: Pod "pvc-snapshottable-tester-2sqpb" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
May  7 07:38:54.360: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comnmnbt] to have phase Bound
May  7 07:38:54.394: INFO: PersistentVolumeClaim test.csi.azure.comnmnbt found and phase=Bound (34.328672ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
May  7 07:38:54.494: INFO: Pod pvc-snapshottable-tester-2sqpb has the following logs: 
... skipping 46 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach]
    test/e2e/storage/testsuites/volumemode.go:299

    Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 113 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:280

    Driver test.csi.azure.com doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 166 lines ...
May  7 07:38:50.924: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:38:50.960: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.combr7pq] to have phase Bound
May  7 07:38:50.993: INFO: PersistentVolumeClaim test.csi.azure.combr7pq found but phase is Pending instead of Bound.
May  7 07:38:53.027: INFO: PersistentVolumeClaim test.csi.azure.combr7pq found and phase=Bound (2.067639333s)
STEP: Creating pod pod-subpath-test-dynamicpv-8zbk
STEP: Creating a pod to test subpath
May  7 07:38:53.149: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-8zbk" in namespace "provisioning-7863" to be "Succeeded or Failed"
May  7 07:38:53.193: INFO: Pod "pod-subpath-test-dynamicpv-8zbk": Phase="Pending", Reason="", readiness=false. Elapsed: 43.576716ms
May  7 07:38:55.227: INFO: Pod "pod-subpath-test-dynamicpv-8zbk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.077677737s
May  7 07:38:57.262: INFO: Pod "pod-subpath-test-dynamicpv-8zbk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.112455084s
May  7 07:38:59.297: INFO: Pod "pod-subpath-test-dynamicpv-8zbk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.147322883s
STEP: Saw pod success
May  7 07:38:59.297: INFO: Pod "pod-subpath-test-dynamicpv-8zbk" satisfied condition "Succeeded or Failed"
May  7 07:38:59.331: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000001 pod pod-subpath-test-dynamicpv-8zbk container test-container-volume-dynamicpv-8zbk: <nil>
STEP: delete the pod
May  7 07:38:59.407: INFO: Waiting for pod pod-subpath-test-dynamicpv-8zbk to disappear
May  7 07:38:59.441: INFO: Pod pod-subpath-test-dynamicpv-8zbk no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-8zbk
May  7 07:38:59.441: INFO: Deleting pod "pod-subpath-test-dynamicpv-8zbk" in namespace "provisioning-7863"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support existing directory
    test/e2e/storage/testsuites/subpath.go:207
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support existing directory","total":36,"completed":2,"skipped":80,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:04.883: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 46 lines ...
May  7 07:38:27.348: INFO: PersistentVolumeClaim test.csi.azure.comj96cs found but phase is Pending instead of Bound.
May  7 07:38:29.383: INFO: PersistentVolumeClaim test.csi.azure.comj96cs found but phase is Pending instead of Bound.
May  7 07:38:31.418: INFO: PersistentVolumeClaim test.csi.azure.comj96cs found but phase is Pending instead of Bound.
May  7 07:38:33.456: INFO: PersistentVolumeClaim test.csi.azure.comj96cs found and phase=Bound (20.385414647s)
STEP: Expanding non-expandable pvc
May  7 07:38:33.532: INFO: currentPvcSize {{5368709120 0} {<nil>} 5Gi BinarySI}, newSize {{6442450944 0} {<nil>}  BinarySI}
May  7 07:38:33.608: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:35.678: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:37.687: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:39.677: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:41.676: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:43.681: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:45.677: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:47.680: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:49.677: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:51.678: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:53.691: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:55.696: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:57.677: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:38:59.676: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:39:01.676: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:39:03.678: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May  7 07:39:03.748: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
May  7 07:39:03.748: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comj96cs"
May  7 07:39:03.786: INFO: Waiting up to 5m0s for PersistentVolume pvc-29acbe9b-7792-4270-923f-a81c9dd177d6 to get deleted
May  7 07:39:03.819: INFO: PersistentVolume pvc-29acbe9b-7792-4270-923f-a81c9dd177d6 found and phase=Released (33.02326ms)
May  7 07:39:08.855: INFO: PersistentVolume pvc-29acbe9b-7792-4270-923f-a81c9dd177d6 was removed
STEP: Deleting sc
... skipping 8 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    should not allow expansion of pvcs without AllowVolumeExpansion property
    test/e2e/storage/testsuites/volume_expand.go:159
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volume-expand should not allow expansion of pvcs without AllowVolumeExpansion property","total":35,"completed":1,"skipped":488,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:09.080: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 3 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:242

    Driver test.csi.azure.com doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 90 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should be able to unmount after the subpath directory is deleted [LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:447
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should be able to unmount after the subpath directory is deleted [LinuxOnly]","total":37,"completed":2,"skipped":506,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:09.439: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 33 lines ...
May  7 07:39:00.367: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:39:00.403: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comgmv9b] to have phase Bound
May  7 07:39:00.436: INFO: PersistentVolumeClaim test.csi.azure.comgmv9b found but phase is Pending instead of Bound.
May  7 07:39:02.471: INFO: PersistentVolumeClaim test.csi.azure.comgmv9b found and phase=Bound (2.068304755s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
May  7 07:39:02.604: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-glh2w" in namespace "snapshotting-7449" to be "Succeeded or Failed"
May  7 07:39:02.637: INFO: Pod "pvc-snapshottable-tester-glh2w": Phase="Pending", Reason="", readiness=false. Elapsed: 33.374968ms
May  7 07:39:04.672: INFO: Pod "pvc-snapshottable-tester-glh2w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.068570986s
May  7 07:39:06.707: INFO: Pod "pvc-snapshottable-tester-glh2w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.103203426s
STEP: Saw pod success
May  7 07:39:06.707: INFO: Pod "pvc-snapshottable-tester-glh2w" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
May  7 07:39:06.740: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comgmv9b] to have phase Bound
May  7 07:39:06.773: INFO: PersistentVolumeClaim test.csi.azure.comgmv9b found and phase=Bound (32.83332ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
May  7 07:39:06.877: INFO: Pod pvc-snapshottable-tester-glh2w has the following logs: 
... skipping 195 lines ...
May  7 07:38:59.126: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:38:59.163: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com4nf84] to have phase Bound
May  7 07:38:59.196: INFO: PersistentVolumeClaim test.csi.azure.com4nf84 found but phase is Pending instead of Bound.
May  7 07:39:01.231: INFO: PersistentVolumeClaim test.csi.azure.com4nf84 found and phase=Bound (2.068024282s)
STEP: Creating pod pod-subpath-test-dynamicpv-thbb
STEP: Creating a pod to test subpath
May  7 07:39:01.339: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-thbb" in namespace "provisioning-2916" to be "Succeeded or Failed"
May  7 07:39:01.372: INFO: Pod "pod-subpath-test-dynamicpv-thbb": Phase="Pending", Reason="", readiness=false. Elapsed: 33.112297ms
May  7 07:39:03.406: INFO: Pod "pod-subpath-test-dynamicpv-thbb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.066517434s
May  7 07:39:05.441: INFO: Pod "pod-subpath-test-dynamicpv-thbb": Phase="Running", Reason="", readiness=false. Elapsed: 4.102358446s
May  7 07:39:07.479: INFO: Pod "pod-subpath-test-dynamicpv-thbb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.139970455s
STEP: Saw pod success
May  7 07:39:07.479: INFO: Pod "pod-subpath-test-dynamicpv-thbb" satisfied condition "Succeeded or Failed"
May  7 07:39:07.512: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000001 pod pod-subpath-test-dynamicpv-thbb container test-container-volume-dynamicpv-thbb: <nil>
STEP: delete the pod
May  7 07:39:07.588: INFO: Waiting for pod pod-subpath-test-dynamicpv-thbb to disappear
May  7 07:39:07.621: INFO: Pod pod-subpath-test-dynamicpv-thbb no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-thbb
May  7 07:39:07.621: INFO: Deleting pod "pod-subpath-test-dynamicpv-thbb" in namespace "provisioning-2916"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support non-existent path
    test/e2e/storage/testsuites/subpath.go:196
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support non-existent path","total":34,"completed":2,"skipped":281,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:12.961: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 64 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    should resize volume when PVC is edited while pod is using it
    test/e2e/storage/testsuites/volume_expand.go:248
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand should resize volume when PVC is edited while pod is using it","total":35,"completed":2,"skipped":617,"failed":0}

SSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:23.297: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 27 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
May  7 07:39:23.601: INFO: Creating resource for dynamic PV
May  7 07:39:23.601: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-2961-e2e-sclx5jg
STEP: [init] starting a pod to use the claim
May  7 07:39:23.677: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-tnbvq" in namespace "snapshotting-2961" to be "Succeeded or Failed"
May  7 07:39:23.721: INFO: Pod "pvc-snapshottable-tester-tnbvq": Phase="Pending", Reason="", readiness=false. Elapsed: 44.441674ms
May  7 07:39:25.756: INFO: Pod "pvc-snapshottable-tester-tnbvq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.078885086s
May  7 07:39:27.791: INFO: Pod "pvc-snapshottable-tester-tnbvq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.114457982s
May  7 07:39:29.826: INFO: Pod "pvc-snapshottable-tester-tnbvq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.1492193s
STEP: Saw pod success
May  7 07:39:29.826: INFO: Pod "pvc-snapshottable-tester-tnbvq" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
May  7 07:39:29.860: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
May  7 07:39:29.861: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-tnbvq-my-volume] to have phase Bound
May  7 07:39:29.896: INFO: PersistentVolumeClaim pvc-snapshottable-tester-tnbvq-my-volume found and phase=Bound (34.448066ms)
STEP: [init] checking the PV
... skipping 211 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with the same volume mode and retain data across pod recreation on different node
    test/e2e/storage/testsuites/multivolume.go:168
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should access to two volumes with the same volume mode and retain data across pod recreation on different node","total":37,"completed":3,"skipped":663,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] provisioning
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:42.985: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 257 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath file is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:258

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May  7 07:39:30.215: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath file is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:258
May  7 07:39:30.460: INFO: Creating resource for dynamic PV
May  7 07:39:30.460: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-2077-e2e-scjtbxr
STEP: creating a claim
May  7 07:39:30.494: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:39:30.531: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comj9stp] to have phase Bound
May  7 07:39:30.565: INFO: PersistentVolumeClaim test.csi.azure.comj9stp found but phase is Pending instead of Bound.
May  7 07:39:32.599: INFO: PersistentVolumeClaim test.csi.azure.comj9stp found and phase=Bound (2.06792975s)
STEP: Creating pod pod-subpath-test-dynamicpv-j4kc
STEP: Checking for subpath error in container status
May  7 07:39:36.770: INFO: Deleting pod "pod-subpath-test-dynamicpv-j4kc" in namespace "provisioning-2077"
May  7 07:39:36.805: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-j4kc" to be fully deleted
STEP: Deleting pod
May  7 07:39:38.873: INFO: Deleting pod "pod-subpath-test-dynamicpv-j4kc" in namespace "provisioning-2077"
STEP: Deleting pvc
May  7 07:39:38.907: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comj9stp"
... skipping 9 lines ...

• [SLOW TEST:13.932 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:258
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath file is outside the volume [Slow][LinuxOnly]","total":35,"completed":3,"skipped":785,"failed":0}

SSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:44.165: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 87 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:280

    Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 43 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read-only inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:175
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should create read-only inline ephemeral volume","total":36,"completed":3,"skipped":244,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:44.380: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 261 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single volume from pods on different node
    test/e2e/storage/testsuites/multivolume.go:451
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the single volume from pods on different node","total":34,"completed":3,"skipped":395,"failed":0}

SSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (xfs)][Slow] volumes
  test/e2e/storage/framework/testsuite.go:51
May  7 07:39:48.876: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 75 lines ...
May  7 07:39:44.681: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:39:44.716: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjllwp] to have phase Bound
May  7 07:39:44.750: INFO: PersistentVolumeClaim test.csi.azure.comjllwp found but phase is Pending instead of Bound.
May  7 07:39:46.783: INFO: PersistentVolumeClaim test.csi.azure.comjllwp found and phase=Bound (2.066790344s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
May  7 07:39:46.918: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-l4g62" in namespace "snapshotting-1793" to be "Succeeded or Failed"
May  7 07:39:46.951: INFO: Pod "pvc-snapshottable-tester-l4g62": Phase="Pending", Reason="", readiness=false. Elapsed: 33.549611ms
May  7 07:39:48.991: INFO: Pod "pvc-snapshottable-tester-l4g62": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.073382903s
STEP: Saw pod success
May  7 07:39:48.991: INFO: Pod "pvc-snapshottable-tester-l4g62" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
May  7 07:39:49.026: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjllwp] to have phase Bound
May  7 07:39:49.059: INFO: PersistentVolumeClaim test.csi.azure.comjllwp found and phase=Bound (32.943016ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
May  7 07:39:49.165: INFO: Pod pvc-snapshottable-tester-l4g62 has the following logs: 
... skipping 67 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach]
    test/e2e/storage/testsuites/volumemode.go:299

    Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 42 lines ...
May  7 07:39:43.835: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:39:43.871: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8dh9w] to have phase Bound
May  7 07:39:43.904: INFO: PersistentVolumeClaim test.csi.azure.com8dh9w found but phase is Pending instead of Bound.
May  7 07:39:45.939: INFO: PersistentVolumeClaim test.csi.azure.com8dh9w found and phase=Bound (2.068176197s)
STEP: Creating pod pod-subpath-test-dynamicpv-p5qx
STEP: Creating a pod to test subpath
May  7 07:39:46.047: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-p5qx" in namespace "provisioning-2915" to be "Succeeded or Failed"
May  7 07:39:46.081: INFO: Pod "pod-subpath-test-dynamicpv-p5qx": Phase="Pending", Reason="", readiness=false. Elapsed: 33.530955ms
May  7 07:39:48.120: INFO: Pod "pod-subpath-test-dynamicpv-p5qx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.073489548s
May  7 07:39:50.155: INFO: Pod "pod-subpath-test-dynamicpv-p5qx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.107830752s
STEP: Saw pod success
May  7 07:39:50.155: INFO: Pod "pod-subpath-test-dynamicpv-p5qx" satisfied condition "Succeeded or Failed"
May  7 07:39:50.188: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-p5qx container test-container-subpath-dynamicpv-p5qx: <nil>
STEP: delete the pod
May  7 07:39:50.265: INFO: Waiting for pod pod-subpath-test-dynamicpv-p5qx to disappear
May  7 07:39:50.299: INFO: Pod pod-subpath-test-dynamicpv-p5qx no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-p5qx
May  7 07:39:50.299: INFO: Deleting pod "pod-subpath-test-dynamicpv-p5qx" in namespace "provisioning-2915"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support existing single file [LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:221
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support existing single file [LinuxOnly]","total":37,"completed":4,"skipped":1024,"failed":0}

SS
------------------------------
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits
... skipping 57 lines ...
May  7 07:39:49.213: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:39:49.249: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.commzkjv] to have phase Bound
May  7 07:39:49.283: INFO: PersistentVolumeClaim test.csi.azure.commzkjv found but phase is Pending instead of Bound.
May  7 07:39:51.317: INFO: PersistentVolumeClaim test.csi.azure.commzkjv found and phase=Bound (2.06831498s)
STEP: Creating pod pod-subpath-test-dynamicpv-z8pt
STEP: Creating a pod to test subpath
May  7 07:39:51.419: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-z8pt" in namespace "provisioning-7990" to be "Succeeded or Failed"
May  7 07:39:51.453: INFO: Pod "pod-subpath-test-dynamicpv-z8pt": Phase="Pending", Reason="", readiness=false. Elapsed: 33.64303ms
May  7 07:39:53.487: INFO: Pod "pod-subpath-test-dynamicpv-z8pt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.067640941s
May  7 07:39:55.520: INFO: Pod "pod-subpath-test-dynamicpv-z8pt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.101547344s
STEP: Saw pod success
May  7 07:39:55.520: INFO: Pod "pod-subpath-test-dynamicpv-z8pt" satisfied condition "Succeeded or Failed"
May  7 07:39:55.554: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-z8pt container test-container-subpath-dynamicpv-z8pt: <nil>
STEP: delete the pod
May  7 07:39:55.630: INFO: Waiting for pod pod-subpath-test-dynamicpv-z8pt to disappear
May  7 07:39:55.665: INFO: Pod pod-subpath-test-dynamicpv-z8pt no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-z8pt
May  7 07:39:55.665: INFO: Deleting pod "pod-subpath-test-dynamicpv-z8pt" in namespace "provisioning-7990"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support readOnly file specified in the volumeMount [LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:382
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support readOnly file specified in the volumeMount [LinuxOnly]","total":34,"completed":4,"skipped":485,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
  test/e2e/storage/framework/testsuite.go:51
May  7 07:40:01.046: INFO: Driver "test.csi.azure.com" does not support volume type "CSIInlineVolume" - skipping
... skipping 250 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single read-only volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:423
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the single read-only volume from pods on the same node","total":35,"completed":4,"skipped":1002,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode 
  should not mount / map unused volumes in a pod [LinuxOnly]
  test/e2e/storage/testsuites/volumemode.go:354
... skipping 55 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should not mount / map unused volumes in a pod [LinuxOnly]
    test/e2e/storage/testsuites/volumemode.go:354
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode should not mount / map unused volumes in a pod [LinuxOnly]","total":36,"completed":4,"skipped":328,"failed":0}

SSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits
... skipping 100 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support restarting containers using directory as subpath [Slow]
    test/e2e/storage/testsuites/subpath.go:322
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support restarting containers using directory as subpath [Slow]","total":31,"completed":1,"skipped":56,"failed":0}
[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  test/e2e/storage/framework/testsuite.go:51
May  7 07:40:23.504: INFO: Driver "test.csi.azure.com" does not support topology - skipping
[AfterEach] [Testpattern: Dynamic PV (delayed binding)] topology
  test/e2e/framework/framework.go:188


S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (delayed binding)] topology
  test/e2e/storage/framework/testsuite.go:50
    should fail to schedule a pod which has topologies that conflict with AllowedTopologies [BeforeEach]
    test/e2e/storage/testsuites/topology.go:194

    Driver "test.csi.azure.com" does not support topology - skipping

    test/e2e/storage/testsuites/topology.go:93
------------------------------
... skipping 65 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read/write inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:196
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should create read/write inline ephemeral volume","total":34,"completed":5,"skipped":763,"failed":0}

SSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumes
  test/e2e/storage/framework/testsuite.go:51
May  7 07:40:43.959: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
... skipping 59 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read/write inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:196
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should create read/write inline ephemeral volume","total":36,"completed":5,"skipped":365,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should support file as subpath [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:232
... skipping 16 lines ...
May  7 07:40:23.826: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:40:23.862: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comrmwbp] to have phase Bound
May  7 07:40:23.896: INFO: PersistentVolumeClaim test.csi.azure.comrmwbp found but phase is Pending instead of Bound.
May  7 07:40:25.933: INFO: PersistentVolumeClaim test.csi.azure.comrmwbp found and phase=Bound (2.070929637s)
STEP: Creating pod pod-subpath-test-dynamicpv-mwvs
STEP: Creating a pod to test atomic-volume-subpath
May  7 07:40:26.038: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-mwvs" in namespace "provisioning-1225" to be "Succeeded or Failed"
May  7 07:40:26.075: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Pending", Reason="", readiness=false. Elapsed: 36.752659ms
May  7 07:40:28.111: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Pending", Reason="", readiness=false. Elapsed: 2.072701089s
May  7 07:40:30.146: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 4.107925134s
May  7 07:40:32.181: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 6.143548139s
May  7 07:40:34.217: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 8.178915754s
May  7 07:40:36.252: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 10.21390381s
... skipping 2 lines ...
May  7 07:40:42.361: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 16.323080768s
May  7 07:40:44.396: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 18.358558151s
May  7 07:40:46.433: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 20.394629404s
May  7 07:40:48.467: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 22.429012576s
May  7 07:40:50.505: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Succeeded", Reason="", readiness=false. Elapsed: 24.467061415s
STEP: Saw pod success
May  7 07:40:50.505: INFO: Pod "pod-subpath-test-dynamicpv-mwvs" satisfied condition "Succeeded or Failed"
May  7 07:40:50.539: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-mwvs container test-container-subpath-dynamicpv-mwvs: <nil>
STEP: delete the pod
May  7 07:40:50.617: INFO: Waiting for pod pod-subpath-test-dynamicpv-mwvs to disappear
May  7 07:40:50.651: INFO: Pod pod-subpath-test-dynamicpv-mwvs no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-mwvs
May  7 07:40:50.651: INFO: Deleting pod "pod-subpath-test-dynamicpv-mwvs" in namespace "provisioning-1225"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support file as subpath [LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:232
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support file as subpath [LinuxOnly]","total":31,"completed":2,"skipped":114,"failed":0}
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:40:55.961: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
[AfterEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/framework/framework.go:188

... skipping 128 lines ...
May  7 07:40:57.315: INFO: ExecWithOptions: execute(POST https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com/api/v1/namespaces/volume-5376/pods/external-client/exec?command=%2Fbin%2Fsh&command=-c&command=test+-d+%2Fopt%2F0&container=external-client&container=external-client&stderr=true&stdout=true)
May  7 07:40:57.632: INFO: ExecWithOptions {Command:[/bin/sh -c test -b /opt/0] Namespace:volume-5376 PodName:external-client ContainerName:external-client Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
May  7 07:40:57.632: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json
May  7 07:40:57.633: INFO: ExecWithOptions: Clientset creation
May  7 07:40:57.633: INFO: ExecWithOptions: execute(POST https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com/api/v1/namespaces/volume-5376/pods/external-client/exec?command=%2Fbin%2Fsh&command=-c&command=test+-b+%2Fopt%2F0&container=external-client&container=external-client&stderr=true&stdout=true)
STEP: Repeating the test on an ephemeral container (if enabled)
May  7 07:40:57.979: INFO: Skipping ephemeral container re-test because feature is disabled (error: "the server could not find the requested resource")
STEP: Deleting pod external-client in namespace volume-5376
May  7 07:40:58.013: INFO: Waiting for pod external-client to disappear
May  7 07:40:58.047: INFO: Pod external-client still exists
May  7 07:41:00.047: INFO: Waiting for pod external-client to disappear
May  7 07:41:00.081: INFO: Pod external-client still exists
May  7 07:41:02.047: INFO: Waiting for pod external-client to disappear
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should store data
    test/e2e/storage/testsuites/volumes.go:161
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should store data","total":34,"completed":6,"skipped":782,"failed":0}

SSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (ntfs)][Feature:Windows] volumes
  test/e2e/storage/framework/testsuite.go:51
May  7 07:41:07.343: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 58 lines ...
May  7 07:40:56.266: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:40:56.303: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjmhsl] to have phase Bound
May  7 07:40:56.342: INFO: PersistentVolumeClaim test.csi.azure.comjmhsl found but phase is Pending instead of Bound.
May  7 07:40:58.378: INFO: PersistentVolumeClaim test.csi.azure.comjmhsl found and phase=Bound (2.0750804s)
STEP: Creating pod pod-subpath-test-dynamicpv-wchd
STEP: Creating a pod to test subpath
May  7 07:40:58.482: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-wchd" in namespace "provisioning-3379" to be "Succeeded or Failed"
May  7 07:40:58.517: INFO: Pod "pod-subpath-test-dynamicpv-wchd": Phase="Pending", Reason="", readiness=false. Elapsed: 34.431035ms
May  7 07:41:00.552: INFO: Pod "pod-subpath-test-dynamicpv-wchd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069500204s
May  7 07:41:02.587: INFO: Pod "pod-subpath-test-dynamicpv-wchd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.104392662s
STEP: Saw pod success
May  7 07:41:02.587: INFO: Pod "pod-subpath-test-dynamicpv-wchd" satisfied condition "Succeeded or Failed"
May  7 07:41:02.620: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-wchd container test-container-subpath-dynamicpv-wchd: <nil>
STEP: delete the pod
May  7 07:41:02.697: INFO: Waiting for pod pod-subpath-test-dynamicpv-wchd to disappear
May  7 07:41:02.732: INFO: Pod pod-subpath-test-dynamicpv-wchd no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-wchd
May  7 07:41:02.732: INFO: Deleting pod "pod-subpath-test-dynamicpv-wchd" in namespace "provisioning-3379"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support readOnly directory specified in the volumeMount
    test/e2e/storage/testsuites/subpath.go:367
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support readOnly directory specified in the volumeMount","total":31,"completed":3,"skipped":144,"failed":0}

SSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May  7 07:41:08.058: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 34 lines ...

    test/e2e/storage/testsuites/volumes.go:114
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:242

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May  7 07:41:07.414: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:242
May  7 07:41:07.651: INFO: Creating resource for dynamic PV
May  7 07:41:07.651: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-18-e2e-sc4dln8
STEP: creating a claim
May  7 07:41:07.686: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:41:07.722: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com649pm] to have phase Bound
May  7 07:41:07.755: INFO: PersistentVolumeClaim test.csi.azure.com649pm found but phase is Pending instead of Bound.
May  7 07:41:09.789: INFO: PersistentVolumeClaim test.csi.azure.com649pm found and phase=Bound (2.06726722s)
STEP: Creating pod pod-subpath-test-dynamicpv-sm7j
STEP: Checking for subpath error in container status
May  7 07:41:13.958: INFO: Deleting pod "pod-subpath-test-dynamicpv-sm7j" in namespace "provisioning-18"
May  7 07:41:13.995: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-sm7j" to be fully deleted
STEP: Deleting pod
May  7 07:41:16.064: INFO: Deleting pod "pod-subpath-test-dynamicpv-sm7j" in namespace "provisioning-18"
STEP: Deleting pvc
May  7 07:41:16.098: INFO: Deleting PersistentVolumeClaim "test.csi.azure.com649pm"
... skipping 9 lines ...

• [SLOW TEST:13.919 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:242
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath directory is outside the volume [Slow][LinuxOnly]","total":34,"completed":7,"skipped":878,"failed":0}

SSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
May  7 07:41:21.342: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 3 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to create pod by failing to mount volume [Slow] [BeforeEach]
    test/e2e/storage/testsuites/volumemode.go:199

    Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 182 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    Verify if offline PVC expansion works
    test/e2e/storage/testsuites/volume_expand.go:176
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand Verify if offline PVC expansion works","total":31,"completed":4,"skipped":227,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand
  test/e2e/storage/framework/testsuite.go:51
May  7 07:41:30.669: INFO: Driver "test.csi.azure.com" does not support block volume mode - skipping
... skipping 111 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should support multiple inline ephemeral volumes
    test/e2e/storage/testsuites/ephemeral.go:254
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should support multiple inline ephemeral volumes","total":36,"completed":6,"skipped":475,"failed":0}

S
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May  7 07:41:39.097: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 149 lines ...
May  7 07:41:39.843: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:41:39.880: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8pxvs] to have phase Bound
May  7 07:41:39.913: INFO: PersistentVolumeClaim test.csi.azure.com8pxvs found but phase is Pending instead of Bound.
May  7 07:41:41.948: INFO: PersistentVolumeClaim test.csi.azure.com8pxvs found and phase=Bound (2.067533088s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
May  7 07:41:42.086: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-tt7qt" in namespace "snapshotting-2368" to be "Succeeded or Failed"
May  7 07:41:42.119: INFO: Pod "pvc-snapshottable-tester-tt7qt": Phase="Pending", Reason="", readiness=false. Elapsed: 33.43518ms
May  7 07:41:44.153: INFO: Pod "pvc-snapshottable-tester-tt7qt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.067260769s
STEP: Saw pod success
May  7 07:41:44.153: INFO: Pod "pvc-snapshottable-tester-tt7qt" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
May  7 07:41:44.186: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8pxvs] to have phase Bound
May  7 07:41:44.223: INFO: PersistentVolumeClaim test.csi.azure.com8pxvs found and phase=Bound (36.862438ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
May  7 07:41:44.329: INFO: Pod pvc-snapshottable-tester-tt7qt has the following logs: 
... skipping 255 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:298
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the single volume from pods on the same node","total":31,"completed":5,"skipped":365,"failed":0}

SSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] volume-expand
  test/e2e/storage/framework/testsuite.go:51
May  7 07:41:57.101: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 13 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:280

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May  7 07:41:50.068: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:280
May  7 07:41:50.299: INFO: Creating resource for dynamic PV
May  7 07:41:50.299: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-2646-e2e-scl88nv
STEP: creating a claim
May  7 07:41:50.335: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:41:50.372: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comnq8s4] to have phase Bound
May  7 07:41:50.406: INFO: PersistentVolumeClaim test.csi.azure.comnq8s4 found but phase is Pending instead of Bound.
May  7 07:41:52.440: INFO: PersistentVolumeClaim test.csi.azure.comnq8s4 found and phase=Bound (2.067525261s)
STEP: Creating pod pod-subpath-test-dynamicpv-mr8l
STEP: Checking for subpath error in container status
May  7 07:41:56.611: INFO: Deleting pod "pod-subpath-test-dynamicpv-mr8l" in namespace "provisioning-2646"
May  7 07:41:56.648: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-mr8l" to be fully deleted
STEP: Deleting pod
May  7 07:41:58.716: INFO: Deleting pod "pod-subpath-test-dynamicpv-mr8l" in namespace "provisioning-2646"
STEP: Deleting pvc
May  7 07:41:58.749: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comnq8s4"
... skipping 9 lines ...

• [SLOW TEST:13.947 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:280
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]","total":36,"completed":7,"skipped":745,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:42:04.085: INFO: Driver test.csi.azure.com doesn't support xfs -- skipping
... skipping 77 lines ...
STEP: creating claim=&PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-4351    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{5368709120 0} {<nil>} 5Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-4351-e2e-scddd86,VolumeMode:nil,DataSource:nil,DataSourceRef:&TypedLocalObjectReference{APIGroup:*hello.example.com,Kind:Hello,Name:example-hello,},},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},AllocatedResources:ResourceList{},ResizeStatus:nil,},}
STEP: checking whether the created volume has the pre-populated data
STEP: starting external-client
STEP: Checking that text file contents are perfect.
May  7 07:42:04.411: INFO: Running '/usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt'
May  7 07:42:05.082: INFO: rc: 1
May  7 07:42:05.082: FAIL: Unexpected error:
    <exec.CodeExitError>: {
        Err: {
            s: "error running /usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt:\nCommand stdout:\n\nstderr:\ncat: can't open '/opt/0/example-provisioning-4351.txt': No such file or directory\ncommand terminated with exit code 1\n\nerror:\nexit status 1",
        },
        Code: 1,
    }
    error running /usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt:
    Command stdout:
    
    stderr:
    cat: can't open '/opt/0/example-provisioning-4351.txt': No such file or directory
    command terminated with exit code 1
    
    error:
    exit status 1
occurred

Full Stack Trace
k8s.io/kubernetes/test/e2e/framework.KubectlBuilder.ExecOrDie({0xc001f39b80?, 0x0?}, {0xc0034f8d50, 0x11})
	test/e2e/framework/util.go:630 +0x1b4
... skipping 172 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:50
    should provision storage with any volume data source [Serial] [Measurement]
    test/e2e/storage/testsuites/provisioning.go:246

    May  7 07:42:05.082: Unexpected error:
        <exec.CodeExitError>: {
            Err: {
                s: "error running /usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt:\nCommand stdout:\n\nstderr:\ncat: can't open '/opt/0/example-provisioning-4351.txt': No such file or directory\ncommand terminated with exit code 1\n\nerror:\nexit status 1",
            },
            Code: 1,
        }
        error running /usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt:
        Command stdout:
        
        stderr:
        cat: can't open '/opt/0/example-provisioning-4351.txt': No such file or directory
        command terminated with exit code 1
        
        error:
        exit status 1
    occurred

    test/e2e/framework/util.go:630
------------------------------
{"msg":"FAILED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should provision storage with any volume data source [Serial]","total":31,"completed":5,"skipped":390,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should provision storage with any volume data source [Serial]"]}

SSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May  7 07:42:23.034: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 3 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:242

    Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 26 lines ...
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May  7 07:42:23.156: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
May  7 07:42:23.391: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
[AfterEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  test/e2e/framework/framework.go:188
May  7 07:42:23.392: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-6924" for this suite.


S [SKIPPING] [0.305 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [Measurement]
    test/e2e/storage/testsuites/volumemode.go:299

    Driver "test.csi.azure.com" does not provide raw block - skipping

    test/e2e/storage/testsuites/volumes.go:114
------------------------------
... skipping 151 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:269

    Driver test.csi.azure.com doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 148 lines ...
May  7 07:38:12.035: INFO: In creating storage class object and pvc objects for driver - sc: &StorageClass{ObjectMeta:{provisioning-4366-e2e-scl7zmc      0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Provisioner:test.csi.azure.com,Parameters:map[string]string{skuName: Premium_LRS,},ReclaimPolicy:*Delete,MountOptions:[dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30],AllowVolumeExpansion:*true,VolumeBindingMode:*Immediate,AllowedTopologies:[]TopologySelectorTerm{},}, pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-4366    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{5368709120 0} {<nil>} 5Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-4366-e2e-scl7zmc,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},AllocatedResources:ResourceList{},ResizeStatus:nil,},}, src-pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-4366    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{5368709120 0} {<nil>} 5Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-4366-e2e-scl7zmc,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},AllocatedResources:ResourceList{},ResizeStatus:nil,},}
STEP: Creating a StorageClass
STEP: creating claim=&PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-4366    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{5368709120 0} {<nil>} 5Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-4366-e2e-scl7zmc,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},AllocatedResources:ResourceList{},ResizeStatus:nil,},}
STEP: Created Pod provisioning-4366/pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109 on node k8s-agentpool1-41236054-vmss000001
STEP: Creating a PVC followed by a pre-bound PV
May  7 07:38:44.498: INFO: Created PVC provisioning-4366/pvc-t955f and PV pv-czp59 in namespace %!s(MISSING)
May  7 07:43:44.637: FAIL: Unexpected error:
    <*errors.errorString | 0xc0037053a0>: {
        s: "pod \"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced\" is not Running: timed out waiting for the condition",
    }
    pod "pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced" is not Running: timed out waiting for the condition
occurred

... skipping 34 lines ...
May  7 07:43:46.877: INFO: At 2022-05-07 07:38:32 +0000 UTC - event for pvc-mbdlx: {test.csi.azure.com_k8s-agentpool1-41236054-vmss000000_966cad7a-184c-4ec9-a4fa-062f5006ba8f } ProvisioningSucceeded: Successfully provisioned volume pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc
May  7 07:43:46.877: INFO: At 2022-05-07 07:38:41 +0000 UTC - event for pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109: {kubelet k8s-agentpool1-41236054-vmss000001} Created: Created container write-pod
May  7 07:43:46.877: INFO: At 2022-05-07 07:38:41 +0000 UTC - event for pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109: {kubelet k8s-agentpool1-41236054-vmss000001} Pulled: Successfully pulled image "k8s.gcr.io/e2e-test-images/busybox:1.29-2" in 263.915057ms
May  7 07:43:46.877: INFO: At 2022-05-07 07:38:41 +0000 UTC - event for pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109: {kubelet k8s-agentpool1-41236054-vmss000001} Pulling: Pulling image "k8s.gcr.io/e2e-test-images/busybox:1.29-2"
May  7 07:43:46.877: INFO: At 2022-05-07 07:38:42 +0000 UTC - event for pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109: {kubelet k8s-agentpool1-41236054-vmss000001} Started: Started container write-pod
May  7 07:43:46.877: INFO: At 2022-05-07 07:38:44 +0000 UTC - event for pvc-t955f: {persistentvolume-controller } ProvisioningFailed: storageclass.storage.k8s.io "provisioning-4366" not found
May  7 07:43:46.877: INFO: At 2022-05-07 07:39:01 +0000 UTC - event for pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced: {kubelet k8s-agentpool1-41236054-vmss000001} FailedMount: MountVolume.SetUp failed for volume "pv-czp59" : rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

May  7 07:43:46.877: INFO: At 2022-05-07 07:41:04 +0000 UTC - event for pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced: {kubelet k8s-agentpool1-41236054-vmss000001} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[kube-api-access-wlxgc volume1]: timed out waiting for the condition
May  7 07:43:46.877: INFO: At 2022-05-07 07:43:21 +0000 UTC - event for pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced: {kubelet k8s-agentpool1-41236054-vmss000001} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 kube-api-access-wlxgc]: timed out waiting for the condition
... skipping 103 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:50
    should mount multiple PV pointing to the same storage on the same node [Measurement]
    test/e2e/storage/testsuites/provisioning.go:518

    May  7 07:43:44.637: Unexpected error:
        <*errors.errorString | 0xc0037053a0>: {
            s: "pod \"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced\" is not Running: timed out waiting for the condition",
        }
        pod "pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced" is not Running: timed out waiting for the condition
    occurred

    test/e2e/storage/testsuites/provisioning.go:1205
------------------------------
{"msg":"FAILED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node","total":36,"completed":0,"skipped":2,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:43:47.906: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 66 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:269

    Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 59 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:269

    Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 8 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:242

    Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 146 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support restarting containers using file as subpath [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:333
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support restarting containers using file as subpath [Slow][LinuxOnly]","total":36,"completed":8,"skipped":835,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral 
  should create read-only inline ephemeral volume
  test/e2e/storage/testsuites/ephemeral.go:175
... skipping 38 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read-only inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:175
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should create read-only inline ephemeral volume","total":36,"completed":9,"skipped":915,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (default fs)] volume-stress
  test/e2e/storage/framework/testsuite.go:51
May  7 07:44:28.802: INFO: Driver test.csi.azure.com doesn't specify stress test options -- skipping
... skipping 58 lines ...
May  7 07:44:29.091: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:44:29.127: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comrfpfm] to have phase Bound
May  7 07:44:29.159: INFO: PersistentVolumeClaim test.csi.azure.comrfpfm found but phase is Pending instead of Bound.
May  7 07:44:31.194: INFO: PersistentVolumeClaim test.csi.azure.comrfpfm found and phase=Bound (2.06705638s)
STEP: Creating pod pod-subpath-test-dynamicpv-hvf2
STEP: Creating a pod to test subpath
May  7 07:44:31.304: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hvf2" in namespace "provisioning-2075" to be "Succeeded or Failed"
May  7 07:44:31.338: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Pending", Reason="", readiness=false. Elapsed: 34.310558ms
May  7 07:44:33.373: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069061589s
May  7 07:44:35.421: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.116920915s
STEP: Saw pod success
May  7 07:44:35.421: INFO: Pod "pod-subpath-test-dynamicpv-hvf2" satisfied condition "Succeeded or Failed"
May  7 07:44:35.454: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-hvf2 container test-container-subpath-dynamicpv-hvf2: <nil>
STEP: delete the pod
May  7 07:44:35.529: INFO: Waiting for pod pod-subpath-test-dynamicpv-hvf2 to disappear
May  7 07:44:35.564: INFO: Pod pod-subpath-test-dynamicpv-hvf2 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-hvf2
May  7 07:44:35.564: INFO: Deleting pod "pod-subpath-test-dynamicpv-hvf2" in namespace "provisioning-2075"
STEP: Creating pod pod-subpath-test-dynamicpv-hvf2
STEP: Creating a pod to test subpath
May  7 07:44:35.636: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hvf2" in namespace "provisioning-2075" to be "Succeeded or Failed"
May  7 07:44:35.669: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Pending", Reason="", readiness=false. Elapsed: 32.757178ms
May  7 07:44:37.704: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.067428196s
STEP: Saw pod success
May  7 07:44:37.704: INFO: Pod "pod-subpath-test-dynamicpv-hvf2" satisfied condition "Succeeded or Failed"
May  7 07:44:37.739: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-hvf2 container test-container-subpath-dynamicpv-hvf2: <nil>
STEP: delete the pod
May  7 07:44:37.814: INFO: Waiting for pod pod-subpath-test-dynamicpv-hvf2 to disappear
May  7 07:44:37.847: INFO: Pod pod-subpath-test-dynamicpv-hvf2 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-hvf2
May  7 07:44:37.847: INFO: Deleting pod "pod-subpath-test-dynamicpv-hvf2" in namespace "provisioning-2075"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support existing directories when readOnly specified in the volumeSource
    test/e2e/storage/testsuites/subpath.go:397
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support existing directories when readOnly specified in the volumeSource","total":36,"completed":10,"skipped":988,"failed":0}

SSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May  7 07:44:43.164: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 80 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should support two pods which have the same volume definition
    test/e2e/storage/testsuites/ephemeral.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should support two pods which have the same volume definition","total":36,"completed":1,"skipped":330,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]}

S
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volume-expand
  test/e2e/storage/framework/testsuite.go:51
May  7 07:45:04.714: INFO: Driver "test.csi.azure.com" does not support block volume mode - skipping
... skipping 24 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:258

    Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 134 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should support two pods which have the same volume definition
    test/e2e/storage/testsuites/ephemeral.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should support two pods which have the same volume definition","total":36,"completed":2,"skipped":474,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]}

SSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] 
  should access to two volumes with the same volume mode and retain data across pod recreation on the same node
  test/e2e/storage/testsuites/multivolume.go:138
... skipping 178 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with the same volume mode and retain data across pod recreation on the same node
    test/e2e/storage/testsuites/multivolume.go:138
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should access to two volumes with the same volume mode and retain data across pod recreation on the same node","total":36,"completed":3,"skipped":484,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]}

SSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable-stress[Feature:VolumeSnapshotDataSource]
  test/e2e/storage/framework/testsuite.go:51
May  7 07:46:56.959: INFO: Driver test.csi.azure.com doesn't specify snapshot stress test options -- skipping
... skipping 212 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumeIO
  test/e2e/storage/framework/testsuite.go:50
    should write files of various sizes, verify size, validate content [Slow]
    test/e2e/storage/testsuites/volume_io.go:149
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumeIO should write files of various sizes, verify size, validate content [Slow]","total":36,"completed":4,"skipped":878,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
... skipping 16 lines ...
May  7 07:47:45.885: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May  7 07:47:45.920: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comfmqzm] to have phase Bound
May  7 07:47:45.953: INFO: PersistentVolumeClaim test.csi.azure.comfmqzm found but phase is Pending instead of Bound.
May  7 07:47:47.988: INFO: PersistentVolumeClaim test.csi.azure.comfmqzm found and phase=Bound (2.067436695s)
STEP: Creating pod exec-volume-test-dynamicpv-zlm7
STEP: Creating a pod to test exec-volume-test
May  7 07:47:48.090: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-zlm7" in namespace "volume-7187" to be "Succeeded or Failed"
May  7 07:47:48.124: INFO: Pod "exec-volume-test-dynamicpv-zlm7": Phase="Pending", Reason="", readiness=false. Elapsed: 33.539163ms
May  7 07:47:50.158: INFO: Pod "exec-volume-test-dynamicpv-zlm7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.068226514s
May  7 07:47:52.196: INFO: Pod "exec-volume-test-dynamicpv-zlm7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.106117654s
STEP: Saw pod success
May  7 07:47:52.196: INFO: Pod "exec-volume-test-dynamicpv-zlm7" satisfied condition "Succeeded or Failed"
May  7 07:47:52.230: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod exec-volume-test-dynamicpv-zlm7 container exec-container-dynamicpv-zlm7: <nil>
STEP: delete the pod
May  7 07:47:52.334: INFO: Waiting for pod exec-volume-test-dynamicpv-zlm7 to disappear
May  7 07:47:52.367: INFO: Pod exec-volume-test-dynamicpv-zlm7 no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-zlm7
May  7 07:47:52.367: INFO: Deleting pod "exec-volume-test-dynamicpv-zlm7" in namespace "volume-7187"
... skipping 14 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume
    test/e2e/storage/testsuites/volumes.go:198
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should allow exec of files on the volume","total":36,"completed":5,"skipped":940,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]}

SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May  7 07:47:57.658: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 135 lines ...
May  7 07:47:58.081: INFO: Running AfterSuite actions on node 1



Summarizing 2 Failures:

[Fail] External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning [Measurement] should provision storage with any volume data source [Serial] 
test/e2e/framework/util.go:630

[Fail] External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning [Measurement] should mount multiple PV pointing to the same storage on the same node 
test/e2e/storage/testsuites/provisioning.go:1205

Ran 39 of 7229 Specs in 588.298 seconds
FAIL! -- 37 Passed | 2 Failed | 0 Pending | 7190 Skipped 

Ginkgo ran 1 suite in 9m51.904278052s
Test Suite Failed
+ print_logs
+ bash ./hack/verify-examples.sh linux
begin to create deployment examples ...
storageclass.storage.k8s.io/azurefile-csi created
Applying config "deploy/example/daemonset.yaml"
Waiting for daemon set "daemonset-azurefile" rollout to finish: 0 of 2 updated pods are available...
... skipping 69 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0507 07:38:03.239892       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test
I0507 07:38:03.240256       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0507 07:38:03.267661       1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0507 07:38:03.267683       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0507 07:38:03.267691       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0507 07:38:03.267716       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0507 07:38:03.268300       1 azure_auth.go:245] Using AzurePublicCloud environment
I0507 07:38:03.268356       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0507 07:38:03.268397       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 163 lines ...
I0507 07:38:45.259071       1 azure_storage.go:66] share pvc-86088b84-850c-4a64-a203-fc7867d8c16f deleted
I0507 07:38:45.259149       1 controllerserver.go:584] azure file(pvc-86088b84-850c-4a64-a203-fc7867d8c16f) under rg(kubetest-btcc2dv0) account(fefc5f86712004996adfb9a) volume(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-86088b84-850c-4a64-a203-fc7867d8c16f###provisioning-9552) is deleted successfully
I0507 07:38:45.259192       1 azure_metrics.go:112] "Observed Request Latency" latency_seconds=0.151856344 request="azurefile_csi_driver_controller_delete_volume" resource_group="kubetest-btcc2dv0" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="test.csi.azure.com" volumeid="kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-86088b84-850c-4a64-a203-fc7867d8c16f###provisioning-9552" result_code="succeeded"
I0507 07:38:45.259212       1 utils.go:83] GRPC response: {}
I0507 07:38:48.877116       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0507 07:38:48.877159       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9bd70868-2fc0-4384-896d-d8efbfc3f8c5","parameters":{"csi.storage.k8s.io/pv/name":"pvc-9bd70868-2fc0-4384-896d-d8efbfc3f8c5","csi.storage.k8s.io/pvc/name":"pvc-zdhsx","csi.storage.k8s.io/pvc/namespace":"volumemode-7633","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]}
E0507 07:38:48.877368       1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes
I0507 07:38:48.995661       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0507 07:38:48.995695       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9bd70868-2fc0-4384-896d-d8efbfc3f8c5","parameters":{"csi.storage.k8s.io/pv/name":"pvc-9bd70868-2fc0-4384-896d-d8efbfc3f8c5","csi.storage.k8s.io/pvc/name":"pvc-zdhsx","csi.storage.k8s.io/pvc/namespace":"volumemode-7633","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]}
E0507 07:38:48.996112       1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes
I0507 07:38:50.034926       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0507 07:38:50.035068       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5f5ce4a8-8dc4-4994-ac90-0620197677d1","parameters":{"csi.storage.k8s.io/pv/name":"pvc-5f5ce4a8-8dc4-4994-ac90-0620197677d1","csi.storage.k8s.io/pvc/name":"test.csi.azure.comnmnbt","csi.storage.k8s.io/pvc/namespace":"snapshotting-6746","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}}]}
I0507 07:38:50.136892       1 controllerserver.go:433] begin to create file share(pvc-5f5ce4a8-8dc4-4994-ac90-0620197677d1) on account(fefc5f86712004996adfb9a) type(Premium_LRS) rg(kubetest-btcc2dv0) location() size(100) protocol(SMB)
I0507 07:38:50.155200       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0507 07:38:50.155220       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-8824185b-2425-41aa-b603-f71d3cd6a755","parameters":{"csi.storage.k8s.io/pv/name":"pvc-8824185b-2425-41aa-b603-f71d3cd6a755","csi.storage.k8s.io/pvc/name":"pvc-snapshottable-tester-d9bhj-my-volume","csi.storage.k8s.io/pvc/namespace":"snapshotting-1997","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}}]}
I0507 07:38:50.239041       1 controllerserver.go:433] begin to create file share(pvc-8824185b-2425-41aa-b603-f71d3cd6a755) on account(fefc5f86712004996adfb9a) type(Premium_LRS) rg(kubetest-btcc2dv0) location() size(100) protocol(SMB)
... skipping 643 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0507 07:38:04.989044       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test
I0507 07:38:04.989363       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0507 07:38:05.014886       1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0507 07:38:05.014898       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0507 07:38:05.014905       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0507 07:38:05.014927       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0507 07:38:05.015497       1 azure_auth.go:245] Using AzurePublicCloud environment
I0507 07:38:05.015528       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0507 07:38:05.015553       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 103 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0507 07:37:59.803237       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test
I0507 07:37:59.803549       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0507 07:37:59.824132       1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0507 07:37:59.824152       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0507 07:37:59.824160       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0507 07:37:59.824182       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0507 07:37:59.824781       1 azure_auth.go:245] Using AzurePublicCloud environment
I0507 07:37:59.824818       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0507 07:37:59.824864       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 278 lines ...
I0507 07:39:01.581045       1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac###provisioning-2916) context(map[csi.storage.k8s.io/pv/name:pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac csi.storage.k8s.io/pvc/name:test.csi.azure.com4nf84 csi.storage.k8s.io/pvc/namespace:provisioning-2916 secretnamespace:provisioning-2916 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup()
I0507 07:39:01.581394       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t cifs -o dir_mode=0777,file_mode=0777,mfsymlinks,cache=strict,nosharesock,actimeo=30,<masked> //fefc5f86712004996adfb9a.file.core.windows.net/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount)
I0507 07:39:01.587353       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:39:01.587371       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:39:01.587767       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:39:01.587790       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:39:01.589367       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:39:01.589439       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:39:01.639938       1 nodeserver.go:313] volume(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac###provisioning-2916) mount //fefc5f86712004996adfb9a.file.core.windows.net/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount succeeded
I0507 07:39:01.639977       1 utils.go:83] GRPC response: {}
I0507 07:39:01.646059       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
... skipping 4 lines ...
I0507 07:39:01.649556       1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount at /var/lib/kubelet/pods/9fbb034a-ce43-48f0-b520-76a58a27ecd4/volumes/kubernetes.io~csi/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/mount successfully
I0507 07:39:01.649585       1 utils.go:83] GRPC response: {}
I0507 07:39:02.184516       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:39:02.184542       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:39:02.185134       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:39:02.185154       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:39:02.187181       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:39:02.187300       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:39:02.890683       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0507 07:39:02.890705       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95","csi.storage.k8s.io/pvc/name":"test.csi.azure.comgmv9b","csi.storage.k8s.io/pvc/namespace":"snapshotting-7449","secretnamespace":"snapshotting-7449","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95###snapshotting-7449"}
I0507 07:39:02.890838       1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95###snapshotting-7449) context(map[csi.storage.k8s.io/pv/name:pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95 csi.storage.k8s.io/pvc/name:test.csi.azure.comgmv9b csi.storage.k8s.io/pvc/namespace:snapshotting-7449 secretnamespace:snapshotting-7449 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup()
... skipping 8 lines ...
I0507 07:39:03.140938       1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/globalmount at /var/lib/kubelet/pods/b6cc1b6c-615e-4ca3-8032-53f1b9f61948/volumes/kubernetes.io~csi/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/mount successfully
I0507 07:39:03.140955       1 utils.go:83] GRPC response: {}
I0507 07:39:03.196869       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:39:03.196883       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:39:03.197308       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:39:03.197321       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:39:03.199105       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:39:03.199177       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:39:05.214206       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:39:05.214228       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:39:05.214780       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:39:05.214805       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:39:05.216509       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:39:05.216593       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:39:06.825611       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I0507 07:39:06.825638       1 utils.go:77] GRPC request: {"target_path":"/var/lib/kubelet/pods/b6cc1b6c-615e-4ca3-8032-53f1b9f61948/volumes/kubernetes.io~csi/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/mount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95###snapshotting-7449"}
I0507 07:39:06.825737       1 nodeserver.go:132] NodeUnpublishVolume: unmounting volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95###snapshotting-7449 on /var/lib/kubelet/pods/b6cc1b6c-615e-4ca3-8032-53f1b9f61948/volumes/kubernetes.io~csi/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/mount
... skipping 27 lines ...
I0507 07:39:07.768768       1 nodeserver.go:369] NodeUnstageVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac###provisioning-2916 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount successfully
I0507 07:39:07.768778       1 utils.go:83] GRPC response: {}
I0507 07:39:09.250354       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:39:09.250375       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:39:09.250841       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:39:09.250863       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:39:09.252530       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:39:09.252610       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:39:11.869136       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0507 07:39:11.869169       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"],"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890","csi.storage.k8s.io/pvc/name":"test.csi.azure.comtrdw2","csi.storage.k8s.io/pvc/namespace":"volume-expand-736","secretnamespace":"volume-expand-736","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736"}
I0507 07:39:11.869372       1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736) context(map[csi.storage.k8s.io/pv/name:pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890 csi.storage.k8s.io/pvc/name:test.csi.azure.comtrdw2 csi.storage.k8s.io/pvc/namespace:volume-expand-736 secretnamespace:volume-expand-736 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30 gid=1000]) volumeMountGroup(1000)
... skipping 32 lines ...
I0507 07:39:17.313559       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:39:17.313584       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
I0507 07:39:17.314213       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I0507 07:39:17.314227       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736"}
I0507 07:39:17.314269       1 nodeserver.go:359] NodeUnstageVolume: CleanupMountPoint volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount
I0507 07:39:17.314276       1 mount_linux.go:294] Unmounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount
E0507 07:39:17.315244       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:39:17.315302       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
W0507 07:39:17.328797       1 mount_helper_common.go:133] Warning: "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount" is not a mountpoint, deleting
I0507 07:39:17.328857       1 nodeserver.go:365] NodeUnstageVolume: CleanupMountPoint volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/proxy-mount
W0507 07:39:17.328875       1 mount_helper_common.go:34] Warning: Unmount skipped because path does not exist: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/proxy-mount
... skipping 100 lines ...
I0507 07:39:33.031964       1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde/globalmount at /var/lib/kubelet/pods/7f7d32b9-a1b7-47f5-85d5-38c037fdf075/volumes/kubernetes.io~csi/pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde/mount successfully
I0507 07:39:33.031984       1 utils.go:83] GRPC response: {}
I0507 07:39:33.362198       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:39:33.362216       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:39:33.362882       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:39:33.362907       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:39:33.364876       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:39:33.364948       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:39:36.983682       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I0507 07:39:36.983710       1 utils.go:77] GRPC request: {"target_path":"/var/lib/kubelet/pods/7f7d32b9-a1b7-47f5-85d5-38c037fdf075/volumes/kubernetes.io~csi/pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde/mount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde###provisioning-2077"}
I0507 07:39:36.983783       1 nodeserver.go:132] NodeUnpublishVolume: unmounting volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde###provisioning-2077 on /var/lib/kubelet/pods/7f7d32b9-a1b7-47f5-85d5-38c037fdf075/volumes/kubernetes.io~csi/pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde/mount
... skipping 128 lines ...
I0507 07:40:03.017210       1 nodeserver.go:369] NodeUnstageVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ece4cf9-6ac2-41c8-9d90-109cf90785dd###multivolume-362 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0ece4cf9-6ac2-41c8-9d90-109cf90785dd/globalmount successfully
I0507 07:40:03.017221       1 utils.go:83] GRPC response: {}
I0507 07:40:05.417827       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:40:05.418086       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:40:05.419018       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:40:05.419057       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:40:05.421670       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:40:05.421978       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:40:15.703876       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0507 07:40:15.703896       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584","csi.storage.k8s.io/pvc/name":"inline-volume-tester-jc2qs-my-volume-0","csi.storage.k8s.io/pvc/namespace":"ephemeral-7412","secretnamespace":"ephemeral-7412","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584###ephemeral-7412"}
I0507 07:40:15.704076       1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584###ephemeral-7412) context(map[csi.storage.k8s.io/pv/name:pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584 csi.storage.k8s.io/pvc/name:inline-volume-tester-jc2qs-my-volume-0 csi.storage.k8s.io/pvc/namespace:ephemeral-7412 secretnamespace:ephemeral-7412 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup()
... skipping 24 lines ...
I0507 07:40:49.591906       1 nodeserver.go:369] NodeUnstageVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584###ephemeral-7412 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584/globalmount successfully
I0507 07:40:49.591917       1 utils.go:83] GRPC response: {}
I0507 07:41:09.447448       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:41:09.447478       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:41:09.448209       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:41:09.448247       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:41:09.450057       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:41:09.450203       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:42:06.805774       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0507 07:42:06.805809       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3","csi.storage.k8s.io/pvc/name":"test.csi.azure.comfzzpt","csi.storage.k8s.io/pvc/namespace":"provisioning-4007","secretnamespace":"provisioning-4007","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3###provisioning-4007"}
I0507 07:42:06.806012       1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3###provisioning-4007) context(map[csi.storage.k8s.io/pv/name:pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3 csi.storage.k8s.io/pvc/name:test.csi.azure.comfzzpt csi.storage.k8s.io/pvc/namespace:provisioning-4007 secretnamespace:provisioning-4007 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup()
... skipping 8 lines ...
I0507 07:42:06.894944       1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/globalmount at /var/lib/kubelet/pods/53867df0-03ab-4f6c-bc61-b992106a4686/volumes/kubernetes.io~csi/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/mount successfully
I0507 07:42:06.894961       1 utils.go:83] GRPC response: {}
I0507 07:43:11.560251       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:43:11.560271       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:43:11.560794       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:43:11.560810       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:43:11.562461       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:43:11.562551       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:43:41.301196       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I0507 07:43:41.301217       1 utils.go:77] GRPC request: {"target_path":"/var/lib/kubelet/pods/53867df0-03ab-4f6c-bc61-b992106a4686/volumes/kubernetes.io~csi/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/mount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3###provisioning-4007"}
I0507 07:43:41.301285       1 nodeserver.go:132] NodeUnpublishVolume: unmounting volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3###provisioning-4007 on /var/lib/kubelet/pods/53867df0-03ab-4f6c-bc61-b992106a4686/volumes/kubernetes.io~csi/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/mount
... skipping 18 lines ...
I0507 07:43:45.534441       1 nodeserver.go:136] NodeUnpublishVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366 on /var/lib/kubelet/pods/c58b154d-b52f-4a73-b27d-ff0a2812bfa8/volumes/kubernetes.io~csi/pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc/mount successfully
I0507 07:43:45.534451       1 utils.go:83] GRPC response: {}
I0507 07:43:45.628680       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:43:45.628712       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:43:45.629363       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:43:45.629401       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:43:45.631944       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:43:45.632043       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:43:46.230286       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:43:46.230308       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:43:46.230960       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:43:46.230991       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:43:46.233777       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:43:46.233840       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:43:47.340531       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:43:47.340566       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:43:47.341143       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:43:47.341164       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:43:47.343245       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:43:47.343333       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:43:49.354367       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:43:49.354387       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:43:49.354851       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:43:49.354871       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:43:49.356555       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:43:49.356615       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:43:53.388121       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:43:53.388154       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:43:53.388841       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:43:53.388878       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:43:53.391539       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:43:53.391617       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:43:56.817802       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0507 07:43:56.817828       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-de104026-29fe-4b63-9f73-255664953fa3/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-de104026-29fe-4b63-9f73-255664953fa3","csi.storage.k8s.io/pvc/name":"inline-volume-tester2-xgksq-my-volume-0","csi.storage.k8s.io/pvc/namespace":"ephemeral-8025","secretnamespace":"ephemeral-8025","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025"}
I0507 07:43:56.817963       1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-de104026-29fe-4b63-9f73-255664953fa3/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025) context(map[csi.storage.k8s.io/pv/name:pvc-de104026-29fe-4b63-9f73-255664953fa3 csi.storage.k8s.io/pvc/name:inline-volume-tester2-xgksq-my-volume-0 csi.storage.k8s.io/pvc/namespace:ephemeral-8025 secretnamespace:ephemeral-8025 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup()
... skipping 8 lines ...
I0507 07:43:56.883744       1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-de104026-29fe-4b63-9f73-255664953fa3/globalmount at /var/lib/kubelet/pods/2cee2ce1-98e1-481c-9b5b-34762e365c19/volumes/kubernetes.io~csi/pvc-de104026-29fe-4b63-9f73-255664953fa3/mount successfully
I0507 07:43:56.883756       1 utils.go:83] GRPC response: {}
I0507 07:44:01.450701       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:44:01.450718       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:44:01.451653       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:44:01.451687       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:44:01.454062       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:44:01.454135       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:44:17.494260       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:44:17.494295       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:44:17.495038       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:44:17.495076       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:44:17.497378       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:44:17.497465       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:44:30.493880       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I0507 07:44:30.493914       1 utils.go:77] GRPC request: {"target_path":"/var/lib/kubelet/pods/2cee2ce1-98e1-481c-9b5b-34762e365c19/volumes/kubernetes.io~csi/pvc-de104026-29fe-4b63-9f73-255664953fa3/mount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025"}
I0507 07:44:30.493986       1 nodeserver.go:132] NodeUnpublishVolume: unmounting volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025 on /var/lib/kubelet/pods/2cee2ce1-98e1-481c-9b5b-34762e365c19/volumes/kubernetes.io~csi/pvc-de104026-29fe-4b63-9f73-255664953fa3/mount
... skipping 11 lines ...
I0507 07:44:30.612805       1 nodeserver.go:369] NodeUnstageVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-de104026-29fe-4b63-9f73-255664953fa3/globalmount successfully
I0507 07:44:30.612816       1 utils.go:83] GRPC response: {}
I0507 07:44:49.542942       1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0507 07:44:49.543232       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:44:49.543951       1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind]
I0507 07:44:49.543989       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount)
E0507 07:44:49.545705       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.

E0507 07:44:49.545793       1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32
Mounting command: mount
Mounting arguments:  -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount
Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist.
I0507 07:45:38.540831       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I0507 07:45:38.540852       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc/globalmount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"}
I0507 07:45:38.540903       1 nodeserver.go:359] NodeUnstageVolume: CleanupMountPoint volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc/globalmount
... skipping 42 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0507 07:37:59.951996       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test
I0507 07:37:59.952341       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0507 07:37:59.973516       1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0507 07:37:59.973534       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0507 07:37:59.973541       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0507 07:37:59.973561       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0507 07:37:59.974166       1 azure_auth.go:245] Using AzurePublicCloud environment
I0507 07:37:59.974206       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0507 07:37:59.974235       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 1181 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0507 07:37:57.729635       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test
I0507 07:37:57.730107       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0507 07:37:57.763961       1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0507 07:37:57.763986       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0507 07:37:57.763996       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0507 07:37:57.764027       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0507 07:37:57.764616       1 azure_auth.go:245] Using AzurePublicCloud environment
I0507 07:37:57.764647       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0507 07:37:57.764674       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 360 lines ...
# HELP process_virtual_memory_bytes Virtual memory size in bytes.
# TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 7.62085376e+08
# HELP process_virtual_memory_max_bytes Maximum amount of virtual memory available in bytes.
# TYPE process_virtual_memory_max_bytes gauge
process_virtual_memory_max_bytes 1.8446744073709552e+19
make: *** [Makefile:85: e2e-test] Error 1
2022/05/07 07:48:26 process.go:155: Step 'make e2e-test' finished in 19m57.250087507s
2022/05/07 07:48:26 aksengine_helpers.go:426: downloading /root/tmp2708233612/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2022/05/07 07:48:26 util.go:71: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2022/05/07 07:48:26 process.go:153: Running: chmod +x /root/tmp2708233612/log-dump.sh
2022/05/07 07:48:26 process.go:155: Step 'chmod +x /root/tmp2708233612/log-dump.sh' finished in 1.049728ms
2022/05/07 07:48:26 aksengine_helpers.go:426: downloading /root/tmp2708233612/log-dump-daemonset.yaml from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump-daemonset.yaml
... skipping 52 lines ...
ssh key file /root/.ssh/id_rsa does not exist. Exiting.
2022/05/07 07:48:49 process.go:155: Step 'bash -c /root/tmp2708233612/win-ci-logs-collector.sh kubetest-btcc2dv0.canadacentral.cloudapp.azure.com /root/tmp2708233612 /root/.ssh/id_rsa' finished in 3.591388ms
2022/05/07 07:48:49 aksengine.go:1141: Deleting resource group: kubetest-btcc2dv0.
2022/05/07 07:55:53 process.go:96: Saved XML output to /logs/artifacts/junit_runner.xml.
2022/05/07 07:55:53 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
2022/05/07 07:55:53 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 286.490643ms
2022/05/07 07:55:53 main.go:331: Something went wrong: encountered 1 errors: [error during make e2e-test: exit status 2]
+ EXIT_VALUE=1
+ set +o xtrace
Cleaning up after docker in docker.
================================================================================
Cleaning up after docker
c221f330c2b1
... skipping 4 lines ...