This job view page is being replaced by Spyglass soon. Check out the new job view.
PRaslafy-z: feat(helm): add support for labels, annotations, podLabels and podAnnotations
ResultFAILURE
Tests 1 failed / 13 succeeded
Started2022-09-29 06:48
Elapsed40m12s
Revisione5d8298b45b0dcdded5ddca4db535a782203526e
Refs 1096
uploadercrier
job-versionv1.26.0-alpha.1.177+c012d901d8bee8
kubetest-versionv20220928-cd48f52a16
revisionv1.26.0-alpha.1.177+c012d901d8bee8

Test Failures


kubetest Test 26m0s

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 232 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11156  100 11156    0     0  72915      0 --:--:-- --:--:-- --:--:-- 72915
Downloading https://get.helm.sh/helm-v3.10.0-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-39436e4fb0516baa38523b851a9bc3e7f5359e5b || make container-all push-manifest
Error response from daemon: manifest for k8sprow.azurecr.io/azurefile-csi:e2e-39436e4fb0516baa38523b851a9bc3e7f5359e5b not found: manifest unknown: manifest tagged by "e2e-39436e4fb0516baa38523b851a9bc3e7f5359e5b" 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-39436e4fb0516baa38523b851a9bc3e7f5359e5b -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.gitCommit=39436e4fb0516baa38523b851a9bc3e7f5359e5b -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.buildDate=2022-09-29T06:55:20Z -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 2005 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 937 lines ...
          image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.5.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 384 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 260 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 92 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.002 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 50 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 554 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":41,"completed":1,"skipped":288,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should verify container cannot write to subpath readonly volumes [Slow]
  test/e2e/storage/testsuites/subpath.go:425
... skipping 44 lines ...
Sep 29 07:08:44.439: INFO: PersistentVolumeClaim test.csi.azure.compfjlr found but phase is Pending instead of Bound.
Sep 29 07:08:46.496: INFO: PersistentVolumeClaim test.csi.azure.compfjlr found but phase is Pending instead of Bound.
Sep 29 07:08:48.553: INFO: PersistentVolumeClaim test.csi.azure.compfjlr found but phase is Pending instead of Bound.
Sep 29 07:08:50.611: INFO: PersistentVolumeClaim test.csi.azure.compfjlr found but phase is Pending instead of Bound.
Sep 29 07:08:52.668: INFO: PersistentVolumeClaim test.csi.azure.compfjlr found and phase=Bound (55.590532521s)
STEP: Creating pod to format volume volume-prep-provisioning-274
Sep 29 07:08:52.836: INFO: Waiting up to 5m0s for pod "volume-prep-provisioning-274" in namespace "provisioning-274" to be "Succeeded or Failed"
Sep 29 07:08:52.892: INFO: Pod "volume-prep-provisioning-274": Phase="Pending", Reason="", readiness=false. Elapsed: 55.596195ms
Sep 29 07:08:54.950: INFO: Pod "volume-prep-provisioning-274": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113328095s
Sep 29 07:08:57.006: INFO: Pod "volume-prep-provisioning-274": Phase="Running", Reason="", readiness=true. Elapsed: 4.170074249s
Sep 29 07:08:59.062: INFO: Pod "volume-prep-provisioning-274": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.225390835s
STEP: Saw pod success
Sep 29 07:08:59.062: INFO: Pod "volume-prep-provisioning-274" satisfied condition "Succeeded or Failed"
Sep 29 07:08:59.062: INFO: Deleting pod "volume-prep-provisioning-274" in namespace "provisioning-274"
Sep 29 07:08:59.119: INFO: Wait up to 5m0s for pod "volume-prep-provisioning-274" to be fully deleted
STEP: Creating pod pod-subpath-test-dynamicpv-gmzv
STEP: Checking for subpath error in container status
Sep 29 07:09:11.342: INFO: Deleting pod "pod-subpath-test-dynamicpv-gmzv" in namespace "provisioning-274"
Sep 29 07:09:11.399: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-gmzv" to be fully deleted
STEP: Deleting pod
Sep 29 07:09:13.510: INFO: Deleting pod "pod-subpath-test-dynamicpv-gmzv" in namespace "provisioning-274"
STEP: Deleting pvc
Sep 29 07:09:13.566: INFO: Deleting PersistentVolumeClaim "test.csi.azure.compfjlr"
... 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":26,"completed":1,"skipped":84,"failed":0}

SSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy 
  (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the volume contents
  test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
... skipping 134 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, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the 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, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the volume contents","total":38,"completed":1,"skipped":168,"failed":0}

SSSS
------------------------------
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
Sep 29 07:09:15.450: INFO: >>> kubeConfig: /root/tmp1144668373/kubeconfig/kubeconfig.westus2.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
Sep 29 07:09:15.847: INFO: Creating resource for dynamic PV
Sep 29 07:09:15.847: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-8648-e2e-schcgss
STEP: creating a claim
Sep 29 07:09:15.908: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:09:15.965: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com4rwqs] to have phase Bound
Sep 29 07:09:16.020: INFO: PersistentVolumeClaim test.csi.azure.com4rwqs found but phase is Pending instead of Bound.
Sep 29 07:09:18.077: INFO: PersistentVolumeClaim test.csi.azure.com4rwqs found and phase=Bound (2.111533045s)
STEP: Creating pod pod-subpath-test-dynamicpv-gjbm
STEP: Checking for subpath error in container status
Sep 29 07:09:26.358: INFO: Deleting pod "pod-subpath-test-dynamicpv-gjbm" in namespace "provisioning-8648"
Sep 29 07:09:26.414: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-gjbm" to be fully deleted
STEP: Deleting pod
Sep 29 07:09:28.525: INFO: Deleting pod "pod-subpath-test-dynamicpv-gjbm" in namespace "provisioning-8648"
STEP: Deleting pvc
Sep 29 07:09:28.581: INFO: Deleting PersistentVolumeClaim "test.csi.azure.com4rwqs"
... skipping 9 lines ...

• [SLOW TEST:18.522 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":41,"completed":2,"skipped":347,"failed":0}

SSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
... skipping 315 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":33,"completed":1,"skipped":212,"failed":0}

SSSSSSSSSSSSSSSSSSS
------------------------------
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
  test/e2e/storage/testsuites/multivolume.go:168
... skipping 204 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":32,"completed":1,"skipped":282,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (ext3)] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:09:40.477: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 54 lines ...
Sep 29 07:09:19.887: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:09:19.945: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com26h2l] to have phase Bound
Sep 29 07:09:20.000: INFO: PersistentVolumeClaim test.csi.azure.com26h2l found but phase is Pending instead of Bound.
Sep 29 07:09:22.056: INFO: PersistentVolumeClaim test.csi.azure.com26h2l found and phase=Bound (2.111308688s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep 29 07:09:22.288: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-xkllv" in namespace "snapshotting-3056" to be "Succeeded or Failed"
Sep 29 07:09:22.343: INFO: Pod "pvc-snapshottable-tester-xkllv": Phase="Pending", Reason="", readiness=false. Elapsed: 55.514182ms
Sep 29 07:09:24.400: INFO: Pod "pvc-snapshottable-tester-xkllv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.112425911s
Sep 29 07:09:26.457: INFO: Pod "pvc-snapshottable-tester-xkllv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.169598845s
Sep 29 07:09:28.515: INFO: Pod "pvc-snapshottable-tester-xkllv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.227365514s
Sep 29 07:09:30.571: INFO: Pod "pvc-snapshottable-tester-xkllv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.283150067s
Sep 29 07:09:32.627: INFO: Pod "pvc-snapshottable-tester-xkllv": Phase="Pending", Reason="", readiness=false. Elapsed: 10.339795938s
Sep 29 07:09:34.685: INFO: Pod "pvc-snapshottable-tester-xkllv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.397227495s
STEP: Saw pod success
Sep 29 07:09:34.685: INFO: Pod "pvc-snapshottable-tester-xkllv" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep 29 07:09:34.741: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com26h2l] to have phase Bound
Sep 29 07:09:34.797: INFO: PersistentVolumeClaim test.csi.azure.com26h2l found and phase=Bound (55.519021ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep 29 07:09:34.965: INFO: Pod pvc-snapshottable-tester-xkllv has the following logs: 
... skipping 80 lines ...
Sep 29 07:09:19.436: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:09:19.493: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comvwk55] to have phase Bound
Sep 29 07:09:19.548: INFO: PersistentVolumeClaim test.csi.azure.comvwk55 found but phase is Pending instead of Bound.
Sep 29 07:09:21.606: INFO: PersistentVolumeClaim test.csi.azure.comvwk55 found and phase=Bound (2.112597354s)
STEP: Creating pod pod-subpath-test-dynamicpv-whg5
STEP: Creating a pod to test subpath
Sep 29 07:09:21.776: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-whg5" in namespace "provisioning-6138" to be "Succeeded or Failed"
Sep 29 07:09:21.842: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Pending", Reason="", readiness=false. Elapsed: 65.827686ms
Sep 29 07:09:23.900: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.123427074s
Sep 29 07:09:25.956: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.179541196s
Sep 29 07:09:28.013: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.23654745s
Sep 29 07:09:30.070: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.293235453s
STEP: Saw pod success
Sep 29 07:09:30.070: INFO: Pod "pod-subpath-test-dynamicpv-whg5" satisfied condition "Succeeded or Failed"
Sep 29 07:09:30.125: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000001 pod pod-subpath-test-dynamicpv-whg5 container test-container-subpath-dynamicpv-whg5: <nil>
STEP: delete the pod
Sep 29 07:09:30.506: INFO: Waiting for pod pod-subpath-test-dynamicpv-whg5 to disappear
Sep 29 07:09:30.562: INFO: Pod pod-subpath-test-dynamicpv-whg5 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-whg5
Sep 29 07:09:30.562: INFO: Deleting pod "pod-subpath-test-dynamicpv-whg5" in namespace "provisioning-6138"
STEP: Creating pod pod-subpath-test-dynamicpv-whg5
STEP: Creating a pod to test subpath
Sep 29 07:09:30.675: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-whg5" in namespace "provisioning-6138" to be "Succeeded or Failed"
Sep 29 07:09:30.732: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Pending", Reason="", readiness=false. Elapsed: 56.859317ms
Sep 29 07:09:32.789: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113832854s
Sep 29 07:09:34.846: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.17081264s
Sep 29 07:09:36.902: INFO: Pod "pod-subpath-test-dynamicpv-whg5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.226778757s
STEP: Saw pod success
Sep 29 07:09:36.902: INFO: Pod "pod-subpath-test-dynamicpv-whg5" satisfied condition "Succeeded or Failed"
Sep 29 07:09:36.959: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000001 pod pod-subpath-test-dynamicpv-whg5 container test-container-subpath-dynamicpv-whg5: <nil>
STEP: delete the pod
Sep 29 07:09:37.076: INFO: Waiting for pod pod-subpath-test-dynamicpv-whg5 to disappear
Sep 29 07:09:37.131: INFO: Pod pod-subpath-test-dynamicpv-whg5 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-whg5
Sep 29 07:09:37.131: INFO: Deleting pod "pod-subpath-test-dynamicpv-whg5" in namespace "provisioning-6138"
... 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":26,"completed":2,"skipped":89,"failed":0}
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:09:42.637: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
[AfterEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow]
  test/e2e/framework/framework.go:188

... skipping 267 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":34,"completed":1,"skipped":267,"failed":0}

SSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:09:44.476: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 79 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":37,"completed":1,"skipped":363,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:09:48.568: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 83 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 6 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 256 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.002 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 21 lines ...
Sep 29 07:09:36.784: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:09:36.841: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comf5vvm] to have phase Bound
Sep 29 07:09:36.897: INFO: PersistentVolumeClaim test.csi.azure.comf5vvm found but phase is Pending instead of Bound.
Sep 29 07:09:38.954: INFO: PersistentVolumeClaim test.csi.azure.comf5vvm found and phase=Bound (2.112975066s)
STEP: Creating pod pod-subpath-test-dynamicpv-g2zb
STEP: Creating a pod to test multi_subpath
Sep 29 07:09:39.123: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-g2zb" in namespace "provisioning-1727" to be "Succeeded or Failed"
Sep 29 07:09:39.178: INFO: Pod "pod-subpath-test-dynamicpv-g2zb": Phase="Pending", Reason="", readiness=false. Elapsed: 55.463353ms
Sep 29 07:09:41.235: INFO: Pod "pod-subpath-test-dynamicpv-g2zb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.112222968s
Sep 29 07:09:43.296: INFO: Pod "pod-subpath-test-dynamicpv-g2zb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.173518035s
Sep 29 07:09:45.354: INFO: Pod "pod-subpath-test-dynamicpv-g2zb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.231221584s
STEP: Saw pod success
Sep 29 07:09:45.354: INFO: Pod "pod-subpath-test-dynamicpv-g2zb" satisfied condition "Succeeded or Failed"
Sep 29 07:09:45.411: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000001 pod pod-subpath-test-dynamicpv-g2zb container test-container-subpath-dynamicpv-g2zb: <nil>
STEP: delete the pod
Sep 29 07:09:45.528: INFO: Waiting for pod pod-subpath-test-dynamicpv-g2zb to disappear
Sep 29 07:09:45.583: INFO: Pod pod-subpath-test-dynamicpv-g2zb no longer exists
STEP: Deleting pod
Sep 29 07:09:45.583: INFO: Deleting pod "pod-subpath-test-dynamicpv-g2zb" in namespace "provisioning-1727"
... 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":33,"completed":2,"skipped":231,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 53 lines ...
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep 29 07:09:51.994: INFO: >>> kubeConfig: /root/tmp1144668373/kubeconfig/kubeconfig.westus2.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
Sep 29 07:09:52.385: 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
Sep 29 07:09:52.386: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-4286" for this suite.


S [SKIPPING] [0.513 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 42 lines ...
Sep 29 07:09:43.198: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:09:43.255: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comzg7c4] to have phase Bound
Sep 29 07:09:43.311: INFO: PersistentVolumeClaim test.csi.azure.comzg7c4 found but phase is Pending instead of Bound.
Sep 29 07:09:45.377: INFO: PersistentVolumeClaim test.csi.azure.comzg7c4 found and phase=Bound (2.121804299s)
STEP: Creating pod pod-subpath-test-dynamicpv-jm6h
STEP: Creating a pod to test subpath
Sep 29 07:09:45.544: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-jm6h" in namespace "provisioning-4602" to be "Succeeded or Failed"
Sep 29 07:09:45.601: INFO: Pod "pod-subpath-test-dynamicpv-jm6h": Phase="Pending", Reason="", readiness=false. Elapsed: 56.492056ms
Sep 29 07:09:47.658: INFO: Pod "pod-subpath-test-dynamicpv-jm6h": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113322988s
Sep 29 07:09:49.714: INFO: Pod "pod-subpath-test-dynamicpv-jm6h": Phase="Pending", Reason="", readiness=false. Elapsed: 4.169519635s
Sep 29 07:09:51.770: INFO: Pod "pod-subpath-test-dynamicpv-jm6h": Phase="Pending", Reason="", readiness=false. Elapsed: 6.225903576s
Sep 29 07:09:53.827: INFO: Pod "pod-subpath-test-dynamicpv-jm6h": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.282987947s
STEP: Saw pod success
Sep 29 07:09:53.828: INFO: Pod "pod-subpath-test-dynamicpv-jm6h" satisfied condition "Succeeded or Failed"
Sep 29 07:09:53.883: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000001 pod pod-subpath-test-dynamicpv-jm6h container test-container-subpath-dynamicpv-jm6h: <nil>
STEP: delete the pod
Sep 29 07:09:54.004: INFO: Waiting for pod pod-subpath-test-dynamicpv-jm6h to disappear
Sep 29 07:09:54.060: INFO: Pod pod-subpath-test-dynamicpv-jm6h no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-jm6h
Sep 29 07:09:54.060: INFO: Deleting pod "pod-subpath-test-dynamicpv-jm6h" in namespace "provisioning-4602"
... 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":26,"completed":3,"skipped":140,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:09:59.615: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 136 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":38,"completed":2,"skipped":251,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should support readOnly file specified in the volumeMount [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:382
... skipping 16 lines ...
Sep 29 07:09:45.083: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:09:45.146: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.coms4l7j] to have phase Bound
Sep 29 07:09:45.202: INFO: PersistentVolumeClaim test.csi.azure.coms4l7j found but phase is Pending instead of Bound.
Sep 29 07:09:47.258: INFO: PersistentVolumeClaim test.csi.azure.coms4l7j found and phase=Bound (2.112771077s)
STEP: Creating pod pod-subpath-test-dynamicpv-cdkf
STEP: Creating a pod to test subpath
Sep 29 07:09:47.432: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-cdkf" in namespace "provisioning-3285" to be "Succeeded or Failed"
Sep 29 07:09:47.493: INFO: Pod "pod-subpath-test-dynamicpv-cdkf": Phase="Pending", Reason="", readiness=false. Elapsed: 60.854015ms
Sep 29 07:09:49.555: INFO: Pod "pod-subpath-test-dynamicpv-cdkf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.122506179s
Sep 29 07:09:51.612: INFO: Pod "pod-subpath-test-dynamicpv-cdkf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.180002252s
Sep 29 07:09:53.672: INFO: Pod "pod-subpath-test-dynamicpv-cdkf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.239971726s
Sep 29 07:09:55.731: INFO: Pod "pod-subpath-test-dynamicpv-cdkf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.299066558s
Sep 29 07:09:57.791: INFO: Pod "pod-subpath-test-dynamicpv-cdkf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.358602021s
STEP: Saw pod success
Sep 29 07:09:57.791: INFO: Pod "pod-subpath-test-dynamicpv-cdkf" satisfied condition "Succeeded or Failed"
Sep 29 07:09:57.847: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000000 pod pod-subpath-test-dynamicpv-cdkf container test-container-subpath-dynamicpv-cdkf: <nil>
STEP: delete the pod
Sep 29 07:09:57.967: INFO: Waiting for pod pod-subpath-test-dynamicpv-cdkf to disappear
Sep 29 07:09:58.023: INFO: Pod pod-subpath-test-dynamicpv-cdkf no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-cdkf
Sep 29 07:09:58.023: INFO: Deleting pod "pod-subpath-test-dynamicpv-cdkf" in namespace "provisioning-3285"
... 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":2,"skipped":356,"failed":0}
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:03.542: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
[AfterEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
  test/e2e/framework/framework.go:188

... skipping 62 lines ...

    test/e2e/storage/testsuites/volume_expand.go:99
------------------------------
SSSSSSSSSSSSSSSSSSSSS
------------------------------
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
Sep 29 07:09:52.623: INFO: >>> kubeConfig: /root/tmp1144668373/kubeconfig/kubeconfig.westus2.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
Sep 29 07:09:53.029: INFO: Creating resource for dynamic PV
Sep 29 07:09:53.029: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-3052-e2e-sckkrl9
STEP: creating a claim
Sep 29 07:09:53.085: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:09:53.142: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com5djmt] to have phase Bound
Sep 29 07:09:53.198: INFO: PersistentVolumeClaim test.csi.azure.com5djmt found but phase is Pending instead of Bound.
Sep 29 07:09:55.255: INFO: PersistentVolumeClaim test.csi.azure.com5djmt found and phase=Bound (2.111983917s)
STEP: Creating pod pod-subpath-test-dynamicpv-wc2r
STEP: Checking for subpath error in container status
Sep 29 07:10:01.538: INFO: Deleting pod "pod-subpath-test-dynamicpv-wc2r" in namespace "provisioning-3052"
Sep 29 07:10:01.596: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-wc2r" to be fully deleted
STEP: Deleting pod
Sep 29 07:10:03.709: INFO: Deleting pod "pod-subpath-test-dynamicpv-wc2r" in namespace "provisioning-3052"
STEP: Deleting pvc
Sep 29 07:10:03.768: INFO: Deleting PersistentVolumeClaim "test.csi.azure.com5djmt"
... skipping 9 lines ...

• [SLOW TEST:16.538 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":33,"completed":3,"skipped":491,"failed":0}

SSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:09.178: INFO: Driver "test.csi.azure.com" does not support topology - 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 (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 91 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":32,"completed":2,"skipped":343,"failed":0}

SSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:23.450: INFO: Driver test.csi.azure.com doesn't support xfs -- skipping
... skipping 33 lines ...
Sep 29 07:10:09.740: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:10:09.798: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comt5ghk] to have phase Bound
Sep 29 07:10:09.854: INFO: PersistentVolumeClaim test.csi.azure.comt5ghk found but phase is Pending instead of Bound.
Sep 29 07:10:11.911: INFO: PersistentVolumeClaim test.csi.azure.comt5ghk found and phase=Bound (2.112620024s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep 29 07:10:12.136: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-qzwcc" in namespace "snapshotting-9214" to be "Succeeded or Failed"
Sep 29 07:10:12.192: INFO: Pod "pvc-snapshottable-tester-qzwcc": Phase="Pending", Reason="", readiness=false. Elapsed: 55.328786ms
Sep 29 07:10:14.248: INFO: Pod "pvc-snapshottable-tester-qzwcc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.111654573s
Sep 29 07:10:16.305: INFO: Pod "pvc-snapshottable-tester-qzwcc": Phase="Running", Reason="", readiness=false. Elapsed: 4.168899646s
Sep 29 07:10:18.363: INFO: Pod "pvc-snapshottable-tester-qzwcc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.226353068s
STEP: Saw pod success
Sep 29 07:10:18.363: INFO: Pod "pvc-snapshottable-tester-qzwcc" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep 29 07:10:18.428: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comt5ghk] to have phase Bound
Sep 29 07:10:18.483: INFO: PersistentVolumeClaim test.csi.azure.comt5ghk found and phase=Bound (55.214455ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep 29 07:10:18.652: INFO: Pod pvc-snapshottable-tester-qzwcc has the following logs: 
... skipping 184 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":37,"completed":2,"skipped":919,"failed":0}

SSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:28.398: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 136 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":38,"completed":3,"skipped":307,"failed":0}

SSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (xfs)][Slow] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:34.000: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 244 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":26,"completed":4,"skipped":191,"failed":0}

SSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:35.935: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 33 lines ...
Sep 29 07:10:23.942: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:10:24.001: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.coms6kbs] to have phase Bound
Sep 29 07:10:24.057: INFO: PersistentVolumeClaim test.csi.azure.coms6kbs found but phase is Pending instead of Bound.
Sep 29 07:10:26.115: INFO: PersistentVolumeClaim test.csi.azure.coms6kbs found and phase=Bound (2.114687522s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep 29 07:10:26.340: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-xzblt" in namespace "snapshotting-4375" to be "Succeeded or Failed"
Sep 29 07:10:26.397: INFO: Pod "pvc-snapshottable-tester-xzblt": Phase="Pending", Reason="", readiness=false. Elapsed: 56.011928ms
Sep 29 07:10:28.453: INFO: Pod "pvc-snapshottable-tester-xzblt": Phase="Running", Reason="", readiness=false. Elapsed: 2.112981945s
Sep 29 07:10:30.511: INFO: Pod "pvc-snapshottable-tester-xzblt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.170465549s
STEP: Saw pod success
Sep 29 07:10:30.511: INFO: Pod "pvc-snapshottable-tester-xzblt" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep 29 07:10:30.568: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.coms6kbs] to have phase Bound
Sep 29 07:10:30.623: INFO: PersistentVolumeClaim test.csi.azure.coms6kbs found and phase=Bound (55.798142ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep 29 07:10:30.796: INFO: Pod pvc-snapshottable-tester-xzblt has the following logs: 
... skipping 55 lines ...
Sep 29 07:10:28.941: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:10:28.999: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comr8tfb] to have phase Bound
Sep 29 07:10:29.059: INFO: PersistentVolumeClaim test.csi.azure.comr8tfb found but phase is Pending instead of Bound.
Sep 29 07:10:31.117: INFO: PersistentVolumeClaim test.csi.azure.comr8tfb found and phase=Bound (2.1182003s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep 29 07:10:31.346: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-7tz8d" in namespace "snapshotting-9419" to be "Succeeded or Failed"
Sep 29 07:10:31.403: INFO: Pod "pvc-snapshottable-tester-7tz8d": Phase="Pending", Reason="", readiness=false. Elapsed: 56.854055ms
Sep 29 07:10:33.460: INFO: Pod "pvc-snapshottable-tester-7tz8d": Phase="Pending", Reason="", readiness=false. Elapsed: 2.114185218s
Sep 29 07:10:35.519: INFO: Pod "pvc-snapshottable-tester-7tz8d": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.1724997s
STEP: Saw pod success
Sep 29 07:10:35.519: INFO: Pod "pvc-snapshottable-tester-7tz8d" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep 29 07:10:35.576: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comr8tfb] to have phase Bound
Sep 29 07:10:35.633: INFO: PersistentVolumeClaim test.csi.azure.comr8tfb found and phase=Bound (57.144268ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep 29 07:10:35.803: INFO: Pod pvc-snapshottable-tester-7tz8d has the following logs: 
... skipping 91 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":34,"completed":3,"skipped":437,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:43.989: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 245 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.002 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 101 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":38,"completed":4,"skipped":460,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable-stress[Feature:VolumeSnapshotDataSource]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:49.775: INFO: Driver test.csi.azure.com doesn't specify snapshot stress test options -- skipping
... skipping 13 lines ...

    test/e2e/storage/testsuites/snapshottable_stress.go:95
------------------------------
SSSSSSSSSS
------------------------------
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
Sep 29 07:10:36.039: INFO: >>> kubeConfig: /root/tmp1144668373/kubeconfig/kubeconfig.westus2.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
Sep 29 07:10:36.426: INFO: Creating resource for dynamic PV
Sep 29 07:10:36.426: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-1344-e2e-scc2666
STEP: creating a claim
Sep 29 07:10:36.482: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:10:36.538: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comsvjz2] to have phase Bound
Sep 29 07:10:36.593: INFO: PersistentVolumeClaim test.csi.azure.comsvjz2 found but phase is Pending instead of Bound.
Sep 29 07:10:38.650: INFO: PersistentVolumeClaim test.csi.azure.comsvjz2 found and phase=Bound (2.11149447s)
STEP: Creating pod pod-subpath-test-dynamicpv-h24b
STEP: Checking for subpath error in container status
Sep 29 07:10:42.931: INFO: Deleting pod "pod-subpath-test-dynamicpv-h24b" in namespace "provisioning-1344"
Sep 29 07:10:42.997: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-h24b" to be fully deleted
STEP: Deleting pod
Sep 29 07:10:45.108: INFO: Deleting pod "pod-subpath-test-dynamicpv-h24b" in namespace "provisioning-1344"
STEP: Deleting pvc
Sep 29 07:10:45.163: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comsvjz2"
... skipping 9 lines ...

• [SLOW TEST:14.518 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":26,"completed":5,"skipped":251,"failed":0}

SS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:50.564: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 70 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":41,"completed":3,"skipped":546,"failed":0}

SSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:10:50.749: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 37 lines ...
Sep 29 07:10:36.939: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:10:36.997: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comg9f6c] to have phase Bound
Sep 29 07:10:37.053: INFO: PersistentVolumeClaim test.csi.azure.comg9f6c found but phase is Pending instead of Bound.
Sep 29 07:10:39.110: INFO: PersistentVolumeClaim test.csi.azure.comg9f6c found and phase=Bound (2.11236604s)
STEP: Creating pod pod-subpath-test-dynamicpv-s6fq
STEP: Creating a pod to test subpath
Sep 29 07:10:39.278: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-s6fq" in namespace "provisioning-5100" to be "Succeeded or Failed"
Sep 29 07:10:39.334: INFO: Pod "pod-subpath-test-dynamicpv-s6fq": Phase="Pending", Reason="", readiness=false. Elapsed: 56.651387ms
Sep 29 07:10:41.392: INFO: Pod "pod-subpath-test-dynamicpv-s6fq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113947952s
Sep 29 07:10:43.451: INFO: Pod "pod-subpath-test-dynamicpv-s6fq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.173508585s
Sep 29 07:10:45.509: INFO: Pod "pod-subpath-test-dynamicpv-s6fq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.230956601s
STEP: Saw pod success
Sep 29 07:10:45.509: INFO: Pod "pod-subpath-test-dynamicpv-s6fq" satisfied condition "Succeeded or Failed"
Sep 29 07:10:45.565: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000001 pod pod-subpath-test-dynamicpv-s6fq container test-container-subpath-dynamicpv-s6fq: <nil>
STEP: delete the pod
Sep 29 07:10:45.684: INFO: Waiting for pod pod-subpath-test-dynamicpv-s6fq to disappear
Sep 29 07:10:45.739: INFO: Pod pod-subpath-test-dynamicpv-s6fq no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-s6fq
Sep 29 07:10:45.739: INFO: Deleting pod "pod-subpath-test-dynamicpv-s6fq" in namespace "provisioning-5100"
... 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":32,"completed":3,"skipped":442,"failed":0}

SSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 116 lines ...
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep 29 07:10:52.026: INFO: >>> kubeConfig: /root/tmp1144668373/kubeconfig/kubeconfig.westus2.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
Sep 29 07:10:52.420: 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
Sep 29 07:10:52.422: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-7975" for this suite.


S [SKIPPING] [0.509 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 72 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
Sep 29 07:10:50.180: INFO: Creating resource for dynamic PV
Sep 29 07:10:50.180: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-2654-e2e-scvrfwj
STEP: [init] starting a pod to use the claim
Sep 29 07:10:50.294: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-42zmc" in namespace "snapshotting-2654" to be "Succeeded or Failed"
Sep 29 07:10:50.350: INFO: Pod "pvc-snapshottable-tester-42zmc": Phase="Pending", Reason="", readiness=false. Elapsed: 55.523755ms
Sep 29 07:10:52.407: INFO: Pod "pvc-snapshottable-tester-42zmc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.112325166s
Sep 29 07:10:54.464: INFO: Pod "pvc-snapshottable-tester-42zmc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.169724125s
Sep 29 07:10:56.521: INFO: Pod "pvc-snapshottable-tester-42zmc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.226624344s
Sep 29 07:10:58.582: INFO: Pod "pvc-snapshottable-tester-42zmc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.287884162s
STEP: Saw pod success
Sep 29 07:10:58.583: INFO: Pod "pvc-snapshottable-tester-42zmc" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
Sep 29 07:10:58.638: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
Sep 29 07:10:58.639: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-42zmc-my-volume] to have phase Bound
Sep 29 07:10:58.695: INFO: PersistentVolumeClaim pvc-snapshottable-tester-42zmc-my-volume found and phase=Bound (55.384044ms)
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: 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 92 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 18 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSS
------------------------------
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
STEP: Creating a kubernetes client
Sep 29 07:10:45.952: INFO: >>> kubeConfig: /root/tmp1144668373/kubeconfig/kubeconfig.westus2.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 non-existent subpath is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:269
Sep 29 07:10:46.363: INFO: Creating resource for dynamic PV
Sep 29 07:10:46.363: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-8433-e2e-scgcx55
STEP: creating a claim
Sep 29 07:10:46.420: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:10:46.478: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comtn9k5] to have phase Bound
Sep 29 07:10:46.535: INFO: PersistentVolumeClaim test.csi.azure.comtn9k5 found but phase is Pending instead of Bound.
Sep 29 07:10:48.593: INFO: PersistentVolumeClaim test.csi.azure.comtn9k5 found and phase=Bound (2.114557843s)
STEP: Creating pod pod-subpath-test-dynamicpv-5rm4
STEP: Checking for subpath error in container status
Sep 29 07:10:52.882: INFO: Deleting pod "pod-subpath-test-dynamicpv-5rm4" in namespace "provisioning-8433"
Sep 29 07:10:52.940: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-5rm4" to be fully deleted
STEP: Deleting pod
Sep 29 07:10:55.054: INFO: Deleting pod "pod-subpath-test-dynamicpv-5rm4" in namespace "provisioning-8433"
STEP: Deleting pvc
Sep 29 07:10:55.111: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comtn9k5"
... skipping 9 lines ...

• [SLOW TEST:14.556 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":34,"completed":4,"skipped":868,"failed":0}

SSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (ntfs)][Feature:Windows] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:11:00.552: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - 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-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":33,"completed":4,"skipped":792,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:11:06.797: 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 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 8 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.002 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 29 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.002 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 19 lines ...
Sep 29 07:10:51.271: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:10:51.331: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com5l42h] to have phase Bound
Sep 29 07:10:51.386: INFO: PersistentVolumeClaim test.csi.azure.com5l42h found but phase is Pending instead of Bound.
Sep 29 07:10:53.443: INFO: PersistentVolumeClaim test.csi.azure.com5l42h found and phase=Bound (2.112433306s)
STEP: Creating pod exec-volume-test-dynamicpv-9z7g
STEP: Creating a pod to test exec-volume-test
Sep 29 07:10:53.612: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-9z7g" in namespace "volume-4214" to be "Succeeded or Failed"
Sep 29 07:10:53.668: INFO: Pod "exec-volume-test-dynamicpv-9z7g": Phase="Pending", Reason="", readiness=false. Elapsed: 55.334506ms
Sep 29 07:10:55.729: INFO: Pod "exec-volume-test-dynamicpv-9z7g": Phase="Pending", Reason="", readiness=false. Elapsed: 2.116231883s
Sep 29 07:10:57.785: INFO: Pod "exec-volume-test-dynamicpv-9z7g": Phase="Pending", Reason="", readiness=false. Elapsed: 4.172294346s
Sep 29 07:10:59.840: INFO: Pod "exec-volume-test-dynamicpv-9z7g": Phase="Pending", Reason="", readiness=false. Elapsed: 6.228096315s
Sep 29 07:11:01.897: INFO: Pod "exec-volume-test-dynamicpv-9z7g": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.284284603s
STEP: Saw pod success
Sep 29 07:11:01.897: INFO: Pod "exec-volume-test-dynamicpv-9z7g" satisfied condition "Succeeded or Failed"
Sep 29 07:11:01.953: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000001 pod exec-volume-test-dynamicpv-9z7g container exec-container-dynamicpv-9z7g: <nil>
STEP: delete the pod
Sep 29 07:11:02.073: INFO: Waiting for pod exec-volume-test-dynamicpv-9z7g to disappear
Sep 29 07:11:02.128: INFO: Pod exec-volume-test-dynamicpv-9z7g no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-9z7g
Sep 29 07:11:02.128: INFO: Deleting pod "exec-volume-test-dynamicpv-9z7g" in namespace "volume-4214"
... 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":41,"completed":4,"skipped":594,"failed":0}

SSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:11:07.603: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 76 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 202 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[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 (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":26,"completed":6,"skipped":274,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:11:11.532: INFO: Driver test.csi.azure.com doesn't support ext4 -- skipping
... skipping 117 lines ...
Sep 29 07:11:01.091: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:11:01.148: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comxgmbg] to have phase Bound
Sep 29 07:11:01.205: INFO: PersistentVolumeClaim test.csi.azure.comxgmbg found but phase is Pending instead of Bound.
Sep 29 07:11:03.262: INFO: PersistentVolumeClaim test.csi.azure.comxgmbg found and phase=Bound (2.114064509s)
STEP: Creating pod pod-subpath-test-dynamicpv-klqb
STEP: Creating a pod to test atomic-volume-subpath
Sep 29 07:11:03.433: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-klqb" in namespace "provisioning-3335" to be "Succeeded or Failed"
Sep 29 07:11:03.490: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Pending", Reason="", readiness=false. Elapsed: 56.672159ms
Sep 29 07:11:05.556: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.122415263s
Sep 29 07:11:07.613: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Running", Reason="", readiness=true. Elapsed: 4.179595049s
Sep 29 07:11:09.671: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Running", Reason="", readiness=true. Elapsed: 6.237584141s
Sep 29 07:11:11.729: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Running", Reason="", readiness=true. Elapsed: 8.295521318s
Sep 29 07:11:13.786: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Running", Reason="", readiness=true. Elapsed: 10.352658119s
... skipping 3 lines ...
Sep 29 07:11:22.019: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Running", Reason="", readiness=true. Elapsed: 18.586057851s
Sep 29 07:11:24.078: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Running", Reason="", readiness=true. Elapsed: 20.644494768s
Sep 29 07:11:26.136: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Running", Reason="", readiness=true. Elapsed: 22.702476424s
Sep 29 07:11:28.193: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Running", Reason="", readiness=false. Elapsed: 24.759410726s
Sep 29 07:11:30.250: INFO: Pod "pod-subpath-test-dynamicpv-klqb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.816307777s
STEP: Saw pod success
Sep 29 07:11:30.250: INFO: Pod "pod-subpath-test-dynamicpv-klqb" satisfied condition "Succeeded or Failed"
Sep 29 07:11:30.306: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000000 pod pod-subpath-test-dynamicpv-klqb container test-container-subpath-dynamicpv-klqb: <nil>
STEP: delete the pod
Sep 29 07:11:30.432: INFO: Waiting for pod pod-subpath-test-dynamicpv-klqb to disappear
Sep 29 07:11:30.490: INFO: Pod pod-subpath-test-dynamicpv-klqb no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-klqb
Sep 29 07:11:30.490: INFO: Deleting pod "pod-subpath-test-dynamicpv-klqb" in namespace "provisioning-3335"
... 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":34,"completed":5,"skipped":924,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Pre-provisioned Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 54 lines ...
Sep 29 07:11:13.091: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:11:13.148: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comtzk22] to have phase Bound
Sep 29 07:11:13.204: INFO: PersistentVolumeClaim test.csi.azure.comtzk22 found but phase is Pending instead of Bound.
Sep 29 07:11:15.262: INFO: PersistentVolumeClaim test.csi.azure.comtzk22 found and phase=Bound (2.113820767s)
STEP: Expanding non-expandable pvc
Sep 29 07:11:15.373: INFO: currentPvcSize {{5368709120 0} {<nil>} 5Gi BinarySI}, newSize {{6442450944 0} {<nil>}  BinarySI}
Sep 29 07:11:15.484: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:17.595: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:19.597: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:21.597: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:23.596: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:25.599: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:27.595: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:29.596: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:31.597: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:33.596: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:35.598: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:37.600: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:39.596: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:41.603: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:43.598: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:45.595: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 29 07:11:45.706: INFO: Error updating pvc test.csi.azure.comtzk22: persistentvolumeclaims "test.csi.azure.comtzk22" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
Sep 29 07:11:45.706: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comtzk22"
Sep 29 07:11:45.762: INFO: Waiting up to 5m0s for PersistentVolume pvc-8254e42d-758d-426e-9309-ab90e70e9ba4 to get deleted
Sep 29 07:11:45.817: INFO: PersistentVolume pvc-8254e42d-758d-426e-9309-ab90e70e9ba4 found and phase=Released (54.654321ms)
Sep 29 07:11:50.874: INFO: PersistentVolume pvc-8254e42d-758d-426e-9309-ab90e70e9ba4 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":26,"completed":7,"skipped":650,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:11:51.207: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
... skipping 45 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 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: 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 155 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":34,"completed":6,"skipped":982,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
Sep 29 07:11:53.051: INFO: Running AfterSuite actions on all nodes
Sep 29 07:11:53.051: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func19.2
Sep 29 07:11:53.051: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func9.2
... skipping 66 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":32,"completed":4,"skipped":684,"failed":0}

SSSSSSSSSSSS
------------------------------
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
  test/e2e/storage/testsuites/ephemeral.go:216
... skipping 49 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":41,"completed":5,"skipped":628,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:12:24.905: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 195 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":38,"completed":5,"skipped":694,"failed":0}

SSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:12:26.232: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 126 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the volume contents","total":38,"completed":6,"skipped":739,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy 
  (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with same fsgroup skips ownership changes to the volume contents
  test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
... skipping 105 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with same fsgroup skips ownership changes to the volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with same fsgroup skips ownership changes to the volume contents","total":41,"completed":6,"skipped":807,"failed":0}

SSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:12:51.845: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 205 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
Sep 29 07:12:50.905: INFO: Creating resource for dynamic PV
Sep 29 07:12:50.905: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-794-e2e-scrfq99
STEP: [init] starting a pod to use the claim
Sep 29 07:12:51.018: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-bxp2q" in namespace "snapshotting-794" to be "Succeeded or Failed"
Sep 29 07:12:51.078: INFO: Pod "pvc-snapshottable-tester-bxp2q": Phase="Pending", Reason="", readiness=false. Elapsed: 59.880639ms
Sep 29 07:12:53.135: INFO: Pod "pvc-snapshottable-tester-bxp2q": Phase="Pending", Reason="", readiness=false. Elapsed: 2.116692563s
Sep 29 07:12:55.191: INFO: Pod "pvc-snapshottable-tester-bxp2q": Phase="Pending", Reason="", readiness=false. Elapsed: 4.172915149s
Sep 29 07:12:57.247: INFO: Pod "pvc-snapshottable-tester-bxp2q": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.228677075s
STEP: Saw pod success
Sep 29 07:12:57.247: INFO: Pod "pvc-snapshottable-tester-bxp2q" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
Sep 29 07:12:57.302: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
Sep 29 07:12:57.303: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-bxp2q-my-volume] to have phase Bound
Sep 29 07:12:57.358: INFO: PersistentVolumeClaim pvc-snapshottable-tester-bxp2q-my-volume found and phase=Bound (54.994198ms)
STEP: [init] checking the PV
... 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 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":32,"completed":5,"skipped":696,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:13:03.605: INFO: Driver test.csi.azure.com doesn't support ext4 -- skipping
... skipping 205 lines ...
Sep 29 07:12:58.285: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:12:58.341: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com7pc7l] to have phase Bound
Sep 29 07:12:58.396: INFO: PersistentVolumeClaim test.csi.azure.com7pc7l found but phase is Pending instead of Bound.
Sep 29 07:13:00.451: INFO: PersistentVolumeClaim test.csi.azure.com7pc7l found and phase=Bound (2.110158288s)
STEP: Creating pod pod-subpath-test-dynamicpv-2b9n
STEP: Creating a pod to test subpath
Sep 29 07:13:00.618: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-2b9n" in namespace "provisioning-1316" to be "Succeeded or Failed"
Sep 29 07:13:00.673: INFO: Pod "pod-subpath-test-dynamicpv-2b9n": Phase="Pending", Reason="", readiness=false. Elapsed: 54.943075ms
Sep 29 07:13:02.730: INFO: Pod "pod-subpath-test-dynamicpv-2b9n": Phase="Pending", Reason="", readiness=false. Elapsed: 2.112151857s
Sep 29 07:13:04.786: INFO: Pod "pod-subpath-test-dynamicpv-2b9n": Phase="Pending", Reason="", readiness=false. Elapsed: 4.167792385s
Sep 29 07:13:06.842: INFO: Pod "pod-subpath-test-dynamicpv-2b9n": Phase="Pending", Reason="", readiness=false. Elapsed: 6.224094051s
Sep 29 07:13:08.898: INFO: Pod "pod-subpath-test-dynamicpv-2b9n": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.279780773s
STEP: Saw pod success
Sep 29 07:13:08.898: INFO: Pod "pod-subpath-test-dynamicpv-2b9n" satisfied condition "Succeeded or Failed"
Sep 29 07:13:08.953: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000001 pod pod-subpath-test-dynamicpv-2b9n container test-container-volume-dynamicpv-2b9n: <nil>
STEP: delete the pod
Sep 29 07:13:09.069: INFO: Waiting for pod pod-subpath-test-dynamicpv-2b9n to disappear
Sep 29 07:13:09.123: INFO: Pod pod-subpath-test-dynamicpv-2b9n no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-2b9n
Sep 29 07:13:09.123: INFO: Deleting pod "pod-subpath-test-dynamicpv-2b9n" in namespace "provisioning-1316"
... 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":38,"completed":7,"skipped":820,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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
Sep 29 07:13:14.665: INFO: >>> kubeConfig: /root/tmp1144668373/kubeconfig/kubeconfig.westus2.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
Sep 29 07:13:15.326: INFO: Deleting PersistentVolumeClaim "pvc-7j7ll"
STEP: Deleting sc
[AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:188
Sep 29 07:13:15.437: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-9300" 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":38,"completed":8,"skipped":858,"failed":0}

SSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)(allowExpansion)][Feature:Windows] volume-expand
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:13:15.573: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 37 lines ...
Sep 29 07:13:16.017: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 29 07:13:16.074: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com9jktl] to have phase Bound
Sep 29 07:13:16.128: INFO: PersistentVolumeClaim test.csi.azure.com9jktl found but phase is Pending instead of Bound.
Sep 29 07:13:18.184: INFO: PersistentVolumeClaim test.csi.azure.com9jktl found and phase=Bound (2.109873087s)
STEP: Creating pod pod-subpath-test-dynamicpv-tq85
STEP: Creating a pod to test subpath
Sep 29 07:13:18.350: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-tq85" in namespace "provisioning-1516" to be "Succeeded or Failed"
Sep 29 07:13:18.405: INFO: Pod "pod-subpath-test-dynamicpv-tq85": Phase="Pending", Reason="", readiness=false. Elapsed: 54.979392ms
Sep 29 07:13:20.461: INFO: Pod "pod-subpath-test-dynamicpv-tq85": Phase="Pending", Reason="", readiness=false. Elapsed: 2.111276393s
Sep 29 07:13:22.518: INFO: Pod "pod-subpath-test-dynamicpv-tq85": Phase="Pending", Reason="", readiness=false. Elapsed: 4.168201481s
Sep 29 07:13:24.575: INFO: Pod "pod-subpath-test-dynamicpv-tq85": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.225050686s
STEP: Saw pod success
Sep 29 07:13:24.575: INFO: Pod "pod-subpath-test-dynamicpv-tq85" satisfied condition "Succeeded or Failed"
Sep 29 07:13:24.630: INFO: Trying to get logs from node k8s-agentpool1-32901493-vmss000001 pod pod-subpath-test-dynamicpv-tq85 container test-container-volume-dynamicpv-tq85: <nil>
STEP: delete the pod
Sep 29 07:13:24.747: INFO: Waiting for pod pod-subpath-test-dynamicpv-tq85 to disappear
Sep 29 07:13:24.802: INFO: Pod pod-subpath-test-dynamicpv-tq85 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-tq85
Sep 29 07:13:24.802: INFO: Deleting pod "pod-subpath-test-dynamicpv-tq85" in namespace "provisioning-1516"
... 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":38,"completed":9,"skipped":876,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep 29 07:13:30.350: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 85 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":38,"completed":10,"skipped":938,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
... skipping 144 lines ...
Sep 29 07:20:37.217: INFO: Waiting for pod external-client to disappear
Sep 29 07:20:37.277: INFO: Pod external-client still exists
Sep 29 07:20:39.218: INFO: Waiting for pod external-client to disappear
Sep 29 07:20:39.277: INFO: Pod external-client still exists
Sep 29 07:20:41.218: INFO: Waiting for pod external-client to disappear
Sep 29 07:20:41.275: INFO: Pod external-client no longer exists
Sep 29 07:20:41.275: FAIL: Failed to create client pod: timed out waiting for the condition

Full Stack Trace
k8s.io/kubernetes/test/e2e/framework/volume.TestVolumeClient(...)
	test/e2e/framework/volume/fixtures.go:580
k8s.io/kubernetes/test/e2e/storage/testsuites.(*volumesTestSuite).DefineTests.func3()
	test/e2e/storage/testsuites/volumes.go:190 +0x525
... skipping 23 lines ...
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:13:50 +0000 UTC - event for external-injector: {kubelet k8s-agentpool1-32901493-vmss000001} Pulling: Pulling image "k8s.gcr.io/e2e-test-images/busybox:1.29-2"
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:13:51 +0000 UTC - event for external-injector: {kubelet k8s-agentpool1-32901493-vmss000001} Started: Started container external-injector
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:13:51 +0000 UTC - event for external-injector: {kubelet k8s-agentpool1-32901493-vmss000001} Created: Created container external-injector
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:13:51 +0000 UTC - event for external-injector: {kubelet k8s-agentpool1-32901493-vmss000001} Pulled: Successfully pulled image "k8s.gcr.io/e2e-test-images/busybox:1.29-2" in 251.511399ms
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:13:54 +0000 UTC - event for external-injector: {kubelet k8s-agentpool1-32901493-vmss000001} Killing: Stopping container external-injector
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:13:58 +0000 UTC - event for external-client: {default-scheduler } Scheduled: Successfully assigned volume-5888/external-client to k8s-agentpool1-32901493-vmss000001
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:15:59 +0000 UTC - event for external-client: {kubelet k8s-agentpool1-32901493-vmss000001} FailedMount: MountVolume.MountDevice failed for volume "pvc-984bac43-321c-45c6-b32a-470bf9895d27" : rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:15:59 +0000 UTC - event for external-client: {kubelet k8s-agentpool1-32901493-vmss000001} FailedMount: MountVolume.MountDevice failed for volume "pvc-984bac43-321c-45c6-b32a-470bf9895d27" : rpc error: code = DeadlineExceeded desc = context deadline exceeded
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:16:01 +0000 UTC - event for external-client: {kubelet k8s-agentpool1-32901493-vmss000001} FailedMount: Unable to attach or mount volumes: unmounted volumes=[external-volume-0], unattached volumes=[external-volume-0 kube-api-access-2xst4]: timed out waiting for the condition
Sep 29 07:20:46.566: INFO: At 2022-09-29 07:20:37 +0000 UTC - event for external-client: {kubelet k8s-agentpool1-32901493-vmss000001} FailedMount: Unable to attach or mount volumes: unmounted volumes=[external-volume-0], unattached volumes=[kube-api-access-2xst4 external-volume-0]: timed out waiting for the condition
Sep 29 07:20:46.622: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Sep 29 07:20:46.622: INFO: 
Sep 29 07:20:46.733: INFO: 
Logging node info for node k8s-agentpool1-32901493-vmss000000
... skipping 95 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should store data [Measurement]
    test/e2e/storage/testsuites/volumes.go:161

    Sep 29 07:20:41.275: Failed to create client pod: timed out waiting for the condition

    test/e2e/framework/volume/fixtures.go:580
------------------------------
{"msg":"FAILED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should store data","total":38,"completed":10,"skipped":994,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should store data"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
Sep 29 07:20:48.204: INFO: Running AfterSuite actions on all nodes
Sep 29 07:20:48.204: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func19.2
Sep 29 07:20:48.204: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func9.2
... skipping 15 lines ...
Sep 29 07:20:48.256: INFO: Running AfterSuite actions on node 1



Summarizing 1 Failure:

[Fail] External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes [Measurement] should store data 
test/e2e/framework/volume/fixtures.go:580

Ran 41 of 7229 Specs in 772.990 seconds
FAIL! -- 40 Passed | 1 Failed | 0 Pending | 7188 Skipped 

Ginkgo ran 1 suite in 12m59.012498398s
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.19.1
Platform: linux/amd64

Streaming logs below:
I0929 07:07:44.939401       1 azurefile.go:289] driver userAgent: test.csi.azure.com/e2e-39436e4fb0516baa38523b851a9bc3e7f5359e5b e2e-test
I0929 07:07:44.939680       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:44.969890       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
I0929 07:07:44.969990       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:44.970050       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0929 07:07:44.970104       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0929 07:07:44.970728       1 azure_auth.go:245] Using AzurePublicCloud environment
I0929 07:07:44.970808       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0929 07:07:44.970868       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 847 lines ...
I0929 07:13:09.408141       1 azure_storage.go:69] share pvcn-06505caf-fc66-4dc3-bea3-53c357af5aff deleted
I0929 07:13:09.408167       1 controllerserver.go:606] azure file(pvcn-06505caf-fc66-4dc3-bea3-53c357af5aff) under subsID(0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e) rg(kubetest-ptenzx6x) account(f9bb862df5c4f4daca24030) volume(kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-06505caf-fc66-4dc3-bea3-53c357af5aff###provisioning-1316) is deleted successfully
I0929 07:13:09.408197       1 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.122865558 request="azurefile_csi_driver_controller_delete_volume" resource_group="kubetest-ptenzx6x" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="test.csi.azure.com" volumeid="kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-06505caf-fc66-4dc3-bea3-53c357af5aff###provisioning-1316" result_code="succeeded"
I0929 07:13:09.408209       1 utils.go:83] GRPC response: {}
I0929 07:13:15.141254       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0929 07:13:15.141266       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ea0dd122-8108-4ea2-98f8-a589225b7717","parameters":{"csi.storage.k8s.io/pv/name":"pvc-ea0dd122-8108-4ea2-98f8-a589225b7717","csi.storage.k8s.io/pvc/name":"pvc-7j7ll","csi.storage.k8s.io/pvc/namespace":"volumemode-9300","protocol":"nfs","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]}
E0929 07:13:15.141417       1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes
I0929 07:13:15.358583       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0929 07:13:15.358625       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ea0dd122-8108-4ea2-98f8-a589225b7717","parameters":{"csi.storage.k8s.io/pv/name":"pvc-ea0dd122-8108-4ea2-98f8-a589225b7717","csi.storage.k8s.io/pvc/name":"pvc-7j7ll","csi.storage.k8s.io/pvc/namespace":"volumemode-9300","protocol":"nfs","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]}
E0929 07:13:15.358742       1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes
I0929 07:13:16.053562       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0929 07:13:16.053580       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-206e1f6b-83bd-4f9a-a326-8514ac88e030","parameters":{"csi.storage.k8s.io/pv/name":"pvc-206e1f6b-83bd-4f9a-a326-8514ac88e030","csi.storage.k8s.io/pvc/name":"test.csi.azure.com9jktl","csi.storage.k8s.io/pvc/namespace":"provisioning-1516","protocol":"nfs","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{}},"access_mode":{"mode":7}}]}
I0929 07:13:16.053707       1 controllerserver.go:294] set vnetResourceID(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ptenzx6x/providers/Microsoft.Network/virtualNetworks/k8s-vnet-32901493/subnets/k8s-subnet) for NFS protocol
I0929 07:13:16.053713       1 azure.go:180] updateSubnetServiceEndpoints on vnetName: k8s-vnet-32901493, subnetName: k8s-subnet, location: westus2
I0929 07:13:16.155414       1 azure.go:209] serviceEndpoint(Microsoft.Storage) is already in subnet(k8s-subnet)
I0929 07:13:16.211636       1 controllerserver.go:449] begin to create file share(pvcn-206e1f6b-83bd-4f9a-a326-8514ac88e030) on account(f9bb862df5c4f4daca24030) type(Premium_LRS) subID() rg(kubetest-ptenzx6x) location() size(100) protocol(NFS)
... skipping 90 lines ...
Go Version: go1.19.1
Platform: linux/amd64

Streaming logs below:
I0929 07:07:45.612308       1 azurefile.go:289] driver userAgent: test.csi.azure.com/e2e-39436e4fb0516baa38523b851a9bc3e7f5359e5b e2e-test
I0929 07:07:45.612578       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:45.630437       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
I0929 07:07:45.630452       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:45.630457       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0929 07:07:45.630473       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0929 07:07:45.631001       1 azure_auth.go:245] Using AzurePublicCloud environment
I0929 07:07:45.631032       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0929 07:07:45.631051       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 105 lines ...
Go Version: go1.19.1
Platform: linux/amd64

Streaming logs below:
I0929 07:07:42.055550       1 azurefile.go:289] driver userAgent: test.csi.azure.com/e2e-39436e4fb0516baa38523b851a9bc3e7f5359e5b e2e-test
I0929 07:07:42.055837       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:42.072586       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
I0929 07:07:42.072601       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:42.072606       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0929 07:07:42.072628       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0929 07:07:42.073178       1 azure_auth.go:245] Using AzurePublicCloud environment
I0929 07:07:42.073263       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0929 07:07:42.073315       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 1426 lines ...
I0929 07:13:59.173588       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:13:59.173605       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
I0929 07:13:59.173706       1 nodeserver.go:302] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount) fstype() volumeID(kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888) context(map[csi.storage.k8s.io/pv/name:pvc-984bac43-321c-45c6-b32a-470bf9895d27 csi.storage.k8s.io/pvc/name:test.csi.azure.comn4sr6 csi.storage.k8s.io/pvc/namespace:volume-5888 protocol:nfs secretnamespace:volume-5888 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1664435265573-8081-test.csi.azure.com]) mountflags([]) mountOptions([vers=4,minorversion=1,sec=sys]) volumeMountGroup()
I0929 07:13:59.173963       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t nfs -o vers=4,minorversion=1,sec=sys f9bb862df5c4f4daca24030.file.core.windows.net:/f9bb862df5c4f4daca24030/pvcn-984bac43-321c-45c6-b32a-470bf9895d27 /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount)
I0929 07:15:59.762151       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:15:59.762166       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:15:59.762255       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:16:00.770344       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:16:00.770359       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:16:00.770441       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:16:02.782860       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:16:02.782874       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:16:02.782964       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:16:06.806749       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:16:06.806762       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:16:06.806843       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:16:14.860234       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:16:14.860249       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:16:14.860336       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:16:30.867653       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:16:30.867669       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:16:30.867905       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:17:02.884306       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:17:02.884322       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:17:02.884428       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:18:06.965548       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:18:06.965562       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:18:06.965648       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:20:09.019218       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:20:09.019234       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-984bac43-321c-45c6-b32a-470bf9895d27","csi.storage.k8s.io/pvc/name":"test.csi.azure.comn4sr6","csi.storage.k8s.io/pvc/namespace":"volume-5888","protocol":"nfs","secretnamespace":"volume-5888","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:20:09.019335       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:20:39.511375       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I0929 07:20:39.511392       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:20:39.511450       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:20:40.014405       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I0929 07:20:40.014421       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:20:40.014455       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:20:41.020740       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I0929 07:20:41.020754       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:20:41.020793       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:20:43.039185       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I0929 07:20:43.039199       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:20:43.039247       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:20:47.056788       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I0929 07:20:47.056804       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:20:47.056851       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
I0929 07:20:50.983508       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:20:50.983525       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/c1757e24cd39bf75a4f65bd6e116c3ab46ec6b45d17efb54b62b1cfb09398b7b/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":5}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1","csi.storage.k8s.io/pvc/name":"pvc-azurefile-ds","csi.storage.k8s.io/pvc/namespace":"default","secretnamespace":"default","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1###default"}
I0929 07:20:50.999563       1 nodeserver.go:302] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/c1757e24cd39bf75a4f65bd6e116c3ab46ec6b45d17efb54b62b1cfb09398b7b/globalmount) fstype() volumeID(kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1###default) context(map[csi.storage.k8s.io/pv/name:pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1 csi.storage.k8s.io/pvc/name:pvc-azurefile-ds csi.storage.k8s.io/pvc/namespace:default secretnamespace:default skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1664435265573-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()
I0929 07:20:50.999819       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> //f9bb862df5c4f4daca24030.file.core.windows.net/pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1 /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/c1757e24cd39bf75a4f65bd6e116c3ab46ec6b45d17efb54b62b1cfb09398b7b/globalmount)
I0929 07:20:51.130765       1 nodeserver.go:332] volume(kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1###default) mount //f9bb862df5c4f4daca24030.file.core.windows.net/pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1 on /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/c1757e24cd39bf75a4f65bd6e116c3ab46ec6b45d17efb54b62b1cfb09398b7b/globalmount succeeded
I0929 07:20:51.130787       1 utils.go:83] GRPC response: {}
... skipping 3 lines ...
I0929 07:20:51.141937       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/c1757e24cd39bf75a4f65bd6e116c3ab46ec6b45d17efb54b62b1cfb09398b7b/globalmount /var/lib/kubelet/pods/7ea6a94c-3b55-4c7e-8778-8fc871f7d904/volumes/kubernetes.io~csi/pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1/mount)
I0929 07:20:51.143389       1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind,remount /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/c1757e24cd39bf75a4f65bd6e116c3ab46ec6b45d17efb54b62b1cfb09398b7b/globalmount /var/lib/kubelet/pods/7ea6a94c-3b55-4c7e-8778-8fc871f7d904/volumes/kubernetes.io~csi/pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1/mount)
I0929 07:20:51.149623       1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/c1757e24cd39bf75a4f65bd6e116c3ab46ec6b45d17efb54b62b1cfb09398b7b/globalmount at /var/lib/kubelet/pods/7ea6a94c-3b55-4c7e-8778-8fc871f7d904/volumes/kubernetes.io~csi/pvc-834c4b9d-f61c-4568-bd57-81f9d3bcf4f1/mount successfully
I0929 07:20:51.149636       1 utils.go:83] GRPC response: {}
I0929 07:20:55.108002       1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume
I0929 07:20:55.108019       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount","volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888"}
E0929 07:20:55.108058       1 utils.go:81] GRPC error: rpc error: code = Aborted desc = An operation with the given Volume ID kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888 already exists
E0929 07:20:55.253763       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t nfs -o vers=4,minorversion=1,sec=sys f9bb862df5c4f4daca24030.file.core.windows.net:/f9bb862df5c4f4daca24030/pvcn-984bac43-321c-45c6-b32a-470bf9895d27 /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount
Output: mount.nfs: access denied by server while mounting f9bb862df5c4f4daca24030.file.core.windows.net:/f9bb862df5c4f4daca24030/pvcn-984bac43-321c-45c6-b32a-470bf9895d27

E0929 07:20:55.253795       1 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvcn-984bac43-321c-45c6-b32a-470bf9895d27###volume-5888) mount f9bb862df5c4f4daca24030.file.core.windows.net:/f9bb862df5c4f4daca24030/pvcn-984bac43-321c-45c6-b32a-470bf9895d27 on /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t nfs -o vers=4,minorversion=1,sec=sys f9bb862df5c4f4daca24030.file.core.windows.net:/f9bb862df5c4f4daca24030/pvcn-984bac43-321c-45c6-b32a-470bf9895d27 /var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/20a50a0797351c75337524ba576a4c567925cc02466e7f2dd27e61e94fff76ef/globalmount
Output: mount.nfs: access denied by server while mounting f9bb862df5c4f4daca24030.file.core.windows.net:/f9bb862df5c4f4daca24030/pvcn-984bac43-321c-45c6-b32a-470bf9895d27
I0929 07:20:58.025749       1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0929 07:20:58.025763       1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/9328b30c00e225a3286045e49dd6ec6c94bdbf8f1f27a93a3debc2cbf0727b7d/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":5}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-8540a7f1-b5e2-45ee-99c9-97ad22300ca2","csi.storage.k8s.io/pvc/name":"pvc-azurefile","csi.storage.k8s.io/pvc/namespace":"default","secretnamespace":"default","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1664435265573-8081-test.csi.azure.com"},"volume_id":"kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvc-8540a7f1-b5e2-45ee-99c9-97ad22300ca2###default"}
I0929 07:20:58.025905       1 nodeserver.go:302] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/test.csi.azure.com/9328b30c00e225a3286045e49dd6ec6c94bdbf8f1f27a93a3debc2cbf0727b7d/globalmount) fstype() volumeID(kubetest-ptenzx6x#f9bb862df5c4f4daca24030#pvc-8540a7f1-b5e2-45ee-99c9-97ad22300ca2###default) context(map[csi.storage.k8s.io/pv/name:pvc-8540a7f1-b5e2-45ee-99c9-97ad22300ca2 csi.storage.k8s.io/pvc/name:pvc-azurefile csi.storage.k8s.io/pvc/namespace:default secretnamespace:default skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1664435265573-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 42 lines ...
Go Version: go1.19.1
Platform: linux/amd64

Streaming logs below:
I0929 07:07:41.133973       1 azurefile.go:289] driver userAgent: test.csi.azure.com/e2e-39436e4fb0516baa38523b851a9bc3e7f5359e5b e2e-test
I0929 07:07:41.135689       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:41.160010       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
I0929 07:07:41.160024       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:41.160030       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0929 07:07:41.160060       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0929 07:07:41.160628       1 azure_auth.go:245] Using AzurePublicCloud environment
I0929 07:07:41.160662       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0929 07:07:41.160682       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 736 lines ...
Go Version: go1.19.1
Platform: linux/amd64

Streaming logs below:
I0929 07:07:36.537178       1 azurefile.go:289] driver userAgent: test.csi.azure.com/e2e-39436e4fb0516baa38523b851a9bc3e7f5359e5b e2e-test
I0929 07:07:36.537586       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:36.558339       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
I0929 07:07:36.558361       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0929 07:07:36.558367       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0929 07:07:36.558391       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0929 07:07:36.558982       1 azure_auth.go:245] Using AzurePublicCloud environment
I0929 07:07:36.559019       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0929 07:07:36.559040       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 176 lines ...
# HELP process_virtual_memory_bytes Virtual memory size in bytes.
# TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 7.70838528e+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/09/29 07:21:20 process.go:155: Step 'make e2e-test' finished in 26m0.936887865s
2022/09/29 07:21:20 aksengine_helpers.go:426: downloading /root/tmp1144668373/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2022/09/29 07:21:20 util.go:71: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2022/09/29 07:21:21 process.go:153: Running: chmod +x /root/tmp1144668373/log-dump.sh
2022/09/29 07:21:21 process.go:155: Step 'chmod +x /root/tmp1144668373/log-dump.sh' finished in 1.217612ms
2022/09/29 07:21:21 aksengine_helpers.go:426: downloading /root/tmp1144668373/log-dump-daemonset.yaml from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump-daemonset.yaml
... skipping 65 lines ...
ssh key file /root/.ssh/id_rsa does not exist. Exiting.
2022/09/29 07:21:51 process.go:155: Step 'bash -c /root/tmp1144668373/win-ci-logs-collector.sh kubetest-ptenzx6x.westus2.cloudapp.azure.com /root/tmp1144668373 /root/.ssh/id_rsa' finished in 4.052125ms
2022/09/29 07:21:51 aksengine.go:1141: Deleting resource group: kubetest-ptenzx6x.
2022/09/29 07:28:08 process.go:96: Saved XML output to /logs/artifacts/junit_runner.xml.
2022/09/29 07:28:08 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
2022/09/29 07:28:09 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 244.979673ms
2022/09/29 07:28:09 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
a51dd95df99b
... skipping 4 lines ...