kubernetes-sigs/azurefile-csi-driver PR #1018 pull-azurefile-csi-driver-external-e2e-smb #1524641361733619712
Recent runs || View in Spyglass
Recent runs || View in Spyglass
| PR | andyzhangx: [WIP]chore: remove VOLUME_MOUNT_GROUP cap |
| Result | FAILURE |
| Tests | 1 failed / 13 succeeded |
| Started | |
| Elapsed | 31m3s |
| Revision | 3947bb1d11a9bc1fc820b35f1821acc93cf20734 |
| Refs |
1018 |
| job-version | v1.25.0-alpha.0.443+8aaea8e24c1b87 |
| kubetest-version | |
| revision | v1.25.0-alpha.0.443+8aaea8e24c1b87 |
error during make e2e-test: exit status 2
from junit_runner.xml
Filter through log files | View test history on testgrid
kubetest Check APIReachability
kubetest Deferred TearDown
kubetest DumpClusterLogs
kubetest GetDeployer
kubetest IsUp
kubetest Prepare
kubetest TearDown
kubetest TearDown Previous
kubetest Timeout
kubetest Up
kubetest kubectl version
kubetest list nodes
kubetest test setup
... skipping 221 lines ... 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 11156 100 11156 0 0 184k 0 --:--:-- --:--:-- --:--:-- 184k Downloading https://get.helm.sh/helm-v3.8.2-linux-amd64.tar.gz Verifying checksum... Done. Preparing to install helm into /usr/local/bin helm installed into /usr/local/bin/helm docker pull k8sprow.azurecr.io/azurefile-csi:e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 || make container-all push-manifest Error response from daemon: manifest for k8sprow.azurecr.io/azurefile-csi:e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 not found: manifest unknown: manifest tagged by "e2e-c52c48007cdd2c836422f7b2374338f4e15ae788" is not found make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver' CGO_ENABLED=0 GOOS=windows go build -a -ldflags "-X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.driverVersion=e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.gitCommit=c52c48007cdd2c836422f7b2374338f4e15ae788 -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.buildDate=2022-05-12T06:51:09Z -s -w -extldflags '-static'" -mod vendor -o _output/amd64/azurefileplugin.exe ./pkg/azurefileplugin docker buildx rm container-builder || true error: no builder "container-builder" found docker buildx create --use --name=container-builder container-builder # enable qemu for arm64 build # https://github.com/docker/buildx/issues/464#issuecomment-741507760 docker run --privileged --rm tonistiigi/binfmt --uninstall qemu-aarch64 Unable to find image 'tonistiigi/binfmt:latest' locally ... skipping 1802 lines ... type: string type: object oneOf: - required: ["persistentVolumeClaimName"] - required: ["volumeSnapshotContentName"] volumeSnapshotClassName: description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.' type: string required: - source type: object status: description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object. ... skipping 2 lines ... description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.' type: string creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown. format: date-time type: string error: description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: type: string description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$ x-kubernetes-int-or-string: true type: object required: - spec type: object ... skipping 60 lines ... type: string volumeSnapshotContentName: description: volumeSnapshotContentName specifies the name of a pre-existing VolumeSnapshotContent object representing an existing volume snapshot. This field should be set if the snapshot already exists and only needs a representation in Kubernetes. This field is immutable. type: string type: object volumeSnapshotClassName: description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.' type: string required: - source type: object status: description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object. ... skipping 2 lines ... description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.' type: string creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown. format: date-time type: string error: description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: type: string description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$ x-kubernetes-int-or-string: true type: object required: - spec type: object ... skipping 254 lines ... description: status represents the current information of a snapshot. properties: creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC. format: int64 type: integer error: description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. format: int64 minimum: 0 type: integer snapshotHandle: description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress. type: string type: object required: - spec type: object served: true ... skipping 108 lines ... description: status represents the current information of a snapshot. properties: creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC. format: int64 type: integer error: description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. format: int64 minimum: 0 type: integer snapshotHandle: description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress. type: string type: object required: - spec type: object served: true ... skipping 938 lines ... image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.4.0" args: - "-csi-address=$(ADDRESS)" - "-v=2" - "-leader-election" - "--leader-election-namespace=kube-system" - '-handle-volume-inuse-error=false' - '-timeout=120s' - '-feature-gates=RecoverVolumeExpansionFailure=true' env: - name: ADDRESS value: /csi/csi.sock imagePullPolicy: IfNotPresent ... skipping 632 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:258[0m [36mDriver test.csi.azure.com doesn't support ntfs -- skipping[0m test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m ... skipping 8 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Pre-provisioned PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:269[0m [36mDriver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 105 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Pre-provisioned PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:258[0m [36mDriver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 423 lines ... test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (default fs)] subPath[0m [1mshould fail if non-existent subpath is outside the volume [Slow][LinuxOnly][0m [37mtest/e2e/storage/testsuites/subpath.go:269[0m [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 12 07:01:08.810: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json [1mSTEP[0m: Building a namespace api object, basename provisioning [1mSTEP[0m: Waiting for a default service account to be provisioned in namespace [1mSTEP[0m: Waiting for kube-root-ca.crt to be provisioned in namespace [It] should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] test/e2e/storage/testsuites/subpath.go:269 May 12 07:01:09.004: INFO: Creating resource for dynamic PV May 12 07:01:09.004: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass provisioning-4022-e2e-scxw4m8 [1mSTEP[0m: creating a claim May 12 07:01:09.034: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil ... skipping 7 lines ... May 12 07:01:21.268: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found but phase is Pending instead of Bound. May 12 07:01:23.297: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found but phase is Pending instead of Bound. May 12 07:01:25.327: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found but phase is Pending instead of Bound. May 12 07:01:27.356: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found but phase is Pending instead of Bound. May 12 07:01:29.385: INFO: PersistentVolumeClaim test.csi.azure.com8zzl6 found and phase=Bound (20.320823718s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-r8mj [1mSTEP[0m: Checking for subpath error in container status May 12 07:01:35.574: INFO: Deleting pod "pod-subpath-test-dynamicpv-r8mj" in namespace "provisioning-4022" May 12 07:01:35.603: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-r8mj" to be fully deleted [1mSTEP[0m: Deleting pod May 12 07:01:37.667: INFO: Deleting pod "pod-subpath-test-dynamicpv-r8mj" in namespace "provisioning-4022" [1mSTEP[0m: Deleting pvc May 12 07:01:37.698: INFO: Deleting PersistentVolumeClaim "test.csi.azure.com8zzl6" ... skipping 9 lines ... [32m• [SLOW TEST:34.090 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:269[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]","total":41,"completed":1,"skipped":361,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (default fs)] subPath[0m [1mshould fail if subpath with backstepping is outside the volume [Slow][LinuxOnly][0m [37mtest/e2e/storage/testsuites/subpath.go:280[0m [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 12 07:01:09.093: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json [1mSTEP[0m: Building a namespace api object, basename provisioning [1mSTEP[0m: Waiting for a default service account to be provisioned in namespace [1mSTEP[0m: Waiting for kube-root-ca.crt to be provisioned in namespace [It] should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] test/e2e/storage/testsuites/subpath.go:280 May 12 07:01:09.289: INFO: Creating resource for dynamic PV May 12 07:01:09.289: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass provisioning-295-e2e-sc262ft [1mSTEP[0m: creating a claim May 12 07:01:09.317: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil ... skipping 7 lines ... May 12 07:01:21.563: INFO: PersistentVolumeClaim test.csi.azure.complckn found but phase is Pending instead of Bound. May 12 07:01:23.592: INFO: PersistentVolumeClaim test.csi.azure.complckn found but phase is Pending instead of Bound. May 12 07:01:25.620: INFO: PersistentVolumeClaim test.csi.azure.complckn found but phase is Pending instead of Bound. May 12 07:01:27.649: INFO: PersistentVolumeClaim test.csi.azure.complckn found but phase is Pending instead of Bound. May 12 07:01:29.677: INFO: PersistentVolumeClaim test.csi.azure.complckn found and phase=Bound (20.327598461s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-zrss [1mSTEP[0m: Checking for subpath error in container status May 12 07:01:39.819: INFO: Deleting pod "pod-subpath-test-dynamicpv-zrss" in namespace "provisioning-295" May 12 07:01:39.849: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-zrss" to be fully deleted [1mSTEP[0m: Deleting pod May 12 07:01:43.905: INFO: Deleting pod "pod-subpath-test-dynamicpv-zrss" in namespace "provisioning-295" [1mSTEP[0m: Deleting pvc May 12 07:01:43.932: INFO: Deleting PersistentVolumeClaim "test.csi.azure.complckn" ... skipping 9 lines ... [32m• [SLOW TEST:40.040 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:280[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]","total":26,"completed":1,"skipped":631,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand[0m [1mVerify if offline PVC expansion works[0m [37mtest/e2e/storage/testsuites/volume_expand.go:176[0m ... skipping 63 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand [90mtest/e2e/storage/framework/testsuite.go:50[0m Verify if offline PVC expansion works [90mtest/e2e/storage/testsuites/volume_expand.go:176[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand Verify if offline PVC expansion works","total":42,"completed":1,"skipped":93,"failed":0} [36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand test/e2e/storage/framework/testsuite.go:51 May 12 07:01:50.325: INFO: Driver "test.csi.azure.com" does not support block volume mode - skipping ... skipping 103 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] [90mtest/e2e/storage/framework/testsuite.go:50[0m should concurrently access the single read-only volume from pods on the same node [90mtest/e2e/storage/testsuites/multivolume.go:423[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the single read-only volume from pods on the same node","total":30,"completed":1,"skipped":78,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Inline-volume (ntfs)][Feature:Windows] volumes test/e2e/storage/framework/testsuite.go:51 May 12 07:02:02.724: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 24 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (delayed binding)] topology [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail to schedule a pod which has topologies that conflict with AllowedTopologies [BeforeEach][0m [90mtest/e2e/storage/testsuites/topology.go:194[0m [36mDriver "test.csi.azure.com" does not support topology - skipping[0m test/e2e/storage/testsuites/topology.go:93 [90m------------------------------[0m ... skipping 50 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (immediate binding)] topology [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail to schedule a pod which has topologies that conflict with AllowedTopologies [BeforeEach][0m [90mtest/e2e/storage/testsuites/topology.go:194[0m [36mDriver "test.csi.azure.com" does not support topology - skipping[0m test/e2e/storage/testsuites/topology.go:93 [90m------------------------------[0m ... skipping 74 lines ... May 12 07:01:50.604: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:01:50.630: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comx4v75] to have phase Bound May 12 07:01:50.655: INFO: PersistentVolumeClaim test.csi.azure.comx4v75 found but phase is Pending instead of Bound. May 12 07:01:52.680: INFO: PersistentVolumeClaim test.csi.azure.comx4v75 found and phase=Bound (2.049579532s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-2xhw [1mSTEP[0m: Creating a pod to test subpath May 12 07:01:52.757: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-2xhw" in namespace "provisioning-6741" to be "Succeeded or Failed" May 12 07:01:52.782: INFO: Pod "pod-subpath-test-dynamicpv-2xhw": Phase="Pending", Reason="", readiness=false. Elapsed: 24.553521ms May 12 07:01:54.809: INFO: Pod "pod-subpath-test-dynamicpv-2xhw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.051947559s May 12 07:01:56.834: INFO: Pod "pod-subpath-test-dynamicpv-2xhw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.077481787s May 12 07:01:58.860: INFO: Pod "pod-subpath-test-dynamicpv-2xhw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.102804692s [1mSTEP[0m: Saw pod success May 12 07:01:58.860: INFO: Pod "pod-subpath-test-dynamicpv-2xhw" satisfied condition "Succeeded or Failed" May 12 07:01:58.887: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-2xhw container test-container-volume-dynamicpv-2xhw: <nil> [1mSTEP[0m: delete the pod May 12 07:01:58.968: INFO: Waiting for pod pod-subpath-test-dynamicpv-2xhw to disappear May 12 07:01:58.994: INFO: Pod pod-subpath-test-dynamicpv-2xhw no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-2xhw May 12 07:01:58.994: INFO: Deleting pod "pod-subpath-test-dynamicpv-2xhw" in namespace "provisioning-6741" ... skipping 16 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support non-existent path [90mtest/e2e/storage/testsuites/subpath.go:196[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support non-existent path","total":42,"completed":2,"skipped":178,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Inline-volume (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:02:04.255: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 79 lines ... May 12 07:02:04.511: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:02:04.541: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.combptls] to have phase Bound May 12 07:02:04.565: INFO: PersistentVolumeClaim test.csi.azure.combptls found but phase is Pending instead of Bound. May 12 07:02:06.591: INFO: PersistentVolumeClaim test.csi.azure.combptls found and phase=Bound (2.050167552s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-x62h [1mSTEP[0m: Creating a pod to test subpath May 12 07:02:06.668: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-x62h" in namespace "provisioning-3629" to be "Succeeded or Failed" May 12 07:02:06.693: INFO: Pod "pod-subpath-test-dynamicpv-x62h": Phase="Pending", Reason="", readiness=false. Elapsed: 24.702114ms May 12 07:02:08.720: INFO: Pod "pod-subpath-test-dynamicpv-x62h": Phase="Pending", Reason="", readiness=false. Elapsed: 2.052000754s May 12 07:02:10.746: INFO: Pod "pod-subpath-test-dynamicpv-x62h": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.077899701s [1mSTEP[0m: Saw pod success May 12 07:02:10.746: INFO: Pod "pod-subpath-test-dynamicpv-x62h" satisfied condition "Succeeded or Failed" May 12 07:02:10.771: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-x62h container test-container-subpath-dynamicpv-x62h: <nil> [1mSTEP[0m: delete the pod May 12 07:02:10.832: INFO: Waiting for pod pod-subpath-test-dynamicpv-x62h to disappear May 12 07:02:10.858: INFO: Pod pod-subpath-test-dynamicpv-x62h no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-x62h May 12 07:02:10.858: INFO: Deleting pod "pod-subpath-test-dynamicpv-x62h" in namespace "provisioning-3629" ... skipping 16 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support existing single file [LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:221[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support existing single file [LinuxOnly]","total":42,"completed":3,"skipped":266,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Inline-volume (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:02:16.103: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 199 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] [90mtest/e2e/storage/framework/testsuite.go:50[0m should access to two volumes with the same volume mode and retain data across pod recreation on the same node [90mtest/e2e/storage/testsuites/multivolume.go:138[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should access to two volumes with the same volume mode and retain data across pod recreation on the same node","total":41,"completed":2,"skipped":378,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource] test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource] ... skipping 12 lines ... May 12 07:02:16.327: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:02:16.354: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjpt5f] to have phase Bound May 12 07:02:16.379: INFO: PersistentVolumeClaim test.csi.azure.comjpt5f found but phase is Pending instead of Bound. May 12 07:02:18.404: INFO: PersistentVolumeClaim test.csi.azure.comjpt5f found and phase=Bound (2.049935414s) [1mSTEP[0m: [init] starting a pod to use the claim [1mSTEP[0m: [init] check pod success May 12 07:02:18.505: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-mhx5w" in namespace "snapshotting-2421" to be "Succeeded or Failed" May 12 07:02:18.547: INFO: Pod "pvc-snapshottable-tester-mhx5w": Phase="Pending", Reason="", readiness=false. Elapsed: 42.434557ms May 12 07:02:20.575: INFO: Pod "pvc-snapshottable-tester-mhx5w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.070320976s May 12 07:02:22.606: INFO: Pod "pvc-snapshottable-tester-mhx5w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.101048578s [1mSTEP[0m: Saw pod success May 12 07:02:22.606: INFO: Pod "pvc-snapshottable-tester-mhx5w" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim May 12 07:02:22.631: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjpt5f] to have phase Bound May 12 07:02:22.656: INFO: PersistentVolumeClaim test.csi.azure.comjpt5f found and phase=Bound (24.76363ms) [1mSTEP[0m: [init] checking the PV [1mSTEP[0m: [init] deleting the pod May 12 07:02:22.732: INFO: Pod pvc-snapshottable-tester-mhx5w has the following logs: ... skipping 190 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] volumeIO [90mtest/e2e/storage/framework/testsuite.go:50[0m should write files of various sizes, verify size, validate content [Slow] [90mtest/e2e/storage/testsuites/volume_io.go:149[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumeIO should write files of various sizes, verify size, validate content [Slow]","total":26,"completed":2,"skipped":650,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral ... skipping 129 lines ... test/e2e/storage/external/external.go:262 [90m------------------------------[0m [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (default fs)] subPath[0m [1mshould fail if subpath file is outside the volume [Slow][LinuxOnly][0m [37mtest/e2e/storage/testsuites/subpath.go:258[0m [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 12 07:02:28.155: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json [1mSTEP[0m: Building a namespace api object, basename provisioning [1mSTEP[0m: Waiting for a default service account to be provisioned in namespace [1mSTEP[0m: Waiting for kube-root-ca.crt to be provisioned in namespace [It] should fail if subpath file is outside the volume [Slow][LinuxOnly] test/e2e/storage/testsuites/subpath.go:258 May 12 07:02:28.328: INFO: Creating resource for dynamic PV May 12 07:02:28.328: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass provisioning-9192-e2e-sc9798s [1mSTEP[0m: creating a claim May 12 07:02:28.355: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:02:28.388: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comqp999] to have phase Bound May 12 07:02:28.412: INFO: PersistentVolumeClaim test.csi.azure.comqp999 found but phase is Pending instead of Bound. May 12 07:02:30.438: INFO: PersistentVolumeClaim test.csi.azure.comqp999 found and phase=Bound (2.050013898s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-jjvz [1mSTEP[0m: Checking for subpath error in container status May 12 07:02:34.569: INFO: Deleting pod "pod-subpath-test-dynamicpv-jjvz" in namespace "provisioning-9192" May 12 07:02:34.595: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-jjvz" to be fully deleted [1mSTEP[0m: Deleting pod May 12 07:02:36.646: INFO: Deleting pod "pod-subpath-test-dynamicpv-jjvz" in namespace "provisioning-9192" [1mSTEP[0m: Deleting pvc May 12 07:02:36.671: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comqp999" ... skipping 9 lines ... [32m• [SLOW TEST:13.694 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should fail if subpath file is outside the volume [Slow][LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:258[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath file is outside the volume [Slow][LinuxOnly]","total":42,"completed":4,"skipped":437,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 12 07:02:41.830: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json [1mSTEP[0m: Building a namespace api object, basename volumemode [1mSTEP[0m: Waiting for a default service account to be provisioned in namespace [1mSTEP[0m: Waiting for kube-root-ca.crt to be provisioned in namespace [It] should fail to use a volume in a pod with mismatched mode [Slow] test/e2e/storage/testsuites/volumemode.go:299 May 12 07:02:42.028: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping [AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode test/e2e/framework/framework.go:188 May 12 07:02:42.029: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready [1mSTEP[0m: Destroying namespace "volumemode-5825" for this suite. [36m[1mS [SKIPPING] [0.256 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (block volmode)] volumeMode [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail to use a volume in a pod with mismatched mode [Slow] [Measurement][0m [90mtest/e2e/storage/testsuites/volumemode.go:299[0m [36mDriver "test.csi.azure.com" does not provide raw block - skipping[0m test/e2e/storage/testsuites/volumes.go:114 [90m------------------------------[0m ... skipping 142 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Inline-volume (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:280[0m [36mDriver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 8 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Inline-volume (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:242[0m [36mDriver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 129 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral [90mtest/e2e/storage/framework/testsuite.go:50[0m should create read/write inline ephemeral volume [90mtest/e2e/storage/testsuites/ephemeral.go:196[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should create read/write inline ephemeral volume","total":30,"completed":2,"skipped":367,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral[0m [1mshould support two pods which have the same volume definition[0m [37mtest/e2e/storage/testsuites/ephemeral.go:216[0m ... skipping 52 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral [90mtest/e2e/storage/framework/testsuite.go:50[0m should support two pods which have the same volume definition [90mtest/e2e/storage/testsuites/ephemeral.go:216[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should support two pods which have the same volume definition","total":18,"completed":1,"skipped":222,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (ext4)] volumes test/e2e/storage/framework/testsuite.go:51 May 12 07:02:48.083: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 259 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral [90mtest/e2e/storage/framework/testsuite.go:50[0m should create read/write inline ephemeral volume [90mtest/e2e/storage/testsuites/ephemeral.go:196[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should create read/write inline ephemeral volume","total":41,"completed":3,"skipped":394,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeLimits test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeLimits ... skipping 89 lines ... May 12 07:02:42.344: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:02:42.385: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjqj4m] to have phase Bound May 12 07:02:42.413: INFO: PersistentVolumeClaim test.csi.azure.comjqj4m found but phase is Pending instead of Bound. May 12 07:02:44.442: INFO: PersistentVolumeClaim test.csi.azure.comjqj4m found and phase=Bound (2.056406703s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-hscf [1mSTEP[0m: Creating a pod to test multi_subpath May 12 07:02:44.527: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hscf" in namespace "provisioning-7397" to be "Succeeded or Failed" May 12 07:02:44.555: INFO: Pod "pod-subpath-test-dynamicpv-hscf": Phase="Pending", Reason="", readiness=false. Elapsed: 28.146828ms May 12 07:02:46.584: INFO: Pod "pod-subpath-test-dynamicpv-hscf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05664391s May 12 07:02:48.612: INFO: Pod "pod-subpath-test-dynamicpv-hscf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.084977188s May 12 07:02:50.642: INFO: Pod "pod-subpath-test-dynamicpv-hscf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.114460823s [1mSTEP[0m: Saw pod success May 12 07:02:50.642: INFO: Pod "pod-subpath-test-dynamicpv-hscf" satisfied condition "Succeeded or Failed" May 12 07:02:50.670: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000000 pod pod-subpath-test-dynamicpv-hscf container test-container-subpath-dynamicpv-hscf: <nil> [1mSTEP[0m: delete the pod May 12 07:02:50.742: INFO: Waiting for pod pod-subpath-test-dynamicpv-hscf to disappear May 12 07:02:50.769: INFO: Pod pod-subpath-test-dynamicpv-hscf no longer exists [1mSTEP[0m: Deleting pod May 12 07:02:50.769: INFO: Deleting pod "pod-subpath-test-dynamicpv-hscf" in namespace "provisioning-7397" ... skipping 14 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support creating multiple subpath from same volumes [Slow] [90mtest/e2e/storage/testsuites/subpath.go:296[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support creating multiple subpath from same volumes [Slow]","total":26,"completed":3,"skipped":983,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode ... skipping 67 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:242[0m [36mDriver test.csi.azure.com doesn't support ntfs -- skipping[0m test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m ... skipping 86 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand [90mtest/e2e/storage/framework/testsuite.go:50[0m should resize volume when PVC is edited while pod is using it [90mtest/e2e/storage/testsuites/volume_expand.go:248[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand should resize volume when PVC is edited while pod is using it","total":42,"completed":5,"skipped":811,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral test/e2e/storage/framework/testsuite.go:51 May 12 07:02:58.326: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping ... skipping 90 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support restarting containers using directory as subpath [Slow] [90mtest/e2e/storage/testsuites/subpath.go:322[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support restarting containers using directory as subpath [Slow]","total":38,"completed":1,"skipped":164,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Inline-volume (xfs)][Slow] volumes test/e2e/storage/framework/testsuite.go:51 May 12 07:02:58.775: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 22 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Inline-volume (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:258[0m [36mDriver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 8 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Inline-volume (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:269[0m [36mDriver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 97 lines ... May 12 07:02:59.763: INFO: ExecWithOptions: execute(POST https://kubetest-oew5xopy.centralus.cloudapp.azure.com/api/v1/namespaces/volume-5198/pods/external-client/exec?command=%2Fbin%2Fsh&command=-c&command=test+-d+%2Fopt%2F0&container=external-client&container=external-client&stderr=true&stdout=true) May 12 07:03:00.020: INFO: ExecWithOptions {Command:[/bin/sh -c test -b /opt/0] Namespace:volume-5198 PodName:external-client ContainerName:external-client Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false} May 12 07:03:00.020: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json May 12 07:03:00.021: INFO: ExecWithOptions: Clientset creation May 12 07:03:00.021: INFO: ExecWithOptions: execute(POST https://kubetest-oew5xopy.centralus.cloudapp.azure.com/api/v1/namespaces/volume-5198/pods/external-client/exec?command=%2Fbin%2Fsh&command=-c&command=test+-b+%2Fopt%2F0&container=external-client&container=external-client&stderr=true&stdout=true) [1mSTEP[0m: Repeating the test on an ephemeral container (if enabled) May 12 07:03:00.382: INFO: Skipping ephemeral container re-test because feature is disabled (error: "the server could not find the requested resource") [1mSTEP[0m: Deleting pod external-client in namespace volume-5198 May 12 07:03:00.412: INFO: Waiting for pod external-client to disappear May 12 07:03:00.440: INFO: Pod external-client still exists May 12 07:03:02.440: INFO: Waiting for pod external-client to disappear May 12 07:03:02.468: INFO: Pod external-client still exists May 12 07:03:04.440: INFO: Waiting for pod external-client to disappear ... skipping 16 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] volumes [90mtest/e2e/storage/framework/testsuite.go:50[0m should store data [90mtest/e2e/storage/testsuites/volumes.go:161[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should store data","total":18,"completed":2,"skipped":833,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] volumes test/e2e/storage/framework/testsuite.go:51 May 12 07:03:09.683: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 37 lines ... May 12 07:02:58.556: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:02:58.581: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comwh97p] to have phase Bound May 12 07:02:58.606: INFO: PersistentVolumeClaim test.csi.azure.comwh97p found but phase is Pending instead of Bound. May 12 07:03:00.632: INFO: PersistentVolumeClaim test.csi.azure.comwh97p found and phase=Bound (2.050947698s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-wfnf [1mSTEP[0m: Creating a pod to test subpath May 12 07:03:00.709: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-wfnf" in namespace "provisioning-5925" to be "Succeeded or Failed" May 12 07:03:00.737: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Pending", Reason="", readiness=false. Elapsed: 27.518666ms May 12 07:03:02.764: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.054419333s May 12 07:03:04.790: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.080762478s May 12 07:03:06.816: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.106339843s May 12 07:03:08.843: INFO: Pod "pod-subpath-test-dynamicpv-wfnf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.13323999s [1mSTEP[0m: Saw pod success May 12 07:03:08.843: INFO: Pod "pod-subpath-test-dynamicpv-wfnf" satisfied condition "Succeeded or Failed" May 12 07:03:08.868: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-wfnf container test-container-volume-dynamicpv-wfnf: <nil> [1mSTEP[0m: delete the pod May 12 07:03:08.928: INFO: Waiting for pod pod-subpath-test-dynamicpv-wfnf to disappear May 12 07:03:08.953: INFO: Pod pod-subpath-test-dynamicpv-wfnf no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-wfnf May 12 07:03:08.953: INFO: Deleting pod "pod-subpath-test-dynamicpv-wfnf" in namespace "provisioning-5925" ... skipping 16 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support existing directory [90mtest/e2e/storage/testsuites/subpath.go:207[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support existing directory","total":42,"completed":6,"skipped":863,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (default fs)] subPath[0m [1mshould support existing directories when readOnly specified in the volumeSource[0m [37mtest/e2e/storage/testsuites/subpath.go:397[0m ... skipping 16 lines ... May 12 07:02:56.307: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:02:56.343: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comqfwh4] to have phase Bound May 12 07:02:56.370: INFO: PersistentVolumeClaim test.csi.azure.comqfwh4 found but phase is Pending instead of Bound. May 12 07:02:58.400: INFO: PersistentVolumeClaim test.csi.azure.comqfwh4 found and phase=Bound (2.057880982s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-gmrb [1mSTEP[0m: Creating a pod to test subpath May 12 07:02:58.485: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-gmrb" in namespace "provisioning-8172" to be "Succeeded or Failed" May 12 07:02:58.517: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 31.514849ms May 12 07:03:00.550: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.063991041s May 12 07:03:02.578: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.092603528s May 12 07:03:04.607: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.121533104s May 12 07:03:06.636: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.150076452s [1mSTEP[0m: Saw pod success May 12 07:03:06.636: INFO: Pod "pod-subpath-test-dynamicpv-gmrb" satisfied condition "Succeeded or Failed" May 12 07:03:06.664: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-gmrb container test-container-subpath-dynamicpv-gmrb: <nil> [1mSTEP[0m: delete the pod May 12 07:03:06.731: INFO: Waiting for pod pod-subpath-test-dynamicpv-gmrb to disappear May 12 07:03:06.759: INFO: Pod pod-subpath-test-dynamicpv-gmrb no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-gmrb May 12 07:03:06.759: INFO: Deleting pod "pod-subpath-test-dynamicpv-gmrb" in namespace "provisioning-8172" [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-gmrb [1mSTEP[0m: Creating a pod to test subpath May 12 07:03:06.817: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-gmrb" in namespace "provisioning-8172" to be "Succeeded or Failed" May 12 07:03:06.845: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 28.126644ms May 12 07:03:08.874: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057039292s May 12 07:03:10.903: INFO: Pod "pod-subpath-test-dynamicpv-gmrb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.086061981s [1mSTEP[0m: Saw pod success May 12 07:03:10.903: INFO: Pod "pod-subpath-test-dynamicpv-gmrb" satisfied condition "Succeeded or Failed" May 12 07:03:10.932: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000000 pod pod-subpath-test-dynamicpv-gmrb container test-container-subpath-dynamicpv-gmrb: <nil> [1mSTEP[0m: delete the pod May 12 07:03:10.998: INFO: Waiting for pod pod-subpath-test-dynamicpv-gmrb to disappear May 12 07:03:11.026: INFO: Pod pod-subpath-test-dynamicpv-gmrb no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-gmrb May 12 07:03:11.026: INFO: Deleting pod "pod-subpath-test-dynamicpv-gmrb" in namespace "provisioning-8172" ... skipping 16 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support existing directories when readOnly specified in the volumeSource [90mtest/e2e/storage/testsuites/subpath.go:397[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support existing directories when readOnly specified in the volumeSource","total":41,"completed":4,"skipped":501,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable-stress[Feature:VolumeSnapshotDataSource] test/e2e/storage/framework/testsuite.go:51 May 12 07:03:16.295: INFO: Driver test.csi.azure.com doesn't specify snapshot stress test options -- skipping ... skipping 36 lines ... [1mSTEP[0m: creating a claim May 12 07:02:59.088: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:02:59.115: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comtf4r8] to have phase Bound May 12 07:02:59.140: INFO: PersistentVolumeClaim test.csi.azure.comtf4r8 found but phase is Pending instead of Bound. May 12 07:03:01.170: INFO: PersistentVolumeClaim test.csi.azure.comtf4r8 found and phase=Bound (2.05506379s) [1mSTEP[0m: Creating pod to format volume volume-prep-provisioning-1665 May 12 07:03:01.246: INFO: Waiting up to 5m0s for pod "volume-prep-provisioning-1665" in namespace "provisioning-1665" to be "Succeeded or Failed" May 12 07:03:01.274: INFO: Pod "volume-prep-provisioning-1665": Phase="Pending", Reason="", readiness=false. Elapsed: 28.535503ms May 12 07:03:03.301: INFO: Pod "volume-prep-provisioning-1665": Phase="Pending", Reason="", readiness=false. Elapsed: 2.055076445s May 12 07:03:05.327: INFO: Pod "volume-prep-provisioning-1665": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.081859847s [1mSTEP[0m: Saw pod success May 12 07:03:05.328: INFO: Pod "volume-prep-provisioning-1665" satisfied condition "Succeeded or Failed" May 12 07:03:05.328: INFO: Deleting pod "volume-prep-provisioning-1665" in namespace "provisioning-1665" May 12 07:03:05.356: INFO: Wait up to 5m0s for pod "volume-prep-provisioning-1665" to be fully deleted [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-lnhj [1mSTEP[0m: Checking for subpath error in container status May 12 07:03:09.457: INFO: Deleting pod "pod-subpath-test-dynamicpv-lnhj" in namespace "provisioning-1665" May 12 07:03:09.484: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-lnhj" to be fully deleted [1mSTEP[0m: Deleting pod May 12 07:03:11.535: INFO: Deleting pod "pod-subpath-test-dynamicpv-lnhj" in namespace "provisioning-1665" [1mSTEP[0m: Deleting pvc May 12 07:03:11.560: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comtf4r8" ... skipping 12 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should verify container cannot write to subpath readonly volumes [Slow] [90mtest/e2e/storage/testsuites/subpath.go:425[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should verify container cannot write to subpath readonly volumes [Slow]","total":38,"completed":2,"skipped":311,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (default fs)] subPath[0m [1mshould support restarting containers using file as subpath [Slow][LinuxOnly][0m [37mtest/e2e/storage/testsuites/subpath.go:333[0m ... skipping 69 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support restarting containers using file as subpath [Slow][LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:333[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support restarting containers using file as subpath [Slow][LinuxOnly]","total":43,"completed":1,"skipped":66,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] volumeMode test/e2e/storage/framework/testsuite.go:51 May 12 07:03:21.705: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 77 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral [90mtest/e2e/storage/framework/testsuite.go:50[0m should support multiple inline ephemeral volumes [90mtest/e2e/storage/testsuites/ephemeral.go:254[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should support multiple inline ephemeral volumes","total":30,"completed":3,"skipped":445,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning ... skipping 86 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach][0m [90mtest/e2e/storage/testsuites/volumemode.go:299[0m [36mDriver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 60 lines ... test/e2e/storage/external/external.go:262 [90m------------------------------[0m [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (default fs)] subPath[0m [1mshould fail if subpath directory is outside the volume [Slow][LinuxOnly][0m [37mtest/e2e/storage/testsuites/subpath.go:242[0m [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 12 07:03:16.303: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json [1mSTEP[0m: Building a namespace api object, basename provisioning [1mSTEP[0m: Waiting for a default service account to be provisioned in namespace [1mSTEP[0m: Waiting for kube-root-ca.crt to be provisioned in namespace [It] should fail if subpath directory is outside the volume [Slow][LinuxOnly] test/e2e/storage/testsuites/subpath.go:242 May 12 07:03:16.496: INFO: Creating resource for dynamic PV May 12 07:03:16.496: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass provisioning-3782-e2e-sc9qw94 [1mSTEP[0m: creating a claim May 12 07:03:16.527: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:03:16.557: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjh89k] to have phase Bound May 12 07:03:16.584: INFO: PersistentVolumeClaim test.csi.azure.comjh89k found but phase is Pending instead of Bound. May 12 07:03:18.613: INFO: PersistentVolumeClaim test.csi.azure.comjh89k found and phase=Bound (2.056137575s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-vfpj [1mSTEP[0m: Checking for subpath error in container status May 12 07:03:22.756: INFO: Deleting pod "pod-subpath-test-dynamicpv-vfpj" in namespace "provisioning-3782" May 12 07:03:22.785: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-vfpj" to be fully deleted [1mSTEP[0m: Deleting pod May 12 07:03:28.842: INFO: Deleting pod "pod-subpath-test-dynamicpv-vfpj" in namespace "provisioning-3782" [1mSTEP[0m: Deleting pvc May 12 07:03:28.869: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comjh89k" ... skipping 9 lines ... [32m• [SLOW TEST:17.767 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should fail if subpath directory is outside the volume [Slow][LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:242[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath directory is outside the volume [Slow][LinuxOnly]","total":41,"completed":5,"skipped":524,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 12 07:03:34.083: INFO: Driver test.csi.azure.com doesn't support xfs -- skipping ... skipping 13 lines ... test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (block volmode)] volumeMode[0m [1mshould fail in binding dynamic provisioned PV to PVC [Slow][LinuxOnly][0m [37mtest/e2e/storage/testsuites/volumemode.go:260[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 12 07:03:34.108: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json [1mSTEP[0m: Building a namespace api object, basename volumemode [1mSTEP[0m: Waiting for a default service account to be provisioned in namespace [1mSTEP[0m: Waiting for kube-root-ca.crt to be provisioned in namespace [It] should fail in binding dynamic provisioned PV to PVC [Slow][LinuxOnly] test/e2e/storage/testsuites/volumemode.go:260 [1mSTEP[0m: Creating sc [1mSTEP[0m: Creating pv and pvc [1mSTEP[0m: Deleting pvc May 12 07:03:34.445: INFO: Deleting PersistentVolumeClaim "pvc-qtgd5" [1mSTEP[0m: Deleting sc [AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode test/e2e/framework/framework.go:188 May 12 07:03:34.504: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready [1mSTEP[0m: Destroying namespace "volumemode-5715" for this suite. [32m•[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (block volmode)] volumeMode should fail in binding dynamic provisioned PV to PVC [Slow][LinuxOnly]","total":41,"completed":6,"skipped":562,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:03:34.580: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 58 lines ... May 12 07:03:21.959: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:03:21.989: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com5gclr] to have phase Bound May 12 07:03:22.018: INFO: PersistentVolumeClaim test.csi.azure.com5gclr found but phase is Pending instead of Bound. May 12 07:03:24.052: INFO: PersistentVolumeClaim test.csi.azure.com5gclr found and phase=Bound (2.062734666s) [1mSTEP[0m: Creating pod exec-volume-test-dynamicpv-rwck [1mSTEP[0m: Creating a pod to test exec-volume-test May 12 07:03:24.138: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-rwck" in namespace "volume-7625" to be "Succeeded or Failed" May 12 07:03:24.166: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Pending", Reason="", readiness=false. Elapsed: 28.022814ms May 12 07:03:26.196: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Pending", Reason="", readiness=false. Elapsed: 2.058698732s May 12 07:03:28.225: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Pending", Reason="", readiness=false. Elapsed: 4.087612533s May 12 07:03:30.256: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Pending", Reason="", readiness=false. Elapsed: 6.11803226s May 12 07:03:32.286: INFO: Pod "exec-volume-test-dynamicpv-rwck": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.147822195s [1mSTEP[0m: Saw pod success May 12 07:03:32.286: INFO: Pod "exec-volume-test-dynamicpv-rwck" satisfied condition "Succeeded or Failed" May 12 07:03:32.314: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000000 pod exec-volume-test-dynamicpv-rwck container exec-container-dynamicpv-rwck: <nil> [1mSTEP[0m: delete the pod May 12 07:03:32.382: INFO: Waiting for pod exec-volume-test-dynamicpv-rwck to disappear May 12 07:03:32.410: INFO: Pod exec-volume-test-dynamicpv-rwck no longer exists [1mSTEP[0m: Deleting pod exec-volume-test-dynamicpv-rwck May 12 07:03:32.410: INFO: Deleting pod "exec-volume-test-dynamicpv-rwck" in namespace "volume-7625" ... skipping 14 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] volumes [90mtest/e2e/storage/framework/testsuite.go:50[0m should allow exec of files on the volume [90mtest/e2e/storage/testsuites/volumes.go:198[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volumes should allow exec of files on the volume","total":43,"completed":2,"skipped":96,"failed":0} [BeforeEach] [Testpattern: Inline-volume (ext4)] volumes test/e2e/storage/framework/testsuite.go:51 May 12 07:03:37.647: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping [AfterEach] [Testpattern: Inline-volume (ext4)] volumes test/e2e/framework/framework.go:188 ... skipping 136 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral [90mtest/e2e/storage/framework/testsuite.go:50[0m should create read-only inline ephemeral volume [90mtest/e2e/storage/testsuites/ephemeral.go:175[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should create read-only inline ephemeral volume","total":18,"completed":3,"skipped":916,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:03:47.073: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 3 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Pre-provisioned PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:280[0m [36mDriver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 21 lines ... May 12 07:03:14.428: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:03:14.455: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comkzx6z] to have phase Bound May 12 07:03:14.487: INFO: PersistentVolumeClaim test.csi.azure.comkzx6z found but phase is Pending instead of Bound. May 12 07:03:16.511: INFO: PersistentVolumeClaim test.csi.azure.comkzx6z found and phase=Bound (2.056131424s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-f4jw [1mSTEP[0m: Creating a pod to test atomic-volume-subpath May 12 07:03:16.589: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-f4jw" in namespace "provisioning-8693" to be "Succeeded or Failed" May 12 07:03:16.614: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Pending", Reason="", readiness=false. Elapsed: 25.440059ms May 12 07:03:18.640: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05164303s May 12 07:03:20.667: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 4.078785748s May 12 07:03:22.695: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 6.106106252s May 12 07:03:24.721: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 8.132521962s May 12 07:03:26.747: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 10.158504832s ... skipping 3 lines ... May 12 07:03:34.854: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 18.265164856s May 12 07:03:36.880: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 20.291318969s May 12 07:03:38.907: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=true. Elapsed: 22.317905678s May 12 07:03:40.934: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Running", Reason="", readiness=false. Elapsed: 24.345178915s May 12 07:03:42.960: INFO: Pod "pod-subpath-test-dynamicpv-f4jw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.371418709s [1mSTEP[0m: Saw pod success May 12 07:03:42.960: INFO: Pod "pod-subpath-test-dynamicpv-f4jw" satisfied condition "Succeeded or Failed" May 12 07:03:42.987: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-f4jw container test-container-subpath-dynamicpv-f4jw: <nil> [1mSTEP[0m: delete the pod May 12 07:03:43.045: INFO: Waiting for pod pod-subpath-test-dynamicpv-f4jw to disappear May 12 07:03:43.070: INFO: Pod pod-subpath-test-dynamicpv-f4jw no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-f4jw May 12 07:03:43.070: INFO: Deleting pod "pod-subpath-test-dynamicpv-f4jw" in namespace "provisioning-8693" ... skipping 16 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support file as subpath [LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:232[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support file as subpath [LinuxOnly]","total":42,"completed":7,"skipped":911,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource] test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource] ... skipping 6 lines ... [It] should check snapshot fields, check restore correctly works, check deletion (ephemeral) test/e2e/storage/testsuites/snapshottable.go:177 May 12 07:03:48.479: INFO: Creating resource for dynamic PV May 12 07:03:48.479: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass snapshotting-4681-e2e-scgh9g9 [1mSTEP[0m: [init] starting a pod to use the claim May 12 07:03:48.532: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-r6ctt" in namespace "snapshotting-4681" to be "Succeeded or Failed" May 12 07:03:48.557: INFO: Pod "pvc-snapshottable-tester-r6ctt": Phase="Pending", Reason="", readiness=false. Elapsed: 25.061785ms May 12 07:03:50.584: INFO: Pod "pvc-snapshottable-tester-r6ctt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.051253902s May 12 07:03:52.609: INFO: Pod "pvc-snapshottable-tester-r6ctt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.07702387s May 12 07:03:54.635: INFO: Pod "pvc-snapshottable-tester-r6ctt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.102806422s [1mSTEP[0m: Saw pod success May 12 07:03:54.635: INFO: Pod "pvc-snapshottable-tester-r6ctt" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim [1mSTEP[0m: creating a SnapshotClass May 12 07:03:54.660: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping May 12 07:03:54.661: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-r6ctt-my-volume] to have phase Bound May 12 07:03:54.686: INFO: PersistentVolumeClaim pvc-snapshottable-tester-r6ctt-my-volume found and phase=Bound (24.580621ms) [1mSTEP[0m: [init] checking the PV ... skipping 139 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should be able to unmount after the subpath directory is deleted [LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:447[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should be able to unmount after the subpath directory is deleted [LinuxOnly]","total":43,"completed":3,"skipped":168,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Inline-volume (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:03:58.289: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 538 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] [90mtest/e2e/storage/framework/testsuite.go:50[0m should concurrently access the single volume from pods on the same node [90mtest/e2e/storage/testsuites/multivolume.go:298[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the single volume from pods on the same node","total":30,"completed":4,"skipped":613,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:04:01.034: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping ... skipping 115 lines ... May 12 07:03:55.183: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:03:55.209: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comtjg95] to have phase Bound May 12 07:03:55.234: INFO: PersistentVolumeClaim test.csi.azure.comtjg95 found but phase is Pending instead of Bound. May 12 07:03:57.261: INFO: PersistentVolumeClaim test.csi.azure.comtjg95 found and phase=Bound (2.051305802s) [1mSTEP[0m: [init] starting a pod to use the claim [1mSTEP[0m: [init] check pod success May 12 07:03:57.361: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-9p79m" in namespace "snapshotting-3177" to be "Succeeded or Failed" May 12 07:03:57.386: INFO: Pod "pvc-snapshottable-tester-9p79m": Phase="Pending", Reason="", readiness=false. Elapsed: 24.506514ms May 12 07:03:59.412: INFO: Pod "pvc-snapshottable-tester-9p79m": Phase="Pending", Reason="", readiness=false. Elapsed: 2.050938614s May 12 07:04:01.438: INFO: Pod "pvc-snapshottable-tester-9p79m": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.076811272s [1mSTEP[0m: Saw pod success May 12 07:04:01.438: INFO: Pod "pvc-snapshottable-tester-9p79m" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim May 12 07:04:01.463: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comtjg95] to have phase Bound May 12 07:04:01.488: INFO: PersistentVolumeClaim test.csi.azure.comtjg95 found and phase=Bound (24.750022ms) [1mSTEP[0m: [init] checking the PV [1mSTEP[0m: [init] deleting the pod May 12 07:04:01.563: INFO: Pod pvc-snapshottable-tester-9p79m has the following logs: ... skipping 76 lines ... May 12 07:03:59.516: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:03:59.546: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8zf9m] to have phase Bound May 12 07:03:59.575: INFO: PersistentVolumeClaim test.csi.azure.com8zf9m found but phase is Pending instead of Bound. May 12 07:04:01.604: INFO: PersistentVolumeClaim test.csi.azure.com8zf9m found and phase=Bound (2.057651603s) [1mSTEP[0m: [init] starting a pod to use the claim [1mSTEP[0m: [init] check pod success May 12 07:04:01.724: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-st7rj" in namespace "snapshotting-482" to be "Succeeded or Failed" May 12 07:04:01.752: INFO: Pod "pvc-snapshottable-tester-st7rj": Phase="Pending", Reason="", readiness=false. Elapsed: 28.458775ms May 12 07:04:03.783: INFO: Pod "pvc-snapshottable-tester-st7rj": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05934676s May 12 07:04:05.814: INFO: Pod "pvc-snapshottable-tester-st7rj": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.089708101s [1mSTEP[0m: Saw pod success May 12 07:04:05.814: INFO: Pod "pvc-snapshottable-tester-st7rj" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim May 12 07:04:05.842: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8zf9m] to have phase Bound May 12 07:04:05.871: INFO: PersistentVolumeClaim test.csi.azure.com8zf9m found and phase=Bound (28.443999ms) [1mSTEP[0m: [init] checking the PV [1mSTEP[0m: [init] deleting the pod May 12 07:04:05.959: INFO: Pod pvc-snapshottable-tester-st7rj has the following logs: ... skipping 80 lines ... May 12 07:03:34.847: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:03:34.876: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.coml6vcq] to have phase Bound May 12 07:03:34.905: INFO: PersistentVolumeClaim test.csi.azure.coml6vcq found but phase is Pending instead of Bound. May 12 07:03:36.935: INFO: PersistentVolumeClaim test.csi.azure.coml6vcq found and phase=Bound (2.058706779s) [1mSTEP[0m: Expanding non-expandable pvc May 12 07:03:36.991: INFO: currentPvcSize {{5368709120 0} {<nil>} 5Gi BinarySI}, newSize {{6442450944 0} {<nil>} BinarySI} May 12 07:03:37.049: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:39.108: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:41.108: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:43.107: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:45.106: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:47.111: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:49.105: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:51.105: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:53.110: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:55.106: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:57.106: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:03:59.106: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:04:01.107: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:04:03.107: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:04:05.109: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:04:07.111: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 12 07:04:07.167: INFO: Error updating pvc test.csi.azure.coml6vcq: persistentvolumeclaims "test.csi.azure.coml6vcq" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize [1mSTEP[0m: Deleting pvc May 12 07:04:07.167: INFO: Deleting PersistentVolumeClaim "test.csi.azure.coml6vcq" May 12 07:04:07.196: INFO: Waiting up to 5m0s for PersistentVolume pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a to get deleted May 12 07:04:07.224: INFO: PersistentVolume pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a found and phase=Released (27.833737ms) May 12 07:04:12.253: INFO: PersistentVolume pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a was removed [1mSTEP[0m: Deleting sc ... skipping 8 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] volume-expand [90mtest/e2e/storage/framework/testsuite.go:50[0m should not allow expansion of pvcs without AllowVolumeExpansion property [90mtest/e2e/storage/testsuites/volume_expand.go:159[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] volume-expand should not allow expansion of pvcs without AllowVolumeExpansion property","total":41,"completed":7,"skipped":606,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning test/e2e/storage/framework/testsuite.go:51 May 12 07:04:12.387: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping ... skipping 59 lines ... [It] should check snapshot fields, check restore correctly works, check deletion (ephemeral) test/e2e/storage/testsuites/snapshottable.go:177 May 12 07:04:07.013: INFO: Creating resource for dynamic PV May 12 07:04:07.013: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass snapshotting-4967-e2e-scmv859 [1mSTEP[0m: [init] starting a pod to use the claim May 12 07:04:07.067: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-xd926" in namespace "snapshotting-4967" to be "Succeeded or Failed" May 12 07:04:07.093: INFO: Pod "pvc-snapshottable-tester-xd926": Phase="Pending", Reason="", readiness=false. Elapsed: 25.694609ms May 12 07:04:09.119: INFO: Pod "pvc-snapshottable-tester-xd926": Phase="Pending", Reason="", readiness=false. Elapsed: 2.051985416s May 12 07:04:11.145: INFO: Pod "pvc-snapshottable-tester-xd926": Phase="Pending", Reason="", readiness=false. Elapsed: 4.077780282s May 12 07:04:13.171: INFO: Pod "pvc-snapshottable-tester-xd926": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.104628452s [1mSTEP[0m: Saw pod success May 12 07:04:13.172: INFO: Pod "pvc-snapshottable-tester-xd926" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim [1mSTEP[0m: creating a SnapshotClass May 12 07:04:13.197: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping May 12 07:04:13.197: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-xd926-my-volume] to have phase Bound May 12 07:04:13.223: INFO: PersistentVolumeClaim pvc-snapshottable-tester-xd926-my-volume found and phase=Bound (25.834737ms) [1mSTEP[0m: [init] checking the PV ... skipping 182 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] [90mtest/e2e/storage/framework/testsuite.go:50[0m should concurrently access the single volume from pods on different node [90mtest/e2e/storage/testsuites/multivolume.go:451[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the single volume from pods on different node","total":30,"completed":5,"skipped":737,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:04:25.821: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 3 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Pre-provisioned PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:242[0m [36mDriver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 133 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (filesystem volmode)] volumeMode [90mtest/e2e/storage/framework/testsuite.go:50[0m should not mount / map unused volumes in a pod [LinuxOnly] [90mtest/e2e/storage/testsuites/volumemode.go:354[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode should not mount / map unused volumes in a pod [LinuxOnly]","total":43,"completed":4,"skipped":699,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Inline-volume (default fs)] volumes test/e2e/storage/framework/testsuite.go:51 May 12 07:04:26.123: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 85 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Pre-provisioned PV (block volmode)] volumeMode [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach][0m [90mtest/e2e/storage/testsuites/volumemode.go:299[0m [36mDriver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 52 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral [90mtest/e2e/storage/framework/testsuite.go:50[0m should support two pods which have the same volume definition [90mtest/e2e/storage/testsuites/ephemeral.go:216[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should support two pods which have the same volume definition","total":38,"completed":3,"skipped":325,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 12 07:04:34.460: INFO: Driver test.csi.azure.com doesn't support Block -- skipping ... skipping 35 lines ... May 12 07:04:26.426: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:04:26.456: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comnsfgx] to have phase Bound May 12 07:04:26.484: INFO: PersistentVolumeClaim test.csi.azure.comnsfgx found but phase is Pending instead of Bound. May 12 07:04:28.514: INFO: PersistentVolumeClaim test.csi.azure.comnsfgx found and phase=Bound (2.057691776s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-tbk7 [1mSTEP[0m: Creating a pod to test subpath May 12 07:04:28.601: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-tbk7" in namespace "provisioning-5789" to be "Succeeded or Failed" May 12 07:04:28.633: INFO: Pod "pod-subpath-test-dynamicpv-tbk7": Phase="Pending", Reason="", readiness=false. Elapsed: 31.852084ms May 12 07:04:30.663: INFO: Pod "pod-subpath-test-dynamicpv-tbk7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.0619154s May 12 07:04:32.695: INFO: Pod "pod-subpath-test-dynamicpv-tbk7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.093810724s May 12 07:04:34.725: INFO: Pod "pod-subpath-test-dynamicpv-tbk7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.123411517s [1mSTEP[0m: Saw pod success May 12 07:04:34.725: INFO: Pod "pod-subpath-test-dynamicpv-tbk7" satisfied condition "Succeeded or Failed" May 12 07:04:34.753: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000000 pod pod-subpath-test-dynamicpv-tbk7 container test-container-subpath-dynamicpv-tbk7: <nil> [1mSTEP[0m: delete the pod May 12 07:04:34.817: INFO: Waiting for pod pod-subpath-test-dynamicpv-tbk7 to disappear May 12 07:04:34.845: INFO: Pod pod-subpath-test-dynamicpv-tbk7 no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-tbk7 May 12 07:04:34.845: INFO: Deleting pod "pod-subpath-test-dynamicpv-tbk7" in namespace "provisioning-5789" ... skipping 16 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support readOnly file specified in the volumeMount [LinuxOnly] [90mtest/e2e/storage/testsuites/subpath.go:382[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support readOnly file specified in the volumeMount [LinuxOnly]","total":43,"completed":5,"skipped":780,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning ... skipping 320 lines ... May 12 07:04:40.351: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:04:40.382: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.combz9jv] to have phase Bound May 12 07:04:40.413: INFO: PersistentVolumeClaim test.csi.azure.combz9jv found but phase is Pending instead of Bound. May 12 07:04:42.442: INFO: PersistentVolumeClaim test.csi.azure.combz9jv found and phase=Bound (2.060601083s) [1mSTEP[0m: [init] starting a pod to use the claim [1mSTEP[0m: [init] check pod success May 12 07:04:42.558: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-5b58x" in namespace "snapshotting-8256" to be "Succeeded or Failed" May 12 07:04:42.589: INFO: Pod "pvc-snapshottable-tester-5b58x": Phase="Pending", Reason="", readiness=false. Elapsed: 30.386485ms May 12 07:04:44.619: INFO: Pod "pvc-snapshottable-tester-5b58x": Phase="Pending", Reason="", readiness=false. Elapsed: 2.060467656s May 12 07:04:46.649: INFO: Pod "pvc-snapshottable-tester-5b58x": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.09089724s [1mSTEP[0m: Saw pod success May 12 07:04:46.649: INFO: Pod "pvc-snapshottable-tester-5b58x" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim May 12 07:04:46.678: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.combz9jv] to have phase Bound May 12 07:04:46.706: INFO: PersistentVolumeClaim test.csi.azure.combz9jv found and phase=Bound (28.0636ms) [1mSTEP[0m: [init] checking the PV [1mSTEP[0m: [init] deleting the pod May 12 07:04:46.793: INFO: Pod pvc-snapshottable-tester-5b58x has the following logs: ... skipping 102 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral [90mtest/e2e/storage/framework/testsuite.go:50[0m should create read-only inline ephemeral volume [90mtest/e2e/storage/testsuites/ephemeral.go:175[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should create read-only inline ephemeral volume","total":41,"completed":8,"skipped":701,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volume-expand test/e2e/storage/framework/testsuite.go:51 May 12 07:04:53.900: INFO: Driver "test.csi.azure.com" does not support block volume mode - skipping ... skipping 135 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:269[0m [36mDriver test.csi.azure.com doesn't support ntfs -- skipping[0m test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m ... skipping 29 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Pre-provisioned PV (block volmode)] volumeMode [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail to create pod by failing to mount volume [Slow] [BeforeEach][0m [90mtest/e2e/storage/testsuites/volumemode.go:199[0m [36mDriver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping[0m test/e2e/storage/external/external.go:262 [90m------------------------------[0m ... skipping 52 lines ... May 12 07:04:52.490: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 12 07:04:52.520: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com7fwmw] to have phase Bound May 12 07:04:52.548: INFO: PersistentVolumeClaim test.csi.azure.com7fwmw found but phase is Pending instead of Bound. May 12 07:04:54.577: INFO: PersistentVolumeClaim test.csi.azure.com7fwmw found and phase=Bound (2.057038082s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-nw7p [1mSTEP[0m: Creating a pod to test subpath May 12 07:04:54.670: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-nw7p" in namespace "provisioning-1431" to be "Succeeded or Failed" May 12 07:04:54.698: INFO: Pod "pod-subpath-test-dynamicpv-nw7p": Phase="Pending", Reason="", readiness=false. Elapsed: 28.035362ms May 12 07:04:56.727: INFO: Pod "pod-subpath-test-dynamicpv-nw7p": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05782852s May 12 07:04:58.757: INFO: Pod "pod-subpath-test-dynamicpv-nw7p": Phase="Pending", Reason="", readiness=false. Elapsed: 4.087833142s May 12 07:05:00.787: INFO: Pod "pod-subpath-test-dynamicpv-nw7p": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.117398384s [1mSTEP[0m: Saw pod success May 12 07:05:00.787: INFO: Pod "pod-subpath-test-dynamicpv-nw7p" satisfied condition "Succeeded or Failed" May 12 07:05:00.816: INFO: Trying to get logs from node k8s-agentpool1-21931944-vmss000001 pod pod-subpath-test-dynamicpv-nw7p container test-container-subpath-dynamicpv-nw7p: <nil> [1mSTEP[0m: delete the pod May 12 07:05:00.881: INFO: Waiting for pod pod-subpath-test-dynamicpv-nw7p to disappear May 12 07:05:00.909: INFO: Pod pod-subpath-test-dynamicpv-nw7p no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-nw7p May 12 07:05:00.909: INFO: Deleting pod "pod-subpath-test-dynamicpv-nw7p" in namespace "provisioning-1431" ... skipping 16 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m should support readOnly directory specified in the volumeMount [90mtest/e2e/storage/testsuites/subpath.go:367[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] subPath should support readOnly directory specified in the volumeMount","total":43,"completed":6,"skipped":964,"failed":0} [BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:05:06.176: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping [AfterEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath test/e2e/framework/framework.go:188 [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90mtest/e2e/storage/testsuites/subpath.go:280[0m [36mDriver test.csi.azure.com doesn't support ntfs -- skipping[0m test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m ... skipping 214 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] [90mtest/e2e/storage/framework/testsuite.go:50[0m should access to two volumes with the same volume mode and retain data across pod recreation on different node [90mtest/e2e/storage/testsuites/multivolume.go:168[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should access to two volumes with the same volume mode and retain data across pod recreation on different node","total":38,"completed":4,"skipped":680,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 12 07:05:14.838: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 48 lines ... May 12 07:05:19.637: INFO: ExecWithOptions {Command:[/bin/sh -c ls -l /mnt/volume1/file1] Namespace:fsgroupchangepolicy-8377 PodName:pod-95879de0-465f-4384-91f3-049642464729 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false} May 12 07:05:19.637: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json May 12 07:05:19.638: INFO: ExecWithOptions: Clientset creation May 12 07:05:19.638: INFO: ExecWithOptions: execute(POST https://kubetest-oew5xopy.centralus.cloudapp.azure.com/api/v1/namespaces/fsgroupchangepolicy-8377/pods/pod-95879de0-465f-4384-91f3-049642464729/exec?command=%2Fbin%2Fsh&command=-c&command=ls+-l+%2Fmnt%2Fvolume1%2Ffile1&container=write-pod&container=write-pod&stderr=true&stdout=true) May 12 07:05:19.923: INFO: pod fsgroupchangepolicy-8377/pod-95879de0-465f-4384-91f3-049642464729 exec for cmd ls -l /mnt/volume1/file1, stdout: -rwxrwxrwx 1 root root 0 May 12 07:05 /mnt/volume1/file1, stderr: May 12 07:05:19.925: INFO: stdout split: [-rwxrwxrwx 1 root root 0 May 12 07:05 /mnt/volume1/file1], expected gid: 1000 May 12 07:05:19.925: FAIL: Expected <string>: root to equal <string>: 1000 Full Stack Trace k8s.io/kubernetes/test/e2e/storage/utils.VerifyFilePathGidInPod(0x7157a49?, {0x717f14f?, 0x0?}, {0xc00123dae8, 0x4}, 0xc00297ac00) ... skipping 71 lines ... May 12 07:09:56.470: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m36.516626597s) May 12 07:10:01.499: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m41.545851847s) May 12 07:10:06.527: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m46.574189368s) May 12 07:10:11.554: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m51.601048165s) May 12 07:10:16.580: INFO: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 found and phase=Bound (4m56.626748807s) [1mSTEP[0m: Deleting sc May 12 07:10:21.608: FAIL: while cleanup resource Unexpected error: <errors.aggregate | len:1, cap:1>: [ [ { msg: "persistent Volume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 not deleted by dynamic provisioner: PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 still exists within 5m0s", err: { s: "PersistentVolume pvc-0ef521d5-dbe5-4e59-92f7-e73b14e10556 still exists within 5m0s", ... skipping 6 lines ... Full Stack Trace k8s.io/kubernetes/test/e2e/storage/testsuites.(*fsGroupChangePolicyTestSuite).DefineTests.func2() test/e2e/storage/testsuites/fsgroupchangepolicy.go:134 +0x233 panic({0x6ca56c0, 0xc0037885c0}) /usr/local/go/src/runtime/panic.go:838 +0x207 k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail.func1() test/e2e/framework/ginkgowrapper/wrapper.go:63 +0x7d panic({0x632c000, 0x7a05090}) /usr/local/go/src/runtime/panic.go:838 +0x207 k8s.io/kubernetes/test/e2e/framework/ginkgowrapper.Fail({0xc00198fcc0, 0x4c}, {0xc0022d4cb0?, 0x714b92b?, 0xc0022d4cd0?}) test/e2e/framework/ginkgowrapper/wrapper.go:67 +0x197 k8s.io/kubernetes/test/e2e/framework.Fail({0xc0009e8340, 0x37}, {0xc000ac7840?, 0xc0009e8340?, 0x705c800?}) test/e2e/framework/log.go:63 +0x145 k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).match(0xc0022d4e20, {0x7a295a8, 0xc0007ee480}, 0x1, {0x0, 0x0, 0x0}) vendor/github.com/onsi/gomega/internal/assertion/assertion.go:79 +0x1bd k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc0022d4e20, {0x7a295a8, 0xc0007ee480}, {0x0, 0x0, 0x0}) vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0x95 k8s.io/kubernetes/test/e2e/framework.ExpectEqual({0x632c000?, 0xc0007ee440?}, {0x632c000?, 0xc0007ee470}, {0x0, 0x0, 0x0}) ... skipping 136 lines ... <string>: root to equal <string>: 1000[0m test/e2e/storage/utils/utils.go:728 [90m------------------------------[0m {"msg":"FAILED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":38,"completed":4,"skipped":756,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents"]} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (xfs)][Slow] volumes test/e2e/storage/framework/testsuite.go:51 May 12 07:10:22.532: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 105 lines ... test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 12 07:10:22.582: INFO: >>> kubeConfig: /root/tmp1625252499/kubeconfig/kubeconfig.centralus.json [1mSTEP[0m: Building a namespace api object, basename volumemode [1mSTEP[0m: Waiting for a default service account to be provisioned in namespace [1mSTEP[0m: Waiting for kube-root-ca.crt to be provisioned in namespace [It] should fail to use a volume in a pod with mismatched mode [Slow] test/e2e/storage/testsuites/volumemode.go:299 May 12 07:10:22.756: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping [AfterEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode test/e2e/framework/framework.go:188 May 12 07:10:22.757: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready [1mSTEP[0m: Destroying namespace "volumemode-1292" for this suite. [36m[1mS [SKIPPING] [0.226 seconds][0m External Storage [Driver: test.csi.azure.com] [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (filesystem volmode)] volumeMode [90mtest/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail to use a volume in a pod with mismatched mode [Slow] [Measurement][0m [90mtest/e2e/storage/testsuites/volumemode.go:299[0m [36mDriver "test.csi.azure.com" does not provide raw block - skipping[0m test/e2e/storage/testsuites/volumes.go:114 [90m------------------------------[0m ... skipping 83 lines ... May 12 07:10:23.024: INFO: Running AfterSuite actions on node 1 [91m[1mSummarizing 1 Failure:[0m [91m[1m[Fail] [0m[90mExternal Storage [Driver: test.csi.azure.com] [0m[0m[Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [0m[91m[1m[Measurement] (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents [0m [37mtest/e2e/storage/utils/utils.go:728[0m [1m[91mRan 37 of 7229 Specs in 555.897 seconds[0m [1m[91mFAIL![0m -- [32m[1m36 Passed[0m | [91m[1m1 Failed[0m | [33m[1m0 Pending[0m | [36m[1m7192 Skipped[0m Ginkgo ran 1 suite in 9m20.378397157s Test Suite Failed + print_logs + bash ./hack/verify-examples.sh linux begin to create deployment examples ... storageclass.storage.k8s.io/azurefile-csi created Applying config "deploy/example/daemonset.yaml" Waiting for daemon set "daemonset-azurefile" rollout to finish: 0 of 2 updated pods are available... ... skipping 69 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0512 07:00:59.271759 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test I0512 07:00:59.272072 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0512 07:00:59.287419 1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found I0512 07:00:59.287437 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0512 07:00:59.287444 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0512 07:00:59.287465 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0512 07:00:59.287984 1 azure_auth.go:245] Using AzurePublicCloud environment I0512 07:00:59.288016 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0512 07:00:59.288043 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 102 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0512 07:00:58.302470 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test I0512 07:00:58.302773 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0512 07:00:58.320391 1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found I0512 07:00:58.320407 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0512 07:00:58.320414 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0512 07:00:58.320432 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0512 07:00:58.320896 1 azure_auth.go:245] Using AzurePublicCloud environment I0512 07:00:58.320927 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0512 07:00:58.320950 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 501 lines ... I0512 07:03:32.665714 1 azure_storage.go:66] share pvc-4b478bb8-04e3-4892-b1b7-2a8aa253c39b deleted I0512 07:03:32.665743 1 controllerserver.go:584] azure file(pvc-4b478bb8-04e3-4892-b1b7-2a8aa253c39b) under rg(kubetest-oew5xopy) account(f6a30d1c0177346d3a9e954) volume(kubetest-oew5xopy#f6a30d1c0177346d3a9e954#pvc-4b478bb8-04e3-4892-b1b7-2a8aa253c39b###volume-7625) is deleted successfully I0512 07:03:32.665789 1 azure_metrics.go:112] "Observed Request Latency" latency_seconds=0.194163682 request="azurefile_csi_driver_controller_delete_volume" resource_group="kubetest-oew5xopy" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="test.csi.azure.com" volumeid="kubetest-oew5xopy#f6a30d1c0177346d3a9e954#pvc-4b478bb8-04e3-4892-b1b7-2a8aa253c39b###volume-7625" result_code="succeeded" I0512 07:03:32.665806 1 utils.go:83] GRPC response: {} I0512 07:03:34.352077 1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume I0512 07:03:34.352217 1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d954320b-df8d-4eae-a94f-294a59ce154c","parameters":{"csi.storage.k8s.io/pv/name":"pvc-d954320b-df8d-4eae-a94f-294a59ce154c","csi.storage.k8s.io/pvc/name":"pvc-qtgd5","csi.storage.k8s.io/pvc/namespace":"volumemode-5715","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]} E0512 07:03:34.352417 1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes I0512 07:03:34.461208 1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume I0512 07:03:34.461365 1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d954320b-df8d-4eae-a94f-294a59ce154c","parameters":{"csi.storage.k8s.io/pv/name":"pvc-d954320b-df8d-4eae-a94f-294a59ce154c","csi.storage.k8s.io/pvc/name":"pvc-qtgd5","csi.storage.k8s.io/pvc/namespace":"volumemode-5715","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]} E0512 07:03:34.461469 1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes I0512 07:03:34.866595 1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume I0512 07:03:34.866746 1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a","parameters":{"csi.storage.k8s.io/pv/name":"pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a","csi.storage.k8s.io/pvc/name":"test.csi.azure.coml6vcq","csi.storage.k8s.io/pvc/namespace":"volume-expand-9509","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}}]} I0512 07:03:34.927493 1 controllerserver.go:433] begin to create file share(pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a) on account(f6a30d1c0177346d3a9e954) type(Premium_LRS) rg(kubetest-oew5xopy) location() size(100) protocol(SMB) I0512 07:03:35.089219 1 controllerserver.go:455] create file share pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a on storage account f6a30d1c0177346d3a9e954 successfully I0512 07:03:35.093178 1 controllerserver.go:501] store account key to k8s secret(azure-storage-account-f6a30d1c0177346d3a9e954-secret) in volume-expand-9509 namespace I0512 07:03:35.093223 1 azure_metrics.go:112] "Observed Request Latency" latency_seconds=0.165741397 request="azurefile_csi_driver_controller_create_volume" resource_group="kubetest-oew5xopy" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="test.csi.azure.com" volumeid="kubetest-oew5xopy#f6a30d1c0177346d3a9e954#pvc-d617a38d-b517-4bbb-b70e-19bb6c24501a###volume-expand-9509" result_code="succeeded" ... skipping 277 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0512 07:00:56.063139 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test I0512 07:00:56.063552 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0512 07:00:56.080264 1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found I0512 07:00:56.080282 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0512 07:00:56.080289 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0512 07:00:56.080309 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0512 07:00:56.080852 1 azure_auth.go:245] Using AzurePublicCloud environment I0512 07:00:56.080889 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0512 07:00:56.080919 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 1038 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0512 07:00:55.813415 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test I0512 07:00:55.813696 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0512 07:00:55.833237 1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found I0512 07:00:55.833254 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0512 07:00:55.833261 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0512 07:00:55.833282 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0512 07:00:55.833764 1 azure_auth.go:245] Using AzurePublicCloud environment I0512 07:00:55.833799 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0512 07:00:55.833824 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 819 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0512 07:00:53.096337 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-c52c48007cdd2c836422f7b2374338f4e15ae788 gc/go1.18.1 (amd64-linux) e2e-test I0512 07:00:53.097422 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0512 07:00:53.116286 1 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found I0512 07:00:53.116304 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0512 07:00:53.116311 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0512 07:00:53.116421 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0512 07:00:53.117022 1 azure_auth.go:245] Using AzurePublicCloud environment I0512 07:00:53.117057 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0512 07:00:53.117087 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 360 lines ... # HELP process_virtual_memory_bytes Virtual memory size in bytes. # TYPE process_virtual_memory_bytes gauge process_virtual_memory_bytes 7.620608e+08 # HELP process_virtual_memory_max_bytes Maximum amount of virtual memory available in bytes. # TYPE process_virtual_memory_max_bytes gauge process_virtual_memory_max_bytes 1.8446744073709552e+19 make: *** [Makefile:85: e2e-test] Error 1 2022/05/12 07:10:48 process.go:155: Step 'make e2e-test' finished in 19m38.555448486s 2022/05/12 07:10:48 aksengine_helpers.go:426: downloading /root/tmp1625252499/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh 2022/05/12 07:10:48 util.go:71: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh 2022/05/12 07:10:48 process.go:153: Running: chmod +x /root/tmp1625252499/log-dump.sh 2022/05/12 07:10:48 process.go:155: Step 'chmod +x /root/tmp1625252499/log-dump.sh' finished in 1.462336ms 2022/05/12 07:10:48 aksengine_helpers.go:426: downloading /root/tmp1625252499/log-dump-daemonset.yaml from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump-daemonset.yaml ... skipping 53 lines ... ssh key file /root/.ssh/id_rsa does not exist. Exiting. 2022/05/12 07:11:09 process.go:155: Step 'bash -c /root/tmp1625252499/win-ci-logs-collector.sh kubetest-oew5xopy.centralus.cloudapp.azure.com /root/tmp1625252499 /root/.ssh/id_rsa' finished in 4.269326ms 2022/05/12 07:11:09 aksengine.go:1141: Deleting resource group: kubetest-oew5xopy. 2022/05/12 07:17:25 process.go:96: Saved XML output to /logs/artifacts/junit_runner.xml. 2022/05/12 07:17:25 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" 2022/05/12 07:17:26 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 285.755624ms 2022/05/12 07:17:26 main.go:331: Something went wrong: encountered 1 errors: [error during make e2e-test: exit status 2] + EXIT_VALUE=1 + set +o xtrace Cleaning up after docker in docker. ================================================================================ Cleaning up after docker 34a8eb8e75a9 ... skipping 4 lines ...