This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: [WIP]chore: remove VOLUME_MOUNT_GROUP cap
ResultFAILURE
Tests 1 failed / 13 succeeded
Started2022-05-12 06:46
Elapsed31m3s
Revision3947bb1d11a9bc1fc820b35f1821acc93cf20734
Refs 1018
job-versionv1.25.0-alpha.0.443+8aaea8e24c1b87
kubetest-version
revisionv1.25.0-alpha.0.443+8aaea8e24c1b87

Test Failures


kubetest Test 19m38s

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

Filter through log files | View test history on testgrid


Show 13 Passed Tests

Error lines from build-log.txt

... skipping 221 lines ...

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

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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
May 12 07:01:08.810: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.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
May 12 07:01:09.004: INFO: Creating resource for dynamic PV
May 12 07:01:09.004: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-4022-e2e-scxw4m8
STEP: creating a claim
May 12 07:01:09.034: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
... skipping 7 lines ...
May 12 07:01:21.268: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found but phase is Pending instead of Bound.
May 12 07:01:23.297: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found but phase is Pending instead of Bound.
May 12 07:01:25.327: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found but phase is Pending instead of Bound.
May 12 07:01:27.356: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found but phase is Pending instead of Bound.
May 12 07:01:29.385: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found and phase=Bound (20.320823718s)
STEP: Creating pod pod-subpath-test-dynamicpv-r8mj
STEP: Checking for subpath error in container status
May 12 07:01:35.574: INFO: Deleting pod "pod-subpath-test-dynamicpv-r8mj" in namespace "provisioning-4022"
May 12 07:01:35.603: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-r8mj" to be fully deleted
STEP: Deleting pod
May 12 07:01:37.667: INFO: Deleting pod "pod-subpath-test-dynamicpv-r8mj" in namespace "provisioning-4022"
STEP: Deleting pvc
May 12 07:01:37.698: INFO: Deleting PersistentVolumeClaim "test.csi.azure.com8zzl6"
... skipping 9 lines ...

• [SLOW TEST:34.090 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":41,"completed":1,"skipped":361,"failed":0}

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

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May 12 07:01:09.093: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:280
May 12 07:01:09.289: INFO: Creating resource for dynamic PV
May 12 07:01:09.289: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-295-e2e-sc262ft
STEP: creating a claim
May 12 07:01:09.317: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
... skipping 7 lines ...
May 12 07:01:21.563: INFO: PersistentVolumeClaim test.csi.azure.complckn found but phase is Pending instead of Bound.
May 12 07:01:23.592: INFO: PersistentVolumeClaim test.csi.azure.complckn found but phase is Pending instead of Bound.
May 12 07:01:25.620: INFO: PersistentVolumeClaim test.csi.azure.complckn found but phase is Pending instead of Bound.
May 12 07:01:27.649: INFO: PersistentVolumeClaim test.csi.azure.complckn found but phase is Pending instead of Bound.
May 12 07:01:29.677: INFO: PersistentVolumeClaim test.csi.azure.complckn found and phase=Bound (20.327598461s)
STEP: Creating pod pod-subpath-test-dynamicpv-zrss
STEP: Checking for subpath error in container status
May 12 07:01:39.819: INFO: Deleting pod "pod-subpath-test-dynamicpv-zrss" in namespace "provisioning-295"
May 12 07:01:39.849: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-zrss" to be fully deleted
STEP: Deleting pod
May 12 07:01:43.905: INFO: Deleting pod "pod-subpath-test-dynamicpv-zrss" in namespace "provisioning-295"
STEP: Deleting pvc
May 12 07:01:43.932: INFO: Deleting PersistentVolumeClaim "test.csi.azure.complckn"
... skipping 9 lines ...

• [SLOW TEST:40.040 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":26,"completed":1,"skipped":631,"failed":0}

SSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand 
  Verify if offline PVC expansion works
  test/e2e/storage/testsuites/volume_expand.go:176
... skipping 63 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":42,"completed":1,"skipped":93,"failed":0}

SS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand
  test/e2e/storage/framework/testsuite.go:51
May 12 07:01:50.325: INFO: Driver "test.csi.azure.com" does not support block volume mode - skipping
... skipping 103 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":30,"completed":1,"skipped":78,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (ntfs)][Feature:Windows] volumes
  test/e2e/storage/framework/testsuite.go:51
May 12 07:02:02.724: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 24 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (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 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: 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 74 lines ...
May 12 07:01:50.604: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:01:50.630: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comx4v75] to have phase Bound
May 12 07:01:50.655: INFO: PersistentVolumeClaim test.csi.azure.comx4v75 found but phase is Pending instead of Bound.
May 12 07:01:52.680: INFO: PersistentVolumeClaim test.csi.azure.comx4v75 found and phase=Bound (2.049579532s)
STEP: Creating pod pod-subpath-test-dynamicpv-2xhw
STEP: Creating a pod to test subpath
May 12 07:01:52.757: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-2xhw" in namespace "provisioning-6741" to be "Succeeded or Failed"
May 12 07:01:52.782: INFO: Pod "pod-subpath-test-dynamicpv-2xhw": Phase="Pending", Reason="", readiness=false. Elapsed: 24.553521ms
May 12 07:01:54.809: INFO: Pod "pod-subpath-test-dynamicpv-2xhw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.051947559s
May 12 07:01:56.834: INFO: Pod "pod-subpath-test-dynamicpv-2xhw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.077481787s
May 12 07:01:58.860: INFO: Pod "pod-subpath-test-dynamicpv-2xhw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.102804692s
STEP: Saw pod success
May 12 07:01:58.860: INFO: Pod "pod-subpath-test-dynamicpv-2xhw" satisfied condition "Succeeded or Failed"
May 12 07:01:58.887: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-2xhw container test-container-volume-dynamicpv-2xhw: <nil>
STEP: delete the pod
May 12 07:01:58.968: INFO: Waiting for pod pod-subpath-test-dynamicpv-2xhw to disappear
May 12 07:01:58.994: INFO: Pod pod-subpath-test-dynamicpv-2xhw no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-2xhw
May 12 07:01:58.994: INFO: Deleting pod "pod-subpath-test-dynamicpv-2xhw" in namespace "provisioning-6741"
... 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":42,"completed":2,"skipped":178,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:02:04.255: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 79 lines ...
May 12 07:02:04.511: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:02:04.541: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.combptls] to have phase Bound
May 12 07:02:04.565: INFO: PersistentVolumeClaim test.csi.azure.combptls found but phase is Pending instead of Bound.
May 12 07:02:06.591: INFO: PersistentVolumeClaim test.csi.azure.combptls found and phase=Bound (2.050167552s)
STEP: Creating pod pod-subpath-test-dynamicpv-x62h
STEP: Creating a pod to test subpath
May 12 07:02:06.668: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-x62h" in namespace "provisioning-3629" to be "Succeeded or Failed"
May 12 07:02:06.693: INFO: Pod "pod-subpath-test-dynamicpv-x62h": Phase="Pending", Reason="", readiness=false. Elapsed: 24.702114ms
May 12 07:02:08.720: INFO: Pod "pod-subpath-test-dynamicpv-x62h": Phase="Pending", Reason="", readiness=false. Elapsed: 2.052000754s
May 12 07:02:10.746: INFO: Pod "pod-subpath-test-dynamicpv-x62h": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.077899701s
STEP: Saw pod success
May 12 07:02:10.746: INFO: Pod "pod-subpath-test-dynamicpv-x62h" satisfied condition "Succeeded or Failed"
May 12 07:02:10.771: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-x62h container test-container-subpath-dynamicpv-x62h: <nil>
STEP: delete the pod
May 12 07:02:10.832: INFO: Waiting for pod pod-subpath-test-dynamicpv-x62h to disappear
May 12 07:02:10.858: INFO: Pod pod-subpath-test-dynamicpv-x62h no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-x62h
May 12 07:02:10.858: INFO: Deleting pod "pod-subpath-test-dynamicpv-x62h" in namespace "provisioning-3629"
... 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":42,"completed":3,"skipped":266,"failed":0}

SSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:02:16.103: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 199 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":41,"completed":2,"skipped":378,"failed":0}

SSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 12 lines ...
May 12 07:02:16.327: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:02:16.354: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjpt5f] to have phase Bound
May 12 07:02:16.379: INFO: PersistentVolumeClaim test.csi.azure.comjpt5f found but phase is Pending instead of Bound.
May 12 07:02:18.404: INFO: PersistentVolumeClaim test.csi.azure.comjpt5f found and phase=Bound (2.049935414s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
May 12 07:02:18.505: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-mhx5w" in namespace "snapshotting-2421" to be "Succeeded or Failed"
May 12 07:02:18.547: INFO: Pod "pvc-snapshottable-tester-mhx5w": Phase="Pending", Reason="", readiness=false. Elapsed: 42.434557ms
May 12 07:02:20.575: INFO: Pod "pvc-snapshottable-tester-mhx5w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.070320976s
May 12 07:02:22.606: INFO: Pod "pvc-snapshottable-tester-mhx5w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.101048578s
STEP: Saw pod success
May 12 07:02:22.606: INFO: Pod "pvc-snapshottable-tester-mhx5w" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
May 12 07:02:22.631: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjpt5f] to have phase Bound
May 12 07:02:22.656: INFO: PersistentVolumeClaim test.csi.azure.comjpt5f found and phase=Bound (24.76363ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
May 12 07:02:22.732: INFO: Pod pvc-snapshottable-tester-mhx5w has the following logs: 
... skipping 190 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":26,"completed":2,"skipped":650,"failed":0}

SSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
... skipping 129 lines ...

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

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May 12 07:02:28.155: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath file is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:258
May 12 07:02:28.328: INFO: Creating resource for dynamic PV
May 12 07:02:28.328: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-9192-e2e-sc9798s
STEP: creating a claim
May 12 07:02:28.355: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:02:28.388: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comqp999] to have phase Bound
May 12 07:02:28.412: INFO: PersistentVolumeClaim test.csi.azure.comqp999 found but phase is Pending instead of Bound.
May 12 07:02:30.438: INFO: PersistentVolumeClaim test.csi.azure.comqp999 found and phase=Bound (2.050013898s)
STEP: Creating pod pod-subpath-test-dynamicpv-jjvz
STEP: Checking for subpath error in container status
May 12 07:02:34.569: INFO: Deleting pod "pod-subpath-test-dynamicpv-jjvz" in namespace "provisioning-9192"
May 12 07:02:34.595: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-jjvz" to be fully deleted
STEP: Deleting pod
May 12 07:02:36.646: INFO: Deleting pod "pod-subpath-test-dynamicpv-jjvz" in namespace "provisioning-9192"
STEP: Deleting pvc
May 12 07:02:36.671: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comqp999"
... skipping 9 lines ...

• [SLOW TEST:13.694 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":42,"completed":4,"skipped":437,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May 12 07:02:41.830: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
May 12 07:02:42.028: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
[AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:188
May 12 07:02:42.029: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-5825" for this suite.


S [SKIPPING] [0.256 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 142 lines ...

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

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

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

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath 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 129 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":30,"completed":2,"skipped":367,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 52 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":18,"completed":1,"skipped":222,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:51
May 12 07:02:48.083: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 259 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":41,"completed":3,"skipped":394,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeLimits
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeLimits
... skipping 89 lines ...
May 12 07:02:42.344: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:02:42.385: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjqj4m] to have phase Bound
May 12 07:02:42.413: INFO: PersistentVolumeClaim test.csi.azure.comjqj4m found but phase is Pending instead of Bound.
May 12 07:02:44.442: INFO: PersistentVolumeClaim test.csi.azure.comjqj4m found and phase=Bound (2.056406703s)
STEP: Creating pod pod-subpath-test-dynamicpv-hscf
STEP: Creating a pod to test multi_subpath
May 12 07:02:44.527: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hscf" in namespace "provisioning-7397" to be "Succeeded or Failed"
May 12 07:02:44.555: INFO: Pod "pod-subpath-test-dynamicpv-hscf": Phase="Pending", Reason="", readiness=false. Elapsed: 28.146828ms
May 12 07:02:46.584: INFO: Pod "pod-subpath-test-dynamicpv-hscf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05664391s
May 12 07:02:48.612: INFO: Pod "pod-subpath-test-dynamicpv-hscf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.084977188s
May 12 07:02:50.642: INFO: Pod "pod-subpath-test-dynamicpv-hscf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.114460823s
STEP: Saw pod success
May 12 07:02:50.642: INFO: Pod "pod-subpath-test-dynamicpv-hscf" satisfied condition "Succeeded or Failed"
May 12 07:02:50.670: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000000 pod pod-subpath-test-dynamicpv-hscf container test-container-subpath-dynamicpv-hscf: <nil>
STEP: delete the pod
May 12 07:02:50.742: INFO: Waiting for pod pod-subpath-test-dynamicpv-hscf to disappear
May 12 07:02:50.769: INFO: Pod pod-subpath-test-dynamicpv-hscf no longer exists
STEP: Deleting pod
May 12 07:02:50.769: INFO: Deleting pod "pod-subpath-test-dynamicpv-hscf" in namespace "provisioning-7397"
... 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":26,"completed":3,"skipped":983,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
... skipping 67 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: 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 86 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":42,"completed":5,"skipped":811,"failed":0}

SSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:51
May 12 07:02:58.326: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
... skipping 90 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":38,"completed":1,"skipped":164,"failed":0}

SSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (xfs)][Slow] volumes
  test/e2e/storage/framework/testsuite.go:51
May 12 07:02:58.775: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 22 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 8 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if 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 97 lines ...
May 12 07:02:59.763: INFO: ExecWithOptions: execute(POST https://kubetest-oew5xopy.centralus.cloudapp.azure.com/api/v1/namespaces/volume-5198/pods/external-client/exec?command=%2Fbin%2Fsh&command=-c&command=test+-d+%2Fopt%2F0&container=external-client&container=external-client&stderr=true&stdout=true)
May 12 07:03:00.020: INFO: ExecWithOptions {Command:[/bin/sh -c test -b /opt/0] Namespace:volume-5198 PodName:external-client ContainerName:external-client Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
May 12 07:03:00.020: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json
May 12 07:03:00.021: INFO: ExecWithOptions: Clientset creation
May 12 07:03:00.021: INFO: ExecWithOptions: execute(POST https://kubetest-oew5xopy.centralus.cloudapp.azure.com/api/v1/namespaces/volume-5198/pods/external-client/exec?command=%2Fbin%2Fsh&command=-c&command=test+-b+%2Fopt%2F0&container=external-client&container=external-client&stderr=true&stdout=true)
STEP: Repeating the test on an ephemeral container (if enabled)
May 12 07:03:00.382: INFO: Skipping ephemeral container re-test because feature is disabled (error: "the server could not find the requested resource")
STEP: Deleting pod external-client in namespace volume-5198
May 12 07:03:00.412: INFO: Waiting for pod external-client to disappear
May 12 07:03:00.440: INFO: Pod external-client still exists
May 12 07:03:02.440: INFO: Waiting for pod external-client to disappear
May 12 07:03:02.468: INFO: Pod external-client still exists
May 12 07:03:04.440: INFO: Waiting for pod external-client to disappear
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should store data
    test/e2e/storage/testsuites/volumes.go:161
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should store data","total":18,"completed":2,"skipped":833,"failed":0}

SSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:51
May 12 07:03:09.683: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 37 lines ...
May 12 07:02:58.556: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:02:58.581: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comwh97p] to have phase Bound
May 12 07:02:58.606: INFO: PersistentVolumeClaim test.csi.azure.comwh97p found but phase is Pending instead of Bound.
May 12 07:03:00.632: INFO: PersistentVolumeClaim test.csi.azure.comwh97p found and phase=Bound (2.050947698s)
STEP: Creating pod pod-subpath-test-dynamicpv-wfnf
STEP: Creating a pod to test subpath
May 12 07:03:00.709: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-wfnf" in namespace "provisioning-5925" to be "Succeeded or Failed"
May 12 07:03:00.737: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Pending", Reason="", readiness=false. Elapsed: 27.518666ms
May 12 07:03:02.764: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.054419333s
May 12 07:03:04.790: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.080762478s
May 12 07:03:06.816: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.106339843s
May 12 07:03:08.843: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.13323999s
STEP: Saw pod success
May 12 07:03:08.843: INFO: Pod "pod-subpath-test-dynamicpv-wfnf" satisfied condition "Succeeded or Failed"
May 12 07:03:08.868: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-wfnf container test-container-volume-dynamicpv-wfnf: <nil>
STEP: delete the pod
May 12 07:03:08.928: INFO: Waiting for pod pod-subpath-test-dynamicpv-wfnf to disappear
May 12 07:03:08.953: INFO: Pod pod-subpath-test-dynamicpv-wfnf no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-wfnf
May 12 07:03:08.953: INFO: Deleting pod "pod-subpath-test-dynamicpv-wfnf" in namespace "provisioning-5925"
... 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":42,"completed":6,"skipped":863,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should support existing directories when readOnly specified in the volumeSource
  test/e2e/storage/testsuites/subpath.go:397
... skipping 16 lines ...
May 12 07:02:56.307: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:02:56.343: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comqfwh4] to have phase Bound
May 12 07:02:56.370: INFO: PersistentVolumeClaim test.csi.azure.comqfwh4 found but phase is Pending instead of Bound.
May 12 07:02:58.400: INFO: PersistentVolumeClaim test.csi.azure.comqfwh4 found and phase=Bound (2.057880982s)
STEP: Creating pod pod-subpath-test-dynamicpv-gmrb
STEP: Creating a pod to test subpath
May 12 07:02:58.485: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-gmrb" in namespace "provisioning-8172" to be "Succeeded or Failed"
May 12 07:02:58.517: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 31.514849ms
May 12 07:03:00.550: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.063991041s
May 12 07:03:02.578: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.092603528s
May 12 07:03:04.607: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.121533104s
May 12 07:03:06.636: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.150076452s
STEP: Saw pod success
May 12 07:03:06.636: INFO: Pod "pod-subpath-test-dynamicpv-gmrb" satisfied condition "Succeeded or Failed"
May 12 07:03:06.664: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-gmrb container test-container-subpath-dynamicpv-gmrb: <nil>
STEP: delete the pod
May 12 07:03:06.731: INFO: Waiting for pod pod-subpath-test-dynamicpv-gmrb to disappear
May 12 07:03:06.759: INFO: Pod pod-subpath-test-dynamicpv-gmrb no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-gmrb
May 12 07:03:06.759: INFO: Deleting pod "pod-subpath-test-dynamicpv-gmrb" in namespace "provisioning-8172"
STEP: Creating pod pod-subpath-test-dynamicpv-gmrb
STEP: Creating a pod to test subpath
May 12 07:03:06.817: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-gmrb" in namespace "provisioning-8172" to be "Succeeded or Failed"
May 12 07:03:06.845: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 28.126644ms
May 12 07:03:08.874: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057039292s
May 12 07:03:10.903: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.086061981s
STEP: Saw pod success
May 12 07:03:10.903: INFO: Pod "pod-subpath-test-dynamicpv-gmrb" satisfied condition "Succeeded or Failed"
May 12 07:03:10.932: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000000 pod pod-subpath-test-dynamicpv-gmrb container test-container-subpath-dynamicpv-gmrb: <nil>
STEP: delete the pod
May 12 07:03:10.998: INFO: Waiting for pod pod-subpath-test-dynamicpv-gmrb to disappear
May 12 07:03:11.026: INFO: Pod pod-subpath-test-dynamicpv-gmrb no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-gmrb
May 12 07:03:11.026: INFO: Deleting pod "pod-subpath-test-dynamicpv-gmrb" in namespace "provisioning-8172"
... 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":41,"completed":4,"skipped":501,"failed":0}

SSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable-stress[Feature:VolumeSnapshotDataSource]
  test/e2e/storage/framework/testsuite.go:51
May 12 07:03:16.295: INFO: Driver test.csi.azure.com doesn't specify snapshot stress test options -- skipping
... skipping 36 lines ...
STEP: creating a claim
May 12 07:02:59.088: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:02:59.115: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comtf4r8] to have phase Bound
May 12 07:02:59.140: INFO: PersistentVolumeClaim test.csi.azure.comtf4r8 found but phase is Pending instead of Bound.
May 12 07:03:01.170: INFO: PersistentVolumeClaim test.csi.azure.comtf4r8 found and phase=Bound (2.05506379s)
STEP: Creating pod to format volume volume-prep-provisioning-1665
May 12 07:03:01.246: INFO: Waiting up to 5m0s for pod "volume-prep-provisioning-1665" in namespace "provisioning-1665" to be "Succeeded or Failed"
May 12 07:03:01.274: INFO: Pod "volume-prep-provisioning-1665": Phase="Pending", Reason="", readiness=false. Elapsed: 28.535503ms
May 12 07:03:03.301: INFO: Pod "volume-prep-provisioning-1665": Phase="Pending", Reason="", readiness=false. Elapsed: 2.055076445s
May 12 07:03:05.327: INFO: Pod "volume-prep-provisioning-1665": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.081859847s
STEP: Saw pod success
May 12 07:03:05.328: INFO: Pod "volume-prep-provisioning-1665" satisfied condition "Succeeded or Failed"
May 12 07:03:05.328: INFO: Deleting pod "volume-prep-provisioning-1665" in namespace "provisioning-1665"
May 12 07:03:05.356: INFO: Wait up to 5m0s for pod "volume-prep-provisioning-1665" to be fully deleted
STEP: Creating pod pod-subpath-test-dynamicpv-lnhj
STEP: Checking for subpath error in container status
May 12 07:03:09.457: INFO: Deleting pod "pod-subpath-test-dynamicpv-lnhj" in namespace "provisioning-1665"
May 12 07:03:09.484: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-lnhj" to be fully deleted
STEP: Deleting pod
May 12 07:03:11.535: INFO: Deleting pod "pod-subpath-test-dynamicpv-lnhj" in namespace "provisioning-1665"
STEP: Deleting pvc
May 12 07:03:11.560: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comtf4r8"
... 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":38,"completed":2,"skipped":311,"failed":0}

SSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should support restarting containers using file as subpath [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:333
... skipping 69 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":43,"completed":1,"skipped":66,"failed":0}

SSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
May 12 07:03:21.705: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 77 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":30,"completed":3,"skipped":445,"failed":0}

SSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 86 lines ...

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

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

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

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

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May 12 07:03:16.303: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:242
May 12 07:03:16.496: INFO: Creating resource for dynamic PV
May 12 07:03:16.496: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-3782-e2e-sc9qw94
STEP: creating a claim
May 12 07:03:16.527: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:03:16.557: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjh89k] to have phase Bound
May 12 07:03:16.584: INFO: PersistentVolumeClaim test.csi.azure.comjh89k found but phase is Pending instead of Bound.
May 12 07:03:18.613: INFO: PersistentVolumeClaim test.csi.azure.comjh89k found and phase=Bound (2.056137575s)
STEP: Creating pod pod-subpath-test-dynamicpv-vfpj
STEP: Checking for subpath error in container status
May 12 07:03:22.756: INFO: Deleting pod "pod-subpath-test-dynamicpv-vfpj" in namespace "provisioning-3782"
May 12 07:03:22.785: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-vfpj" to be fully deleted
STEP: Deleting pod
May 12 07:03:28.842: INFO: Deleting pod "pod-subpath-test-dynamicpv-vfpj" in namespace "provisioning-3782"
STEP: Deleting pvc
May 12 07:03:28.869: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comjh89k"
... skipping 9 lines ...

• [SLOW TEST:17.767 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":41,"completed":5,"skipped":524,"failed":0}

SSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May 12 07:03:34.083: INFO: Driver test.csi.azure.com doesn't support xfs -- skipping
... skipping 13 lines ...

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

[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May 12 07:03:34.108: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail in binding dynamic provisioned PV to PVC [Slow][LinuxOnly]
  test/e2e/storage/testsuites/volumemode.go:260
STEP: Creating sc
STEP: Creating pv and pvc
STEP: Deleting pvc
May 12 07:03:34.445: INFO: Deleting PersistentVolumeClaim "pvc-qtgd5"
STEP: Deleting sc
[AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:188
May 12 07:03:34.504: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-5715" 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":41,"completed":6,"skipped":562,"failed":0}

SSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:03:34.580: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 58 lines ...
May 12 07:03:21.959: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:03:21.989: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com5gclr] to have phase Bound
May 12 07:03:22.018: INFO: PersistentVolumeClaim test.csi.azure.com5gclr found but phase is Pending instead of Bound.
May 12 07:03:24.052: INFO: PersistentVolumeClaim test.csi.azure.com5gclr found and phase=Bound (2.062734666s)
STEP: Creating pod exec-volume-test-dynamicpv-rwck
STEP: Creating a pod to test exec-volume-test
May 12 07:03:24.138: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-rwck" in namespace "volume-7625" to be "Succeeded or Failed"
May 12 07:03:24.166: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Pending", Reason="", readiness=false. Elapsed: 28.022814ms
May 12 07:03:26.196: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Pending", Reason="", readiness=false. Elapsed: 2.058698732s
May 12 07:03:28.225: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Pending", Reason="", readiness=false. Elapsed: 4.087612533s
May 12 07:03:30.256: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Pending", Reason="", readiness=false. Elapsed: 6.11803226s
May 12 07:03:32.286: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.147822195s
STEP: Saw pod success
May 12 07:03:32.286: INFO: Pod "exec-volume-test-dynamicpv-rwck" satisfied condition "Succeeded or Failed"
May 12 07:03:32.314: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000000 pod exec-volume-test-dynamicpv-rwck container exec-container-dynamicpv-rwck: <nil>
STEP: delete the pod
May 12 07:03:32.382: INFO: Waiting for pod exec-volume-test-dynamicpv-rwck to disappear
May 12 07:03:32.410: INFO: Pod exec-volume-test-dynamicpv-rwck no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-rwck
May 12 07:03:32.410: INFO: Deleting pod "exec-volume-test-dynamicpv-rwck" in namespace "volume-7625"
... 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":43,"completed":2,"skipped":96,"failed":0}
[BeforeEach] [Testpattern: Inline-volume (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:51
May 12 07:03:37.647: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
[AfterEach] [Testpattern: Inline-volume (ext4)] volumes
  test/e2e/framework/framework.go:188

... skipping 136 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":18,"completed":3,"skipped":916,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:03:47.073: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 3 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (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 21 lines ...
May 12 07:03:14.428: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:03:14.455: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comkzx6z] to have phase Bound
May 12 07:03:14.487: INFO: PersistentVolumeClaim test.csi.azure.comkzx6z found but phase is Pending instead of Bound.
May 12 07:03:16.511: INFO: PersistentVolumeClaim test.csi.azure.comkzx6z found and phase=Bound (2.056131424s)
STEP: Creating pod pod-subpath-test-dynamicpv-f4jw
STEP: Creating a pod to test atomic-volume-subpath
May 12 07:03:16.589: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-f4jw" in namespace "provisioning-8693" to be "Succeeded or Failed"
May 12 07:03:16.614: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Pending", Reason="", readiness=false. Elapsed: 25.440059ms
May 12 07:03:18.640: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05164303s
May 12 07:03:20.667: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 4.078785748s
May 12 07:03:22.695: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 6.106106252s
May 12 07:03:24.721: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 8.132521962s
May 12 07:03:26.747: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 10.158504832s
... skipping 3 lines ...
May 12 07:03:34.854: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 18.265164856s
May 12 07:03:36.880: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 20.291318969s
May 12 07:03:38.907: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 22.317905678s
May 12 07:03:40.934: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=false. Elapsed: 24.345178915s
May 12 07:03:42.960: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.371418709s
STEP: Saw pod success
May 12 07:03:42.960: INFO: Pod "pod-subpath-test-dynamicpv-f4jw" satisfied condition "Succeeded or Failed"
May 12 07:03:42.987: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-f4jw container test-container-subpath-dynamicpv-f4jw: <nil>
STEP: delete the pod
May 12 07:03:43.045: INFO: Waiting for pod pod-subpath-test-dynamicpv-f4jw to disappear
May 12 07:03:43.070: INFO: Pod pod-subpath-test-dynamicpv-f4jw no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-f4jw
May 12 07:03:43.070: INFO: Deleting pod "pod-subpath-test-dynamicpv-f4jw" in namespace "provisioning-8693"
... 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":42,"completed":7,"skipped":911,"failed":0}

SSSSSS
------------------------------
[BeforeEach] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 6 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
May 12 07:03:48.479: INFO: Creating resource for dynamic PV
May 12 07:03:48.479: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-4681-e2e-scgh9g9
STEP: [init] starting a pod to use the claim
May 12 07:03:48.532: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-r6ctt" in namespace "snapshotting-4681" to be "Succeeded or Failed"
May 12 07:03:48.557: INFO: Pod "pvc-snapshottable-tester-r6ctt": Phase="Pending", Reason="", readiness=false. Elapsed: 25.061785ms
May 12 07:03:50.584: INFO: Pod "pvc-snapshottable-tester-r6ctt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.051253902s
May 12 07:03:52.609: INFO: Pod "pvc-snapshottable-tester-r6ctt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.07702387s
May 12 07:03:54.635: INFO: Pod "pvc-snapshottable-tester-r6ctt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.102806422s
STEP: Saw pod success
May 12 07:03:54.635: INFO: Pod "pvc-snapshottable-tester-r6ctt" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
May 12 07:03:54.660: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
May 12 07:03:54.661: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-r6ctt-my-volume] to have phase Bound
May 12 07:03:54.686: INFO: PersistentVolumeClaim pvc-snapshottable-tester-r6ctt-my-volume found and phase=Bound (24.580621ms)
STEP: [init] checking the PV
... skipping 139 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":43,"completed":3,"skipped":168,"failed":0}

SSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:03:58.289: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 538 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":30,"completed":4,"skipped":613,"failed":0}

SSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:04:01.034: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 115 lines ...
May 12 07:03:55.183: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:03:55.209: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comtjg95] to have phase Bound
May 12 07:03:55.234: INFO: PersistentVolumeClaim test.csi.azure.comtjg95 found but phase is Pending instead of Bound.
May 12 07:03:57.261: INFO: PersistentVolumeClaim test.csi.azure.comtjg95 found and phase=Bound (2.051305802s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
May 12 07:03:57.361: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-9p79m" in namespace "snapshotting-3177" to be "Succeeded or Failed"
May 12 07:03:57.386: INFO: Pod "pvc-snapshottable-tester-9p79m": Phase="Pending", Reason="", readiness=false. Elapsed: 24.506514ms
May 12 07:03:59.412: INFO: Pod "pvc-snapshottable-tester-9p79m": Phase="Pending", Reason="", readiness=false. Elapsed: 2.050938614s
May 12 07:04:01.438: INFO: Pod "pvc-snapshottable-tester-9p79m": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.076811272s
STEP: Saw pod success
May 12 07:04:01.438: INFO: Pod "pvc-snapshottable-tester-9p79m" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
May 12 07:04:01.463: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comtjg95] to have phase Bound
May 12 07:04:01.488: INFO: PersistentVolumeClaim test.csi.azure.comtjg95 found and phase=Bound (24.750022ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
May 12 07:04:01.563: INFO: Pod pvc-snapshottable-tester-9p79m has the following logs: 
... skipping 76 lines ...
May 12 07:03:59.516: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:03:59.546: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8zf9m] to have phase Bound
May 12 07:03:59.575: INFO: PersistentVolumeClaim test.csi.azure.com8zf9m found but phase is Pending instead of Bound.
May 12 07:04:01.604: INFO: PersistentVolumeClaim test.csi.azure.com8zf9m found and phase=Bound (2.057651603s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
May 12 07:04:01.724: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-st7rj" in namespace "snapshotting-482" to be "Succeeded or Failed"
May 12 07:04:01.752: INFO: Pod "pvc-snapshottable-tester-st7rj": Phase="Pending", Reason="", readiness=false. Elapsed: 28.458775ms
May 12 07:04:03.783: INFO: Pod "pvc-snapshottable-tester-st7rj": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05934676s
May 12 07:04:05.814: INFO: Pod "pvc-snapshottable-tester-st7rj": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.089708101s
STEP: Saw pod success
May 12 07:04:05.814: INFO: Pod "pvc-snapshottable-tester-st7rj" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
May 12 07:04:05.842: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8zf9m] to have phase Bound
May 12 07:04:05.871: INFO: PersistentVolumeClaim test.csi.azure.com8zf9m found and phase=Bound (28.443999ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
May 12 07:04:05.959: INFO: Pod pvc-snapshottable-tester-st7rj has the following logs: 
... skipping 80 lines ...
May 12 07:03:34.847: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:03:34.876: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.coml6vcq] to have phase Bound
May 12 07:03:34.905: INFO: PersistentVolumeClaim test.csi.azure.coml6vcq found but phase is Pending instead of Bound.
May 12 07:03:36.935: INFO: PersistentVolumeClaim test.csi.azure.coml6vcq found and phase=Bound (2.058706779s)
STEP: Expanding non-expandable pvc
May 12 07:03:36.991: INFO: currentPvcSize {{5368709120 0} {<nil>} 5Gi BinarySI}, newSize {{6442450944 0} {<nil>}  BinarySI}
May 12 07:03:37.049: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:39.108: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:41.108: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:43.107: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:45.106: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:47.111: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:49.105: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:51.105: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:53.110: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:55.106: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:57.106: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:03:59.106: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:04:01.107: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:04:03.107: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:04:05.109: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:04:07.111: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
May 12 07:04:07.167: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
May 12 07:04:07.167: INFO: Deleting PersistentVolumeClaim "test.csi.azure.coml6vcq"
May 12 07:04:07.196: INFO: Waiting up to 5m0s for PersistentVolume pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a to get deleted
May 12 07:04:07.224: INFO: PersistentVolume pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a found and phase=Released (27.833737ms)
May 12 07:04:12.253: INFO: PersistentVolume pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a 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":41,"completed":7,"skipped":606,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning
  test/e2e/storage/framework/testsuite.go:51
May 12 07:04:12.387: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 59 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
May 12 07:04:07.013: INFO: Creating resource for dynamic PV
May 12 07:04:07.013: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-4967-e2e-scmv859
STEP: [init] starting a pod to use the claim
May 12 07:04:07.067: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-xd926" in namespace "snapshotting-4967" to be "Succeeded or Failed"
May 12 07:04:07.093: INFO: Pod "pvc-snapshottable-tester-xd926": Phase="Pending", Reason="", readiness=false. Elapsed: 25.694609ms
May 12 07:04:09.119: INFO: Pod "pvc-snapshottable-tester-xd926": Phase="Pending", Reason="", readiness=false. Elapsed: 2.051985416s
May 12 07:04:11.145: INFO: Pod "pvc-snapshottable-tester-xd926": Phase="Pending", Reason="", readiness=false. Elapsed: 4.077780282s
May 12 07:04:13.171: INFO: Pod "pvc-snapshottable-tester-xd926": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.104628452s
STEP: Saw pod success
May 12 07:04:13.172: INFO: Pod "pvc-snapshottable-tester-xd926" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
May 12 07:04:13.197: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
May 12 07:04:13.197: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-xd926-my-volume] to have phase Bound
May 12 07:04:13.223: INFO: PersistentVolumeClaim pvc-snapshottable-tester-xd926-my-volume found and phase=Bound (25.834737ms)
STEP: [init] checking the PV
... skipping 182 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":30,"completed":5,"skipped":737,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:04:25.821: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 3 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (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 133 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":43,"completed":4,"skipped":699,"failed":0}

SSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:51
May 12 07:04:26.123: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 85 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 52 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":38,"completed":3,"skipped":325,"failed":0}

SSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
May 12 07:04:34.460: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 35 lines ...
May 12 07:04:26.426: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:04:26.456: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comnsfgx] to have phase Bound
May 12 07:04:26.484: INFO: PersistentVolumeClaim test.csi.azure.comnsfgx found but phase is Pending instead of Bound.
May 12 07:04:28.514: INFO: PersistentVolumeClaim test.csi.azure.comnsfgx found and phase=Bound (2.057691776s)
STEP: Creating pod pod-subpath-test-dynamicpv-tbk7
STEP: Creating a pod to test subpath
May 12 07:04:28.601: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-tbk7" in namespace "provisioning-5789" to be "Succeeded or Failed"
May 12 07:04:28.633: INFO: Pod "pod-subpath-test-dynamicpv-tbk7": Phase="Pending", Reason="", readiness=false. Elapsed: 31.852084ms
May 12 07:04:30.663: INFO: Pod "pod-subpath-test-dynamicpv-tbk7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.0619154s
May 12 07:04:32.695: INFO: Pod "pod-subpath-test-dynamicpv-tbk7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.093810724s
May 12 07:04:34.725: INFO: Pod "pod-subpath-test-dynamicpv-tbk7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.123411517s
STEP: Saw pod success
May 12 07:04:34.725: INFO: Pod "pod-subpath-test-dynamicpv-tbk7" satisfied condition "Succeeded or Failed"
May 12 07:04:34.753: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000000 pod pod-subpath-test-dynamicpv-tbk7 container test-container-subpath-dynamicpv-tbk7: <nil>
STEP: delete the pod
May 12 07:04:34.817: INFO: Waiting for pod pod-subpath-test-dynamicpv-tbk7 to disappear
May 12 07:04:34.845: INFO: Pod pod-subpath-test-dynamicpv-tbk7 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-tbk7
May 12 07:04:34.845: INFO: Deleting pod "pod-subpath-test-dynamicpv-tbk7" in namespace "provisioning-5789"
... 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":43,"completed":5,"skipped":780,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 320 lines ...
May 12 07:04:40.351: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:04:40.382: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.combz9jv] to have phase Bound
May 12 07:04:40.413: INFO: PersistentVolumeClaim test.csi.azure.combz9jv found but phase is Pending instead of Bound.
May 12 07:04:42.442: INFO: PersistentVolumeClaim test.csi.azure.combz9jv found and phase=Bound (2.060601083s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
May 12 07:04:42.558: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-5b58x" in namespace "snapshotting-8256" to be "Succeeded or Failed"
May 12 07:04:42.589: INFO: Pod "pvc-snapshottable-tester-5b58x": Phase="Pending", Reason="", readiness=false. Elapsed: 30.386485ms
May 12 07:04:44.619: INFO: Pod "pvc-snapshottable-tester-5b58x": Phase="Pending", Reason="", readiness=false. Elapsed: 2.060467656s
May 12 07:04:46.649: INFO: Pod "pvc-snapshottable-tester-5b58x": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.09089724s
STEP: Saw pod success
May 12 07:04:46.649: INFO: Pod "pvc-snapshottable-tester-5b58x" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
May 12 07:04:46.678: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.combz9jv] to have phase Bound
May 12 07:04:46.706: INFO: PersistentVolumeClaim test.csi.azure.combz9jv found and phase=Bound (28.0636ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
May 12 07:04:46.793: INFO: Pod pvc-snapshottable-tester-5b58x has the following logs: 
... skipping 102 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":41,"completed":8,"skipped":701,"failed":0}

SSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volume-expand
  test/e2e/storage/framework/testsuite.go:51
May 12 07:04:53.900: INFO: Driver "test.csi.azure.com" does not support block volume mode - skipping
... skipping 135 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 29 lines ...

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

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

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 52 lines ...
May 12 07:04:52.490: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
May 12 07:04:52.520: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com7fwmw] to have phase Bound
May 12 07:04:52.548: INFO: PersistentVolumeClaim test.csi.azure.com7fwmw found but phase is Pending instead of Bound.
May 12 07:04:54.577: INFO: PersistentVolumeClaim test.csi.azure.com7fwmw found and phase=Bound (2.057038082s)
STEP: Creating pod pod-subpath-test-dynamicpv-nw7p
STEP: Creating a pod to test subpath
May 12 07:04:54.670: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-nw7p" in namespace "provisioning-1431" to be "Succeeded or Failed"
May 12 07:04:54.698: INFO: Pod "pod-subpath-test-dynamicpv-nw7p": Phase="Pending", Reason="", readiness=false. Elapsed: 28.035362ms
May 12 07:04:56.727: INFO: Pod "pod-subpath-test-dynamicpv-nw7p": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05782852s
May 12 07:04:58.757: INFO: Pod "pod-subpath-test-dynamicpv-nw7p": Phase="Pending", Reason="", readiness=false. Elapsed: 4.087833142s
May 12 07:05:00.787: INFO: Pod "pod-subpath-test-dynamicpv-nw7p": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.117398384s
STEP: Saw pod success
May 12 07:05:00.787: INFO: Pod "pod-subpath-test-dynamicpv-nw7p" satisfied condition "Succeeded or Failed"
May 12 07:05:00.816: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-nw7p container test-container-subpath-dynamicpv-nw7p: <nil>
STEP: delete the pod
May 12 07:05:00.881: INFO: Waiting for pod pod-subpath-test-dynamicpv-nw7p to disappear
May 12 07:05:00.909: INFO: Pod pod-subpath-test-dynamicpv-nw7p no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-nw7p
May 12 07:05:00.909: INFO: Deleting pod "pod-subpath-test-dynamicpv-nw7p" in namespace "provisioning-1431"
... 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":43,"completed":6,"skipped":964,"failed":0}
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:05:06.176: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
[AfterEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/framework/framework.go:188


S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (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 214 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":38,"completed":4,"skipped":680,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
May 12 07:05:14.838: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 48 lines ...
May 12 07:05:19.637: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/file1] Namespace:fsgroupchangepolicy-8377 PodName:pod-95879de0-465f-4384-91f3-049642464729 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
May 12 07:05:19.637: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json
May 12 07:05:19.638: INFO: ExecWithOptions: Clientset creation
May 12 07:05:19.638: INFO: ExecWithOptions: execute(POST https://kubetest-oew5xopy.centralus.cloudapp.azure.com/api/v1/namespaces/fsgroupchangepolicy-8377/pods/pod-95879de0-465f-4384-91f3-049642464729/exec?command=%2Fbin%2Fsh&command=-c&command=ls+-l+%2Fmnt%2Fvolume1%2Ffile1&container=write-pod&container=write-pod&stderr=true&stdout=true)
May 12 07:05:19.923: INFO: pod fsgroupchangepolicy-8377/pod-95879de0-465f-4384-91f3-049642464729 exec for cmd ls -l /mnt/volume1/file1, stdout: -rwxrwxrwx    1 root     root             0 May 12 07:05 /mnt/volume1/file1, stderr: 
May 12 07:05:19.925: INFO: stdout split: [-rwxrwxrwx 1 root root 0 May 12 07:05 /mnt/volume1/file1], expected gid: 1000
May 12 07:05:19.925: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0x7157a49?, {0x717f14f?, 0x0?}, {0xc00123dae8, 0x4}, 0xc00297ac00)
... skipping 71 lines ...
May 12 07:09:56.470: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m36.516626597s)
May 12 07:10:01.499: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m41.545851847s)
May 12 07:10:06.527: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m46.574189368s)
May 12 07:10:11.554: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m51.601048165s)
May 12 07:10:16.580: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m56.626748807s)
STEP: Deleting sc
May 12 07:10:21.608: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 not deleted by dynamic provisioner: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 still exists within 5m0s",
... skipping 6 lines ...

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/testsuites.(*fsGroupChangePolicyTestSuite).DefineTests.func2()
	test/e2e/storage/testsuites/fsgroupchangepolicy.go:134 +0x233
panic({0x6ca56c0, 0xc0037885c0})
	/usr/local/go/src/runtime/panic.go:838 +0x207
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1()
	test/e2e/framework/ginkgowrapper/wrapper.go:63 +0x7d
panic({0x632c000, 0x7a05090})
	/usr/local/go/src/runtime/panic.go:838 +0x207
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail({0xc00198fcc0, 0x4c}, {0xc0022d4cb0?, 0x714b92b?, 0xc0022d4cd0?})
	test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x197
k8s.io/kubernetes/test/e2e/framework.Fail({0xc0009e8340, 0x37}, {0xc000ac7840?, 0xc0009e8340?, 0x705c800?})
	test/e2e/framework/log.go:63 +0x145
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc0022d4e20, {0x7a295a8, 0xc0007ee480}, 0x1, {0x0, 0x0, 0x0})
	vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x1bd
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc0022d4e20, {0x7a295a8, 0xc0007ee480}, {0x0, 0x0, 0x0})
	vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0x95
k8s.io/kubernetes/test/e2e/framework.ExpectEqual({0x632c000?, 0xc0007ee440?}, {0x632c000?, 0xc0007ee470}, {0x0, 0x0, 0x0})
... skipping 136 lines ...
        <string>: root
    to equal
        <string>: 1000

    test/e2e/storage/utils/utils.go:728
------------------------------
{"msg":"FAILED 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":4,"skipped":756,"failed":1,"failures":["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"]}

SSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (xfs)][Slow] volumes
  test/e2e/storage/framework/testsuite.go:51
May 12 07:10:22.532: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 105 lines ...
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
May 12 07:10:22.582: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
May 12 07:10:22.756: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
[AfterEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  test/e2e/framework/framework.go:188
May 12 07:10:22.757: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "volumemode-1292" for this suite.


S [SKIPPING] [0.226 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 83 lines ...
May 12 07:10:23.024: INFO: Running AfterSuite actions on node 1



Summarizing 1 Failure:

[Fail] External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [Measurement] (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents 
test/e2e/storage/utils/utils.go:728

Ran 37 of 7229 Specs in 555.897 seconds
FAIL! -- 36 Passed | 1 Failed | 0 Pending | 7192 Skipped 

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

Streaming logs below:
I0512 07:00:59.271759       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test
I0512 07:00:59.272072       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0512 07:00:59.287419       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
I0512 07:00:59.287437       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0512 07:00:59.287444       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0512 07:00:59.287465       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0512 07:00:59.287984       1 azure_auth.go:245] Using AzurePublicCloud environment
I0512 07:00:59.288016       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0512 07:00:59.288043       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 102 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0512 07:00:58.302470       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test
I0512 07:00:58.302773       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0512 07:00:58.320391       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
I0512 07:00:58.320407       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0512 07:00:58.320414       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0512 07:00:58.320432       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0512 07:00:58.320896       1 azure_auth.go:245] Using AzurePublicCloud environment
I0512 07:00:58.320927       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0512 07:00:58.320950       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 501 lines ...
I0512 07:03:32.665714       1 azure_storage.go:66] share pvc-4b478bb8-04e3-4892-b1b7-2a8aa253c39b deleted
I0512 07:03:32.665743       1 controllerserver.go:584] azure file(pvc-4b478bb8-04e3-4892-b1b7-2a8aa253c39b) under rg(kubetest-oew5xopy) account(f6a30d1c0177346d3a9e954) volume(kubetest-oew5xopy#f6a30d1c0177346d3a9e954#pvc-4b478bb8-04e3-4892-b1b7-2a8aa253c39b###volume-7625) is deleted successfully
I0512 07:03:32.665789       1 azure_metrics.go:112] "Observed Request Latency" latency_seconds=0.194163682 request="azurefile_csi_driver_controller_delete_volume" resource_group="kubetest-oew5xopy" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="test.csi.azure.com" volumeid="kubetest-oew5xopy#f6a30d1c0177346d3a9e954#pvc-4b478bb8-04e3-4892-b1b7-2a8aa253c39b###volume-7625" result_code="succeeded"
I0512 07:03:32.665806       1 utils.go:83] GRPC response: {}
I0512 07:03:34.352077       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0512 07:03:34.352217       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d954320b-df8d-4eae-a94f-294a59ce154c","parameters":{"csi.storage.k8s.io/pv/name":"pvc-d954320b-df8d-4eae-a94f-294a59ce154c","csi.storage.k8s.io/pvc/name":"pvc-qtgd5","csi.storage.k8s.io/pvc/namespace":"volumemode-5715","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]}
E0512 07:03:34.352417       1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes
I0512 07:03:34.461208       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0512 07:03:34.461365       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d954320b-df8d-4eae-a94f-294a59ce154c","parameters":{"csi.storage.k8s.io/pv/name":"pvc-d954320b-df8d-4eae-a94f-294a59ce154c","csi.storage.k8s.io/pvc/name":"pvc-qtgd5","csi.storage.k8s.io/pvc/namespace":"volumemode-5715","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]}
E0512 07:03:34.461469       1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes
I0512 07:03:34.866595       1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume
I0512 07:03:34.866746       1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a","parameters":{"csi.storage.k8s.io/pv/name":"pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a","csi.storage.k8s.io/pvc/name":"test.csi.azure.coml6vcq","csi.storage.k8s.io/pvc/namespace":"volume-expand-9509","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}}]}
I0512 07:03:34.927493       1 controllerserver.go:433] begin to create file share(pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a) on account(f6a30d1c0177346d3a9e954) type(Premium_LRS) rg(kubetest-oew5xopy) location() size(100) protocol(SMB)
I0512 07:03:35.089219       1 controllerserver.go:455] create file share pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a on storage account f6a30d1c0177346d3a9e954 successfully
I0512 07:03:35.093178       1 controllerserver.go:501] store account key to k8s secret(azure-storage-account-f6a30d1c0177346d3a9e954-secret) in volume-expand-9509 namespace
I0512 07:03:35.093223       1 azure_metrics.go:112] "Observed Request Latency" latency_seconds=0.165741397 request="azurefile_csi_driver_controller_create_volume" resource_group="kubetest-oew5xopy" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="test.csi.azure.com" volumeid="kubetest-oew5xopy#f6a30d1c0177346d3a9e954#pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a###volume-expand-9509" result_code="succeeded"
... skipping 277 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0512 07:00:56.063139       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test
I0512 07:00:56.063552       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0512 07:00:56.080264       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
I0512 07:00:56.080282       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0512 07:00:56.080289       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0512 07:00:56.080309       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0512 07:00:56.080852       1 azure_auth.go:245] Using AzurePublicCloud environment
I0512 07:00:56.080889       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0512 07:00:56.080919       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 1038 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0512 07:00:55.813415       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test
I0512 07:00:55.813696       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0512 07:00:55.833237       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
I0512 07:00:55.833254       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0512 07:00:55.833261       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0512 07:00:55.833282       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0512 07:00:55.833764       1 azure_auth.go:245] Using AzurePublicCloud environment
I0512 07:00:55.833799       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0512 07:00:55.833824       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 819 lines ...
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
I0512 07:00:53.096337       1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test
I0512 07:00:53.097422       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0512 07:00:53.116286       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
I0512 07:00:53.116304       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0512 07:00:53.116311       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0512 07:00:53.116421       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0512 07:00:53.117022       1 azure_auth.go:245] Using AzurePublicCloud environment
I0512 07:00:53.117057       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0512 07:00:53.117087       1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 360 lines ...
# HELP process_virtual_memory_bytes Virtual memory size in bytes.
# TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 7.620608e+08
# HELP process_virtual_memory_max_bytes Maximum amount of virtual memory available in bytes.
# TYPE process_virtual_memory_max_bytes gauge
process_virtual_memory_max_bytes 1.8446744073709552e+19
make: *** [Makefile:85: e2e-test] Error 1
2022/05/12 07:10:48 process.go:155: Step 'make e2e-test' finished in 19m38.555448486s
2022/05/12 07:10:48 aksengine_helpers.go:426: downloading /root/tmp1625252499/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2022/05/12 07:10:48 util.go:71: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2022/05/12 07:10:48 process.go:153: Running: chmod +x /root/tmp1625252499/log-dump.sh
2022/05/12 07:10:48 process.go:155: Step 'chmod +x /root/tmp1625252499/log-dump.sh' finished in 1.462336ms
2022/05/12 07:10:48 aksengine_helpers.go:426: downloading /root/tmp1625252499/log-dump-daemonset.yaml from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump-daemonset.yaml
... skipping 53 lines ...
ssh key file /root/.ssh/id_rsa does not exist. Exiting.
2022/05/12 07:11:09 process.go:155: Step 'bash -c /root/tmp1625252499/win-ci-logs-collector.sh kubetest-oew5xopy.centralus.cloudapp.azure.com /root/tmp1625252499 /root/.ssh/id_rsa' finished in 4.269326ms
2022/05/12 07:11:09 aksengine.go:1141: Deleting resource group: kubetest-oew5xopy.
2022/05/12 07:17:25 process.go:96: Saved XML output to /logs/artifacts/junit_runner.xml.
2022/05/12 07:17:25 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
2022/05/12 07:17:26 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 285.755624ms
2022/05/12 07:17:26 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
34a8eb8e75a9
... skipping 4 lines ...