This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: feat: enable fsGroup for nfs
ResultFAILURE
Tests 1 failed / 11 succeeded
Started2021-09-15 14:49
Elapsed43m54s
Revision0e9a97fc22d2e81d8cbe0b12a65d347e564a91b3
Refs 759
job-versionv1.23.0-alpha.2.17+07a4ae18450a0b
kubetest-version
revisionv1.23.0-alpha.2.17+07a4ae18450a0b

Test Failures


kubetest Test 28m50s

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

Filter through log files | View test history on testgrid


Show 11 Passed Tests

Error lines from build-log.txt

... skipping 223 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11248  100 11248    0     0   180k      0 --:--:-- --:--:-- --:--:--  180k
Downloading https://get.helm.sh/helm-v3.6.3-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-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd || make container-all push-manifest
Error response from daemon: manifest for k8sprow.azurecr.io/azurefile-csi:e2e-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd not found: manifest unknown: manifest tagged by "e2e-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd" 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-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.gitCommit=bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.buildDate=2021-09-15T14:54:11Z -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 1725 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 55 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 239 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 99 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 829 lines ...
        - name: csi-resizer
          image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.3.0"
          args:
            - "-csi-address=$(ADDRESS)"
            - "-v=2"
            - "-leader-election"
            - '-handle-volume-inuse-error=false'
          env:
            - name: ADDRESS
              value: /csi/csi.sock
          imagePullPolicy: IfNotPresent
          volumeMounts:
            - name: socket-dir
... skipping 564 lines ...
Sep 15 15:04:48.904: INFO: PersistentVolumeClaim test.csi.azure.com6w8g6 found but phase is Pending instead of Bound.
Sep 15 15:04:51.013: INFO: PersistentVolumeClaim test.csi.azure.com6w8g6 found but phase is Pending instead of Bound.
Sep 15 15:04:53.120: INFO: PersistentVolumeClaim test.csi.azure.com6w8g6 found but phase is Pending instead of Bound.
Sep 15 15:04:55.229: INFO: PersistentVolumeClaim test.csi.azure.com6w8g6 found and phase=Bound (54.934685853s)
STEP: Creating pod exec-volume-test-dynamicpv-7rrk
STEP: Creating a pod to test exec-volume-test
Sep 15 15:04:55.554: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-7rrk" in namespace "volume-5889" to be "Succeeded or Failed"
Sep 15 15:04:55.662: INFO: Pod "exec-volume-test-dynamicpv-7rrk": Phase="Pending", Reason="", readiness=false. Elapsed: 107.153502ms
Sep 15 15:04:57.770: INFO: Pod "exec-volume-test-dynamicpv-7rrk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.215290713s
Sep 15 15:04:59.877: INFO: Pod "exec-volume-test-dynamicpv-7rrk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.323032361s
Sep 15 15:05:01.991: INFO: Pod "exec-volume-test-dynamicpv-7rrk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.436201937s
STEP: Saw pod success
Sep 15 15:05:01.991: INFO: Pod "exec-volume-test-dynamicpv-7rrk" satisfied condition "Succeeded or Failed"
Sep 15 15:05:02.099: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000000 pod exec-volume-test-dynamicpv-7rrk container exec-container-dynamicpv-7rrk: <nil>
STEP: delete the pod
Sep 15 15:05:02.376: INFO: Waiting for pod exec-volume-test-dynamicpv-7rrk to disappear
Sep 15 15:05:02.484: INFO: Pod exec-volume-test-dynamicpv-7rrk no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-7rrk
Sep 15 15:05:02.484: INFO: Deleting pod "exec-volume-test-dynamicpv-7rrk" in namespace "volume-5889"
... 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":21,"completed":1,"skipped":4,"failed":0}

SSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned 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: Pre-provisioned Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 38 lines ...
Sep 15 15:04:47.082: INFO: PersistentVolumeClaim test.csi.azure.comws5pb found but phase is Pending instead of Bound.
Sep 15 15:04:49.198: INFO: PersistentVolumeClaim test.csi.azure.comws5pb found but phase is Pending instead of Bound.
Sep 15 15:04:51.313: INFO: PersistentVolumeClaim test.csi.azure.comws5pb found but phase is Pending instead of Bound.
Sep 15 15:04:53.429: INFO: PersistentVolumeClaim test.csi.azure.comws5pb found but phase is Pending instead of Bound.
Sep 15 15:04:55.543: INFO: PersistentVolumeClaim test.csi.azure.comws5pb found and phase=Bound (55.182371432s)
STEP: [init] starting a pod to use the claim
Sep 15 15:04:55.888: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-nmndh" in namespace "snapshotting-5427" to be "Succeeded or Failed"
Sep 15 15:04:56.003: INFO: Pod "pvc-snapshottable-tester-nmndh": Phase="Pending", Reason="", readiness=false. Elapsed: 114.559098ms
Sep 15 15:04:58.120: INFO: Pod "pvc-snapshottable-tester-nmndh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.231181367s
Sep 15 15:05:00.236: INFO: Pod "pvc-snapshottable-tester-nmndh": Phase="Pending", Reason="", readiness=false. Elapsed: 4.347095245s
Sep 15 15:05:02.350: INFO: Pod "pvc-snapshottable-tester-nmndh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.461711165s
Sep 15 15:05:04.465: INFO: Pod "pvc-snapshottable-tester-nmndh": Phase="Running", Reason="", readiness=true. Elapsed: 8.576518233s
Sep 15 15:05:06.580: INFO: Pod "pvc-snapshottable-tester-nmndh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.69185869s
STEP: Saw pod success
Sep 15 15:05:06.580: INFO: Pod "pvc-snapshottable-tester-nmndh" satisfied condition "Succeeded or Failed"
Sep 15 15:05:06.817: INFO: Pod pvc-snapshottable-tester-nmndh has the following logs: 
Sep 15 15:05:06.817: INFO: Deleting pod "pvc-snapshottable-tester-nmndh" in namespace "snapshotting-5427"
Sep 15 15:05:06.938: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-nmndh" to be fully deleted
Sep 15 15:05:07.052: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comws5pb] to have phase Bound
Sep 15 15:05:07.169: INFO: PersistentVolumeClaim test.csi.azure.comws5pb found and phase=Bound (116.706417ms)
STEP: [init] checking the claim
... skipping 263 lines ...
Sep 15 15:04:49.062: INFO: PersistentVolumeClaim test.csi.azure.com7jxxt found but phase is Pending instead of Bound.
Sep 15 15:04:51.172: INFO: PersistentVolumeClaim test.csi.azure.com7jxxt found but phase is Pending instead of Bound.
Sep 15 15:04:53.281: INFO: PersistentVolumeClaim test.csi.azure.com7jxxt found but phase is Pending instead of Bound.
Sep 15 15:04:55.393: INFO: PersistentVolumeClaim test.csi.azure.com7jxxt found and phase=Bound (54.932738428s)
STEP: Creating pod pod-subpath-test-dynamicpv-djhw
STEP: Creating a pod to test subpath
Sep 15 15:04:55.718: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-djhw" in namespace "provisioning-281" to be "Succeeded or Failed"
Sep 15 15:04:55.825: INFO: Pod "pod-subpath-test-dynamicpv-djhw": Phase="Pending", Reason="", readiness=false. Elapsed: 107.000948ms
Sep 15 15:04:57.933: INFO: Pod "pod-subpath-test-dynamicpv-djhw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.215158924s
Sep 15 15:05:00.043: INFO: Pod "pod-subpath-test-dynamicpv-djhw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.325025311s
Sep 15 15:05:02.153: INFO: Pod "pod-subpath-test-dynamicpv-djhw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.435271342s
Sep 15 15:05:04.263: INFO: Pod "pod-subpath-test-dynamicpv-djhw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.545096508s
Sep 15 15:05:06.381: INFO: Pod "pod-subpath-test-dynamicpv-djhw": Phase="Pending", Reason="", readiness=false. Elapsed: 10.663062961s
Sep 15 15:05:08.489: INFO: Pod "pod-subpath-test-dynamicpv-djhw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.770778839s
STEP: Saw pod success
Sep 15 15:05:08.489: INFO: Pod "pod-subpath-test-dynamicpv-djhw" satisfied condition "Succeeded or Failed"
Sep 15 15:05:08.596: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000000 pod pod-subpath-test-dynamicpv-djhw container test-container-volume-dynamicpv-djhw: <nil>
STEP: delete the pod
Sep 15 15:05:08.835: INFO: Waiting for pod pod-subpath-test-dynamicpv-djhw to disappear
Sep 15 15:05:08.942: INFO: Pod pod-subpath-test-dynamicpv-djhw no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-djhw
Sep 15 15:05:08.942: INFO: Deleting pod "pod-subpath-test-dynamicpv-djhw" in namespace "provisioning-281"
... 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":17,"completed":1,"skipped":158,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:05:15.007: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 24 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 46 lines ...
Sep 15 15:04:49.298: INFO: PersistentVolumeClaim test.csi.azure.comrls8q found but phase is Pending instead of Bound.
Sep 15 15:04:51.413: INFO: PersistentVolumeClaim test.csi.azure.comrls8q found but phase is Pending instead of Bound.
Sep 15 15:04:53.529: INFO: PersistentVolumeClaim test.csi.azure.comrls8q found but phase is Pending instead of Bound.
Sep 15 15:04:55.645: INFO: PersistentVolumeClaim test.csi.azure.comrls8q found and phase=Bound (55.154490968s)
STEP: Creating pod pod-subpath-test-dynamicpv-jbc8
STEP: Creating a pod to test subpath
Sep 15 15:04:55.989: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-jbc8" in namespace "provisioning-4952" to be "Succeeded or Failed"
Sep 15 15:04:56.105: INFO: Pod "pod-subpath-test-dynamicpv-jbc8": Phase="Pending", Reason="", readiness=false. Elapsed: 115.022279ms
Sep 15 15:04:58.220: INFO: Pod "pod-subpath-test-dynamicpv-jbc8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.230653955s
Sep 15 15:05:00.336: INFO: Pod "pod-subpath-test-dynamicpv-jbc8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.346415717s
Sep 15 15:05:02.451: INFO: Pod "pod-subpath-test-dynamicpv-jbc8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.461453741s
Sep 15 15:05:04.567: INFO: Pod "pod-subpath-test-dynamicpv-jbc8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.577459765s
Sep 15 15:05:06.682: INFO: Pod "pod-subpath-test-dynamicpv-jbc8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.69214083s
Sep 15 15:05:08.808: INFO: Pod "pod-subpath-test-dynamicpv-jbc8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.818309636s
STEP: Saw pod success
Sep 15 15:05:08.808: INFO: Pod "pod-subpath-test-dynamicpv-jbc8" satisfied condition "Succeeded or Failed"
Sep 15 15:05:08.922: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000000 pod pod-subpath-test-dynamicpv-jbc8 container test-container-volume-dynamicpv-jbc8: <nil>
STEP: delete the pod
Sep 15 15:05:09.160: INFO: Waiting for pod pod-subpath-test-dynamicpv-jbc8 to disappear
Sep 15 15:05:09.295: INFO: Pod pod-subpath-test-dynamicpv-jbc8 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-jbc8
Sep 15 15:05:09.295: INFO: Deleting pod "pod-subpath-test-dynamicpv-jbc8" in namespace "provisioning-4952"
... 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":15,"completed":1,"skipped":129,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:05:15.405: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 110 lines ...
STEP: creating a claim
Sep 15 15:05:16.131: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:05:16.248: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.commv28g] to have phase Bound
Sep 15 15:05:16.362: INFO: PersistentVolumeClaim test.csi.azure.commv28g found but phase is Pending instead of Bound.
Sep 15 15:05:18.477: INFO: PersistentVolumeClaim test.csi.azure.commv28g found and phase=Bound (2.228463662s)
STEP: [init] starting a pod to use the claim
Sep 15 15:05:18.827: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-xw7jd" in namespace "snapshotting-1227" to be "Succeeded or Failed"
Sep 15 15:05:18.942: INFO: Pod "pvc-snapshottable-tester-xw7jd": Phase="Pending", Reason="", readiness=false. Elapsed: 114.224759ms
Sep 15 15:05:21.057: INFO: Pod "pvc-snapshottable-tester-xw7jd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.230135672s
STEP: Saw pod success
Sep 15 15:05:21.058: INFO: Pod "pvc-snapshottable-tester-xw7jd" satisfied condition "Succeeded or Failed"
Sep 15 15:05:21.295: INFO: Pod pvc-snapshottable-tester-xw7jd has the following logs: 
Sep 15 15:05:21.295: INFO: Deleting pod "pvc-snapshottable-tester-xw7jd" in namespace "snapshotting-1227"
Sep 15 15:05:21.420: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-xw7jd" to be fully deleted
Sep 15 15:05:21.534: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.commv28g] to have phase Bound
Sep 15 15:05:21.648: INFO: PersistentVolumeClaim test.csi.azure.commv28g found and phase=Bound (113.95696ms)
STEP: [init] checking the claim
... skipping 85 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":20,"completed":1,"skipped":488,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:05:31.329: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 83 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:221
------------------------------
{"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":11,"completed":1,"skipped":83,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[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
Sep 15 15:05:35.048: INFO: Driver test.csi.azure.com doesn't support ext4 -- skipping
... skipping 100 lines ...
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand 
  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)] subPath should be able to unmount after the subpath directory is deleted [LinuxOnly]","total":10,"completed":1,"skipped":20,"failed":0}
[BeforeEach] [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:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 15 15:05:15.485: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
... skipping 43 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":10,"completed":2,"skipped":20,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:05:37.211: INFO: Driver "test.csi.azure.com" does not support topology - skipping
... skipping 3 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: test.csi.azure.com]
/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 91 lines ...
STEP: creating a claim
Sep 15 15:05:32.139: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:05:32.257: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com5nrkb] to have phase Bound
Sep 15 15:05:32.371: INFO: PersistentVolumeClaim test.csi.azure.com5nrkb found but phase is Pending instead of Bound.
Sep 15 15:05:34.487: INFO: PersistentVolumeClaim test.csi.azure.com5nrkb found and phase=Bound (2.230115173s)
STEP: [init] starting a pod to use the claim
Sep 15 15:05:34.831: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-hvdnt" in namespace "snapshotting-7117" to be "Succeeded or Failed"
Sep 15 15:05:34.946: INFO: Pod "pvc-snapshottable-tester-hvdnt": Phase="Pending", Reason="", readiness=false. Elapsed: 115.163903ms
Sep 15 15:05:37.063: INFO: Pod "pvc-snapshottable-tester-hvdnt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.231772605s
STEP: Saw pod success
Sep 15 15:05:37.063: INFO: Pod "pvc-snapshottable-tester-hvdnt" satisfied condition "Succeeded or Failed"
Sep 15 15:05:37.297: INFO: Pod pvc-snapshottable-tester-hvdnt has the following logs: 
Sep 15 15:05:37.297: INFO: Deleting pod "pvc-snapshottable-tester-hvdnt" in namespace "snapshotting-7117"
Sep 15 15:05:37.421: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-hvdnt" to be fully deleted
Sep 15 15:05:37.534: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com5nrkb] to have phase Bound
Sep 15 15:05:37.649: INFO: PersistentVolumeClaim test.csi.azure.com5nrkb found and phase=Bound (114.675662ms)
STEP: [init] checking the claim
... skipping 122 lines ...
Sep 15 15:05:15.784: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:05:15.896: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comx7fj8] to have phase Bound
Sep 15 15:05:16.003: INFO: PersistentVolumeClaim test.csi.azure.comx7fj8 found but phase is Pending instead of Bound.
Sep 15 15:05:18.110: INFO: PersistentVolumeClaim test.csi.azure.comx7fj8 found and phase=Bound (2.214373188s)
STEP: Creating pod pod-subpath-test-dynamicpv-jq6f
STEP: Creating a pod to test atomic-volume-subpath
Sep 15 15:05:18.436: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-jq6f" in namespace "provisioning-1017" to be "Succeeded or Failed"
Sep 15 15:05:18.547: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Pending", Reason="", readiness=false. Elapsed: 110.540314ms
Sep 15 15:05:20.656: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Pending", Reason="", readiness=false. Elapsed: 2.220097056s
Sep 15 15:05:22.764: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Running", Reason="", readiness=true. Elapsed: 4.328262595s
Sep 15 15:05:24.873: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Running", Reason="", readiness=true. Elapsed: 6.436975041s
Sep 15 15:05:26.982: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Running", Reason="", readiness=true. Elapsed: 8.546292965s
Sep 15 15:05:29.091: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Running", Reason="", readiness=true. Elapsed: 10.655220151s
... skipping 2 lines ...
Sep 15 15:05:35.425: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Running", Reason="", readiness=true. Elapsed: 16.988536714s
Sep 15 15:05:37.534: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Running", Reason="", readiness=true. Elapsed: 19.097671008s
Sep 15 15:05:39.648: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Running", Reason="", readiness=true. Elapsed: 21.21197711s
Sep 15 15:05:41.757: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Running", Reason="", readiness=true. Elapsed: 23.320725305s
Sep 15 15:05:43.865: INFO: Pod "pod-subpath-test-dynamicpv-jq6f": Phase="Succeeded", Reason="", readiness=false. Elapsed: 25.429107497s
STEP: Saw pod success
Sep 15 15:05:43.865: INFO: Pod "pod-subpath-test-dynamicpv-jq6f" satisfied condition "Succeeded or Failed"
Sep 15 15:05:43.973: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000000 pod pod-subpath-test-dynamicpv-jq6f container test-container-subpath-dynamicpv-jq6f: <nil>
STEP: delete the pod
Sep 15 15:05:44.197: INFO: Waiting for pod pod-subpath-test-dynamicpv-jq6f to disappear
Sep 15 15:05:44.303: INFO: Pod pod-subpath-test-dynamicpv-jq6f no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-jq6f
Sep 15 15:05:44.303: INFO: Deleting pod "pod-subpath-test-dynamicpv-jq6f" in namespace "provisioning-1017"
... 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":17,"completed":2,"skipped":328,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[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
Sep 15 15:05:50.463: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 87 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":10,"completed":3,"skipped":125,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral 
  should support two pods which share the same volume
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:183
... skipping 45 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 share the same volume
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:183
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should support two pods which share the same volume","total":15,"completed":1,"skipped":431,"failed":0}

SSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  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
... skipping 15 lines ...
Sep 15 15:06:04.343: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:06:04.463: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comrdjxr] to have phase Bound
Sep 15 15:06:04.577: INFO: PersistentVolumeClaim test.csi.azure.comrdjxr found but phase is Pending instead of Bound.
Sep 15 15:06:06.692: INFO: PersistentVolumeClaim test.csi.azure.comrdjxr found and phase=Bound (2.229038681s)
STEP: Creating pod pod-subpath-test-dynamicpv-sxvf
STEP: Creating a pod to test subpath
Sep 15 15:06:07.038: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-sxvf" in namespace "provisioning-3951" to be "Succeeded or Failed"
Sep 15 15:06:07.152: INFO: Pod "pod-subpath-test-dynamicpv-sxvf": Phase="Pending", Reason="", readiness=false. Elapsed: 114.311655ms
Sep 15 15:06:09.268: INFO: Pod "pod-subpath-test-dynamicpv-sxvf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.229838375s
Sep 15 15:06:11.384: INFO: Pod "pod-subpath-test-dynamicpv-sxvf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.345811849s
STEP: Saw pod success
Sep 15 15:06:11.384: INFO: Pod "pod-subpath-test-dynamicpv-sxvf" satisfied condition "Succeeded or Failed"
Sep 15 15:06:11.498: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000001 pod pod-subpath-test-dynamicpv-sxvf container test-container-subpath-dynamicpv-sxvf: <nil>
STEP: delete the pod
Sep 15 15:06:11.736: INFO: Waiting for pod pod-subpath-test-dynamicpv-sxvf to disappear
Sep 15 15:06:11.850: INFO: Pod pod-subpath-test-dynamicpv-sxvf no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-sxvf
Sep 15 15:06:11.850: INFO: Deleting pod "pod-subpath-test-dynamicpv-sxvf" in namespace "provisioning-3951"
STEP: Creating pod pod-subpath-test-dynamicpv-sxvf
STEP: Creating a pod to test subpath
Sep 15 15:06:12.081: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-sxvf" in namespace "provisioning-3951" to be "Succeeded or Failed"
Sep 15 15:06:12.194: INFO: Pod "pod-subpath-test-dynamicpv-sxvf": Phase="Pending", Reason="", readiness=false. Elapsed: 113.639566ms
Sep 15 15:06:14.310: INFO: Pod "pod-subpath-test-dynamicpv-sxvf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.229407469s
STEP: Saw pod success
Sep 15 15:06:14.310: INFO: Pod "pod-subpath-test-dynamicpv-sxvf" satisfied condition "Succeeded or Failed"
Sep 15 15:06:14.425: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000001 pod pod-subpath-test-dynamicpv-sxvf container test-container-subpath-dynamicpv-sxvf: <nil>
STEP: delete the pod
Sep 15 15:06:14.685: INFO: Waiting for pod pod-subpath-test-dynamicpv-sxvf to disappear
Sep 15 15:06:14.806: INFO: Pod pod-subpath-test-dynamicpv-sxvf no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-sxvf
Sep 15 15:06:14.806: INFO: Deleting pod "pod-subpath-test-dynamicpv-sxvf" in namespace "provisioning-3951"
... 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":10,"completed":4,"skipped":419,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:06:21.023: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 141 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:149
------------------------------
{"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":15,"completed":2,"skipped":414,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[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
Sep 15 15:06:22.898: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping
... skipping 99 lines ...
Sep 15 15:05:51.202: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:05:51.313: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comd2wrm] to have phase Bound
Sep 15 15:05:51.420: INFO: PersistentVolumeClaim test.csi.azure.comd2wrm found but phase is Pending instead of Bound.
Sep 15 15:05:53.528: INFO: PersistentVolumeClaim test.csi.azure.comd2wrm found and phase=Bound (2.214485868s)
STEP: Expanding non-expandable pvc
Sep 15 15:05:53.742: INFO: currentPvcSize {{5368709120 0} {<nil>} 5Gi BinarySI}, newSize {{6442450944 0} {<nil>}  BinarySI}
Sep 15 15:05:53.958: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:05:56.176: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:05:58.174: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:00.177: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:02.176: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:04.176: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:06.175: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:08.174: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:10.177: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:12.174: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:14.175: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:16.174: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:18.174: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:20.175: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:22.177: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:24.175: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep 15 15:06:24.391: INFO: Error updating pvc test.csi.azure.comd2wrm: persistentvolumeclaims "test.csi.azure.comd2wrm" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
Sep 15 15:06:24.391: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comd2wrm"
Sep 15 15:06:24.500: INFO: Waiting up to 5m0s for PersistentVolume pvc-5ce63638-db03-453d-86f5-bfde5ac80da6 to get deleted
Sep 15 15:06:24.607: INFO: PersistentVolume pvc-5ce63638-db03-453d-86f5-bfde5ac80da6 found and phase=Released (106.801161ms)
Sep 15 15:06:29.715: INFO: PersistentVolume pvc-5ce63638-db03-453d-86f5-bfde5ac80da6 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":17,"completed":3,"skipped":585,"failed":0}

SSSSSSSSSS
------------------------------
[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 100 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:351
------------------------------
{"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":15,"completed":2,"skipped":442,"failed":0}

SSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath 
  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
... skipping 15 lines ...
Sep 15 15:06:31.832: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:06:31.943: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com9698g] to have phase Bound
Sep 15 15:06:32.051: INFO: PersistentVolumeClaim test.csi.azure.com9698g found but phase is Pending instead of Bound.
Sep 15 15:06:34.161: INFO: PersistentVolumeClaim test.csi.azure.com9698g found and phase=Bound (2.21777414s)
STEP: Creating pod pod-subpath-test-dynamicpv-9l7v
STEP: Creating a pod to test subpath
Sep 15 15:06:34.487: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-9l7v" in namespace "provisioning-8827" to be "Succeeded or Failed"
Sep 15 15:06:34.594: INFO: Pod "pod-subpath-test-dynamicpv-9l7v": Phase="Pending", Reason="", readiness=false. Elapsed: 107.310982ms
Sep 15 15:06:36.703: INFO: Pod "pod-subpath-test-dynamicpv-9l7v": Phase="Pending", Reason="", readiness=false. Elapsed: 2.216510699s
Sep 15 15:06:38.818: INFO: Pod "pod-subpath-test-dynamicpv-9l7v": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.330860023s
STEP: Saw pod success
Sep 15 15:06:38.818: INFO: Pod "pod-subpath-test-dynamicpv-9l7v" satisfied condition "Succeeded or Failed"
Sep 15 15:06:38.926: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000000 pod pod-subpath-test-dynamicpv-9l7v container test-container-subpath-dynamicpv-9l7v: <nil>
STEP: delete the pod
Sep 15 15:06:39.151: INFO: Waiting for pod pod-subpath-test-dynamicpv-9l7v to disappear
Sep 15 15:06:39.258: INFO: Pod pod-subpath-test-dynamicpv-9l7v no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-9l7v
Sep 15 15:06:39.258: INFO: Deleting pod "pod-subpath-test-dynamicpv-9l7v" in namespace "provisioning-8827"
... 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":17,"completed":4,"skipped":864,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ext3)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:06:45.287: INFO: Driver test.csi.azure.com doesn't support ext3 -- skipping
... skipping 97 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 share the same volume
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:183
------------------------------
{"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should support two pods which share the same volume","total":11,"completed":2,"skipped":505,"failed":0}

SSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
... skipping 119 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:166
------------------------------
{"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":15,"completed":3,"skipped":699,"failed":0}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[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
Sep 15 15:07:03.075: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping
... skipping 57 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:149
------------------------------
{"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":15,"completed":3,"skipped":457,"failed":0}

SSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (ntfs)][Feature:Windows] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:07:20.697: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 93 lines ...
Sep 15 15:05:16.707: INFO: ExecWithOptions {Command:[/bin/sh -c touch /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-702 PodName:pod-ef9eb389-4dcf-4e1e-b592-41c49644513d ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:05:16.707: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:05:17.628: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-702 PodName:pod-ef9eb389-4dcf-4e1e-b592-41c49644513d ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:05:17.630: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:05:18.473: INFO: pod fsgroupchangepolicy-702/pod-ef9eb389-4dcf-4e1e-b592-41c49644513d exec for cmd ls -l /mnt/volume1/subdir/file2, stdout: -rw-r--r--    1 root     root             0 Sep 15 15:05 /mnt/volume1/subdir/file2, stderr: 
Sep 15 15:05:18.473: INFO: stdout split: [-rw-r--r-- 1 root root 0 Sep 15 15:05 /mnt/volume1/subdir/file2], expected gid: 1000
Sep 15 15:05:18.473: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0xc0022cb4a0, 0x70bd1d0, 0x19, 0xc003231fd8, 0x4, 0xc00472ac00)
... skipping 70 lines ...
Sep 15 15:09:54.598: INFO: PersistentVolume pvc-60a72bc3-7f03-4ddd-9c70-2bbfb1e66c75 found and phase=Bound (4m36.016188337s)
Sep 15 15:09:59.708: INFO: PersistentVolume pvc-60a72bc3-7f03-4ddd-9c70-2bbfb1e66c75 found and phase=Bound (4m41.125492948s)
Sep 15 15:10:04.816: INFO: PersistentVolume pvc-60a72bc3-7f03-4ddd-9c70-2bbfb1e66c75 found and phase=Bound (4m46.233975973s)
Sep 15 15:10:09.924: INFO: PersistentVolume pvc-60a72bc3-7f03-4ddd-9c70-2bbfb1e66c75 found and phase=Bound (4m51.341797816s)
Sep 15 15:10:15.033: INFO: PersistentVolume pvc-60a72bc3-7f03-4ddd-9c70-2bbfb1e66c75 found and phase=Bound (4m56.4504443s)
STEP: Deleting sc
Sep 15 15:10:20.146: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-60a72bc3-7f03-4ddd-9c70-2bbfb1e66c75 not deleted by dynamic provisioner: PersistentVolume pvc-60a72bc3-7f03-4ddd-9c70-2bbfb1e66c75 still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-60a72bc3-7f03-4ddd-9c70-2bbfb1e66c75 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 +0xf0
panic(0x6bf5d00, 0xc0036dda40)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1(0xc0047d34a0, 0x4c, 0x895c71a, 0x6c, 0x2d8, 0xc000e16500, 0x499)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0xa5
panic(0x6323060, 0x77ced70)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail(0xc0047d34a0, 0x4c, 0xc003ccec38, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1b5
k8s.io/kubernetes/test/e2e/framework.Fail(0xc003947000, 0x37, 0xc0042ec3a0, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:62 +0x1ea
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc003ccedc0, 0x7904368, 0xc003e4b5b0, 0x1, 0x0, 0x0, 0x0, 0xc003e4b5b0)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x216
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc003ccedc0, 0x7904368, 0xc003e4b5b0, 0x0, 0x0, 0x0, 0xc000182400)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0xc7
k8s.io/kubernetes/test/e2e/framework.ExpectEqual(0x6323060, 0xc003e4b590, 0x6323060, 0xc003e4b5a0, 0x0, 0x0, 0x0)
... skipping 140 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":21,"completed":1,"skipped":22,"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 different fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:10:23.403: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 150 lines ...
Sep 15 15:10:25.211: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:10:25.323: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.compw58k] to have phase Bound
Sep 15 15:10:25.430: INFO: PersistentVolumeClaim test.csi.azure.compw58k found but phase is Pending instead of Bound.
Sep 15 15:10:27.539: INFO: PersistentVolumeClaim test.csi.azure.compw58k found and phase=Bound (2.216097645s)
STEP: Creating pod pod-subpath-test-dynamicpv-kztl
STEP: Creating a pod to test subpath
Sep 15 15:10:27.865: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-kztl" in namespace "provisioning-8017" to be "Succeeded or Failed"
Sep 15 15:10:27.973: INFO: Pod "pod-subpath-test-dynamicpv-kztl": Phase="Pending", Reason="", readiness=false. Elapsed: 108.070069ms
Sep 15 15:10:30.083: INFO: Pod "pod-subpath-test-dynamicpv-kztl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.21790313s
Sep 15 15:10:32.192: INFO: Pod "pod-subpath-test-dynamicpv-kztl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.326965026s
STEP: Saw pod success
Sep 15 15:10:32.192: INFO: Pod "pod-subpath-test-dynamicpv-kztl" satisfied condition "Succeeded or Failed"
Sep 15 15:10:32.300: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000001 pod pod-subpath-test-dynamicpv-kztl container test-container-subpath-dynamicpv-kztl: <nil>
STEP: delete the pod
Sep 15 15:10:32.528: INFO: Waiting for pod pod-subpath-test-dynamicpv-kztl to disappear
Sep 15 15:10:32.637: INFO: Pod pod-subpath-test-dynamicpv-kztl no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-kztl
Sep 15 15:10:32.637: INFO: Deleting pod "pod-subpath-test-dynamicpv-kztl" in namespace "provisioning-8017"
... 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":21,"completed":2,"skipped":551,"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 different fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208
... skipping 30 lines ...
Sep 15 15:05:52.369: INFO: ExecWithOptions {Command:[/bin/sh -c touch /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-999 PodName:pod-988eeee1-0766-4382-9bfe-74e26676674e ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:05:52.369: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:05:53.243: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-999 PodName:pod-988eeee1-0766-4382-9bfe-74e26676674e ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:05:53.243: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:05:54.013: INFO: pod fsgroupchangepolicy-999/pod-988eeee1-0766-4382-9bfe-74e26676674e exec for cmd ls -l /mnt/volume1/subdir/file2, stdout: -rw-r--r--    1 root     root             0 Sep 15 15:05 /mnt/volume1/subdir/file2, stderr: 
Sep 15 15:05:54.013: INFO: stdout split: [-rw-r--r-- 1 root root 0 Sep 15 15:05 /mnt/volume1/subdir/file2], expected gid: 1000
Sep 15 15:05:54.013: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0xc002a5fa20, 0x70bd1d0, 0x19, 0xc004054fa8, 0x4, 0xc004464400)
... skipping 70 lines ...
Sep 15 15:10:30.579: INFO: PersistentVolume pvc-3701b5a5-2a0b-4936-9a60-f625d0256b1b found and phase=Bound (4m36.44957776s)
Sep 15 15:10:35.695: INFO: PersistentVolume pvc-3701b5a5-2a0b-4936-9a60-f625d0256b1b found and phase=Bound (4m41.566187964s)
Sep 15 15:10:40.811: INFO: PersistentVolume pvc-3701b5a5-2a0b-4936-9a60-f625d0256b1b found and phase=Bound (4m46.681711692s)
Sep 15 15:10:45.926: INFO: PersistentVolume pvc-3701b5a5-2a0b-4936-9a60-f625d0256b1b found and phase=Bound (4m51.796701253s)
Sep 15 15:10:51.042: INFO: PersistentVolume pvc-3701b5a5-2a0b-4936-9a60-f625d0256b1b found and phase=Bound (4m56.912771573s)
STEP: Deleting sc
Sep 15 15:10:56.161: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-3701b5a5-2a0b-4936-9a60-f625d0256b1b not deleted by dynamic provisioner: PersistentVolume pvc-3701b5a5-2a0b-4936-9a60-f625d0256b1b still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-3701b5a5-2a0b-4936-9a60-f625d0256b1b 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 +0xf0
panic(0x6bf5d00, 0xc003fa80c0)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1(0xc001e680a0, 0x4c, 0x895c71a, 0x6c, 0x2d8, 0xc00492ef00, 0x499)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0xa5
panic(0x6323060, 0x77ced70)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail(0xc001e680a0, 0x4c, 0xc0013e8c38, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1b5
k8s.io/kubernetes/test/e2e/framework.Fail(0xc00230c040, 0x37, 0xc0046440c0, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:62 +0x1ea
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc0013e8dc0, 0x7904368, 0xc004352110, 0x1, 0x0, 0x0, 0x0, 0xc004352110)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x216
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc0013e8dc0, 0x7904368, 0xc004352110, 0x0, 0x0, 0x0, 0xc000500000)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0xc7
k8s.io/kubernetes/test/e2e/framework.ExpectEqual(0x6323060, 0xc0043520f0, 0x6323060, 0xc004352100, 0x0, 0x0, 0x0)
... skipping 140 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 (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":20,"completed":1,"skipped":753,"failed":1,"failures":["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"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic 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: Dynamic Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 10 lines ...
STEP: creating a claim
Sep 15 15:10:59.988: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:11:00.104: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comd4zw6] to have phase Bound
Sep 15 15:11:00.219: INFO: PersistentVolumeClaim test.csi.azure.comd4zw6 found but phase is Pending instead of Bound.
Sep 15 15:11:02.335: INFO: PersistentVolumeClaim test.csi.azure.comd4zw6 found and phase=Bound (2.231199071s)
STEP: [init] starting a pod to use the claim
Sep 15 15:11:02.682: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-8fdl6" in namespace "snapshotting-6521" to be "Succeeded or Failed"
Sep 15 15:11:02.797: INFO: Pod "pvc-snapshottable-tester-8fdl6": Phase="Pending", Reason="", readiness=false. Elapsed: 115.050092ms
Sep 15 15:11:04.912: INFO: Pod "pvc-snapshottable-tester-8fdl6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.230311773s
STEP: Saw pod success
Sep 15 15:11:04.912: INFO: Pod "pvc-snapshottable-tester-8fdl6" satisfied condition "Succeeded or Failed"
Sep 15 15:11:05.144: INFO: Pod pvc-snapshottable-tester-8fdl6 has the following logs: 
Sep 15 15:11:05.144: INFO: Deleting pod "pvc-snapshottable-tester-8fdl6" in namespace "snapshotting-6521"
Sep 15 15:11:05.263: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-8fdl6" to be fully deleted
Sep 15 15:11:05.377: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comd4zw6] to have phase Bound
Sep 15 15:11:05.492: INFO: PersistentVolumeClaim test.csi.azure.comd4zw6 found and phase=Bound (114.316148ms)
STEP: [init] checking the claim
... skipping 125 lines ...
Sep 15 15:07:11.617: INFO: ExecWithOptions {Command:[/bin/sh -c touch /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-9809 PodName:pod-3885d737-4509-4861-a3ed-e096722fee48 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:07:11.617: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:07:12.567: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-9809 PodName:pod-3885d737-4509-4861-a3ed-e096722fee48 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:07:12.567: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:07:13.516: INFO: pod fsgroupchangepolicy-9809/pod-3885d737-4509-4861-a3ed-e096722fee48 exec for cmd ls -l /mnt/volume1/subdir/file2, stdout: -rw-r--r--    1 root     root             0 Sep 15 15:07 /mnt/volume1/subdir/file2, stderr: 
Sep 15 15:07:13.516: INFO: stdout split: [-rw-r--r-- 1 root root 0 Sep 15 15:07 /mnt/volume1/subdir/file2], expected gid: 1000
Sep 15 15:07:13.516: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0xc0025cf340, 0x70bd1d0, 0x19, 0xc003d8e3e8, 0x4, 0xc0034f2000)
... skipping 70 lines ...
Sep 15 15:11:50.090: INFO: PersistentVolume pvc-c650303f-0c95-41c3-8835-a2f894a9d945 found and phase=Bound (4m36.457394606s)
Sep 15 15:11:55.206: INFO: PersistentVolume pvc-c650303f-0c95-41c3-8835-a2f894a9d945 found and phase=Bound (4m41.573281957s)
Sep 15 15:12:00.321: INFO: PersistentVolume pvc-c650303f-0c95-41c3-8835-a2f894a9d945 found and phase=Bound (4m46.688341188s)
Sep 15 15:12:05.436: INFO: PersistentVolume pvc-c650303f-0c95-41c3-8835-a2f894a9d945 found and phase=Bound (4m51.803718683s)
Sep 15 15:12:10.553: INFO: PersistentVolume pvc-c650303f-0c95-41c3-8835-a2f894a9d945 found and phase=Bound (4m56.919937032s)
STEP: Deleting sc
Sep 15 15:12:15.669: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-c650303f-0c95-41c3-8835-a2f894a9d945 not deleted by dynamic provisioner: PersistentVolume pvc-c650303f-0c95-41c3-8835-a2f894a9d945 still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-c650303f-0c95-41c3-8835-a2f894a9d945 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 +0xf0
panic(0x6bf5d00, 0xc003b6a0c0)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1(0xc003352050, 0x4c, 0x895c71a, 0x6c, 0x2d8, 0xc003b60500, 0x499)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0xa5
panic(0x6323060, 0x77ced70)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail(0xc003352050, 0x4c, 0xc002978c38, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1b5
k8s.io/kubernetes/test/e2e/framework.Fail(0xc003192040, 0x37, 0xc003b20190, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:62 +0x1ea
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc002978dc0, 0x7904368, 0xc003b3c140, 0x1, 0x0, 0x0, 0x0, 0xc003b3c140)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x216
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc002978dc0, 0x7904368, 0xc003b3c140, 0x0, 0x0, 0x0, 0xc003d9cc00)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0xc7
k8s.io/kubernetes/test/e2e/framework.ExpectEqual(0x6323060, 0xc003b3c120, 0x6323060, 0xc003b3c130, 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 (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":15,"completed":3,"skipped":877,"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 different fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:12:18.844: INFO: Driver "test.csi.azure.com" does not support volume type "CSIInlineVolume" - skipping
... skipping 82 lines ...
Sep 15 15:07:29.740: INFO: ExecWithOptions {Command:[/bin/sh -c touch /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-5212 PodName:pod-9ba3df43-7a41-4246-ba84-24baa74acabe ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:07:29.740: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:07:30.613: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-5212 PodName:pod-9ba3df43-7a41-4246-ba84-24baa74acabe ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:07:30.613: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:07:31.372: INFO: pod fsgroupchangepolicy-5212/pod-9ba3df43-7a41-4246-ba84-24baa74acabe exec for cmd ls -l /mnt/volume1/subdir/file2, stdout: -rw-r--r--    1 root     root             0 Sep 15 15:07 /mnt/volume1/subdir/file2, stderr: 
Sep 15 15:07:31.372: INFO: stdout split: [-rw-r--r-- 1 root root 0 Sep 15 15:07 /mnt/volume1/subdir/file2], expected gid: 1000
Sep 15 15:07:31.373: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0xc0031de420, 0x70bd1d0, 0x19, 0xc002ce3ba8, 0x4, 0xc001c8ec00)
... skipping 70 lines ...
Sep 15 15:12:07.827: INFO: PersistentVolume pvc-6afaef18-2315-44a0-840f-ce3b2e353e84 found and phase=Bound (4m36.338541493s)
Sep 15 15:12:12.946: INFO: PersistentVolume pvc-6afaef18-2315-44a0-840f-ce3b2e353e84 found and phase=Bound (4m41.45734602s)
Sep 15 15:12:18.061: INFO: PersistentVolume pvc-6afaef18-2315-44a0-840f-ce3b2e353e84 found and phase=Bound (4m46.571874667s)
Sep 15 15:12:23.179: INFO: PersistentVolume pvc-6afaef18-2315-44a0-840f-ce3b2e353e84 found and phase=Bound (4m51.689834294s)
Sep 15 15:12:28.294: INFO: PersistentVolume pvc-6afaef18-2315-44a0-840f-ce3b2e353e84 found and phase=Bound (4m56.805050727s)
STEP: Deleting sc
Sep 15 15:12:33.414: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-6afaef18-2315-44a0-840f-ce3b2e353e84 not deleted by dynamic provisioner: PersistentVolume pvc-6afaef18-2315-44a0-840f-ce3b2e353e84 still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-6afaef18-2315-44a0-840f-ce3b2e353e84 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 +0xf0
panic(0x6bf5d00, 0xc00337ac00)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1(0xc0021f9360, 0x4c, 0x895c71a, 0x6c, 0x2d8, 0xc003f44500, 0x499)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0xa5
panic(0x6323060, 0x77ced70)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail(0xc0021f9360, 0x4c, 0xc00331cc38, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1b5
k8s.io/kubernetes/test/e2e/framework.Fail(0xc000cb7f40, 0x37, 0xc003ec0f40, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:62 +0x1ea
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc00331cdc0, 0x7904368, 0xc003e86e70, 0x1, 0x0, 0x0, 0x0, 0xc003e86e70)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x216
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc00331cdc0, 0x7904368, 0xc003e86e70, 0x0, 0x0, 0x0, 0xc000488000)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0xc7
k8s.io/kubernetes/test/e2e/framework.ExpectEqual(0x6323060, 0xc003e86e50, 0x6323060, 0xc003e86e60, 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 (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":15,"completed":3,"skipped":908,"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"]}

SSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (default fs)] capacity
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:12:36.513: INFO: Driver test.csi.azure.com doesn't publish storage capacity -- skipping
... skipping 82 lines ...
Sep 15 15:10:47.009: INFO: ExecWithOptions {Command:[/bin/sh -c touch /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-2017 PodName:pod-95971227-6032-44ac-a101-dc910ea45dde ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:10:47.009: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:10:47.855: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-2017 PodName:pod-95971227-6032-44ac-a101-dc910ea45dde ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:10:47.856: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:10:48.754: INFO: pod fsgroupchangepolicy-2017/pod-95971227-6032-44ac-a101-dc910ea45dde exec for cmd ls -l /mnt/volume1/subdir/file2, stdout: -rw-r--r--    1 root     root             0 Sep 15 15:10 /mnt/volume1/subdir/file2, stderr: 
Sep 15 15:10:48.755: INFO: stdout split: [-rw-r--r-- 1 root root 0 Sep 15 15:10 /mnt/volume1/subdir/file2], expected gid: 1000
Sep 15 15:10:48.755: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0xc0022cb4a0, 0x70bd1d0, 0x19, 0xc000a75ee8, 0x4, 0xc00444ac00)
... skipping 70 lines ...
Sep 15 15:15:24.901: INFO: PersistentVolume pvc-45471dc0-ec59-4034-bdcc-549511d76b15 found and phase=Bound (4m36.035864716s)
Sep 15 15:15:30.010: INFO: PersistentVolume pvc-45471dc0-ec59-4034-bdcc-549511d76b15 found and phase=Bound (4m41.144123274s)
Sep 15 15:15:35.119: INFO: PersistentVolume pvc-45471dc0-ec59-4034-bdcc-549511d76b15 found and phase=Bound (4m46.25307875s)
Sep 15 15:15:40.227: INFO: PersistentVolume pvc-45471dc0-ec59-4034-bdcc-549511d76b15 found and phase=Bound (4m51.361594338s)
Sep 15 15:15:45.336: INFO: PersistentVolume pvc-45471dc0-ec59-4034-bdcc-549511d76b15 found and phase=Bound (4m56.470892638s)
STEP: Deleting sc
Sep 15 15:15:50.446: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-45471dc0-ec59-4034-bdcc-549511d76b15 not deleted by dynamic provisioner: PersistentVolume pvc-45471dc0-ec59-4034-bdcc-549511d76b15 still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-45471dc0-ec59-4034-bdcc-549511d76b15 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 +0xf0
panic(0x6bf5d00, 0xc004075c00)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1(0xc0037c9a90, 0x4c, 0x895c71a, 0x6c, 0x2d8, 0xc001fa4000, 0x499)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0xa5
panic(0x6323060, 0x77ced70)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail(0xc0037c9a90, 0x4c, 0xc003ccec38, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1b5
k8s.io/kubernetes/test/e2e/framework.Fail(0xc0030eb9c0, 0x37, 0xc002227660, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:62 +0x1ea
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc003ccedc0, 0x7904368, 0xc002e37c30, 0x1, 0x0, 0x0, 0x0, 0xc002e37c30)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x216
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc003ccedc0, 0x7904368, 0xc002e37c30, 0x0, 0x0, 0x0, 0xa09f580)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0xc7
k8s.io/kubernetes/test/e2e/framework.ExpectEqual(0x6323060, 0xc002e37c00, 0x6323060, 0xc002e37c20, 0x0, 0x0, 0x0)
... skipping 134 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":21,"completed":2,"skipped":610,"failed":2,"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 different fsgroup applied 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 same fsgroup applied to the volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208
... skipping 30 lines ...
Sep 15 15:16:03.854: INFO: ExecWithOptions {Command:[/bin/sh -c touch /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-8599 PodName:pod-934e60d6-84dc-4614-8f12-09ec6364c364 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:16:03.854: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:16:04.723: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/subdir/file2] Namespace:fsgroupchangepolicy-8599 PodName:pod-934e60d6-84dc-4614-8f12-09ec6364c364 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false}
Sep 15 15:16:04.723: INFO: >>> kubeConfig: /root/tmp823767799/kubeconfig/kubeconfig.francecentral.json
Sep 15 15:16:05.579: INFO: pod fsgroupchangepolicy-8599/pod-934e60d6-84dc-4614-8f12-09ec6364c364 exec for cmd ls -l /mnt/volume1/subdir/file2, stdout: -rw-r--r--    1 root     root             0 Sep 15 15:16 /mnt/volume1/subdir/file2, stderr: 
Sep 15 15:16:05.582: INFO: stdout split: [-rw-r--r-- 1 root root 0 Sep 15 15:16 /mnt/volume1/subdir/file2], expected gid: 1000
Sep 15 15:16:05.582: FAIL: Expected
    <string>: root
to equal
    <string>: 1000

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0xc0022cb4a0, 0x70bd1d0, 0x19, 0xc003950458, 0x4, 0xc002ae1c00)
... skipping 70 lines ...
Sep 15 15:20:41.770: INFO: PersistentVolume pvc-6471cccb-0c39-48d3-adb1-4464011641aa found and phase=Bound (4m36.076649493s)
Sep 15 15:20:46.880: INFO: PersistentVolume pvc-6471cccb-0c39-48d3-adb1-4464011641aa found and phase=Bound (4m41.186913622s)
Sep 15 15:20:51.994: INFO: PersistentVolume pvc-6471cccb-0c39-48d3-adb1-4464011641aa found and phase=Bound (4m46.300622409s)
Sep 15 15:20:57.103: INFO: PersistentVolume pvc-6471cccb-0c39-48d3-adb1-4464011641aa found and phase=Bound (4m51.409737725s)
Sep 15 15:21:02.213: INFO: PersistentVolume pvc-6471cccb-0c39-48d3-adb1-4464011641aa found and phase=Bound (4m56.519627914s)
STEP: Deleting sc
Sep 15 15:21:07.327: FAIL: while cleanup resource
Unexpected error:
    <errors.aggregate | len:1, cap:1>: [
        [
            {
                msg: "persistent Volume pvc-6471cccb-0c39-48d3-adb1-4464011641aa not deleted by dynamic provisioner: PersistentVolume pvc-6471cccb-0c39-48d3-adb1-4464011641aa still exists within 5m0s",
                err: {
                    s: "PersistentVolume pvc-6471cccb-0c39-48d3-adb1-4464011641aa 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 +0xf0
panic(0x6bf5d00, 0xc003d81240)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1(0xc0028cb4f0, 0x4c, 0x895c71a, 0x6c, 0x2d8, 0xc003fb6f00, 0x499)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:63 +0xa5
panic(0x6323060, 0x77ced70)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail(0xc0028cb4f0, 0x4c, 0xc003ccec38, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x1b5
k8s.io/kubernetes/test/e2e/framework.Fail(0xc003fd7ac0, 0x37, 0xc00419e920, 0x1, 0x1)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/log.go:62 +0x1ea
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc003ccedc0, 0x7904368, 0xc0028bfeb0, 0x1, 0x0, 0x0, 0x0, 0xc0028bfeb0)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x216
k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc003ccedc0, 0x7904368, 0xc0028bfeb0, 0x0, 0x0, 0x0, 0xa09f580)
	/workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0xc7
k8s.io/kubernetes/test/e2e/framework.ExpectEqual(0x6323060, 0xc0028bfe90, 0x6323060, 0xc0028bfea0, 0x0, 0x0, 0x0)
... skipping 134 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, new pod fsgroup applied to volume contents","total":21,"completed":2,"skipped":662,"failed":3,"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 different fsgroup applied 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 same fsgroup applied 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, new pod fsgroup applied to volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (ext4)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:21:10.517: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping
... skipping 57 lines ...
Sep 15 15:21:11.188: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep 15 15:21:11.300: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com65x7k] to have phase Bound
Sep 15 15:21:11.407: INFO: PersistentVolumeClaim test.csi.azure.com65x7k found but phase is Pending instead of Bound.
Sep 15 15:21:13.517: INFO: PersistentVolumeClaim test.csi.azure.com65x7k found and phase=Bound (2.216668508s)
STEP: Creating pod pod-subpath-test-dynamicpv-g25g
STEP: Creating a pod to test subpath
Sep 15 15:21:13.841: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-g25g" in namespace "provisioning-6393" to be "Succeeded or Failed"
Sep 15 15:21:13.949: INFO: Pod "pod-subpath-test-dynamicpv-g25g": Phase="Pending", Reason="", readiness=false. Elapsed: 107.942162ms
Sep 15 15:21:16.058: INFO: Pod "pod-subpath-test-dynamicpv-g25g": Phase="Pending", Reason="", readiness=false. Elapsed: 2.216241299s
Sep 15 15:21:18.167: INFO: Pod "pod-subpath-test-dynamicpv-g25g": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.325295088s
STEP: Saw pod success
Sep 15 15:21:18.167: INFO: Pod "pod-subpath-test-dynamicpv-g25g" satisfied condition "Succeeded or Failed"
Sep 15 15:21:18.275: INFO: Trying to get logs from node k8s-agentpool1-41472973-vmss000000 pod pod-subpath-test-dynamicpv-g25g container test-container-subpath-dynamicpv-g25g: <nil>
STEP: delete the pod
Sep 15 15:21:18.499: INFO: Waiting for pod pod-subpath-test-dynamicpv-g25g to disappear
Sep 15 15:21:18.606: INFO: Pod pod-subpath-test-dynamicpv-g25g no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-g25g
Sep 15 15:21:18.606: INFO: Deleting pod "pod-subpath-test-dynamicpv-g25g" in namespace "provisioning-6393"
... 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":3,"skipped":772,"failed":3,"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 different fsgroup applied 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 same fsgroup applied 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, new pod fsgroup applied to volume contents"]}

SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ext3)] volumes
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:21:24.620: INFO: Driver test.csi.azure.com doesn't support ext3 -- skipping
... skipping 88 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:166
------------------------------
{"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":21,"completed":4,"skipped":839,"failed":3,"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 different fsgroup applied 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 same fsgroup applied 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, new pod fsgroup applied to volume contents"]}

S
------------------------------
[BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
  /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
Sep 15 15:22:05.279: INFO: Driver "test.csi.azure.com" does not support volume type "CSIInlineVolume" - skipping
... skipping 99 lines ...
Sep 15 15:22:05.825: INFO: Running AfterSuite actions on node 1



Summarizing 6 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 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

[Fail] External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [Measurement] (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/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 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

[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 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] (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/utils/utils.go:728

Ran 27 of 6666 Specs in 1088.636 seconds
FAIL! -- 21 Passed | 6 Failed | 0 Pending | 6639 Skipped 

Ginkgo ran 1 suite in 18m12.437820441s
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 68 lines ...
Go Version: go1.17.1
Platform: linux/amd64

Streaming logs below:
I0915 15:03:49.743495       1 azurefile.go:233] driver userAgent: test.csi.azure.com/e2e-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd gc/go1.17.1 (amd64-linux) e2e-test
I0915 15:03:49.744431       1 azure.go:70] reading cloud config from secret kube-system/azure-cloud-provider
W0915 15:03:49.801497       1 azure.go:77] 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
I0915 15:03:49.801514       1 azure.go:82] could not read cloud config from secret kube-system/azure-cloud-provider
I0915 15:03:49.801520       1 azure.go:92] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0915 15:03:49.801544       1 azure.go:100] read cloud config from file: /etc/kubernetes/azure.json successfully
I0915 15:03:49.802974       1 azure_auth.go:234] Using AzurePublicCloud environment
I0915 15:03:49.803769       1 azure_auth.go:119] azure: using client_id+client_secret to retrieve access token
I0915 15:03:49.803810       1 azure.go:685] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 100 lines ...
Go Version: go1.17.1
Platform: linux/amd64

Streaming logs below:
I0915 15:03:47.272701       1 azurefile.go:233] driver userAgent: test.csi.azure.com/e2e-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd gc/go1.17.1 (amd64-linux) e2e-test
I0915 15:03:47.274577       1 azure.go:70] reading cloud config from secret kube-system/azure-cloud-provider
W0915 15:03:47.298342       1 azure.go:77] 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
I0915 15:03:47.298371       1 azure.go:82] could not read cloud config from secret kube-system/azure-cloud-provider
I0915 15:03:47.298378       1 azure.go:92] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0915 15:03:47.298401       1 azure.go:100] read cloud config from file: /etc/kubernetes/azure.json successfully
I0915 15:03:47.299861       1 azure_auth.go:234] Using AzurePublicCloud environment
I0915 15:03:47.336640       1 azure_auth.go:119] azure: using client_id+client_secret to retrieve access token
I0915 15:03:47.336951       1 azure.go:685] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 643 lines ...
Go Version: go1.17.1
Platform: linux/amd64

Streaming logs below:
I0915 15:03:34.182433       1 azurefile.go:233] driver userAgent: test.csi.azure.com/e2e-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd gc/go1.17.1 (amd64-linux) e2e-test
I0915 15:03:34.183400       1 azure.go:70] reading cloud config from secret kube-system/azure-cloud-provider
W0915 15:03:34.221251       1 azure.go:77] 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
I0915 15:03:34.221274       1 azure.go:82] could not read cloud config from secret kube-system/azure-cloud-provider
I0915 15:03:34.221281       1 azure.go:92] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0915 15:03:34.221302       1 azure.go:100] read cloud config from file: /etc/kubernetes/azure.json successfully
I0915 15:03:34.222770       1 azure_auth.go:234] Using AzurePublicCloud environment
I0915 15:03:34.222818       1 azure_auth.go:119] azure: using client_id+client_secret to retrieve access token
I0915 15:03:34.222846       1 azure.go:685] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 68 lines ...
Go Version: go1.17.1
Platform: linux/amd64

Streaming logs below:
I0915 15:03:45.365937       1 azurefile.go:233] driver userAgent: test.csi.azure.com/e2e-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd gc/go1.17.1 (amd64-linux) e2e-test
I0915 15:03:45.368918       1 azure.go:70] reading cloud config from secret kube-system/azure-cloud-provider
W0915 15:03:45.391662       1 azure.go:77] 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
I0915 15:03:45.391681       1 azure.go:82] could not read cloud config from secret kube-system/azure-cloud-provider
I0915 15:03:45.391687       1 azure.go:92] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0915 15:03:45.391706       1 azure.go:100] read cloud config from file: /etc/kubernetes/azure.json successfully
I0915 15:03:45.392284       1 azure_auth.go:234] Using AzurePublicCloud environment
I0915 15:03:45.392315       1 azure_auth.go:119] azure: using client_id+client_secret to retrieve access token
I0915 15:03:45.392348       1 azure.go:685] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 740 lines ...
Go Version: go1.17.1
Platform: linux/amd64

Streaming logs below:
I0915 15:03:39.921333       1 azurefile.go:233] driver userAgent: test.csi.azure.com/e2e-bee1dcde0f17cb58cccb95e4100ef6b64e1a91bd gc/go1.17.1 (amd64-linux) e2e-test
I0915 15:03:39.922486       1 azure.go:70] reading cloud config from secret kube-system/azure-cloud-provider
W0915 15:03:39.946131       1 azure.go:77] 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
I0915 15:03:39.946149       1 azure.go:82] could not read cloud config from secret kube-system/azure-cloud-provider
I0915 15:03:39.946155       1 azure.go:92] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0915 15:03:39.946174       1 azure.go:100] read cloud config from file: /etc/kubernetes/azure.json successfully
I0915 15:03:39.946734       1 azure_auth.go:234] Using AzurePublicCloud environment
I0915 15:03:39.946765       1 azure_auth.go:119] azure: using client_id+client_secret to retrieve access token
I0915 15:03:39.946789       1 azure.go:685] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 832 lines ...
# HELP process_virtual_memory_bytes Virtual memory size in bytes.
# TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 7.62425344e+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
make: *** [Makefile:85: e2e-test] Error 1
2021/09/15 15:23:01 process.go:155: Step 'make e2e-test' finished in 28m50.224249428s
2021/09/15 15:23:01 aksengine_helpers.go:425: downloading /root/tmp823767799/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2021/09/15 15:23:01 util.go:68: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2021/09/15 15:23:01 process.go:153: Running: chmod +x /root/tmp823767799/log-dump.sh
2021/09/15 15:23:01 process.go:155: Step 'chmod +x /root/tmp823767799/log-dump.sh' finished in 1.344587ms
2021/09/15 15:23:01 aksengine_helpers.go:425: downloading /root/tmp823767799/log-dump-daemonset.yaml from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump-daemonset.yaml
... skipping 55 lines ...
ssh key file /root/.ssh/id_rsa does not exist. Exiting.
2021/09/15 15:23:58 process.go:155: Step 'bash -c /root/tmp823767799/win-ci-logs-collector.sh kubetest-ha3uofve.francecentral.cloudapp.azure.com /root/tmp823767799 /root/.ssh/id_rsa' finished in 4.341301ms
2021/09/15 15:23:58 aksengine.go:1141: Deleting resource group: kubetest-ha3uofve.
2021/09/15 15:33:12 process.go:96: Saved XML output to /logs/artifacts/junit_runner.xml.
2021/09/15 15:33:12 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
2021/09/15 15:33:12 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 209.759124ms
2021/09/15 15:33:12 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
a7f2a9cb7f37
... skipping 4 lines ...