This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: test: enable fsGroup external test for nfs
ResultFAILURE
Tests 1 failed / 13 succeeded
Started2022-04-08 06:03
Elapsed38m43s
Revision34a83f4b50e794ce546f1940c49c1c3345eecd16
Refs 820
job-versionv1.24.0-beta.0.109+707b8b6efd1691
kubetest-version
revisionv1.24.0-beta.0.109+707b8b6efd1691

Test Failures


kubetest Test 26m19s

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   175k      0 --:--:-- --:--:-- --:--:--  175k
Downloading https://get.helm.sh/helm-v3.8.1-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-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e || make container-all push-manifest
Error response from daemon: manifest for k8sprow.azurecr.io/azurefile-csi:e2e-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e not found: manifest unknown: manifest tagged by "e2e-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e" 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-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.gitCommit=fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.buildDate=2022-04-08T06:07:59Z -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 1955 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 608 lines ...

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

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

    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:92
------------------------------
... skipping 152 lines ...
STEP: creating a claim
Apr  8 06:20:03.340: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:20:03.400: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comrwpvf] to have phase Bound
Apr  8 06:20:03.457: INFO: PersistentVolumeClaim test.csi.azure.comrwpvf found but phase is Pending instead of Bound.
Apr  8 06:20:05.516: INFO: PersistentVolumeClaim test.csi.azure.comrwpvf found and phase=Bound (2.116277835s)
STEP: [init] starting a pod to use the claim
Apr  8 06:20:05.694: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-md94f" in namespace "snapshotting-5587" to be "Succeeded or Failed"
Apr  8 06:20:05.751: INFO: Pod "pvc-snapshottable-tester-md94f": Phase="Pending", Reason="", readiness=false. Elapsed: 57.071056ms
Apr  8 06:20:07.814: INFO: Pod "pvc-snapshottable-tester-md94f": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.120108086s
STEP: Saw pod success
Apr  8 06:20:07.815: INFO: Pod "pvc-snapshottable-tester-md94f" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
Apr  8 06:20:07.873: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
STEP: updating the snapshot content deletion policy to retain
[AfterEach] volume snapshot controller
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:170
... skipping 182 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    Verify if offline PVC expansion works
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:174
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand Verify if offline PVC expansion works","total":22,"completed":1,"skipped":11,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] provisioning
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:20:29.408: INFO: Driver test.csi.azure.com doesn't support Block -- skipping
... skipping 211 lines ...
Apr  8 06:20:14.368: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:20:14.428: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjqrfx] to have phase Bound
Apr  8 06:20:14.485: INFO: PersistentVolumeClaim test.csi.azure.comjqrfx found but phase is Pending instead of Bound.
Apr  8 06:20:16.544: INFO: PersistentVolumeClaim test.csi.azure.comjqrfx found and phase=Bound (2.115860201s)
STEP: Creating pod pod-subpath-test-dynamicpv-g9wc
STEP: Creating a pod to test subpath
Apr  8 06:20:16.716: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-g9wc" in namespace "provisioning-4739" to be "Succeeded or Failed"
Apr  8 06:20:16.773: INFO: Pod "pod-subpath-test-dynamicpv-g9wc": Phase="Pending", Reason="", readiness=false. Elapsed: 56.979542ms
Apr  8 06:20:18.832: INFO: Pod "pod-subpath-test-dynamicpv-g9wc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.115699845s
Apr  8 06:20:20.890: INFO: Pod "pod-subpath-test-dynamicpv-g9wc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.173745822s
Apr  8 06:20:22.948: INFO: Pod "pod-subpath-test-dynamicpv-g9wc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.231922408s
Apr  8 06:20:25.007: INFO: Pod "pod-subpath-test-dynamicpv-g9wc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.290457054s
STEP: Saw pod success
Apr  8 06:20:25.007: INFO: Pod "pod-subpath-test-dynamicpv-g9wc" satisfied condition "Succeeded or Failed"
Apr  8 06:20:25.065: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000000 pod pod-subpath-test-dynamicpv-g9wc container test-container-subpath-dynamicpv-g9wc: <nil>
STEP: delete the pod
Apr  8 06:20:25.217: INFO: Waiting for pod pod-subpath-test-dynamicpv-g9wc to disappear
Apr  8 06:20:25.274: INFO: Pod pod-subpath-test-dynamicpv-g9wc no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-g9wc
Apr  8 06:20:25.274: INFO: Deleting pod "pod-subpath-test-dynamicpv-g9wc" in namespace "provisioning-4739"
... skipping 16 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support readOnly file specified in the volumeMount [LinuxOnly]
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:380
------------------------------
{"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":21,"completed":1,"skipped":773,"failed":0}

SSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (ntfs)][Feature:Windows] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:20:30.808: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 225 lines ...
Apr  8 06:20:20.766: INFO: PersistentVolumeClaim test.csi.azure.com49zbv found but phase is Pending instead of Bound.
Apr  8 06:20:22.825: INFO: PersistentVolumeClaim test.csi.azure.com49zbv found but phase is Pending instead of Bound.
Apr  8 06:20:24.884: INFO: PersistentVolumeClaim test.csi.azure.com49zbv found but phase is Pending instead of Bound.
Apr  8 06:20:26.942: INFO: PersistentVolumeClaim test.csi.azure.com49zbv found but phase is Pending instead of Bound.
Apr  8 06:20:29.000: INFO: PersistentVolumeClaim test.csi.azure.com49zbv found and phase=Bound (1m36.774021905s)
STEP: [init] starting a pod to use the claim
Apr  8 06:20:29.174: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-ct7gq" in namespace "snapshotting-7505" to be "Succeeded or Failed"
Apr  8 06:20:29.231: INFO: Pod "pvc-snapshottable-tester-ct7gq": Phase="Pending", Reason="", readiness=false. Elapsed: 56.95035ms
Apr  8 06:20:31.289: INFO: Pod "pvc-snapshottable-tester-ct7gq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.1149917s
STEP: Saw pod success
Apr  8 06:20:31.289: INFO: Pod "pvc-snapshottable-tester-ct7gq" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
Apr  8 06:20:31.346: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
STEP: updating the snapshot content deletion policy to retain
[AfterEach] volume snapshot controller
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:170
... skipping 92 lines ...
Apr  8 06:20:37.677: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:20:37.738: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjndtd] to have phase Bound
Apr  8 06:20:37.795: INFO: PersistentVolumeClaim test.csi.azure.comjndtd found but phase is Pending instead of Bound.
Apr  8 06:20:39.854: INFO: PersistentVolumeClaim test.csi.azure.comjndtd found and phase=Bound (2.115346661s)
STEP: Creating pod pod-subpath-test-dynamicpv-jwbb
STEP: Creating a pod to test subpath
Apr  8 06:20:40.026: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-jwbb" in namespace "provisioning-2698" to be "Succeeded or Failed"
Apr  8 06:20:40.085: INFO: Pod "pod-subpath-test-dynamicpv-jwbb": Phase="Pending", Reason="", readiness=false. Elapsed: 58.370304ms
Apr  8 06:20:42.143: INFO: Pod "pod-subpath-test-dynamicpv-jwbb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.116259291s
Apr  8 06:20:44.200: INFO: Pod "pod-subpath-test-dynamicpv-jwbb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.173166774s
Apr  8 06:20:46.257: INFO: Pod "pod-subpath-test-dynamicpv-jwbb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.230618015s
Apr  8 06:20:48.315: INFO: Pod "pod-subpath-test-dynamicpv-jwbb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.288274391s
STEP: Saw pod success
Apr  8 06:20:48.315: INFO: Pod "pod-subpath-test-dynamicpv-jwbb" satisfied condition "Succeeded or Failed"
Apr  8 06:20:48.372: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000001 pod pod-subpath-test-dynamicpv-jwbb container test-container-subpath-dynamicpv-jwbb: <nil>
STEP: delete the pod
Apr  8 06:20:48.519: INFO: Waiting for pod pod-subpath-test-dynamicpv-jwbb to disappear
Apr  8 06:20:48.576: INFO: Pod pod-subpath-test-dynamicpv-jwbb no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-jwbb
Apr  8 06:20:48.576: INFO: Deleting pod "pod-subpath-test-dynamicpv-jwbb" in namespace "provisioning-2698"
... skipping 16 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support existing single file [LinuxOnly]
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:219
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support existing single file [LinuxOnly]","total":13,"completed":1,"skipped":497,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Ephemeral Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Ephemeral Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 5 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:175
Apr  8 06:20:54.599: INFO: Creating resource for dynamic PV
Apr  8 06:20:54.599: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-6889-e2e-sclskp2
STEP: [init] starting a pod to use the claim
Apr  8 06:20:54.725: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-k77qt" in namespace "snapshotting-6889" to be "Succeeded or Failed"
Apr  8 06:20:54.781: INFO: Pod "pvc-snapshottable-tester-k77qt": Phase="Pending", Reason="", readiness=false. Elapsed: 56.677602ms
Apr  8 06:20:56.839: INFO: Pod "pvc-snapshottable-tester-k77qt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.114546299s
Apr  8 06:20:58.898: INFO: Pod "pvc-snapshottable-tester-k77qt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.173219215s
STEP: Saw pod success
Apr  8 06:20:58.898: INFO: Pod "pvc-snapshottable-tester-k77qt" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
Apr  8 06:20:58.955: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
Apr  8 06:20:58.956: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-k77qt-my-volume] to have phase Bound
Apr  8 06:20:59.014: INFO: PersistentVolumeClaim pvc-snapshottable-tester-k77qt-my-volume found and phase=Bound (57.773895ms)
STEP: [init] checking the PV
... skipping 107 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should create read/write inline ephemeral volume
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:194
------------------------------
{"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":22,"completed":2,"skipped":528,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 8 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:175
Apr  8 06:18:52.125: INFO: Creating resource for dynamic PV
Apr  8 06:18:52.125: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-7332-e2e-scq6n8f
STEP: [init] starting a pod to use the claim
Apr  8 06:18:52.254: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-28dg2" in namespace "snapshotting-7332" to be "Succeeded or Failed"
Apr  8 06:18:52.311: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 57.11645ms
Apr  8 06:18:54.368: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.114646498s
Apr  8 06:18:56.426: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.172727149s
Apr  8 06:18:58.486: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.231931794s
Apr  8 06:19:00.544: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.290392126s
Apr  8 06:19:02.602: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.348298289s
... skipping 60 lines ...
Apr  8 06:21:08.156: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 2m15.902641035s
Apr  8 06:21:10.215: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 2m17.961190288s
Apr  8 06:21:12.273: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 2m20.019266814s
Apr  8 06:21:14.331: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Pending", Reason="", readiness=false. Elapsed: 2m22.076918586s
Apr  8 06:21:16.389: INFO: Pod "pvc-snapshottable-tester-28dg2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2m24.13559308s
STEP: Saw pod success
Apr  8 06:21:16.389: INFO: Pod "pvc-snapshottable-tester-28dg2" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
Apr  8 06:21:16.447: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
Apr  8 06:21:16.448: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-28dg2-my-volume] to have phase Bound
Apr  8 06:21:16.505: INFO: PersistentVolumeClaim pvc-snapshottable-tester-28dg2-my-volume found and phase=Bound (57.151079ms)
STEP: [init] checking the PV
... skipping 132 lines ...
Apr  8 06:21:10.767: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:21:10.827: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com9rzck] to have phase Bound
Apr  8 06:21:10.884: INFO: PersistentVolumeClaim test.csi.azure.com9rzck found but phase is Pending instead of Bound.
Apr  8 06:21:12.941: INFO: PersistentVolumeClaim test.csi.azure.com9rzck found and phase=Bound (2.113714405s)
STEP: Creating pod pod-subpath-test-dynamicpv-gfvq
STEP: Creating a pod to test subpath
Apr  8 06:21:13.114: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-gfvq" in namespace "provisioning-639" to be "Succeeded or Failed"
Apr  8 06:21:13.171: INFO: Pod "pod-subpath-test-dynamicpv-gfvq": Phase="Pending", Reason="", readiness=false. Elapsed: 56.585601ms
Apr  8 06:21:15.228: INFO: Pod "pod-subpath-test-dynamicpv-gfvq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113865283s
Apr  8 06:21:17.286: INFO: Pod "pod-subpath-test-dynamicpv-gfvq": Phase="Running", Reason="", readiness=false. Elapsed: 4.171622805s
Apr  8 06:21:19.347: INFO: Pod "pod-subpath-test-dynamicpv-gfvq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.23235032s
STEP: Saw pod success
Apr  8 06:21:19.347: INFO: Pod "pod-subpath-test-dynamicpv-gfvq" satisfied condition "Succeeded or Failed"
Apr  8 06:21:19.404: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000000 pod pod-subpath-test-dynamicpv-gfvq container test-container-volume-dynamicpv-gfvq: <nil>
STEP: delete the pod
Apr  8 06:21:19.524: INFO: Waiting for pod pod-subpath-test-dynamicpv-gfvq to disappear
Apr  8 06:21:19.582: INFO: Pod pod-subpath-test-dynamicpv-gfvq no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-gfvq
Apr  8 06:21:19.582: INFO: Deleting pod "pod-subpath-test-dynamicpv-gfvq" in namespace "provisioning-639"
... skipping 16 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support existing directory
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:205
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support existing directory","total":22,"completed":3,"skipped":576,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:21:25.123: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 136 lines ...
Apr  8 06:21:00.373: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:21:00.431: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comn88x4] to have phase Bound
Apr  8 06:21:00.488: INFO: PersistentVolumeClaim test.csi.azure.comn88x4 found but phase is Pending instead of Bound.
Apr  8 06:21:02.545: INFO: PersistentVolumeClaim test.csi.azure.comn88x4 found and phase=Bound (2.113857859s)
STEP: Creating pod pod-subpath-test-dynamicpv-45n9
STEP: Creating a pod to test atomic-volume-subpath
Apr  8 06:21:02.719: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-45n9" in namespace "provisioning-4886" to be "Succeeded or Failed"
Apr  8 06:21:02.776: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Pending", Reason="", readiness=false. Elapsed: 56.780113ms
Apr  8 06:21:04.835: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.115352996s
Apr  8 06:21:06.893: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 4.173487917s
Apr  8 06:21:08.952: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 6.23223015s
Apr  8 06:21:11.009: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 8.289788677s
Apr  8 06:21:13.068: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 10.34850723s
Apr  8 06:21:15.126: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 12.406676036s
Apr  8 06:21:17.184: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 14.464548013s
Apr  8 06:21:19.243: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 16.523469389s
Apr  8 06:21:21.302: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 18.581971939s
Apr  8 06:21:23.360: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Running", Reason="", readiness=true. Elapsed: 20.640486924s
Apr  8 06:21:25.417: INFO: Pod "pod-subpath-test-dynamicpv-45n9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.697296745s
STEP: Saw pod success
Apr  8 06:21:25.417: INFO: Pod "pod-subpath-test-dynamicpv-45n9" satisfied condition "Succeeded or Failed"
Apr  8 06:21:25.473: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000000 pod pod-subpath-test-dynamicpv-45n9 container test-container-subpath-dynamicpv-45n9: <nil>
STEP: delete the pod
Apr  8 06:21:25.607: INFO: Waiting for pod pod-subpath-test-dynamicpv-45n9 to disappear
Apr  8 06:21:25.663: INFO: Pod pod-subpath-test-dynamicpv-45n9 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-45n9
Apr  8 06:21:25.663: INFO: Deleting pod "pod-subpath-test-dynamicpv-45n9" in namespace "provisioning-4886"
... skipping 16 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support file as subpath [LinuxOnly]
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:230
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support file as subpath [LinuxOnly]","total":13,"completed":2,"skipped":817,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:21:31.269: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
... skipping 31 lines ...
STEP: creating a claim
Apr  8 06:21:26.178: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:21:26.237: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com92mlb] to have phase Bound
Apr  8 06:21:26.293: INFO: PersistentVolumeClaim test.csi.azure.com92mlb found but phase is Pending instead of Bound.
Apr  8 06:21:28.350: INFO: PersistentVolumeClaim test.csi.azure.com92mlb found and phase=Bound (2.112920429s)
STEP: [init] starting a pod to use the claim
Apr  8 06:21:28.521: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-fplwd" in namespace "snapshotting-4046" to be "Succeeded or Failed"
Apr  8 06:21:28.578: INFO: Pod "pvc-snapshottable-tester-fplwd": Phase="Pending", Reason="", readiness=false. Elapsed: 56.897015ms
Apr  8 06:21:30.636: INFO: Pod "pvc-snapshottable-tester-fplwd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.114169836s
STEP: Saw pod success
Apr  8 06:21:30.636: INFO: Pod "pvc-snapshottable-tester-fplwd" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
Apr  8 06:21:30.706: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
Apr  8 06:21:30.707: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com92mlb] to have phase Bound
Apr  8 06:21:30.763: INFO: PersistentVolumeClaim test.csi.azure.com92mlb found and phase=Bound (56.33797ms)
STEP: [init] checking the PV
... skipping 220 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":14,"completed":1,"skipped":240,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:246
... skipping 42 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should resize volume when PVC is edited while pod is using it
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:246
------------------------------
{"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":22,"completed":4,"skipped":877,"failed":0}

SSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:21:53.428: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 189 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should not mount / map unused volumes in a pod [LinuxOnly]
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:352
------------------------------
{"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":13,"completed":1,"skipped":284,"failed":0}

SSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ext4)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:21:59.558: INFO: Driver test.csi.azure.com doesn't support ext4 -- skipping
... skipping 118 lines ...
Apr  8 06:21:31.645: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:21:31.704: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comgc7n7] to have phase Bound
Apr  8 06:21:31.760: INFO: PersistentVolumeClaim test.csi.azure.comgc7n7 found but phase is Pending instead of Bound.
Apr  8 06:21:33.818: INFO: PersistentVolumeClaim test.csi.azure.comgc7n7 found and phase=Bound (2.114597316s)
STEP: Expanding non-expandable pvc
Apr  8 06:21:33.933: INFO: currentPvcSize {{5368709120 0} {<nil>} 5Gi BinarySI}, newSize {{6442450944 0} {<nil>}  BinarySI}
Apr  8 06:21:34.049: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:36.165: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:38.165: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:40.166: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:42.165: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:44.165: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:46.163: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:48.551: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:50.166: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:52.164: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:54.169: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:56.168: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:21:58.165: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:22:00.165: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:22:02.167: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:22:04.164: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Apr  8 06:22:04.279: INFO: Error updating pvc test.csi.azure.comgc7n7: persistentvolumeclaims "test.csi.azure.comgc7n7" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
Apr  8 06:22:04.279: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comgc7n7"
Apr  8 06:22:04.338: INFO: Waiting up to 5m0s for PersistentVolume pvc-7e70bcfc-a6eb-410d-8a34-de7febadda83 to get deleted
Apr  8 06:22:04.394: INFO: PersistentVolume pvc-7e70bcfc-a6eb-410d-8a34-de7febadda83 found and phase=Released (56.45147ms)
Apr  8 06:22:09.451: INFO: PersistentVolume pvc-7e70bcfc-a6eb-410d-8a34-de7febadda83 was removed
STEP: Deleting sc
... skipping 8 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volume-expand
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should not allow expansion of pvcs without AllowVolumeExpansion property
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:157
------------------------------
{"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":13,"completed":3,"skipped":895,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:22:09.723: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping
... skipping 70 lines ...
Apr  8 06:22:13.283: INFO: ExecWithOptions: execute(POST https://kubetest-xmzujtwb.westus2.cloudapp.azure.com/api/v1/namespaces/volume-4874/pods/external-client/exec?command=%2Fbin%2Fsh&command=-c&command=test+-d+%2Fopt%2F0&container=external-client&container=external-client&stderr=true&stdout=true %!s(MISSING))
Apr  8 06:22:13.723: INFO: ExecWithOptions {Command:[/bin/sh -c test -b /opt/0] Namespace:volume-4874 PodName:external-client ContainerName:external-client Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Apr  8 06:22:13.723: INFO: >>> kubeConfig: /root/tmp794858964/kubeconfig/kubeconfig.westus2.json
Apr  8 06:22:13.725: INFO: ExecWithOptions: Clientset creation
Apr  8 06:22:13.725: INFO: ExecWithOptions: execute(POST https://kubetest-xmzujtwb.westus2.cloudapp.azure.com/api/v1/namespaces/volume-4874/pods/external-client/exec?command=%2Fbin%2Fsh&command=-c&command=test+-b+%2Fopt%2F0&container=external-client&container=external-client&stderr=true&stdout=true %!s(MISSING))
STEP: Repeating the test on an ephemeral container (if enabled)
Apr  8 06:22:14.283: 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-4874
Apr  8 06:22:14.340: INFO: Waiting for pod external-client to disappear
Apr  8 06:22:14.396: INFO: Pod external-client still exists
Apr  8 06:22:16.397: INFO: Waiting for pod external-client to disappear
Apr  8 06:22:16.455: INFO: Pod external-client no longer exists
STEP: cleaning the environment after external
... skipping 14 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should store data
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:159
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should store data","total":13,"completed":2,"skipped":556,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:22:21.929: INFO: Driver "test.csi.azure.com" does not support block volume mode - skipping
... skipping 78 lines ...
Apr  8 06:22:22.315: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:22:22.377: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comh44f5] to have phase Bound
Apr  8 06:22:22.433: INFO: PersistentVolumeClaim test.csi.azure.comh44f5 found but phase is Pending instead of Bound.
Apr  8 06:22:24.489: INFO: PersistentVolumeClaim test.csi.azure.comh44f5 found and phase=Bound (2.112494618s)
STEP: Creating pod pod-subpath-test-dynamicpv-bkx5
STEP: Creating a pod to test subpath
Apr  8 06:22:24.661: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-bkx5" in namespace "provisioning-1272" to be "Succeeded or Failed"
Apr  8 06:22:24.717: INFO: Pod "pod-subpath-test-dynamicpv-bkx5": Phase="Pending", Reason="", readiness=false. Elapsed: 56.648183ms
Apr  8 06:22:26.775: INFO: Pod "pod-subpath-test-dynamicpv-bkx5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.114135665s
Apr  8 06:22:28.832: INFO: Pod "pod-subpath-test-dynamicpv-bkx5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.171118399s
STEP: Saw pod success
Apr  8 06:22:28.832: INFO: Pod "pod-subpath-test-dynamicpv-bkx5" satisfied condition "Succeeded or Failed"
Apr  8 06:22:28.888: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000001 pod pod-subpath-test-dynamicpv-bkx5 container test-container-volume-dynamicpv-bkx5: <nil>
STEP: delete the pod
Apr  8 06:22:29.007: INFO: Waiting for pod pod-subpath-test-dynamicpv-bkx5 to disappear
Apr  8 06:22:29.063: INFO: Pod pod-subpath-test-dynamicpv-bkx5 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-bkx5
Apr  8 06:22:29.063: INFO: Deleting pod "pod-subpath-test-dynamicpv-bkx5" in namespace "provisioning-1272"
... skipping 16 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support non-existent path
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:194
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support non-existent path","total":13,"completed":3,"skipped":667,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:214
... skipping 48 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support two pods which have the same volume definition
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:214
------------------------------
{"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":20,"completed":1,"skipped":326,"failed":0}

SSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (ext3)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:22:36.493: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 36 lines ...
Apr  8 06:22:35.161: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:22:35.221: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comn87jp] to have phase Bound
Apr  8 06:22:35.277: INFO: PersistentVolumeClaim test.csi.azure.comn87jp found but phase is Pending instead of Bound.
Apr  8 06:22:37.334: INFO: PersistentVolumeClaim test.csi.azure.comn87jp found and phase=Bound (2.113577301s)
STEP: Creating pod pod-subpath-test-dynamicpv-n66q
STEP: Creating a pod to test subpath
Apr  8 06:22:37.507: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-n66q" in namespace "provisioning-6871" to be "Succeeded or Failed"
Apr  8 06:22:37.564: INFO: Pod "pod-subpath-test-dynamicpv-n66q": Phase="Pending", Reason="", readiness=false. Elapsed: 57.053165ms
Apr  8 06:22:39.621: INFO: Pod "pod-subpath-test-dynamicpv-n66q": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113563052s
Apr  8 06:22:41.681: INFO: Pod "pod-subpath-test-dynamicpv-n66q": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.173585454s
STEP: Saw pod success
Apr  8 06:22:41.681: INFO: Pod "pod-subpath-test-dynamicpv-n66q" satisfied condition "Succeeded or Failed"
Apr  8 06:22:41.737: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000000 pod pod-subpath-test-dynamicpv-n66q container test-container-subpath-dynamicpv-n66q: <nil>
STEP: delete the pod
Apr  8 06:22:41.861: INFO: Waiting for pod pod-subpath-test-dynamicpv-n66q to disappear
Apr  8 06:22:41.917: INFO: Pod pod-subpath-test-dynamicpv-n66q no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-n66q
Apr  8 06:22:41.917: INFO: Deleting pod "pod-subpath-test-dynamicpv-n66q" in namespace "provisioning-6871"
... skipping 16 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support readOnly directory specified in the volumeMount
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:365
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support readOnly directory specified in the volumeMount","total":13,"completed":4,"skipped":884,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral 
  should create read-only inline ephemeral volume
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:173
... skipping 37 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should create read-only inline ephemeral volume
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:173
------------------------------
{"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":20,"completed":2,"skipped":440,"failed":0}

SS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)(allowExpansion)][Feature:Windows] volume-expand
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:23:16.712: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 69 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support two pods which have the same volume definition
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:214
------------------------------
{"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":13,"completed":4,"skipped":955,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 10 lines ...
STEP: creating a claim
Apr  8 06:23:17.093: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:23:17.153: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com7wsrn] to have phase Bound
Apr  8 06:23:17.211: INFO: PersistentVolumeClaim test.csi.azure.com7wsrn found but phase is Pending instead of Bound.
Apr  8 06:23:19.268: INFO: PersistentVolumeClaim test.csi.azure.com7wsrn found and phase=Bound (2.114935391s)
STEP: [init] starting a pod to use the claim
Apr  8 06:23:19.441: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-fzq92" in namespace "snapshotting-1839" to be "Succeeded or Failed"
Apr  8 06:23:19.506: INFO: Pod "pvc-snapshottable-tester-fzq92": Phase="Pending", Reason="", readiness=false. Elapsed: 64.663875ms
Apr  8 06:23:21.564: INFO: Pod "pvc-snapshottable-tester-fzq92": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.123025097s
STEP: Saw pod success
Apr  8 06:23:21.564: INFO: Pod "pvc-snapshottable-tester-fzq92" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
Apr  8 06:23:21.621: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping
Apr  8 06:23:21.622: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com7wsrn] to have phase Bound
Apr  8 06:23:21.679: INFO: PersistentVolumeClaim test.csi.azure.com7wsrn found and phase=Bound (56.781893ms)
STEP: [init] checking the PV
... skipping 281 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":13,"completed":5,"skipped":991,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
Apr  8 06:23:28.644: INFO: Running AfterSuite actions on all nodes
Apr  8 06:23:28.644: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func18.2
Apr  8 06:23:28.644: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func8.2
... skipping 114 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with different fsgroup applied to the volume contents
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with different fsgroup applied to the volume contents","total":20,"completed":3,"skipped":923,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
Apr  8 06:23:52.409: INFO: Running AfterSuite actions on all nodes
Apr  8 06:23:52.409: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func18.2
Apr  8 06:23:52.409: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func8.2
... skipping 47 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should create read/write inline ephemeral volume
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:194
------------------------------
{"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":13,"completed":5,"skipped":996,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
Apr  8 06:24:03.171: INFO: Running AfterSuite actions on all nodes
Apr  8 06:24:03.171: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func18.2
Apr  8 06:24:03.171: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func8.2
... skipping 108 lines ...
Apr  8 06:20:51.731: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-7010 PodName:pod-3d9bc2f6-2558-4270-8a58-0a6998d22bfb ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Apr  8 06:20:51.731: INFO: >>> kubeConfig: /root/tmp794858964/kubeconfig/kubeconfig.westus2.json
Apr  8 06:20:51.732: INFO: ExecWithOptions: Clientset creation
Apr  8 06:20:51.732: INFO: ExecWithOptions: execute(POST https://kubetest-xmzujtwb.westus2.cloudapp.azure.com/api/v1/namespaces/fsgroupchangepolicy-7010/pods/pod-3d9bc2f6-2558-4270-8a58-0a6998d22bfb/exec?command=%2Fbin%2Fsh&command=-c&command=ls+-l+%2Fmnt%2Fvolume1%2Fsubdir%2Ffile2&container=write-pod&container=write-pod&stderr=true&stdout=true %!s(MISSING))
Apr  8 06:20:52.247: INFO: pod fsgroupchangepolicy-7010/pod-3d9bc2f6-2558-4270-8a58-0a6998d22bfb exec for cmd ls -l /mnt/volume1/subdir/file2, stdout: -rw-r--r--    1 root     root             0 Apr  8 06:20 /mnt/volume1/subdir/file2, stderr: 
Apr  8 06:20:52.247: INFO: stdout split: [-rw-r--r-- 1 root root 0 Apr 8 06:20 /mnt/volume1/subdir/file2], expected gid: 1000
Apr  8 06:20:52.247: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0x6ecc9f5, {0x6f1e2db, 0x0}, {0xc00014ac88, 0x4}, 0xc0020ab000)
... skipping 71 lines ...
Apr  8 06:25:30.399: INFO: PersistentVolume pvc-e096efe9-5c4c-4083-9888-10d5e87067fd found and phase=Bound (4m38.095755988s)
Apr  8 06:25:35.454: INFO: PersistentVolume pvc-e096efe9-5c4c-4083-9888-10d5e87067fd found and phase=Bound (4m43.150390569s)
Apr  8 06:25:40.510: INFO: PersistentVolume pvc-e096efe9-5c4c-4083-9888-10d5e87067fd found and phase=Bound (4m48.206471281s)
Apr  8 06:25:45.564: INFO: PersistentVolume pvc-e096efe9-5c4c-4083-9888-10d5e87067fd found and phase=Bound (4m53.260121429s)
Apr  8 06:25:50.619: INFO: PersistentVolume pvc-e096efe9-5c4c-4083-9888-10d5e87067fd found and phase=Bound (4m58.315530715s)
STEP: Deleting sc
Apr  8 06:25:55.681: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-e096efe9-5c4c-4083-9888-10d5e87067fd not deleted by dynamic provisioner: PersistentVolume pvc-e096efe9-5c4c-4083-9888-10d5e87067fd still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-e096efe9-5c4c-4083-9888-10d5e87067fd still exists within 5m0s",
... skipping 6 lines ...

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/testsuites.(*fsGroupChangePolicyTestSuite).DefineTests.func2()
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:132 +0x20f
panic({0x6a34a60, 0xc001eefc80})
	/usr/local/go/src/runtime/panic.go:1038 +0x215
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1()
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0x73
panic({0x6107b00, 0x7693f30})
	/usr/local/go/src/runtime/panic.go:1038 +0x215
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail({0xc000fec7d0, 0x4c}, {0xc004ad2ca0, 0x6ec0bea, 0xc004ad2cc0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1a7
k8s.io/kubernetes/test/e2e/framework.Fail({0xc004b22680, 0x37}, {0xc002fe9310, 0xc004b22680, 0x6de25a0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:63 +0x149
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc004ad2e10, {0x779f1e8, 0xc0009a8f00}, 0x1, {0x0, 0x0, 0x0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x1bd
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc004ad2e10, {0x779f1e8, 0xc0009a8f00}, {0x0, 0x0, 0x0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0x95
k8s.io/kubernetes/test/e2e/framework.ExpectEqual({0x6107b00, 0xc0009a8e30}, {0x6107b00, 0xc0009a8e40}, {0x0, 0x0, 0x0})
... skipping 138 lines ...
        <string>: root
    to equal
        <string>: 1000

    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/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, volume contents ownership changed in first pod, new pod with same fsgroup applied to the volume contents","total":20,"completed":0,"skipped":114,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy 
  (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208
... skipping 74 lines ...
Apr  8 06:21:56.950: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/file1] Namespace:fsgroupchangepolicy-4369 PodName:pod-c868ba9f-8357-45f6-a2d7-e09bd7649a1e ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Apr  8 06:21:56.950: INFO: >>> kubeConfig: /root/tmp794858964/kubeconfig/kubeconfig.westus2.json
Apr  8 06:21:56.952: INFO: ExecWithOptions: Clientset creation
Apr  8 06:21:56.952: INFO: ExecWithOptions: execute(POST https://kubetest-xmzujtwb.westus2.cloudapp.azure.com/api/v1/namespaces/fsgroupchangepolicy-4369/pods/pod-c868ba9f-8357-45f6-a2d7-e09bd7649a1e/exec?command=%2Fbin%2Fsh&command=-c&command=ls+-l+%2Fmnt%2Fvolume1%2Ffile1&container=write-pod&container=write-pod&stderr=true&stdout=true %!s(MISSING))
Apr  8 06:21:57.430: INFO: pod fsgroupchangepolicy-4369/pod-c868ba9f-8357-45f6-a2d7-e09bd7649a1e exec for cmd ls -l /mnt/volume1/file1, stdout: -rw-rw-r--    1 root     1000             0 Apr  8 06:21 /mnt/volume1/file1, stderr: 
Apr  8 06:21:57.430: INFO: stdout split: [-rw-rw-r-- 1 root 1000 0 Apr 8 06:21 /mnt/volume1/file1], expected gid: 2000
Apr  8 06:21:57.430: FAIL: Expected
    <string>: 1000
to equal
    <string>: 2000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0xc0006ad9c0, {0x6ef33da, 0x0}, {0xc003c3cf00, 0x4}, 0xc004b31c00)
... skipping 71 lines ...
Apr  8 06:26:35.774: INFO: PersistentVolume pvc-902d4ffc-328e-435b-be55-f0ff40a9ac81 found and phase=Bound (4m38.284523855s)
Apr  8 06:26:40.832: INFO: PersistentVolume pvc-902d4ffc-328e-435b-be55-f0ff40a9ac81 found and phase=Bound (4m43.342354509s)
Apr  8 06:26:45.892: INFO: PersistentVolume pvc-902d4ffc-328e-435b-be55-f0ff40a9ac81 found and phase=Bound (4m48.402305863s)
Apr  8 06:26:50.952: INFO: PersistentVolume pvc-902d4ffc-328e-435b-be55-f0ff40a9ac81 found and phase=Bound (4m53.462119963s)
Apr  8 06:26:56.020: INFO: PersistentVolume pvc-902d4ffc-328e-435b-be55-f0ff40a9ac81 found and phase=Bound (4m58.530993916s)
STEP: Deleting sc
Apr  8 06:27:01.084: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-902d4ffc-328e-435b-be55-f0ff40a9ac81 not deleted by dynamic provisioner: PersistentVolume pvc-902d4ffc-328e-435b-be55-f0ff40a9ac81 still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-902d4ffc-328e-435b-be55-f0ff40a9ac81 still exists within 5m0s",
... skipping 6 lines ...

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/testsuites.(*fsGroupChangePolicyTestSuite).DefineTests.func2()
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:132 +0x20f
panic({0x6a34a60, 0xc002c1dd80})
	/usr/local/go/src/runtime/panic.go:1038 +0x215
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1()
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0x73
panic({0x6107b00, 0x7693f30})
	/usr/local/go/src/runtime/panic.go:1038 +0x215
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail({0xc002566eb0, 0x4c}, {0xc004bc6ca0, 0x6ec0bea, 0xc004bc6cc0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1a7
k8s.io/kubernetes/test/e2e/framework.Fail({0xc001e11700, 0x37}, {0xc004b3d4f0, 0xc001e11700, 0x6de25a0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:63 +0x149
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc004bc6e10, {0x779f1e8, 0xc00475c210}, 0x1, {0x0, 0x0, 0x0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x1bd
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc004bc6e10, {0x779f1e8, 0xc00475c210}, {0x0, 0x0, 0x0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0x95
k8s.io/kubernetes/test/e2e/framework.ExpectEqual({0x6107b00, 0xc00475c1f0}, {0x6107b00, 0xc00475c200}, {0x0, 0x0, 0x0})
... skipping 144 lines ...
        <string>: 1000
    to equal
        <string>: 2000

    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/utils.go:728
------------------------------
{"msg":"FAILED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents","total":14,"completed":1,"skipped":285,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents"]}

SSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral 
  should support multiple inline ephemeral volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:252
... skipping 36 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support multiple inline ephemeral volumes
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:252
------------------------------
{"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":20,"completed":1,"skipped":142,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:27:17.020: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 45 lines ...

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

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

    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:92
------------------------------
... skipping 68 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should be able to unmount after the subpath directory is deleted [LinuxOnly]
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:445
------------------------------
{"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":20,"completed":2,"skipped":437,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 152 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should create read-only inline ephemeral volume
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:173
------------------------------
{"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":14,"completed":2,"skipped":297,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:27:40.949: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 120 lines ...
Apr  8 06:27:33.656: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Apr  8 06:27:33.712: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com7x5g7] to have phase Bound
Apr  8 06:27:33.766: INFO: PersistentVolumeClaim test.csi.azure.com7x5g7 found but phase is Pending instead of Bound.
Apr  8 06:27:35.820: INFO: PersistentVolumeClaim test.csi.azure.com7x5g7 found and phase=Bound (2.108703932s)
STEP: Creating pod exec-volume-test-dynamicpv-tf9n
STEP: Creating a pod to test exec-volume-test
Apr  8 06:27:35.984: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-tf9n" in namespace "volume-7184" to be "Succeeded or Failed"
Apr  8 06:27:36.038: INFO: Pod "exec-volume-test-dynamicpv-tf9n": Phase="Pending", Reason="", readiness=false. Elapsed: 53.539911ms
Apr  8 06:27:38.093: INFO: Pod "exec-volume-test-dynamicpv-tf9n": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108932925s
Apr  8 06:27:40.148: INFO: Pod "exec-volume-test-dynamicpv-tf9n": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.164270354s
STEP: Saw pod success
Apr  8 06:27:40.148: INFO: Pod "exec-volume-test-dynamicpv-tf9n" satisfied condition "Succeeded or Failed"
Apr  8 06:27:40.202: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000000 pod exec-volume-test-dynamicpv-tf9n container exec-container-dynamicpv-tf9n: <nil>
STEP: delete the pod
Apr  8 06:27:40.326: INFO: Waiting for pod exec-volume-test-dynamicpv-tf9n to disappear
Apr  8 06:27:40.380: INFO: Pod exec-volume-test-dynamicpv-tf9n no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-tf9n
Apr  8 06:27:40.380: INFO: Deleting pod "exec-volume-test-dynamicpv-tf9n" in namespace "volume-7184"
... skipping 14 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:196
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should allow exec of files on the volume","total":20,"completed":3,"skipped":831,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:27:45.842: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 74 lines ...
Apr  8 06:28:17.177: INFO: PersistentVolumeClaim test.csi.azure.com68t57 found but phase is Pending instead of Bound.
Apr  8 06:28:19.233: INFO: PersistentVolumeClaim test.csi.azure.com68t57 found but phase is Pending instead of Bound.
Apr  8 06:28:21.291: INFO: PersistentVolumeClaim test.csi.azure.com68t57 found but phase is Pending instead of Bound.
Apr  8 06:28:23.346: INFO: PersistentVolumeClaim test.csi.azure.com68t57 found and phase=Bound (37.053697817s)
STEP: Creating pod pod-subpath-test-dynamicpv-hzc2
STEP: Creating a pod to test subpath
Apr  8 06:28:23.511: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hzc2" in namespace "provisioning-5813" to be "Succeeded or Failed"
Apr  8 06:28:23.565: INFO: Pod "pod-subpath-test-dynamicpv-hzc2": Phase="Pending", Reason="", readiness=false. Elapsed: 53.983965ms
Apr  8 06:28:25.619: INFO: Pod "pod-subpath-test-dynamicpv-hzc2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107986336s
Apr  8 06:28:27.674: INFO: Pod "pod-subpath-test-dynamicpv-hzc2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.16312375s
STEP: Saw pod success
Apr  8 06:28:27.674: INFO: Pod "pod-subpath-test-dynamicpv-hzc2" satisfied condition "Succeeded or Failed"
Apr  8 06:28:27.728: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000001 pod pod-subpath-test-dynamicpv-hzc2 container test-container-subpath-dynamicpv-hzc2: <nil>
STEP: delete the pod
Apr  8 06:28:27.848: INFO: Waiting for pod pod-subpath-test-dynamicpv-hzc2 to disappear
Apr  8 06:28:27.902: INFO: Pod pod-subpath-test-dynamicpv-hzc2 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-hzc2
Apr  8 06:28:27.902: INFO: Deleting pod "pod-subpath-test-dynamicpv-hzc2" in namespace "provisioning-5813"
STEP: Creating pod pod-subpath-test-dynamicpv-hzc2
STEP: Creating a pod to test subpath
Apr  8 06:28:28.011: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hzc2" in namespace "provisioning-5813" to be "Succeeded or Failed"
Apr  8 06:28:28.065: INFO: Pod "pod-subpath-test-dynamicpv-hzc2": Phase="Pending", Reason="", readiness=false. Elapsed: 53.700807ms
Apr  8 06:28:30.120: INFO: Pod "pod-subpath-test-dynamicpv-hzc2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.108719749s
STEP: Saw pod success
Apr  8 06:28:30.120: INFO: Pod "pod-subpath-test-dynamicpv-hzc2" satisfied condition "Succeeded or Failed"
Apr  8 06:28:30.174: INFO: Trying to get logs from node k8s-agentpool1-21626799-vmss000001 pod pod-subpath-test-dynamicpv-hzc2 container test-container-subpath-dynamicpv-hzc2: <nil>
STEP: delete the pod
Apr  8 06:28:30.291: INFO: Waiting for pod pod-subpath-test-dynamicpv-hzc2 to disappear
Apr  8 06:28:30.345: INFO: Pod pod-subpath-test-dynamicpv-hzc2 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-hzc2
Apr  8 06:28:30.345: INFO: Deleting pod "pod-subpath-test-dynamicpv-hzc2" in namespace "provisioning-5813"
... skipping 16 lines ...
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support existing directories when readOnly specified in the volumeSource
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:395
------------------------------
{"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":20,"completed":4,"skipped":914,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:28:35.866: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 102 lines ...
Apr  8 06:28:10.987: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-4678 PodName:pod-187be0ee-cdd8-4eff-abe7-d1c0fdb50959 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Apr  8 06:28:10.987: INFO: >>> kubeConfig: /root/tmp794858964/kubeconfig/kubeconfig.westus2.json
Apr  8 06:28:10.988: INFO: ExecWithOptions: Clientset creation
Apr  8 06:28:10.988: INFO: ExecWithOptions: execute(POST https://kubetest-xmzujtwb.westus2.cloudapp.azure.com/api/v1/namespaces/fsgroupchangepolicy-4678/pods/pod-187be0ee-cdd8-4eff-abe7-d1c0fdb50959/exec?command=%2Fbin%2Fsh&command=-c&command=ls+-l+%2Fmnt%2Fvolume1%2Fsubdir%2Ffile2&container=write-pod&container=write-pod&stderr=true&stdout=true %!s(MISSING))
Apr  8 06:28:11.504: INFO: pod fsgroupchangepolicy-4678/pod-187be0ee-cdd8-4eff-abe7-d1c0fdb50959 exec for cmd ls -l /mnt/volume1/subdir/file2, stdout: -rw-r--r--    1 root     root             0 Apr  8 06:28 /mnt/volume1/subdir/file2, stderr: 
Apr  8 06:28:11.504: INFO: stdout split: [-rw-r--r-- 1 root root 0 Apr 8 06:28 /mnt/volume1/subdir/file2], expected gid: 1000
Apr  8 06:28:11.504: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0x6ecc9f5, {0x6f1e2db, 0x0}, {0xc00552fb18, 0x4}, 0xc0025a3400)
... skipping 71 lines ...
Apr  8 06:32:49.837: INFO: PersistentVolume pvc-689bf1ac-7b94-4ada-ae22-e03c3fc710f8 found and phase=Bound (4m38.273445158s)
Apr  8 06:32:54.895: INFO: PersistentVolume pvc-689bf1ac-7b94-4ada-ae22-e03c3fc710f8 found and phase=Bound (4m43.331817104s)
Apr  8 06:32:59.952: INFO: PersistentVolume pvc-689bf1ac-7b94-4ada-ae22-e03c3fc710f8 found and phase=Bound (4m48.388914594s)
Apr  8 06:33:05.010: INFO: PersistentVolume pvc-689bf1ac-7b94-4ada-ae22-e03c3fc710f8 found and phase=Bound (4m53.446624867s)
Apr  8 06:33:10.072: INFO: PersistentVolume pvc-689bf1ac-7b94-4ada-ae22-e03c3fc710f8 found and phase=Bound (4m58.508636646s)
STEP: Deleting sc
Apr  8 06:33:15.136: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-689bf1ac-7b94-4ada-ae22-e03c3fc710f8 not deleted by dynamic provisioner: PersistentVolume pvc-689bf1ac-7b94-4ada-ae22-e03c3fc710f8 still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-689bf1ac-7b94-4ada-ae22-e03c3fc710f8 still exists within 5m0s",
... skipping 6 lines ...

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/testsuites.(*fsGroupChangePolicyTestSuite).DefineTests.func2()
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:132 +0x20f
panic({0x6a34a60, 0xc0035ea9c0})
	/usr/local/go/src/runtime/panic.go:1038 +0x215
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1()
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0x73
panic({0x6107b00, 0x7693f30})
	/usr/local/go/src/runtime/panic.go:1038 +0x215
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail({0xc004454820, 0x4c}, {0xc005606ca0, 0x6ec0bea, 0xc005606cc0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1a7
k8s.io/kubernetes/test/e2e/framework.Fail({0xc003f87500, 0x37}, {0xc00401e640, 0xc003f87500, 0x6de25a0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:63 +0x149
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc005606e10, {0x779f1e8, 0xc00066ccd0}, 0x1, {0x0, 0x0, 0x0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x1bd
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc005606e10, {0x779f1e8, 0xc00066ccd0}, {0x0, 0x0, 0x0})
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0x95
k8s.io/kubernetes/test/e2e/framework.ExpectEqual({0x6107b00, 0xc00066cb70}, {0x6107b00, 0xc00066cca0}, {0x0, 0x0, 0x0})
... skipping 136 lines ...
        <string>: root
    to equal
        <string>: 1000

    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/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, volume contents ownership changed in first pod, new pod with different fsgroup applied to the volume contents","total":14,"completed":2,"skipped":784,"failed":2,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents","External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with different fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Apr  8 06:33:16.958: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 57 lines ...
Apr  8 06:33:17.152: INFO: Running AfterSuite actions on node 1



Summarizing 3 Failures:

[Fail] External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [Measurement] (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup applied to the volume contents 
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/utils.go:728

[Fail] External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [Measurement] (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents 
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/utils.go:728

[Fail] External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [Measurement] (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with different fsgroup applied to the volume contents 
/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/utils.go:728

Ran 27 of 7300 Specs in 866.770 seconds
FAIL! -- 24 Passed | 3 Failed | 0 Pending | 7273 Skipped 

Ginkgo ran 1 suite in 14m30.899552743s
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
Platform: linux/amd64

Streaming logs below:
I0408 06:18:42.377620       1 azurefile.go:266] driver userAgent: test.csi.azure.com/e2e-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e gc/go1.18 (amd64-linux) e2e-test
I0408 06:18:42.377934       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0408 06:18:42.405485       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
I0408 06:18:42.405506       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0408 06:18:42.405514       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0408 06:18:42.405537       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0408 06:18:42.406103       1 azure_auth.go:245] Using AzurePublicCloud environment
I0408 06:18:42.406136       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0408 06:18:42.406158       1 azure.go:738] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 102 lines ...
Go Version: go1.18
Platform: linux/amd64

Streaming logs below:
I0408 06:18:39.298085       1 azurefile.go:266] driver userAgent: test.csi.azure.com/e2e-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e gc/go1.18 (amd64-linux) e2e-test
I0408 06:18:39.298348       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0408 06:18:39.323228       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
I0408 06:18:39.323249       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0408 06:18:39.323255       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0408 06:18:39.323274       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0408 06:18:39.323709       1 azure_auth.go:245] Using AzurePublicCloud environment
I0408 06:18:39.323745       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0408 06:18:39.323769       1 azure.go:738] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 756 lines ...
Go Version: go1.18
Platform: linux/amd64

Streaming logs below:
I0408 06:18:29.681480       1 azurefile.go:266] driver userAgent: test.csi.azure.com/e2e-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e gc/go1.18 (amd64-linux) e2e-test
I0408 06:18:29.681816       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0408 06:18:29.710576       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
I0408 06:18:29.710597       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0408 06:18:29.710605       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0408 06:18:29.710627       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0408 06:18:29.711325       1 azure_auth.go:245] Using AzurePublicCloud environment
I0408 06:18:29.711388       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0408 06:18:29.711430       1 azure.go:738] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 70 lines ...
Go Version: go1.18
Platform: linux/amd64

Streaming logs below:
I0408 06:18:34.710052       1 azurefile.go:266] driver userAgent: test.csi.azure.com/e2e-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e gc/go1.18 (amd64-linux) e2e-test
I0408 06:18:34.710465       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0408 06:18:34.734739       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
I0408 06:18:34.734856       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0408 06:18:34.734864       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0408 06:18:34.734902       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0408 06:18:34.735464       1 azure_auth.go:245] Using AzurePublicCloud environment
I0408 06:18:34.735506       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0408 06:18:34.735532       1 azure.go:738] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 905 lines ...
Go Version: go1.18
Platform: linux/amd64

Streaming logs below:
I0408 06:18:34.490718       1 azurefile.go:266] driver userAgent: test.csi.azure.com/e2e-fb8ac24d9a7c8095e0c5fbc810f6a23eb57a249e gc/go1.18 (amd64-linux) e2e-test
I0408 06:18:34.491018       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
W0408 06:18:34.515482       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
I0408 06:18:34.515500       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0408 06:18:34.515506       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0408 06:18:34.515529       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0408 06:18:34.515975       1 azure_auth.go:245] Using AzurePublicCloud environment
I0408 06:18:34.516001       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0408 06:18:34.516028       1 azure.go:738] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 894 lines ...
# HELP process_virtual_memory_bytes Virtual memory size in bytes.
# TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 7.62036224e+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/04/08 06:34:18 process.go:155: Step 'make e2e-test' finished in 26m19.631793021s
2022/04/08 06:34:18 aksengine_helpers.go:426: downloading /root/tmp794858964/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2022/04/08 06:34:18 util.go:68: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2022/04/08 06:34:19 process.go:153: Running: chmod +x /root/tmp794858964/log-dump.sh
2022/04/08 06:34:19 process.go:155: Step 'chmod +x /root/tmp794858964/log-dump.sh' finished in 1.131971ms
2022/04/08 06:34:19 aksengine_helpers.go:426: downloading /root/tmp794858964/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/04/08 06:34:53 process.go:155: Step 'bash -c /root/tmp794858964/win-ci-logs-collector.sh kubetest-xmzujtwb.westus2.cloudapp.azure.com /root/tmp794858964 /root/.ssh/id_rsa' finished in 4.553494ms
2022/04/08 06:34:53 aksengine.go:1141: Deleting resource group: kubetest-xmzujtwb.
2022/04/08 06:41:58 process.go:96: Saved XML output to /logs/artifacts/junit_runner.xml.
2022/04/08 06:41:58 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
2022/04/08 06:41:58 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 219.989125ms
2022/04/08 06:41:58 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
b36f6c7d4673
... skipping 4 lines ...