Recent runs || View in Spyglass
PR | andyzhangx: test: run k8s 1.24 external e2e test |
Result | FAILURE |
Tests | 1 failed / 13 succeeded |
Started | |
Elapsed | 32m8s |
Revision | 70d38bbb09178d7d3c95bed995df44431b6b3e6c |
Refs |
1014 |
job-version | v1.25.0-alpha.0.340+9d0bb09fae6a6a |
kubetest-version | |
revision | v1.25.0-alpha.0.340+9d0bb09fae6a6a |
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 213k 0 --:--:-- --:--:-- --:--:-- 213k 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-3273d65a31e38c7a128a9fa367eba2609e4079b6 || make container-all push-manifest Error response from daemon: manifest for k8sprow.azurecr.io/azurefile-csi:e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 not found: manifest unknown: manifest tagged by "e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6" 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-3273d65a31e38c7a128a9fa367eba2609e4079b6 -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.gitCommit=3273d65a31e38c7a128a9fa367eba2609e4079b6 -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.buildDate=2022-05-07T07:28:29Z -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 1791 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 308 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 549 lines ... test/e2e/storage/testsuites/provisioning.go:111 [90m------------------------------[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 ... skipping 2 lines ... [1mSTEP[0m: Building a namespace api object, basename provisioning W0507 07:38:11.923510 35577 warnings.go:70] policy/v1beta1 PodSecurityPolicy is deprecated in v1.21+, unavailable in v1.25+ May 7 07:38:11.923: INFO: Found PodSecurityPolicies; testing pod creation to see if PodSecurityPolicy is enabled May 7 07:38:11.960: INFO: No PSP annotation exists on dry run pod; assuming PodSecurityPolicy is disabled [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 7 07:38:12.089: INFO: Creating resource for dynamic PV May 7 07:38:12.089: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass provisioning-6812-e2e-scds4qq [1mSTEP[0m: creating a claim May 7 07:38:12.126: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil ... skipping 7 lines ... May 7 07:38:24.406: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found but phase is Pending instead of Bound. May 7 07:38:26.441: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found but phase is Pending instead of Bound. May 7 07:38:28.474: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found but phase is Pending instead of Bound. May 7 07:38:30.508: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found but phase is Pending instead of Bound. May 7 07:38:32.542: INFO: PersistentVolumeClaim test.csi.azure.comzdckn found and phase=Bound (20.378175722s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-dkq2 [1mSTEP[0m: Checking for subpath error in container status May 7 07:38:40.720: INFO: Deleting pod "pod-subpath-test-dynamicpv-dkq2" in namespace "provisioning-6812" May 7 07:38:40.755: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-dkq2" to be fully deleted [1mSTEP[0m: Deleting pod May 7 07:38:42.821: INFO: Deleting pod "pod-subpath-test-dynamicpv-dkq2" in namespace "provisioning-6812" [1mSTEP[0m: Deleting pvc May 7 07:38:42.854: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comzdckn" ... skipping 9 lines ... [32m• [SLOW TEST:36.334 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":35,"completed":1,"skipped":40,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:38:48.149: INFO: Driver test.csi.azure.com doesn't support Block -- 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 (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 5 lines ... test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 7 07:38:48.214: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.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 7 07:38:48.447: 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 7 07:38:48.448: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready [1mSTEP[0m: Destroying namespace "volumemode-5219" for this suite. [36m[1mS [SKIPPING] [0.301 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 18 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 [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 7 07:38:48.564: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.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 7 07:38:48.978: INFO: Deleting PersistentVolumeClaim "pvc-zdhsx" [1mSTEP[0m: Deleting sc [AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode test/e2e/framework/framework.go:188 May 7 07:38:49.047: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready [1mSTEP[0m: Destroying namespace "volumemode-7633" 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":35,"completed":2,"skipped":209,"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[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[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)] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:38:49.225: INFO: Driver test.csi.azure.com doesn't support Block -- skipping ... skipping 130 lines ... May 7 07:38:27.288: INFO: PersistentVolumeClaim test.csi.azure.com7zmwh found but phase is Pending instead of Bound. May 7 07:38:29.323: INFO: PersistentVolumeClaim test.csi.azure.com7zmwh found but phase is Pending instead of Bound. May 7 07:38:31.359: INFO: PersistentVolumeClaim test.csi.azure.com7zmwh found but phase is Pending instead of Bound. May 7 07:38:33.394: INFO: PersistentVolumeClaim test.csi.azure.com7zmwh found and phase=Bound (20.386133363s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-89ss [1mSTEP[0m: Creating a pod to test multi_subpath May 7 07:38:33.496: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-89ss" in namespace "provisioning-4020" to be "Succeeded or Failed" May 7 07:38:33.532: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 35.370591ms May 7 07:38:35.566: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069932271s May 7 07:38:37.601: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 4.104848032s May 7 07:38:39.637: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 6.140143543s May 7 07:38:41.672: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Pending", Reason="", readiness=false. Elapsed: 8.175979558s May 7 07:38:43.707: INFO: Pod "pod-subpath-test-dynamicpv-89ss": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.210125353s [1mSTEP[0m: Saw pod success May 7 07:38:43.707: INFO: Pod "pod-subpath-test-dynamicpv-89ss" satisfied condition "Succeeded or Failed" May 7 07:38:43.741: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000001 pod pod-subpath-test-dynamicpv-89ss container test-container-subpath-dynamicpv-89ss: <nil> [1mSTEP[0m: delete the pod May 7 07:38:44.334: INFO: Waiting for pod pod-subpath-test-dynamicpv-89ss to disappear May 7 07:38:44.368: INFO: Pod pod-subpath-test-dynamicpv-89ss no longer exists [1mSTEP[0m: Deleting pod May 7 07:38:44.368: INFO: Deleting pod "pod-subpath-test-dynamicpv-89ss" in namespace "provisioning-4020" ... 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":37,"completed":1,"skipped":120,"failed":0} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral test/e2e/storage/framework/testsuite.go:51 May 7 07:38:49.656: INFO: Driver "test.csi.azure.com" does not support volume type "CSIInlineVolume" - skipping ... skipping 184 lines ... May 7 07:38:24.418: INFO: PersistentVolumeClaim test.csi.azure.comss72b found but phase is Pending instead of Bound. May 7 07:38:26.452: INFO: PersistentVolumeClaim test.csi.azure.comss72b found but phase is Pending instead of Bound. May 7 07:38:28.486: INFO: PersistentVolumeClaim test.csi.azure.comss72b found but phase is Pending instead of Bound. May 7 07:38:30.521: INFO: PersistentVolumeClaim test.csi.azure.comss72b found but phase is Pending instead of Bound. May 7 07:38:32.555: INFO: PersistentVolumeClaim test.csi.azure.comss72b found and phase=Bound (20.386073035s) [1mSTEP[0m: Creating pod to format volume volume-prep-provisioning-9552 May 7 07:38:32.673: INFO: Waiting up to 5m0s for pod "volume-prep-provisioning-9552" in namespace "provisioning-9552" to be "Succeeded or Failed" May 7 07:38:32.720: INFO: Pod "volume-prep-provisioning-9552": Phase="Pending", Reason="", readiness=false. Elapsed: 46.163857ms May 7 07:38:34.755: INFO: Pod "volume-prep-provisioning-9552": Phase="Pending", Reason="", readiness=false. Elapsed: 2.081283032s May 7 07:38:36.789: INFO: Pod "volume-prep-provisioning-9552": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.115485431s [1mSTEP[0m: Saw pod success May 7 07:38:36.789: INFO: Pod "volume-prep-provisioning-9552" satisfied condition "Succeeded or Failed" May 7 07:38:36.789: INFO: Deleting pod "volume-prep-provisioning-9552" in namespace "provisioning-9552" May 7 07:38:36.828: INFO: Wait up to 5m0s for pod "volume-prep-provisioning-9552" to be fully deleted [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-5hcf [1mSTEP[0m: Checking for subpath error in container status May 7 07:38:44.966: INFO: Deleting pod "pod-subpath-test-dynamicpv-5hcf" in namespace "provisioning-9552" May 7 07:38:45.007: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-5hcf" to be fully deleted [1mSTEP[0m: Deleting pod May 7 07:38:45.040: INFO: Deleting pod "pod-subpath-test-dynamicpv-5hcf" in namespace "provisioning-9552" [1mSTEP[0m: Deleting pvc May 7 07:38:45.074: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comss72b" ... 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":36,"completed":1,"skipped":39,"failed":0} [36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:38:50.316: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 59 lines ... [It] should check snapshot fields, check restore correctly works, check deletion (ephemeral) test/e2e/storage/testsuites/snapshottable.go:177 May 7 07:38:50.068: INFO: Creating resource for dynamic PV May 7 07:38:50.068: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass snapshotting-1997-e2e-scv8ts7 [1mSTEP[0m: [init] starting a pod to use the claim May 7 07:38:50.140: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-d9bhj" in namespace "snapshotting-1997" to be "Succeeded or Failed" May 7 07:38:50.176: INFO: Pod "pvc-snapshottable-tester-d9bhj": Phase="Pending", Reason="", readiness=false. Elapsed: 35.588744ms May 7 07:38:52.210: INFO: Pod "pvc-snapshottable-tester-d9bhj": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069858016s May 7 07:38:54.244: INFO: Pod "pvc-snapshottable-tester-d9bhj": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.104308051s [1mSTEP[0m: Saw pod success May 7 07:38:54.244: INFO: Pod "pvc-snapshottable-tester-d9bhj" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim [1mSTEP[0m: creating a SnapshotClass May 7 07:38:54.279: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping May 7 07:38:54.280: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-d9bhj-my-volume] to have phase Bound May 7 07:38:54.314: INFO: PersistentVolumeClaim pvc-snapshottable-tester-d9bhj-my-volume found and phase=Bound (33.602367ms) [1mSTEP[0m: [init] checking the PV ... skipping 57 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 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 164 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [90mtest/e2e/storage/framework/testsuite.go:50[0m (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents [90mtest/e2e/storage/testsuites/fsgroupchangepolicy.go:216[0m [90m------------------------------[0m {"msg":"PASSED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":34,"completed":1,"skipped":129,"failed":0} [36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:38:58.711: INFO: Driver test.csi.azure.com doesn't support ext4 -- skipping ... skipping 117 lines ... May 7 07:38:50.012: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:38:50.049: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comnmnbt] to have phase Bound May 7 07:38:50.082: INFO: PersistentVolumeClaim test.csi.azure.comnmnbt found but phase is Pending instead of Bound. May 7 07:38:52.123: INFO: PersistentVolumeClaim test.csi.azure.comnmnbt found and phase=Bound (2.073542902s) [1mSTEP[0m: [init] starting a pod to use the claim [1mSTEP[0m: [init] check pod success May 7 07:38:52.256: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-2sqpb" in namespace "snapshotting-6746" to be "Succeeded or Failed" May 7 07:38:52.289: INFO: Pod "pvc-snapshottable-tester-2sqpb": Phase="Pending", Reason="", readiness=false. Elapsed: 33.093749ms May 7 07:38:54.326: INFO: Pod "pvc-snapshottable-tester-2sqpb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.069341535s [1mSTEP[0m: Saw pod success May 7 07:38:54.326: INFO: Pod "pvc-snapshottable-tester-2sqpb" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim May 7 07:38:54.360: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comnmnbt] to have phase Bound May 7 07:38:54.394: INFO: PersistentVolumeClaim test.csi.azure.comnmnbt found and phase=Bound (34.328672ms) [1mSTEP[0m: [init] checking the PV [1mSTEP[0m: [init] deleting the pod May 7 07:38:54.494: INFO: Pod pvc-snapshottable-tester-2sqpb has the following logs: ... skipping 46 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 113 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 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 166 lines ... May 7 07:38:50.924: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:38:50.960: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.combr7pq] to have phase Bound May 7 07:38:50.993: INFO: PersistentVolumeClaim test.csi.azure.combr7pq found but phase is Pending instead of Bound. May 7 07:38:53.027: INFO: PersistentVolumeClaim test.csi.azure.combr7pq found and phase=Bound (2.067639333s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-8zbk [1mSTEP[0m: Creating a pod to test subpath May 7 07:38:53.149: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-8zbk" in namespace "provisioning-7863" to be "Succeeded or Failed" May 7 07:38:53.193: INFO: Pod "pod-subpath-test-dynamicpv-8zbk": Phase="Pending", Reason="", readiness=false. Elapsed: 43.576716ms May 7 07:38:55.227: INFO: Pod "pod-subpath-test-dynamicpv-8zbk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.077677737s May 7 07:38:57.262: INFO: Pod "pod-subpath-test-dynamicpv-8zbk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.112455084s May 7 07:38:59.297: INFO: Pod "pod-subpath-test-dynamicpv-8zbk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.147322883s [1mSTEP[0m: Saw pod success May 7 07:38:59.297: INFO: Pod "pod-subpath-test-dynamicpv-8zbk" satisfied condition "Succeeded or Failed" May 7 07:38:59.331: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000001 pod pod-subpath-test-dynamicpv-8zbk container test-container-volume-dynamicpv-8zbk: <nil> [1mSTEP[0m: delete the pod May 7 07:38:59.407: INFO: Waiting for pod pod-subpath-test-dynamicpv-8zbk to disappear May 7 07:38:59.441: INFO: Pod pod-subpath-test-dynamicpv-8zbk no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-8zbk May 7 07:38:59.441: INFO: Deleting pod "pod-subpath-test-dynamicpv-8zbk" in namespace "provisioning-7863" ... 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":36,"completed":2,"skipped":80,"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[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[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 (ext4)] volumes test/e2e/storage/framework/testsuite.go:51 May 7 07:39:04.883: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 46 lines ... May 7 07:38:27.348: INFO: PersistentVolumeClaim test.csi.azure.comj96cs found but phase is Pending instead of Bound. May 7 07:38:29.383: INFO: PersistentVolumeClaim test.csi.azure.comj96cs found but phase is Pending instead of Bound. May 7 07:38:31.418: INFO: PersistentVolumeClaim test.csi.azure.comj96cs found but phase is Pending instead of Bound. May 7 07:38:33.456: INFO: PersistentVolumeClaim test.csi.azure.comj96cs found and phase=Bound (20.385414647s) [1mSTEP[0m: Expanding non-expandable pvc May 7 07:38:33.532: INFO: currentPvcSize {{5368709120 0} {<nil>} 5Gi BinarySI}, newSize {{6442450944 0} {<nil>} BinarySI} May 7 07:38:33.608: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:35.678: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:37.687: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:39.677: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:41.676: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:43.681: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:45.677: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:47.680: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:49.677: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:51.678: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:53.691: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:55.696: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:57.677: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:38:59.676: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:39:01.676: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:39:03.678: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize May 7 07:39:03.748: INFO: Error updating pvc test.csi.azure.comj96cs: persistentvolumeclaims "test.csi.azure.comj96cs" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize [1mSTEP[0m: Deleting pvc May 7 07:39:03.748: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comj96cs" May 7 07:39:03.786: INFO: Waiting up to 5m0s for PersistentVolume pvc-29acbe9b-7792-4270-923f-a81c9dd177d6 to get deleted May 7 07:39:03.819: INFO: PersistentVolume pvc-29acbe9b-7792-4270-923f-a81c9dd177d6 found and phase=Released (33.02326ms) May 7 07:39:08.855: INFO: PersistentVolume pvc-29acbe9b-7792-4270-923f-a81c9dd177d6 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":35,"completed":1,"skipped":488,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath test/e2e/storage/framework/testsuite.go:51 May 7 07:39:09.080: INFO: Driver test.csi.azure.com doesn't support ntfs -- 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: 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 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 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":37,"completed":2,"skipped":506,"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[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[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)] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:39:09.439: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 33 lines ... May 7 07:39:00.367: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:39:00.403: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comgmv9b] to have phase Bound May 7 07:39:00.436: INFO: PersistentVolumeClaim test.csi.azure.comgmv9b found but phase is Pending instead of Bound. May 7 07:39:02.471: INFO: PersistentVolumeClaim test.csi.azure.comgmv9b found and phase=Bound (2.068304755s) [1mSTEP[0m: [init] starting a pod to use the claim [1mSTEP[0m: [init] check pod success May 7 07:39:02.604: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-glh2w" in namespace "snapshotting-7449" to be "Succeeded or Failed" May 7 07:39:02.637: INFO: Pod "pvc-snapshottable-tester-glh2w": Phase="Pending", Reason="", readiness=false. Elapsed: 33.374968ms May 7 07:39:04.672: INFO: Pod "pvc-snapshottable-tester-glh2w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.068570986s May 7 07:39:06.707: INFO: Pod "pvc-snapshottable-tester-glh2w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.103203426s [1mSTEP[0m: Saw pod success May 7 07:39:06.707: INFO: Pod "pvc-snapshottable-tester-glh2w" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim May 7 07:39:06.740: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comgmv9b] to have phase Bound May 7 07:39:06.773: INFO: PersistentVolumeClaim test.csi.azure.comgmv9b found and phase=Bound (32.83332ms) [1mSTEP[0m: [init] checking the PV [1mSTEP[0m: [init] deleting the pod May 7 07:39:06.877: INFO: Pod pvc-snapshottable-tester-glh2w has the following logs: ... skipping 195 lines ... May 7 07:38:59.126: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:38:59.163: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com4nf84] to have phase Bound May 7 07:38:59.196: INFO: PersistentVolumeClaim test.csi.azure.com4nf84 found but phase is Pending instead of Bound. May 7 07:39:01.231: INFO: PersistentVolumeClaim test.csi.azure.com4nf84 found and phase=Bound (2.068024282s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-thbb [1mSTEP[0m: Creating a pod to test subpath May 7 07:39:01.339: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-thbb" in namespace "provisioning-2916" to be "Succeeded or Failed" May 7 07:39:01.372: INFO: Pod "pod-subpath-test-dynamicpv-thbb": Phase="Pending", Reason="", readiness=false. Elapsed: 33.112297ms May 7 07:39:03.406: INFO: Pod "pod-subpath-test-dynamicpv-thbb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.066517434s May 7 07:39:05.441: INFO: Pod "pod-subpath-test-dynamicpv-thbb": Phase="Running", Reason="", readiness=false. Elapsed: 4.102358446s May 7 07:39:07.479: INFO: Pod "pod-subpath-test-dynamicpv-thbb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.139970455s [1mSTEP[0m: Saw pod success May 7 07:39:07.479: INFO: Pod "pod-subpath-test-dynamicpv-thbb" satisfied condition "Succeeded or Failed" May 7 07:39:07.512: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000001 pod pod-subpath-test-dynamicpv-thbb container test-container-volume-dynamicpv-thbb: <nil> [1mSTEP[0m: delete the pod May 7 07:39:07.588: INFO: Waiting for pod pod-subpath-test-dynamicpv-thbb to disappear May 7 07:39:07.621: INFO: Pod pod-subpath-test-dynamicpv-thbb no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-thbb May 7 07:39:07.621: INFO: Deleting pod "pod-subpath-test-dynamicpv-thbb" in namespace "provisioning-2916" ... 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":34,"completed":2,"skipped":281,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning test/e2e/storage/framework/testsuite.go:51 May 7 07:39:12.961: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping ... skipping 64 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":35,"completed":2,"skipped":617,"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: Inline-volume (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 7 07:39:23.297: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 27 lines ... [It] should check snapshot fields, check restore correctly works, check deletion (ephemeral) test/e2e/storage/testsuites/snapshottable.go:177 May 7 07:39:23.601: INFO: Creating resource for dynamic PV May 7 07:39:23.601: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass snapshotting-2961-e2e-sclx5jg [1mSTEP[0m: [init] starting a pod to use the claim May 7 07:39:23.677: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-tnbvq" in namespace "snapshotting-2961" to be "Succeeded or Failed" May 7 07:39:23.721: INFO: Pod "pvc-snapshottable-tester-tnbvq": Phase="Pending", Reason="", readiness=false. Elapsed: 44.441674ms May 7 07:39:25.756: INFO: Pod "pvc-snapshottable-tester-tnbvq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.078885086s May 7 07:39:27.791: INFO: Pod "pvc-snapshottable-tester-tnbvq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.114457982s May 7 07:39:29.826: INFO: Pod "pvc-snapshottable-tester-tnbvq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.1492193s [1mSTEP[0m: Saw pod success May 7 07:39:29.826: INFO: Pod "pvc-snapshottable-tester-tnbvq" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim [1mSTEP[0m: creating a SnapshotClass May 7 07:39:29.860: INFO: Driver "test.csi.azure.com" does not support snapshotting - skipping May 7 07:39:29.861: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-snapshottable-tester-tnbvq-my-volume] to have phase Bound May 7 07:39:29.896: INFO: PersistentVolumeClaim pvc-snapshottable-tester-tnbvq-my-volume found and phase=Bound (34.448066ms) [1mSTEP[0m: [init] checking the PV ... skipping 211 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":37,"completed":3,"skipped":663,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)] provisioning test/e2e/storage/framework/testsuite.go:51 May 7 07:39:42.985: INFO: Driver test.csi.azure.com doesn't support Block -- skipping ... skipping 257 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 [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 7 07:39:30.215: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.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 7 07:39:30.460: INFO: Creating resource for dynamic PV May 7 07:39:30.460: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass provisioning-2077-e2e-scjtbxr [1mSTEP[0m: creating a claim May 7 07:39:30.494: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:39:30.531: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comj9stp] to have phase Bound May 7 07:39:30.565: INFO: PersistentVolumeClaim test.csi.azure.comj9stp found but phase is Pending instead of Bound. May 7 07:39:32.599: INFO: PersistentVolumeClaim test.csi.azure.comj9stp found and phase=Bound (2.06792975s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-j4kc [1mSTEP[0m: Checking for subpath error in container status May 7 07:39:36.770: INFO: Deleting pod "pod-subpath-test-dynamicpv-j4kc" in namespace "provisioning-2077" May 7 07:39:36.805: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-j4kc" to be fully deleted [1mSTEP[0m: Deleting pod May 7 07:39:38.873: INFO: Deleting pod "pod-subpath-test-dynamicpv-j4kc" in namespace "provisioning-2077" [1mSTEP[0m: Deleting pvc May 7 07:39:38.907: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comj9stp" ... skipping 9 lines ... [32m• [SLOW TEST:13.932 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":35,"completed":3,"skipped":785,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:39:44.165: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping ... skipping 87 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 43 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":36,"completed":3,"skipped":244,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:39:44.380: INFO: Driver test.csi.azure.com doesn't support ntfs -- skipping ... skipping 261 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":34,"completed":3,"skipped":395,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Inline-volume (xfs)][Slow] volumes test/e2e/storage/framework/testsuite.go:51 May 7 07:39:48.876: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 75 lines ... May 7 07:39:44.681: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:39:44.716: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjllwp] to have phase Bound May 7 07:39:44.750: INFO: PersistentVolumeClaim test.csi.azure.comjllwp found but phase is Pending instead of Bound. May 7 07:39:46.783: INFO: PersistentVolumeClaim test.csi.azure.comjllwp found and phase=Bound (2.066790344s) [1mSTEP[0m: [init] starting a pod to use the claim [1mSTEP[0m: [init] check pod success May 7 07:39:46.918: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-l4g62" in namespace "snapshotting-1793" to be "Succeeded or Failed" May 7 07:39:46.951: INFO: Pod "pvc-snapshottable-tester-l4g62": Phase="Pending", Reason="", readiness=false. Elapsed: 33.549611ms May 7 07:39:48.991: INFO: Pod "pvc-snapshottable-tester-l4g62": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.073382903s [1mSTEP[0m: Saw pod success May 7 07:39:48.991: INFO: Pod "pvc-snapshottable-tester-l4g62" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim May 7 07:39:49.026: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjllwp] to have phase Bound May 7 07:39:49.059: INFO: PersistentVolumeClaim test.csi.azure.comjllwp found and phase=Bound (32.943016ms) [1mSTEP[0m: [init] checking the PV [1mSTEP[0m: [init] deleting the pod May 7 07:39:49.165: INFO: Pod pvc-snapshottable-tester-l4g62 has the following logs: ... 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: 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 42 lines ... May 7 07:39:43.835: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:39:43.871: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8dh9w] to have phase Bound May 7 07:39:43.904: INFO: PersistentVolumeClaim test.csi.azure.com8dh9w found but phase is Pending instead of Bound. May 7 07:39:45.939: INFO: PersistentVolumeClaim test.csi.azure.com8dh9w found and phase=Bound (2.068176197s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-p5qx [1mSTEP[0m: Creating a pod to test subpath May 7 07:39:46.047: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-p5qx" in namespace "provisioning-2915" to be "Succeeded or Failed" May 7 07:39:46.081: INFO: Pod "pod-subpath-test-dynamicpv-p5qx": Phase="Pending", Reason="", readiness=false. Elapsed: 33.530955ms May 7 07:39:48.120: INFO: Pod "pod-subpath-test-dynamicpv-p5qx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.073489548s May 7 07:39:50.155: INFO: Pod "pod-subpath-test-dynamicpv-p5qx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.107830752s [1mSTEP[0m: Saw pod success May 7 07:39:50.155: INFO: Pod "pod-subpath-test-dynamicpv-p5qx" satisfied condition "Succeeded or Failed" May 7 07:39:50.188: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-p5qx container test-container-subpath-dynamicpv-p5qx: <nil> [1mSTEP[0m: delete the pod May 7 07:39:50.265: INFO: Waiting for pod pod-subpath-test-dynamicpv-p5qx to disappear May 7 07:39:50.299: INFO: Pod pod-subpath-test-dynamicpv-p5qx no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-p5qx May 7 07:39:50.299: INFO: Deleting pod "pod-subpath-test-dynamicpv-p5qx" in namespace "provisioning-2915" ... 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":37,"completed":4,"skipped":1024,"failed":0} [36mS[0m[36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits ... skipping 57 lines ... May 7 07:39:49.213: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:39:49.249: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.commzkjv] to have phase Bound May 7 07:39:49.283: INFO: PersistentVolumeClaim test.csi.azure.commzkjv found but phase is Pending instead of Bound. May 7 07:39:51.317: INFO: PersistentVolumeClaim test.csi.azure.commzkjv found and phase=Bound (2.06831498s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-z8pt [1mSTEP[0m: Creating a pod to test subpath May 7 07:39:51.419: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-z8pt" in namespace "provisioning-7990" to be "Succeeded or Failed" May 7 07:39:51.453: INFO: Pod "pod-subpath-test-dynamicpv-z8pt": Phase="Pending", Reason="", readiness=false. Elapsed: 33.64303ms May 7 07:39:53.487: INFO: Pod "pod-subpath-test-dynamicpv-z8pt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.067640941s May 7 07:39:55.520: INFO: Pod "pod-subpath-test-dynamicpv-z8pt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.101547344s [1mSTEP[0m: Saw pod success May 7 07:39:55.520: INFO: Pod "pod-subpath-test-dynamicpv-z8pt" satisfied condition "Succeeded or Failed" May 7 07:39:55.554: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-z8pt container test-container-subpath-dynamicpv-z8pt: <nil> [1mSTEP[0m: delete the pod May 7 07:39:55.630: INFO: Waiting for pod pod-subpath-test-dynamicpv-z8pt to disappear May 7 07:39:55.665: INFO: Pod pod-subpath-test-dynamicpv-z8pt no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-z8pt May 7 07:39:55.665: INFO: Deleting pod "pod-subpath-test-dynamicpv-z8pt" in namespace "provisioning-7990" ... 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":34,"completed":4,"skipped":485,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral test/e2e/storage/framework/testsuite.go:51 May 7 07:40:01.046: INFO: Driver "test.csi.azure.com" does not support volume type "CSIInlineVolume" - skipping ... skipping 250 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":35,"completed":4,"skipped":1002,"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 [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (filesystem volmode)] volumeMode[0m [1mshould not mount / map unused volumes in a pod [LinuxOnly][0m [37mtest/e2e/storage/testsuites/volumemode.go:354[0m ... skipping 55 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":36,"completed":4,"skipped":328,"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: Generic Ephemeral-volume (default fs)] volumeLimits test/e2e/storage/framework/testsuite.go:51 [BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits ... skipping 100 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":31,"completed":1,"skipped":56,"failed":0} [BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology test/e2e/storage/framework/testsuite.go:51 May 7 07:40:23.504: INFO: Driver "test.csi.azure.com" does not support topology - skipping [AfterEach] [Testpattern: Dynamic PV (delayed binding)] topology 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 (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 65 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":34,"completed":5,"skipped":763,"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: Dynamic PV (block volmode)] volumes test/e2e/storage/framework/testsuite.go:51 May 7 07:40:43.959: INFO: Driver "test.csi.azure.com" does not provide raw block - skipping ... skipping 59 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":36,"completed":5,"skipped":365,"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 [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Dynamic PV (default fs)] subPath[0m [1mshould support file as subpath [LinuxOnly][0m [37mtest/e2e/storage/testsuites/subpath.go:232[0m ... skipping 16 lines ... May 7 07:40:23.826: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:40:23.862: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comrmwbp] to have phase Bound May 7 07:40:23.896: INFO: PersistentVolumeClaim test.csi.azure.comrmwbp found but phase is Pending instead of Bound. May 7 07:40:25.933: INFO: PersistentVolumeClaim test.csi.azure.comrmwbp found and phase=Bound (2.070929637s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-mwvs [1mSTEP[0m: Creating a pod to test atomic-volume-subpath May 7 07:40:26.038: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-mwvs" in namespace "provisioning-1225" to be "Succeeded or Failed" May 7 07:40:26.075: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Pending", Reason="", readiness=false. Elapsed: 36.752659ms May 7 07:40:28.111: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Pending", Reason="", readiness=false. Elapsed: 2.072701089s May 7 07:40:30.146: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 4.107925134s May 7 07:40:32.181: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 6.143548139s May 7 07:40:34.217: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 8.178915754s May 7 07:40:36.252: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 10.21390381s ... skipping 2 lines ... May 7 07:40:42.361: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 16.323080768s May 7 07:40:44.396: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 18.358558151s May 7 07:40:46.433: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 20.394629404s May 7 07:40:48.467: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Running", Reason="", readiness=true. Elapsed: 22.429012576s May 7 07:40:50.505: INFO: Pod "pod-subpath-test-dynamicpv-mwvs": Phase="Succeeded", Reason="", readiness=false. Elapsed: 24.467061415s [1mSTEP[0m: Saw pod success May 7 07:40:50.505: INFO: Pod "pod-subpath-test-dynamicpv-mwvs" satisfied condition "Succeeded or Failed" May 7 07:40:50.539: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-mwvs container test-container-subpath-dynamicpv-mwvs: <nil> [1mSTEP[0m: delete the pod May 7 07:40:50.617: INFO: Waiting for pod pod-subpath-test-dynamicpv-mwvs to disappear May 7 07:40:50.651: INFO: Pod pod-subpath-test-dynamicpv-mwvs no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-mwvs May 7 07:40:50.651: INFO: Deleting pod "pod-subpath-test-dynamicpv-mwvs" in namespace "provisioning-1225" ... 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":31,"completed":2,"skipped":114,"failed":0} [BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:40:55.961: INFO: Driver test.csi.azure.com doesn't support Block -- skipping [AfterEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] test/e2e/framework/framework.go:188 ... skipping 128 lines ... May 7 07:40:57.315: INFO: ExecWithOptions: execute(POST https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com/api/v1/namespaces/volume-5376/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 7 07:40:57.632: INFO: ExecWithOptions {Command:[/bin/sh -c test -b /opt/0] Namespace:volume-5376 PodName:external-client ContainerName:external-client Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false Quiet:false} May 7 07:40:57.632: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json May 7 07:40:57.633: INFO: ExecWithOptions: Clientset creation May 7 07:40:57.633: INFO: ExecWithOptions: execute(POST https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com/api/v1/namespaces/volume-5376/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 7 07:40:57.979: 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-5376 May 7 07:40:58.013: INFO: Waiting for pod external-client to disappear May 7 07:40:58.047: INFO: Pod external-client still exists May 7 07:41:00.047: INFO: Waiting for pod external-client to disappear May 7 07:41:00.081: INFO: Pod external-client still exists May 7 07:41:02.047: 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":34,"completed":6,"skipped":782,"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 (ntfs)][Feature:Windows] volumes test/e2e/storage/framework/testsuite.go:51 May 7 07:41:07.343: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 58 lines ... May 7 07:40:56.266: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:40:56.303: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comjmhsl] to have phase Bound May 7 07:40:56.342: INFO: PersistentVolumeClaim test.csi.azure.comjmhsl found but phase is Pending instead of Bound. May 7 07:40:58.378: INFO: PersistentVolumeClaim test.csi.azure.comjmhsl found and phase=Bound (2.0750804s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-wchd [1mSTEP[0m: Creating a pod to test subpath May 7 07:40:58.482: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-wchd" in namespace "provisioning-3379" to be "Succeeded or Failed" May 7 07:40:58.517: INFO: Pod "pod-subpath-test-dynamicpv-wchd": Phase="Pending", Reason="", readiness=false. Elapsed: 34.431035ms May 7 07:41:00.552: INFO: Pod "pod-subpath-test-dynamicpv-wchd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069500204s May 7 07:41:02.587: INFO: Pod "pod-subpath-test-dynamicpv-wchd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.104392662s [1mSTEP[0m: Saw pod success May 7 07:41:02.587: INFO: Pod "pod-subpath-test-dynamicpv-wchd" satisfied condition "Succeeded or Failed" May 7 07:41:02.620: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-wchd container test-container-subpath-dynamicpv-wchd: <nil> [1mSTEP[0m: delete the pod May 7 07:41:02.697: INFO: Waiting for pod pod-subpath-test-dynamicpv-wchd to disappear May 7 07:41:02.732: INFO: Pod pod-subpath-test-dynamicpv-wchd no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-wchd May 7 07:41:02.732: INFO: Deleting pod "pod-subpath-test-dynamicpv-wchd" in namespace "provisioning-3379" ... 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":31,"completed":3,"skipped":144,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 7 07:41:08.058: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 34 lines ... test/e2e/storage/testsuites/volumes.go:114 [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 [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 7 07:41:07.414: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.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 7 07:41:07.651: INFO: Creating resource for dynamic PV May 7 07:41:07.651: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass provisioning-18-e2e-sc4dln8 [1mSTEP[0m: creating a claim May 7 07:41:07.686: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:41:07.722: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com649pm] to have phase Bound May 7 07:41:07.755: INFO: PersistentVolumeClaim test.csi.azure.com649pm found but phase is Pending instead of Bound. May 7 07:41:09.789: INFO: PersistentVolumeClaim test.csi.azure.com649pm found and phase=Bound (2.06726722s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-sm7j [1mSTEP[0m: Checking for subpath error in container status May 7 07:41:13.958: INFO: Deleting pod "pod-subpath-test-dynamicpv-sm7j" in namespace "provisioning-18" May 7 07:41:13.995: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-sm7j" to be fully deleted [1mSTEP[0m: Deleting pod May 7 07:41:16.064: INFO: Deleting pod "pod-subpath-test-dynamicpv-sm7j" in namespace "provisioning-18" [1mSTEP[0m: Deleting pvc May 7 07:41:16.098: INFO: Deleting PersistentVolumeClaim "test.csi.azure.com649pm" ... skipping 9 lines ... [32m• [SLOW TEST:13.919 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":34,"completed":7,"skipped":878,"failed":0} [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 7 07:41:21.342: 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 (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 182 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":31,"completed":4,"skipped":227,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand test/e2e/storage/framework/testsuite.go:51 May 7 07:41:30.669: INFO: Driver "test.csi.azure.com" does not support block volume mode - skipping ... skipping 111 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":36,"completed":6,"skipped":475,"failed":0} [36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 7 07:41:39.097: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 149 lines ... May 7 07:41:39.843: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:41:39.880: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8pxvs] to have phase Bound May 7 07:41:39.913: INFO: PersistentVolumeClaim test.csi.azure.com8pxvs found but phase is Pending instead of Bound. May 7 07:41:41.948: INFO: PersistentVolumeClaim test.csi.azure.com8pxvs found and phase=Bound (2.067533088s) [1mSTEP[0m: [init] starting a pod to use the claim [1mSTEP[0m: [init] check pod success May 7 07:41:42.086: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-tt7qt" in namespace "snapshotting-2368" to be "Succeeded or Failed" May 7 07:41:42.119: INFO: Pod "pvc-snapshottable-tester-tt7qt": Phase="Pending", Reason="", readiness=false. Elapsed: 33.43518ms May 7 07:41:44.153: INFO: Pod "pvc-snapshottable-tester-tt7qt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.067260769s [1mSTEP[0m: Saw pod success May 7 07:41:44.153: INFO: Pod "pvc-snapshottable-tester-tt7qt" satisfied condition "Succeeded or Failed" [1mSTEP[0m: [init] checking the claim May 7 07:41:44.186: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.com8pxvs] to have phase Bound May 7 07:41:44.223: INFO: PersistentVolumeClaim test.csi.azure.com8pxvs found and phase=Bound (36.862438ms) [1mSTEP[0m: [init] checking the PV [1mSTEP[0m: [init] deleting the pod May 7 07:41:44.329: INFO: Pod pvc-snapshottable-tester-tt7qt has the following logs: ... skipping 255 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":31,"completed":5,"skipped":365,"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 [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] volume-expand test/e2e/storage/framework/testsuite.go:51 May 7 07:41:57.101: INFO: Driver test.csi.azure.com doesn't support ntfs -- 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 [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 7 07:41:50.068: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.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 7 07:41:50.299: INFO: Creating resource for dynamic PV May 7 07:41:50.299: INFO: Using claimSize:5Gi, test suite supported size:{ 1Mi}, driver(test.csi.azure.com) supported size:{ 1Mi} [1mSTEP[0m: creating a StorageClass provisioning-2646-e2e-scl88nv [1mSTEP[0m: creating a claim May 7 07:41:50.335: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:41:50.372: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comnq8s4] to have phase Bound May 7 07:41:50.406: INFO: PersistentVolumeClaim test.csi.azure.comnq8s4 found but phase is Pending instead of Bound. May 7 07:41:52.440: INFO: PersistentVolumeClaim test.csi.azure.comnq8s4 found and phase=Bound (2.067525261s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-mr8l [1mSTEP[0m: Checking for subpath error in container status May 7 07:41:56.611: INFO: Deleting pod "pod-subpath-test-dynamicpv-mr8l" in namespace "provisioning-2646" May 7 07:41:56.648: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-mr8l" to be fully deleted [1mSTEP[0m: Deleting pod May 7 07:41:58.716: INFO: Deleting pod "pod-subpath-test-dynamicpv-mr8l" in namespace "provisioning-2646" [1mSTEP[0m: Deleting pvc May 7 07:41:58.749: INFO: Deleting PersistentVolumeClaim "test.csi.azure.comnq8s4" ... skipping 9 lines ... [32m• [SLOW TEST:13.947 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":36,"completed":7,"skipped":745,"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 [BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:42:04.085: INFO: Driver test.csi.azure.com doesn't support xfs -- skipping ... skipping 77 lines ... [1mSTEP[0m: creating claim=&PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-4351 0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{5368709120 0} {<nil>} 5Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-4351-e2e-scddd86,VolumeMode:nil,DataSource:nil,DataSourceRef:&TypedLocalObjectReference{APIGroup:*hello.example.com,Kind:Hello,Name:example-hello,},},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},AllocatedResources:ResourceList{},ResizeStatus:nil,},} [1mSTEP[0m: checking whether the created volume has the pre-populated data [1mSTEP[0m: starting external-client [1mSTEP[0m: Checking that text file contents are perfect. May 7 07:42:04.411: INFO: Running '/usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt' May 7 07:42:05.082: INFO: rc: 1 May 7 07:42:05.082: FAIL: Unexpected error: <exec.CodeExitError>: { Err: { s: "error running /usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt:\nCommand stdout:\n\nstderr:\ncat: can't open '/opt/0/example-provisioning-4351.txt': No such file or directory\ncommand terminated with exit code 1\n\nerror:\nexit status 1", }, Code: 1, } error running /usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt: Command stdout: stderr: cat: can't open '/opt/0/example-provisioning-4351.txt': No such file or directory command terminated with exit code 1 error: exit status 1 occurred Full Stack Trace k8s.io/kubernetes/test/e2e/framework.KubectlBuilder.ExecOrDie({0xc001f39b80?, 0x0?}, {0xc0034f8d50, 0x11}) test/e2e/framework/util.go:630 +0x1b4 ... skipping 172 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] provisioning [90mtest/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould provision storage with any volume data source [Serial] [Measurement][0m [90mtest/e2e/storage/testsuites/provisioning.go:246[0m [91mMay 7 07:42:05.082: Unexpected error: <exec.CodeExitError>: { Err: { s: "error running /usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt:\nCommand stdout:\n\nstderr:\ncat: can't open '/opt/0/example-provisioning-4351.txt': No such file or directory\ncommand terminated with exit code 1\n\nerror:\nexit status 1", }, Code: 1, } error running /usr/local/bin/kubectl --server=https://kubetest-btcc2dv0.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.json --namespace=provisioning-4351 exec external-client --namespace=provisioning-4351 -- cat /opt/0/example-provisioning-4351.txt: Command stdout: stderr: cat: can't open '/opt/0/example-provisioning-4351.txt': No such file or directory command terminated with exit code 1 error: exit status 1 occurred[0m test/e2e/framework/util.go:630 [90m------------------------------[0m {"msg":"FAILED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should provision storage with any volume data source [Serial]","total":31,"completed":5,"skipped":390,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should provision storage with any volume data source [Serial]"]} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[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 7 07:42:23.034: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - 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: 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 26 lines ... test/e2e/framework/framework.go:187 [1mSTEP[0m: Creating a kubernetes client May 7 07:42:23.156: INFO: >>> kubeConfig: /root/tmp2708233612/kubeconfig/kubeconfig.canadacentral.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 7 07:42:23.391: 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 7 07:42:23.392: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready [1mSTEP[0m: Destroying namespace "volumemode-6924" for this suite. [36m[1mS [SKIPPING] [0.305 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 151 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 148 lines ... May 7 07:38:12.035: INFO: In creating storage class object and pvc objects for driver - sc: &StorageClass{ObjectMeta:{provisioning-4366-e2e-scl7zmc 0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},Provisioner:test.csi.azure.com,Parameters:map[string]string{skuName: Premium_LRS,},ReclaimPolicy:*Delete,MountOptions:[dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30],AllowVolumeExpansion:*true,VolumeBindingMode:*Immediate,AllowedTopologies:[]TopologySelectorTerm{},}, pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-4366 0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{5368709120 0} {<nil>} 5Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-4366-e2e-scl7zmc,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},AllocatedResources:ResourceList{},ResizeStatus:nil,},}, src-pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-4366 0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{5368709120 0} {<nil>} 5Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-4366-e2e-scl7zmc,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},AllocatedResources:ResourceList{},ResizeStatus:nil,},} [1mSTEP[0m: Creating a StorageClass [1mSTEP[0m: creating claim=&PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-4366 0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{5368709120 0} {<nil>} 5Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-4366-e2e-scl7zmc,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},AllocatedResources:ResourceList{},ResizeStatus:nil,},} [1mSTEP[0m: Created Pod provisioning-4366/pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109 on node k8s-agentpool1-41236054-vmss000001 [1mSTEP[0m: Creating a PVC followed by a pre-bound PV May 7 07:38:44.498: INFO: Created PVC provisioning-4366/pvc-t955f and PV pv-czp59 in namespace %!s(MISSING) May 7 07:43:44.637: FAIL: Unexpected error: <*errors.errorString | 0xc0037053a0>: { s: "pod \"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced\" is not Running: timed out waiting for the condition", } pod "pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced" is not Running: timed out waiting for the condition occurred ... skipping 34 lines ... May 7 07:43:46.877: INFO: At 2022-05-07 07:38:32 +0000 UTC - event for pvc-mbdlx: {test.csi.azure.com_k8s-agentpool1-41236054-vmss000000_966cad7a-184c-4ec9-a4fa-062f5006ba8f } ProvisioningSucceeded: Successfully provisioned volume pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc May 7 07:43:46.877: INFO: At 2022-05-07 07:38:41 +0000 UTC - event for pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109: {kubelet k8s-agentpool1-41236054-vmss000001} Created: Created container write-pod May 7 07:43:46.877: INFO: At 2022-05-07 07:38:41 +0000 UTC - event for pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109: {kubelet k8s-agentpool1-41236054-vmss000001} Pulled: Successfully pulled image "k8s.gcr.io/e2e-test-images/busybox:1.29-2" in 263.915057ms May 7 07:43:46.877: INFO: At 2022-05-07 07:38:41 +0000 UTC - event for pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109: {kubelet k8s-agentpool1-41236054-vmss000001} Pulling: Pulling image "k8s.gcr.io/e2e-test-images/busybox:1.29-2" May 7 07:43:46.877: INFO: At 2022-05-07 07:38:42 +0000 UTC - event for pod-b1364b9f-ea72-4d0c-a7d4-e8668bb4e109: {kubelet k8s-agentpool1-41236054-vmss000001} Started: Started container write-pod May 7 07:43:46.877: INFO: At 2022-05-07 07:38:44 +0000 UTC - event for pvc-t955f: {persistentvolume-controller } ProvisioningFailed: storageclass.storage.k8s.io "provisioning-4366" not found May 7 07:43:46.877: INFO: At 2022-05-07 07:39:01 +0000 UTC - event for pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced: {kubelet k8s-agentpool1-41236054-vmss000001} FailedMount: MountVolume.SetUp failed for volume "pv-czp59" : rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. May 7 07:43:46.877: INFO: At 2022-05-07 07:41:04 +0000 UTC - event for pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced: {kubelet k8s-agentpool1-41236054-vmss000001} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[kube-api-access-wlxgc volume1]: timed out waiting for the condition May 7 07:43:46.877: INFO: At 2022-05-07 07:43:21 +0000 UTC - event for pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced: {kubelet k8s-agentpool1-41236054-vmss000001} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 kube-api-access-wlxgc]: timed out waiting for the condition ... skipping 103 lines ... [90mtest/e2e/storage/external/external.go:174[0m [Testpattern: Dynamic PV (default fs)] provisioning [90mtest/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould mount multiple PV pointing to the same storage on the same node [Measurement][0m [90mtest/e2e/storage/testsuites/provisioning.go:518[0m [91mMay 7 07:43:44.637: Unexpected error: <*errors.errorString | 0xc0037053a0>: { s: "pod \"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced\" is not Running: timed out waiting for the condition", } pod "pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced" is not Running: timed out waiting for the condition occurred[0m test/e2e/storage/testsuites/provisioning.go:1205 [90m------------------------------[0m {"msg":"FAILED External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node","total":36,"completed":0,"skipped":2,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[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)] multiVolume [Slow] test/e2e/storage/framework/testsuite.go:51 May 7 07:43:47.906: INFO: Driver test.csi.azure.com doesn't support Block -- skipping ... skipping 66 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 59 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 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 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 146 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":36,"completed":8,"skipped":835,"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 [90m------------------------------[0m [0mExternal Storage [Driver: test.csi.azure.com][0m [90m[Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral[0m [1mshould create read-only inline ephemeral volume[0m [37mtest/e2e/storage/testsuites/ephemeral.go:175[0m ... skipping 38 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":36,"completed":9,"skipped":915,"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: Dynamic PV (default fs)] volume-stress test/e2e/storage/framework/testsuite.go:51 May 7 07:44:28.802: INFO: Driver test.csi.azure.com doesn't specify stress test options -- skipping ... skipping 58 lines ... May 7 07:44:29.091: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:44:29.127: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comrfpfm] to have phase Bound May 7 07:44:29.159: INFO: PersistentVolumeClaim test.csi.azure.comrfpfm found but phase is Pending instead of Bound. May 7 07:44:31.194: INFO: PersistentVolumeClaim test.csi.azure.comrfpfm found and phase=Bound (2.06705638s) [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-hvf2 [1mSTEP[0m: Creating a pod to test subpath May 7 07:44:31.304: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hvf2" in namespace "provisioning-2075" to be "Succeeded or Failed" May 7 07:44:31.338: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Pending", Reason="", readiness=false. Elapsed: 34.310558ms May 7 07:44:33.373: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069061589s May 7 07:44:35.421: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.116920915s [1mSTEP[0m: Saw pod success May 7 07:44:35.421: INFO: Pod "pod-subpath-test-dynamicpv-hvf2" satisfied condition "Succeeded or Failed" May 7 07:44:35.454: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-hvf2 container test-container-subpath-dynamicpv-hvf2: <nil> [1mSTEP[0m: delete the pod May 7 07:44:35.529: INFO: Waiting for pod pod-subpath-test-dynamicpv-hvf2 to disappear May 7 07:44:35.564: INFO: Pod pod-subpath-test-dynamicpv-hvf2 no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-hvf2 May 7 07:44:35.564: INFO: Deleting pod "pod-subpath-test-dynamicpv-hvf2" in namespace "provisioning-2075" [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-hvf2 [1mSTEP[0m: Creating a pod to test subpath May 7 07:44:35.636: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hvf2" in namespace "provisioning-2075" to be "Succeeded or Failed" May 7 07:44:35.669: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Pending", Reason="", readiness=false. Elapsed: 32.757178ms May 7 07:44:37.704: INFO: Pod "pod-subpath-test-dynamicpv-hvf2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.067428196s [1mSTEP[0m: Saw pod success May 7 07:44:37.704: INFO: Pod "pod-subpath-test-dynamicpv-hvf2" satisfied condition "Succeeded or Failed" May 7 07:44:37.739: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod pod-subpath-test-dynamicpv-hvf2 container test-container-subpath-dynamicpv-hvf2: <nil> [1mSTEP[0m: delete the pod May 7 07:44:37.814: INFO: Waiting for pod pod-subpath-test-dynamicpv-hvf2 to disappear May 7 07:44:37.847: INFO: Pod pod-subpath-test-dynamicpv-hvf2 no longer exists [1mSTEP[0m: Deleting pod pod-subpath-test-dynamicpv-hvf2 May 7 07:44:37.847: INFO: Deleting pod "pod-subpath-test-dynamicpv-hvf2" in namespace "provisioning-2075" ... 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":36,"completed":10,"skipped":988,"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: Pre-provisioned PV (default fs)] subPath test/e2e/storage/framework/testsuite.go:51 May 7 07:44:43.164: INFO: Driver "test.csi.azure.com" does not support volume type "PreprovisionedPV" - skipping ... skipping 80 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":36,"completed":1,"skipped":330,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]} [36mS[0m [90m------------------------------[0m [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volume-expand test/e2e/storage/framework/testsuite.go:51 May 7 07:45:04.714: INFO: Driver "test.csi.azure.com" does not support block volume mode - 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: 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 134 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":36,"completed":2,"skipped":474,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]} [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 (filesystem volmode)] multiVolume [Slow][0m [1mshould access to two volumes with the same volume mode and retain data across pod recreation on the same node[0m [37mtest/e2e/storage/testsuites/multivolume.go:138[0m ... skipping 178 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":36,"completed":3,"skipped":484,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[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-stress[Feature:VolumeSnapshotDataSource] test/e2e/storage/framework/testsuite.go:51 May 7 07:46:56.959: INFO: Driver test.csi.azure.com doesn't specify snapshot stress test options -- skipping ... skipping 212 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":36,"completed":4,"skipped":878,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[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)] volumes[0m [1mshould allow exec of files on the volume[0m [37mtest/e2e/storage/testsuites/volumes.go:198[0m ... skipping 16 lines ... May 7 07:47:45.885: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil May 7 07:47:45.920: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [test.csi.azure.comfmqzm] to have phase Bound May 7 07:47:45.953: INFO: PersistentVolumeClaim test.csi.azure.comfmqzm found but phase is Pending instead of Bound. May 7 07:47:47.988: INFO: PersistentVolumeClaim test.csi.azure.comfmqzm found and phase=Bound (2.067436695s) [1mSTEP[0m: Creating pod exec-volume-test-dynamicpv-zlm7 [1mSTEP[0m: Creating a pod to test exec-volume-test May 7 07:47:48.090: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-zlm7" in namespace "volume-7187" to be "Succeeded or Failed" May 7 07:47:48.124: INFO: Pod "exec-volume-test-dynamicpv-zlm7": Phase="Pending", Reason="", readiness=false. Elapsed: 33.539163ms May 7 07:47:50.158: INFO: Pod "exec-volume-test-dynamicpv-zlm7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.068226514s May 7 07:47:52.196: INFO: Pod "exec-volume-test-dynamicpv-zlm7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.106117654s [1mSTEP[0m: Saw pod success May 7 07:47:52.196: INFO: Pod "exec-volume-test-dynamicpv-zlm7" satisfied condition "Succeeded or Failed" May 7 07:47:52.230: INFO: Trying to get logs from node k8s-agentpool1-41236054-vmss000000 pod exec-volume-test-dynamicpv-zlm7 container exec-container-dynamicpv-zlm7: <nil> [1mSTEP[0m: delete the pod May 7 07:47:52.334: INFO: Waiting for pod exec-volume-test-dynamicpv-zlm7 to disappear May 7 07:47:52.367: INFO: Pod exec-volume-test-dynamicpv-zlm7 no longer exists [1mSTEP[0m: Deleting pod exec-volume-test-dynamicpv-zlm7 May 7 07:47:52.367: INFO: Deleting pod "exec-volume-test-dynamicpv-zlm7" in namespace "volume-7187" ... 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":36,"completed":5,"skipped":940,"failed":1,"failures":["External Storage [Driver: test.csi.azure.com] [Testpattern: Dynamic PV (default fs)] provisioning should mount multiple PV pointing to the same storage on the same node"]} [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m[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 7 07:47:57.658: INFO: Driver "test.csi.azure.com" does not support volume type "InlineVolume" - skipping ... skipping 135 lines ... May 7 07:47:58.081: INFO: Running AfterSuite actions on node 1 [91m[1mSummarizing 2 Failures:[0m [91m[1m[Fail] [0m[90mExternal Storage [Driver: test.csi.azure.com] [0m[0m[Testpattern: Dynamic PV (default fs)] provisioning [0m[91m[1m[Measurement] should provision storage with any volume data source [Serial] [0m [37mtest/e2e/framework/util.go:630[0m [91m[1m[Fail] [0m[90mExternal Storage [Driver: test.csi.azure.com] [0m[0m[Testpattern: Dynamic PV (default fs)] provisioning [0m[91m[1m[Measurement] should mount multiple PV pointing to the same storage on the same node [0m [37mtest/e2e/storage/testsuites/provisioning.go:1205[0m [1m[91mRan 39 of 7229 Specs in 588.298 seconds[0m [1m[91mFAIL![0m -- [32m[1m37 Passed[0m | [91m[1m2 Failed[0m | [33m[1m0 Pending[0m | [36m[1m7190 Skipped[0m Ginkgo ran 1 suite in 9m51.904278052s 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: I0507 07:38:03.239892 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test I0507 07:38:03.240256 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0507 07:38:03.267661 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 I0507 07:38:03.267683 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0507 07:38:03.267691 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0507 07:38:03.267716 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0507 07:38:03.268300 1 azure_auth.go:245] Using AzurePublicCloud environment I0507 07:38:03.268356 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0507 07:38:03.268397 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 163 lines ... I0507 07:38:45.259071 1 azure_storage.go:66] share pvc-86088b84-850c-4a64-a203-fc7867d8c16f deleted I0507 07:38:45.259149 1 controllerserver.go:584] azure file(pvc-86088b84-850c-4a64-a203-fc7867d8c16f) under rg(kubetest-btcc2dv0) account(fefc5f86712004996adfb9a) volume(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-86088b84-850c-4a64-a203-fc7867d8c16f###provisioning-9552) is deleted successfully I0507 07:38:45.259192 1 azure_metrics.go:112] "Observed Request Latency" latency_seconds=0.151856344 request="azurefile_csi_driver_controller_delete_volume" resource_group="kubetest-btcc2dv0" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="test.csi.azure.com" volumeid="kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-86088b84-850c-4a64-a203-fc7867d8c16f###provisioning-9552" result_code="succeeded" I0507 07:38:45.259212 1 utils.go:83] GRPC response: {} I0507 07:38:48.877116 1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume I0507 07:38:48.877159 1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9bd70868-2fc0-4384-896d-d8efbfc3f8c5","parameters":{"csi.storage.k8s.io/pv/name":"pvc-9bd70868-2fc0-4384-896d-d8efbfc3f8c5","csi.storage.k8s.io/pvc/name":"pvc-zdhsx","csi.storage.k8s.io/pvc/namespace":"volumemode-7633","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]} E0507 07:38:48.877368 1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes I0507 07:38:48.995661 1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume I0507 07:38:48.995695 1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9bd70868-2fc0-4384-896d-d8efbfc3f8c5","parameters":{"csi.storage.k8s.io/pv/name":"pvc-9bd70868-2fc0-4384-896d-d8efbfc3f8c5","csi.storage.k8s.io/pvc/name":"pvc-zdhsx","csi.storage.k8s.io/pvc/namespace":"volumemode-7633","skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Block":{}},"access_mode":{"mode":7}}]} E0507 07:38:48.996112 1 utils.go:81] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities not valid: driver does not support block volumes I0507 07:38:50.034926 1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume I0507 07:38:50.035068 1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5f5ce4a8-8dc4-4994-ac90-0620197677d1","parameters":{"csi.storage.k8s.io/pv/name":"pvc-5f5ce4a8-8dc4-4994-ac90-0620197677d1","csi.storage.k8s.io/pvc/name":"test.csi.azure.comnmnbt","csi.storage.k8s.io/pvc/namespace":"snapshotting-6746","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}}]} I0507 07:38:50.136892 1 controllerserver.go:433] begin to create file share(pvc-5f5ce4a8-8dc4-4994-ac90-0620197677d1) on account(fefc5f86712004996adfb9a) type(Premium_LRS) rg(kubetest-btcc2dv0) location() size(100) protocol(SMB) I0507 07:38:50.155200 1 utils.go:76] GRPC call: /csi.v1.Controller/CreateVolume I0507 07:38:50.155220 1 utils.go:77] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-8824185b-2425-41aa-b603-f71d3cd6a755","parameters":{"csi.storage.k8s.io/pv/name":"pvc-8824185b-2425-41aa-b603-f71d3cd6a755","csi.storage.k8s.io/pvc/name":"pvc-snapshottable-tester-d9bhj-my-volume","csi.storage.k8s.io/pvc/namespace":"snapshotting-1997","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}}]} I0507 07:38:50.239041 1 controllerserver.go:433] begin to create file share(pvc-8824185b-2425-41aa-b603-f71d3cd6a755) on account(fefc5f86712004996adfb9a) type(Premium_LRS) rg(kubetest-btcc2dv0) location() size(100) protocol(SMB) ... skipping 643 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0507 07:38:04.989044 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test I0507 07:38:04.989363 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0507 07:38:05.014886 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 I0507 07:38:05.014898 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0507 07:38:05.014905 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0507 07:38:05.014927 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0507 07:38:05.015497 1 azure_auth.go:245] Using AzurePublicCloud environment I0507 07:38:05.015528 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0507 07:38:05.015553 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 103 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0507 07:37:59.803237 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test I0507 07:37:59.803549 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0507 07:37:59.824132 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 I0507 07:37:59.824152 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0507 07:37:59.824160 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0507 07:37:59.824182 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0507 07:37:59.824781 1 azure_auth.go:245] Using AzurePublicCloud environment I0507 07:37:59.824818 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0507 07:37:59.824864 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 278 lines ... I0507 07:39:01.581045 1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac###provisioning-2916) context(map[csi.storage.k8s.io/pv/name:pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac csi.storage.k8s.io/pvc/name:test.csi.azure.com4nf84 csi.storage.k8s.io/pvc/namespace:provisioning-2916 secretnamespace:provisioning-2916 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup() I0507 07:39:01.581394 1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t cifs -o dir_mode=0777,file_mode=0777,mfsymlinks,cache=strict,nosharesock,actimeo=30,<masked> //fefc5f86712004996adfb9a.file.core.windows.net/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount) I0507 07:39:01.587353 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:39:01.587371 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:39:01.587767 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:39:01.587790 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:39:01.589367 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:39:01.589439 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:39:01.639938 1 nodeserver.go:313] volume(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac###provisioning-2916) mount //fefc5f86712004996adfb9a.file.core.windows.net/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount succeeded I0507 07:39:01.639977 1 utils.go:83] GRPC response: {} I0507 07:39:01.646059 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume ... skipping 4 lines ... I0507 07:39:01.649556 1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount at /var/lib/kubelet/pods/9fbb034a-ce43-48f0-b520-76a58a27ecd4/volumes/kubernetes.io~csi/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/mount successfully I0507 07:39:01.649585 1 utils.go:83] GRPC response: {} I0507 07:39:02.184516 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:39:02.184542 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:39:02.185134 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:39:02.185154 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:39:02.187181 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:39:02.187300 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:39:02.890683 1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume I0507 07:39:02.890705 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95","csi.storage.k8s.io/pvc/name":"test.csi.azure.comgmv9b","csi.storage.k8s.io/pvc/namespace":"snapshotting-7449","secretnamespace":"snapshotting-7449","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95###snapshotting-7449"} I0507 07:39:02.890838 1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95###snapshotting-7449) context(map[csi.storage.k8s.io/pv/name:pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95 csi.storage.k8s.io/pvc/name:test.csi.azure.comgmv9b csi.storage.k8s.io/pvc/namespace:snapshotting-7449 secretnamespace:snapshotting-7449 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup() ... skipping 8 lines ... I0507 07:39:03.140938 1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/globalmount at /var/lib/kubelet/pods/b6cc1b6c-615e-4ca3-8032-53f1b9f61948/volumes/kubernetes.io~csi/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/mount successfully I0507 07:39:03.140955 1 utils.go:83] GRPC response: {} I0507 07:39:03.196869 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:39:03.196883 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:39:03.197308 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:39:03.197321 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:39:03.199105 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:39:03.199177 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:39:05.214206 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:39:05.214228 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:39:05.214780 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:39:05.214805 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:39:05.216509 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:39:05.216593 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:39:06.825611 1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume I0507 07:39:06.825638 1 utils.go:77] GRPC request: {"target_path":"/var/lib/kubelet/pods/b6cc1b6c-615e-4ca3-8032-53f1b9f61948/volumes/kubernetes.io~csi/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/mount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95###snapshotting-7449"} I0507 07:39:06.825737 1 nodeserver.go:132] NodeUnpublishVolume: unmounting volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95###snapshotting-7449 on /var/lib/kubelet/pods/b6cc1b6c-615e-4ca3-8032-53f1b9f61948/volumes/kubernetes.io~csi/pvc-3f039fdd-f2f1-4187-a47d-8ce5e615ba95/mount ... skipping 27 lines ... I0507 07:39:07.768768 1 nodeserver.go:369] NodeUnstageVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac###provisioning-2916 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-b02a2899-aae7-4836-8d75-ec3cf22c28ac/globalmount successfully I0507 07:39:07.768778 1 utils.go:83] GRPC response: {} I0507 07:39:09.250354 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:39:09.250375 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:39:09.250841 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:39:09.250863 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:39:09.252530 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:39:09.252610 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:39:11.869136 1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume I0507 07:39:11.869169 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"],"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890","csi.storage.k8s.io/pvc/name":"test.csi.azure.comtrdw2","csi.storage.k8s.io/pvc/namespace":"volume-expand-736","secretnamespace":"volume-expand-736","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736"} I0507 07:39:11.869372 1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736) context(map[csi.storage.k8s.io/pv/name:pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890 csi.storage.k8s.io/pvc/name:test.csi.azure.comtrdw2 csi.storage.k8s.io/pvc/namespace:volume-expand-736 secretnamespace:volume-expand-736 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30 gid=1000]) volumeMountGroup(1000) ... skipping 32 lines ... I0507 07:39:17.313559 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:39:17.313584 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) I0507 07:39:17.314213 1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume I0507 07:39:17.314227 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736"} I0507 07:39:17.314269 1 nodeserver.go:359] NodeUnstageVolume: CleanupMountPoint volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount I0507 07:39:17.314276 1 mount_linux.go:294] Unmounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount E0507 07:39:17.315244 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:39:17.315302 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. W0507 07:39:17.328797 1 mount_helper_common.go:133] Warning: "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/globalmount" is not a mountpoint, deleting I0507 07:39:17.328857 1 nodeserver.go:365] NodeUnstageVolume: CleanupMountPoint volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890###volume-expand-736 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/proxy-mount W0507 07:39:17.328875 1 mount_helper_common.go:34] Warning: Unmount skipped because path does not exist: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4949f6a0-c8dd-4200-9049-eba8efaf4890/proxy-mount ... skipping 100 lines ... I0507 07:39:33.031964 1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde/globalmount at /var/lib/kubelet/pods/7f7d32b9-a1b7-47f5-85d5-38c037fdf075/volumes/kubernetes.io~csi/pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde/mount successfully I0507 07:39:33.031984 1 utils.go:83] GRPC response: {} I0507 07:39:33.362198 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:39:33.362216 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:39:33.362882 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:39:33.362907 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:39:33.364876 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:39:33.364948 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:39:36.983682 1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume I0507 07:39:36.983710 1 utils.go:77] GRPC request: {"target_path":"/var/lib/kubelet/pods/7f7d32b9-a1b7-47f5-85d5-38c037fdf075/volumes/kubernetes.io~csi/pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde/mount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde###provisioning-2077"} I0507 07:39:36.983783 1 nodeserver.go:132] NodeUnpublishVolume: unmounting volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde###provisioning-2077 on /var/lib/kubelet/pods/7f7d32b9-a1b7-47f5-85d5-38c037fdf075/volumes/kubernetes.io~csi/pvc-649c0be0-0bea-42c1-9733-cbb3c8ef5cde/mount ... skipping 128 lines ... I0507 07:40:03.017210 1 nodeserver.go:369] NodeUnstageVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ece4cf9-6ac2-41c8-9d90-109cf90785dd###multivolume-362 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0ece4cf9-6ac2-41c8-9d90-109cf90785dd/globalmount successfully I0507 07:40:03.017221 1 utils.go:83] GRPC response: {} I0507 07:40:05.417827 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:40:05.418086 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:40:05.419018 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:40:05.419057 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:40:05.421670 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:40:05.421978 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:40:15.703876 1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume I0507 07:40:15.703896 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584","csi.storage.k8s.io/pvc/name":"inline-volume-tester-jc2qs-my-volume-0","csi.storage.k8s.io/pvc/namespace":"ephemeral-7412","secretnamespace":"ephemeral-7412","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584###ephemeral-7412"} I0507 07:40:15.704076 1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584###ephemeral-7412) context(map[csi.storage.k8s.io/pv/name:pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584 csi.storage.k8s.io/pvc/name:inline-volume-tester-jc2qs-my-volume-0 csi.storage.k8s.io/pvc/namespace:ephemeral-7412 secretnamespace:ephemeral-7412 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup() ... skipping 24 lines ... I0507 07:40:49.591906 1 nodeserver.go:369] NodeUnstageVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584###ephemeral-7412 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-cb352dea-5e75-49d2-8e04-40aa6ca7d584/globalmount successfully I0507 07:40:49.591917 1 utils.go:83] GRPC response: {} I0507 07:41:09.447448 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:41:09.447478 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:41:09.448209 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:41:09.448247 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:41:09.450057 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:41:09.450203 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:42:06.805774 1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume I0507 07:42:06.805809 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3","csi.storage.k8s.io/pvc/name":"test.csi.azure.comfzzpt","csi.storage.k8s.io/pvc/namespace":"provisioning-4007","secretnamespace":"provisioning-4007","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3###provisioning-4007"} I0507 07:42:06.806012 1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3###provisioning-4007) context(map[csi.storage.k8s.io/pv/name:pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3 csi.storage.k8s.io/pvc/name:test.csi.azure.comfzzpt csi.storage.k8s.io/pvc/namespace:provisioning-4007 secretnamespace:provisioning-4007 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup() ... skipping 8 lines ... I0507 07:42:06.894944 1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/globalmount at /var/lib/kubelet/pods/53867df0-03ab-4f6c-bc61-b992106a4686/volumes/kubernetes.io~csi/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/mount successfully I0507 07:42:06.894961 1 utils.go:83] GRPC response: {} I0507 07:43:11.560251 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:43:11.560271 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:43:11.560794 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:43:11.560810 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:43:11.562461 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:43:11.562551 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:43:41.301196 1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume I0507 07:43:41.301217 1 utils.go:77] GRPC request: {"target_path":"/var/lib/kubelet/pods/53867df0-03ab-4f6c-bc61-b992106a4686/volumes/kubernetes.io~csi/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/mount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3###provisioning-4007"} I0507 07:43:41.301285 1 nodeserver.go:132] NodeUnpublishVolume: unmounting volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3###provisioning-4007 on /var/lib/kubelet/pods/53867df0-03ab-4f6c-bc61-b992106a4686/volumes/kubernetes.io~csi/pvc-0ce37206-e249-4ee0-a362-f0d50b68cda3/mount ... skipping 18 lines ... I0507 07:43:45.534441 1 nodeserver.go:136] NodeUnpublishVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366 on /var/lib/kubelet/pods/c58b154d-b52f-4a73-b27d-ff0a2812bfa8/volumes/kubernetes.io~csi/pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc/mount successfully I0507 07:43:45.534451 1 utils.go:83] GRPC response: {} I0507 07:43:45.628680 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:43:45.628712 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:43:45.629363 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:43:45.629401 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:43:45.631944 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:43:45.632043 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:43:46.230286 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:43:46.230308 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:43:46.230960 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:43:46.230991 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:43:46.233777 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:43:46.233840 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:43:47.340531 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:43:47.340566 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:43:47.341143 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:43:47.341164 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:43:47.343245 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:43:47.343333 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:43:49.354367 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:43:49.354387 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:43:49.354851 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:43:49.354871 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:43:49.356555 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:43:49.356615 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:43:53.388121 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:43:53.388154 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:43:53.388841 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:43:53.388878 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:43:53.391539 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:43:53.391617 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:43:56.817802 1 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume I0507 07:43:56.817828 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-de104026-29fe-4b63-9f73-255664953fa3/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-de104026-29fe-4b63-9f73-255664953fa3","csi.storage.k8s.io/pvc/name":"inline-volume-tester2-xgksq-my-volume-0","csi.storage.k8s.io/pvc/namespace":"ephemeral-8025","secretnamespace":"ephemeral-8025","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025"} I0507 07:43:56.817963 1 nodeserver.go:275] cifsMountPath(/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-de104026-29fe-4b63-9f73-255664953fa3/globalmount) fstype() volumeID(kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025) context(map[csi.storage.k8s.io/pv/name:pvc-de104026-29fe-4b63-9f73-255664953fa3 csi.storage.k8s.io/pvc/name:inline-volume-tester2-xgksq-my-volume-0 csi.storage.k8s.io/pvc/namespace:ephemeral-8025 secretnamespace:ephemeral-8025 skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1651909084142-8081-test.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) volumeMountGroup() ... skipping 8 lines ... I0507 07:43:56.883744 1 nodeserver.go:116] NodePublishVolume: mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-de104026-29fe-4b63-9f73-255664953fa3/globalmount at /var/lib/kubelet/pods/2cee2ce1-98e1-481c-9b5b-34762e365c19/volumes/kubernetes.io~csi/pvc-de104026-29fe-4b63-9f73-255664953fa3/mount successfully I0507 07:43:56.883756 1 utils.go:83] GRPC response: {} I0507 07:44:01.450701 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:44:01.450718 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:44:01.451653 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:44:01.451687 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:44:01.454062 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:44:01.454135 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:44:17.494260 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:44:17.494295 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:44:17.495038 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:44:17.495076 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:44:17.497378 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:44:17.497465 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:44:30.493880 1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnpublishVolume I0507 07:44:30.493914 1 utils.go:77] GRPC request: {"target_path":"/var/lib/kubelet/pods/2cee2ce1-98e1-481c-9b5b-34762e365c19/volumes/kubernetes.io~csi/pvc-de104026-29fe-4b63-9f73-255664953fa3/mount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025"} I0507 07:44:30.493986 1 nodeserver.go:132] NodeUnpublishVolume: unmounting volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025 on /var/lib/kubelet/pods/2cee2ce1-98e1-481c-9b5b-34762e365c19/volumes/kubernetes.io~csi/pvc-de104026-29fe-4b63-9f73-255664953fa3/mount ... skipping 11 lines ... I0507 07:44:30.612805 1 nodeserver.go:369] NodeUnstageVolume: unmount volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-de104026-29fe-4b63-9f73-255664953fa3###ephemeral-8025 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-de104026-29fe-4b63-9f73-255664953fa3/globalmount successfully I0507 07:44:30.612816 1 utils.go:83] GRPC response: {} I0507 07:44:49.542942 1 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0507 07:44:49.543232 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount","target_path":"/var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount","volume_capability":{"AccessType":{"Mount":{"volume_mount_group":"1000"}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"pod-ad3c0b4e-9066-4470-87ff-d0972b0a6ced","csi.storage.k8s.io/pod.namespace":"provisioning-4366","csi.storage.k8s.io/pod.uid":"2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2","csi.storage.k8s.io/pv/name":"pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc","csi.storage.k8s.io/pvc/name":"pvc-mbdlx","csi.storage.k8s.io/pvc/namespace":"provisioning-4366","csi.storage.k8s.io/serviceAccount.name":"default","secretnamespace":"provisioning-4366","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1651909084142-8081-test.csi.azure.com"},"volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:44:49.543951 1 nodeserver.go:109] NodePublishVolume: mounting /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount with mountOptions: [bind] I0507 07:44:49.543989 1 mount_linux.go:183] Mounting cmd (mount) with arguments ( -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount) E0507 07:44:49.545705 1 mount_linux.go:195] Mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. E0507 07:44:49.545793 1 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount at /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: mount failed: exit status 32 Mounting command: mount Mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount Output: mount: /var/lib/kubelet/pods/2e201c3b-9bd8-4b64-bb04-cebe41ebf0b2/volumes/kubernetes.io~csi/pv-czp59/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pv-czp59/globalmount does not exist. I0507 07:45:38.540831 1 utils.go:76] GRPC call: /csi.v1.Node/NodeUnstageVolume I0507 07:45:38.540852 1 utils.go:77] GRPC request: {"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc/globalmount","volume_id":"kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366"} I0507 07:45:38.540903 1 nodeserver.go:359] NodeUnstageVolume: CleanupMountPoint volume kubetest-btcc2dv0#fefc5f86712004996adfb9a#pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc###provisioning-4366 on /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9f86b8f4-6da3-4d93-990a-a893897f6fcc/globalmount ... skipping 42 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0507 07:37:59.951996 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test I0507 07:37:59.952341 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0507 07:37:59.973516 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 I0507 07:37:59.973534 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0507 07:37:59.973541 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0507 07:37:59.973561 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0507 07:37:59.974166 1 azure_auth.go:245] Using AzurePublicCloud environment I0507 07:37:59.974206 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0507 07:37:59.974235 1 azure.go:746] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000 ... skipping 1181 lines ... Go Version: go1.18.1 Platform: linux/amd64 Streaming logs below: I0507 07:37:57.729635 1 azurefile.go:272] driver userAgent: test.csi.azure.com/e2e-3273d65a31e38c7a128a9fa367eba2609e4079b6 gc/go1.18.1 (amd64-linux) e2e-test I0507 07:37:57.730107 1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider W0507 07:37:57.763961 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 I0507 07:37:57.763986 1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider I0507 07:37:57.763996 1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0507 07:37:57.764027 1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully I0507 07:37:57.764616 1 azure_auth.go:245] Using AzurePublicCloud environment I0507 07:37:57.764647 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0507 07:37:57.764674 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.62085376e+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/07 07:48:26 process.go:155: Step 'make e2e-test' finished in 19m57.250087507s 2022/05/07 07:48:26 aksengine_helpers.go:426: downloading /root/tmp2708233612/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh 2022/05/07 07:48:26 util.go:71: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh 2022/05/07 07:48:26 process.go:153: Running: chmod +x /root/tmp2708233612/log-dump.sh 2022/05/07 07:48:26 process.go:155: Step 'chmod +x /root/tmp2708233612/log-dump.sh' finished in 1.049728ms 2022/05/07 07:48:26 aksengine_helpers.go:426: downloading /root/tmp2708233612/log-dump-daemonset.yaml from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump-daemonset.yaml ... skipping 52 lines ... ssh key file /root/.ssh/id_rsa does not exist. Exiting. 2022/05/07 07:48:49 process.go:155: Step 'bash -c /root/tmp2708233612/win-ci-logs-collector.sh kubetest-btcc2dv0.canadacentral.cloudapp.azure.com /root/tmp2708233612 /root/.ssh/id_rsa' finished in 3.591388ms 2022/05/07 07:48:49 aksengine.go:1141: Deleting resource group: kubetest-btcc2dv0. 2022/05/07 07:55:53 process.go:96: Saved XML output to /logs/artifacts/junit_runner.xml. 2022/05/07 07:55:53 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" 2022/05/07 07:55:53 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 286.490643ms 2022/05/07 07:55:53 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 c221f330c2b1 ... skipping 4 lines ...