This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: fix: inline volume mount options passing issue
ResultFAILURE
Tests 1 failed / 18 succeeded
Started2022-05-20 04:44
Elapsed52m59s
Revisiond9adc2b64ef194b6f97cf6ca895f17c3ecfcca5b
Refs 1026

Test Failures

AzureFile CSI Driver End-to-End Tests Pre-Provisioned should use a pre-provisioned volume and mount it as readOnly in a pod [file.csi.azure.com] [Windows] 8m1s

go run hack/e2e.go -v --test --test_args='--ginkgo.focus=AzureFile\sCSI\sDriver\sEnd\-to\-End\sTests\sPre\-Provisioned\sshould\suse\sa\spre\-provisioned\svolume\sand\smount\sit\sas\sreadOnly\sin\sa\spod\s\[file\.csi\.azure\.com\]\s\[Windows\]$'
/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/pre_provisioning_test.go:77
Expected
    <string>: 
to contain substring
    <string>: FileOpenFailure
/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/pre_provisioned_read_only_volume_tester.go:59
				
				Click to see stdout/stderrfrom junit_01.xml

Filter through log files | View test history on testgrid

Show 18 Passed Tests
Show 15 Skipped Tests

Error lines from build-log.txt

... skipping 673 lines ...
certificate.cert-manager.io "selfsigned-cert" deleted
# Create secret for AzureClusterIdentity
./hack/create-identity-secret.sh
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
make[2]: Nothing to be done for 'kubectl'.
make[2]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
Error from server (NotFound): secrets "cluster-identity-secret" not found
secret/cluster-identity-secret created
secret/cluster-identity-secret labeled
# Deploy CAPI
curl --retry 3 -sSL https://github.com/kubernetes-sigs/cluster-api/releases/download/v1.1.2/cluster-api-components.yaml | /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/envsubst-v2.0.0-20210730161058-179042472c46 | kubectl apply -f -
namespace/capi-system created
customresourcedefinition.apiextensions.k8s.io/clusterclasses.cluster.x-k8s.io created
... skipping 127 lines ...
# Wait for the kubeconfig to become available.
timeout --foreground 300 bash -c "while ! kubectl get secrets | grep capz-bfmcxl-kubeconfig; do sleep 1; done"
capz-bfmcxl-kubeconfig                 cluster.x-k8s.io/secret               1      1s
# Get kubeconfig and store it locally.
kubectl get secrets capz-bfmcxl-kubeconfig -o json | jq -r .data.value | base64 --decode > ./kubeconfig
timeout --foreground 600 bash -c "while ! kubectl --kubeconfig=./kubeconfig get nodes | grep control-plane; do sleep 1; done"
error: the server doesn't have a resource type "nodes"
capz-bfmcxl-control-plane-znm9z   NotReady   control-plane,master   5s    v1.23.5
run "kubectl --kubeconfig=./kubeconfig ..." to work with the new target cluster
make[1]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
Waiting for 1 control plane machine(s), 0 worker machine(s), and 2 windows machine(s) to become Ready
node/capz-bfmc-jln2f condition met
node/capz-bfmc-z5gh4 condition met
... skipping 1001 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 183 lines ...
May 20 05:06:14.749: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-gz7ts] to have phase Bound
May 20 05:06:14.864: INFO: PersistentVolumeClaim pvc-gz7ts found and phase=Bound (114.725812ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with an error
May 20 05:06:15.181: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-5d9j6" in namespace "azurefile-8081" to be "Error status code"
May 20 05:06:15.287: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 106.285814ms
May 20 05:06:17.391: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.209596555s
May 20 05:06:19.495: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.314166684s
May 20 05:06:21.604: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.422717019s
May 20 05:06:23.708: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.526633191s
May 20 05:06:25.823: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.641764054s
... skipping 201 lines ...
May 20 05:13:32.495: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 7m17.313713938s
May 20 05:13:34.605: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 7m19.423737778s
May 20 05:13:36.715: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 7m21.534312119s
May 20 05:13:38.826: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 7m23.644782855s
May 20 05:13:40.937: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 7m25.755868631s
May 20 05:13:43.047: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Pending", Reason="", readiness=false. Elapsed: 7m27.866156913s
May 20 05:13:45.158: INFO: Pod "azurefile-volume-tester-5d9j6": Phase="Failed", Reason="", readiness=false. Elapsed: 7m29.976794676s
STEP: Saw pod failure
May 20 05:13:45.158: INFO: Pod "azurefile-volume-tester-5d9j6" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
May 20 05:13:45.288: INFO: deleting Pod "azurefile-8081"/"azurefile-volume-tester-5d9j6"
May 20 05:13:45.395: INFO: Pod azurefile-volume-tester-5d9j6 has the following logs: 
STEP: Deleting pod azurefile-volume-tester-5d9j6 in namespace azurefile-8081
May 20 05:13:45.512: INFO: deleting PVC "azurefile-8081"/"pvc-gz7ts"
May 20 05:13:45.512: INFO: Deleting PersistentVolumeClaim "pvc-gz7ts"
... skipping 7 lines ...
STEP: Collecting events from namespace "azurefile-8081".
STEP: Found 6 events.
May 20 05:13:46.036: INFO: At 2022-05-20 05:06:15 +0000 UTC - event for azurefile-volume-tester-5d9j6: {default-scheduler } Scheduled: Successfully assigned azurefile-8081/azurefile-volume-tester-5d9j6 to capz-bfmc-jln2f
May 20 05:13:46.036: INFO: At 2022-05-20 05:06:28 +0000 UTC - event for azurefile-volume-tester-5d9j6: {kubelet capz-bfmc-jln2f} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
May 20 05:13:46.036: INFO: At 2022-05-20 05:11:42 +0000 UTC - event for azurefile-volume-tester-5d9j6: {kubelet capz-bfmc-jln2f} Pulled: Successfully pulled image "mcr.microsoft.com/windows/servercore:ltsc2022" in 5m13.9313459s
May 20 05:13:46.036: INFO: At 2022-05-20 05:11:42 +0000 UTC - event for azurefile-volume-tester-5d9j6: {kubelet capz-bfmc-jln2f} Created: Created container volume-tester
May 20 05:13:46.036: INFO: At 2022-05-20 05:13:42 +0000 UTC - event for azurefile-volume-tester-5d9j6: {kubelet capz-bfmc-jln2f} Failed: Error: context deadline exceeded
May 20 05:13:46.036: INFO: At 2022-05-20 05:13:43 +0000 UTC - event for azurefile-volume-tester-5d9j6: {kubelet capz-bfmc-jln2f} Pulled: Container image "mcr.microsoft.com/windows/servercore:ltsc2022" already present on machine
May 20 05:13:46.141: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 20 05:13:46.141: INFO: 
May 20 05:13:46.286: INFO: 
Logging node info for node capz-bfmc-jln2f
May 20 05:13:46.402: INFO: Node Info: &Node{ObjectMeta:{capz-bfmc-jln2f    eff7b2e0-ba44-4bc6-a9c6-9f9852539882 2689 0 2022-05-20 04:58:24 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:northeurope failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-bfmc-jln2f kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.20348 topology.kubernetes.io/region:northeurope topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-bfmcxl cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-bfmcxl-md-win-7d8f6b8b8-c22z8 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-bfmcxl-md-win-7d8f6b8b8 csi.volume.kubernetes.io/nodeid:{"file.csi.azure.com":"capz-bfmc-jln2f"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.11.65 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:d6:3f:c5 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{Go-http-client Update v1 2022-05-20 04:58:24 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:kubeadm.alpha.kubernetes.io/cri-socket":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kube-controller-manager Update v1 2022-05-20 04:58:36 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-05-20 04:59:40 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:cluster.x-k8s.io/cluster-name":{},"f:cluster.x-k8s.io/cluster-namespace":{},"f:cluster.x-k8s.io/machine":{},"f:cluster.x-k8s.io/owner-kind":{},"f:cluster.x-k8s.io/owner-name":{}}}} } {Go-http-client Update v1 2022-05-20 05:05:50 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{},"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"DiskPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"MemoryPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"PIDPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"Ready\"}":{"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{}}},"f:images":{}}} status}]},Spec:NodeSpec{PodCIDR:,DoNotUseExternalID:,ProviderID:azure:///subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-bfmcxl/providers/Microsoft.Compute/virtualMachines/capz-bfmc-jln2f,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{136912564224 0} {<nil>} 133703676Ki BinarySI},memory: {{17179398144 0} {<nil>} 16776756Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{123221307598 0} {<nil>} 123221307598 DecimalSI},memory: {{17074540544 0} {<nil>} 16674356Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-20 05:12:01 +0000 UTC,LastTransitionTime:2022-05-20 04:58:24 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-20 05:12:01 +0000 UTC,LastTransitionTime:2022-05-20 04:58:24 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-20 05:12:01 +0000 UTC,LastTransitionTime:2022-05-20 04:58:24 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-20 05:12:01 +0000 UTC,LastTransitionTime:2022-05-20 05:00:16 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-bfmc-jln2f,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-bfmc-jln2f,SystemUUID:5F2677B1-8140-494D-93B5-4190DDAEA523,BootID:,KernelVersion:10.0.20348.405,OSImage:Windows Server 2022 Datacenter,ContainerRuntimeVersion:containerd://1.6.1,KubeletVersion:v1.23.5,KubeProxyVersion:v1.23.5,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[mcr.microsoft.com/windows/servercore@sha256:93373be6f6c576ef3f778b9d5e7b54231975bb6876a07d90c4e4599a29a65d54 mcr.microsoft.com/windows/servercore:ltsc2022],SizeBytes:2237537294,},ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:148054279,},ContainerImage{Names:[capzci.azurecr.io/azurefile-csi@sha256:25099cd5bea00e260828a4ab4511d7a9ed86fe6f3514b810728c5e7ee94e9d86 capzci.azurecr.io/azurefile-csi:e2e-7c75002423fc579c4a5870e30aea9e5666557c59],SizeBytes:130588901,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:125796204,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:124893309,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:123925937,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:119397646,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy@sha256:0f8a44b795d1824358f24cc56f0024d18a39ae044656686596d8b7fa6d78e1fa docker.io/sigwindowstools/kube-proxy:v1.23.5-calico-hostprocess],SizeBytes:116337721,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 115 lines ...
May 20 05:13:53.575: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-kqm98] to have phase Bound
May 20 05:13:53.678: INFO: PersistentVolumeClaim pvc-kqm98 found and phase=Bound (102.53488ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:13:53.989: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-jdbq7" in namespace "azurefile-2540" to be "Succeeded or Failed"
May 20 05:13:54.093: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Pending", Reason="", readiness=false. Elapsed: 103.290439ms
May 20 05:13:56.196: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206725861s
May 20 05:13:58.299: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309571414s
May 20 05:14:00.403: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.413600844s
May 20 05:14:02.508: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.518440874s
May 20 05:14:04.612: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Pending", Reason="", readiness=false. Elapsed: 10.622992842s
May 20 05:14:06.720: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Pending", Reason="", readiness=false. Elapsed: 12.731083559s
May 20 05:14:08.825: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Running", Reason="", readiness=true. Elapsed: 14.835464012s
May 20 05:14:10.930: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Running", Reason="", readiness=true. Elapsed: 16.941085551s
May 20 05:14:13.036: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Running", Reason="", readiness=true. Elapsed: 19.0464236s
May 20 05:14:15.140: INFO: Pod "azurefile-volume-tester-jdbq7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.150696622s
STEP: Saw pod success
May 20 05:14:15.140: INFO: Pod "azurefile-volume-tester-jdbq7" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
May 20 05:14:15.348: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-2ltmx] to have phase Bound
May 20 05:14:15.455: INFO: PersistentVolumeClaim pvc-2ltmx found and phase=Bound (106.644442ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:14:15.790: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-mjntp" in namespace "azurefile-2540" to be "Succeeded or Failed"
May 20 05:14:15.901: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Pending", Reason="", readiness=false. Elapsed: 110.681342ms
May 20 05:14:18.005: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.21441192s
May 20 05:14:20.111: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.32010295s
May 20 05:14:22.216: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.425871965s
May 20 05:14:24.321: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.531064457s
May 20 05:14:26.428: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.63744982s
May 20 05:14:28.532: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Running", Reason="", readiness=true. Elapsed: 12.741755502s
May 20 05:14:30.636: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Running", Reason="", readiness=true. Elapsed: 14.84561443s
May 20 05:14:32.740: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Running", Reason="", readiness=true. Elapsed: 16.949920027s
May 20 05:14:34.847: INFO: Pod "azurefile-volume-tester-mjntp": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.05699112s
STEP: Saw pod success
May 20 05:14:34.848: INFO: Pod "azurefile-volume-tester-mjntp" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
May 20 05:14:35.061: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-6mzhd] to have phase Bound
May 20 05:14:35.164: INFO: PersistentVolumeClaim pvc-6mzhd found and phase=Bound (102.607749ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:14:35.482: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-w7md8" in namespace "azurefile-2540" to be "Succeeded or Failed"
May 20 05:14:35.585: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Pending", Reason="", readiness=false. Elapsed: 102.717477ms
May 20 05:14:37.694: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.212397026s
May 20 05:14:39.800: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.317570469s
May 20 05:14:41.904: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.42177433s
May 20 05:14:44.009: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.526823139s
May 20 05:14:46.115: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.632791344s
May 20 05:14:48.220: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Running", Reason="", readiness=true. Elapsed: 12.738091907s
May 20 05:14:50.329: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Running", Reason="", readiness=true. Elapsed: 14.846615962s
May 20 05:14:52.434: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Running", Reason="", readiness=true. Elapsed: 16.952350927s
May 20 05:14:54.538: INFO: Pod "azurefile-volume-tester-w7md8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.05626183s
STEP: Saw pod success
May 20 05:14:54.538: INFO: Pod "azurefile-volume-tester-w7md8" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
May 20 05:14:54.749: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-k7xfg] to have phase Bound
May 20 05:14:54.852: INFO: PersistentVolumeClaim pvc-k7xfg found and phase=Bound (102.060011ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:14:55.160: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-l7w5b" in namespace "azurefile-2540" to be "Succeeded or Failed"
May 20 05:14:55.262: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Pending", Reason="", readiness=false. Elapsed: 101.863898ms
May 20 05:14:57.367: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207171204s
May 20 05:14:59.473: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Pending", Reason="", readiness=false. Elapsed: 4.313352694s
May 20 05:15:01.578: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Pending", Reason="", readiness=false. Elapsed: 6.418121326s
May 20 05:15:03.694: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Pending", Reason="", readiness=false. Elapsed: 8.533597378s
May 20 05:15:05.799: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Running", Reason="", readiness=true. Elapsed: 10.638416716s
May 20 05:15:07.904: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Running", Reason="", readiness=true. Elapsed: 12.743360177s
May 20 05:15:10.339: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Running", Reason="", readiness=true. Elapsed: 15.179001185s
May 20 05:15:12.443: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Running", Reason="", readiness=true. Elapsed: 17.283045239s
May 20 05:15:14.548: INFO: Pod "azurefile-volume-tester-l7w5b": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.388025524s
STEP: Saw pod success
May 20 05:15:14.548: INFO: Pod "azurefile-volume-tester-l7w5b" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
May 20 05:15:14.773: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-bzrcm] to have phase Bound
May 20 05:15:14.876: INFO: PersistentVolumeClaim pvc-bzrcm found and phase=Bound (103.130605ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:15:15.193: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-4q69d" in namespace "azurefile-2540" to be "Succeeded or Failed"
May 20 05:15:15.296: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Pending", Reason="", readiness=false. Elapsed: 103.46779ms
May 20 05:15:17.400: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207004726s
May 20 05:15:19.505: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Pending", Reason="", readiness=false. Elapsed: 4.312248487s
May 20 05:15:21.611: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Pending", Reason="", readiness=false. Elapsed: 6.418574052s
May 20 05:15:23.721: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Pending", Reason="", readiness=false. Elapsed: 8.528105309s
May 20 05:15:25.827: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Pending", Reason="", readiness=false. Elapsed: 10.634651753s
May 20 05:15:27.932: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Running", Reason="", readiness=true. Elapsed: 12.739334921s
May 20 05:15:30.036: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Running", Reason="", readiness=true. Elapsed: 14.843421029s
May 20 05:15:32.141: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Running", Reason="", readiness=true. Elapsed: 16.94802583s
May 20 05:15:34.244: INFO: Pod "azurefile-volume-tester-4q69d": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.051415366s
STEP: Saw pod success
May 20 05:15:34.244: INFO: Pod "azurefile-volume-tester-4q69d" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
May 20 05:15:34.452: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-vq5ll] to have phase Bound
May 20 05:15:34.554: INFO: PersistentVolumeClaim pvc-vq5ll found and phase=Bound (101.959438ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:15:34.867: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-9kfz7" in namespace "azurefile-2540" to be "Succeeded or Failed"
May 20 05:15:34.976: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Pending", Reason="", readiness=false. Elapsed: 108.853401ms
May 20 05:15:37.080: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.213520814s
May 20 05:15:39.185: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.317615659s
May 20 05:15:41.290: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.42288739s
May 20 05:15:43.394: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.526941637s
May 20 05:15:45.500: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Running", Reason="", readiness=true. Elapsed: 10.633043981s
May 20 05:15:47.604: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Running", Reason="", readiness=true. Elapsed: 12.737321037s
May 20 05:15:49.710: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Running", Reason="", readiness=true. Elapsed: 14.842663636s
May 20 05:15:51.814: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Running", Reason="", readiness=true. Elapsed: 16.946813252s
May 20 05:15:53.918: INFO: Pod "azurefile-volume-tester-9kfz7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.050797379s
STEP: Saw pod success
May 20 05:15:53.918: INFO: Pod "azurefile-volume-tester-9kfz7" satisfied condition "Succeeded or Failed"
May 20 05:15:53.918: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-9kfz7"
May 20 05:15:54.052: INFO: Pod azurefile-volume-tester-9kfz7 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-9kfz7 in namespace azurefile-2540
May 20 05:15:54.168: INFO: deleting PVC "azurefile-2540"/"pvc-vq5ll"
May 20 05:15:54.168: INFO: Deleting PersistentVolumeClaim "pvc-vq5ll"
... skipping 148 lines ...
May 20 05:16:06.743: INFO: PersistentVolumeClaim pvc-4bsrg found but phase is Pending instead of Bound.
May 20 05:16:08.847: INFO: PersistentVolumeClaim pvc-4bsrg found and phase=Bound (2.206175528s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:16:09.160: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-w8sr7" in namespace "azurefile-5466" to be "Succeeded or Failed"
May 20 05:16:09.263: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Pending", Reason="", readiness=false. Elapsed: 102.901831ms
May 20 05:16:11.366: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205876477s
May 20 05:16:13.472: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311889741s
May 20 05:16:15.576: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415968572s
May 20 05:16:17.680: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.52052411s
May 20 05:16:19.785: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Pending", Reason="", readiness=false. Elapsed: 10.625313016s
May 20 05:16:21.890: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Running", Reason="", readiness=true. Elapsed: 12.729988669s
May 20 05:16:23.995: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Running", Reason="", readiness=true. Elapsed: 14.834569126s
May 20 05:16:26.099: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Running", Reason="", readiness=true. Elapsed: 16.939468704s
May 20 05:16:28.204: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Running", Reason="", readiness=true. Elapsed: 19.043717641s
May 20 05:16:30.309: INFO: Pod "azurefile-volume-tester-w8sr7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.148582092s
STEP: Saw pod success
May 20 05:16:30.309: INFO: Pod "azurefile-volume-tester-w8sr7" satisfied condition "Succeeded or Failed"
May 20 05:16:30.309: INFO: deleting Pod "azurefile-5466"/"azurefile-volume-tester-w8sr7"
May 20 05:16:30.429: INFO: Pod azurefile-volume-tester-w8sr7 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-w8sr7 in namespace azurefile-5466
May 20 05:16:30.547: INFO: deleting PVC "azurefile-5466"/"pvc-4bsrg"
May 20 05:16:30.547: INFO: Deleting PersistentVolumeClaim "pvc-4bsrg"
... skipping 33 lines ...
May 20 05:16:34.327: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-z4jms] to have phase Bound
May 20 05:16:34.430: INFO: PersistentVolumeClaim pvc-z4jms found and phase=Bound (102.317605ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:16:34.755: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-m75cg" in namespace "azurefile-2790" to be "Succeeded or Failed"
May 20 05:16:34.859: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Pending", Reason="", readiness=false. Elapsed: 104.086654ms
May 20 05:16:36.962: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207259918s
May 20 05:16:39.068: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.312902237s
May 20 05:16:41.175: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.419843199s
May 20 05:16:43.280: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.524759008s
May 20 05:16:45.385: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.629693356s
May 20 05:16:47.489: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Pending", Reason="", readiness=false. Elapsed: 12.734189236s
May 20 05:16:49.594: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Running", Reason="", readiness=true. Elapsed: 14.839006355s
May 20 05:16:51.698: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Running", Reason="", readiness=true. Elapsed: 16.942954484s
May 20 05:16:53.802: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Running", Reason="", readiness=true. Elapsed: 19.046875546s
May 20 05:16:55.907: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Running", Reason="", readiness=true. Elapsed: 21.152118003s
May 20 05:16:58.012: INFO: Pod "azurefile-volume-tester-m75cg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 23.256915811s
STEP: Saw pod success
May 20 05:16:58.012: INFO: Pod "azurefile-volume-tester-m75cg" satisfied condition "Succeeded or Failed"
May 20 05:16:58.012: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-m75cg"
May 20 05:16:58.131: INFO: Pod azurefile-volume-tester-m75cg has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-m75cg in namespace azurefile-2790
May 20 05:16:58.248: INFO: deleting PVC "azurefile-2790"/"pvc-z4jms"
May 20 05:16:58.248: INFO: Deleting PersistentVolumeClaim "pvc-z4jms"
... skipping 131 lines ...
May 20 05:19:00.346: INFO: PersistentVolumeClaim pvc-rclzp found but phase is Pending instead of Bound.
May 20 05:19:02.450: INFO: PersistentVolumeClaim pvc-rclzp found and phase=Bound (1m36.888219215s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:19:02.761: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n7w6j" in namespace "azurefile-5194" to be "Succeeded or Failed"
May 20 05:19:02.863: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Pending", Reason="", readiness=false. Elapsed: 101.971426ms
May 20 05:19:04.967: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206565766s
May 20 05:19:07.071: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310242492s
May 20 05:19:09.175: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Pending", Reason="", readiness=false. Elapsed: 6.413970398s
May 20 05:19:11.279: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Pending", Reason="", readiness=false. Elapsed: 8.518157993s
May 20 05:19:13.384: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Pending", Reason="", readiness=false. Elapsed: 10.623586855s
May 20 05:19:15.490: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Running", Reason="", readiness=true. Elapsed: 12.729303489s
May 20 05:19:17.595: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Running", Reason="", readiness=true. Elapsed: 14.834541516s
May 20 05:19:19.701: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Running", Reason="", readiness=true. Elapsed: 16.940060781s
May 20 05:19:21.805: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Running", Reason="", readiness=true. Elapsed: 19.044045214s
May 20 05:19:23.909: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.148316918s
STEP: Saw pod success
May 20 05:19:23.909: INFO: Pod "azurefile-volume-tester-n7w6j" satisfied condition "Succeeded or Failed"
May 20 05:19:23.909: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n7w6j" in namespace "azurefile-5194" to be "Succeeded or Failed"
May 20 05:19:24.012: INFO: Pod "azurefile-volume-tester-n7w6j": Phase="Succeeded", Reason="", readiness=false. Elapsed: 103.236601ms
STEP: Saw pod success
May 20 05:19:24.012: INFO: Pod "azurefile-volume-tester-n7w6j" satisfied condition "Succeeded or Failed"
May 20 05:19:24.012: INFO: deleting Pod "azurefile-5194"/"azurefile-volume-tester-n7w6j"
May 20 05:19:24.147: INFO: Pod azurefile-volume-tester-n7w6j has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-n7w6j in namespace azurefile-5194
May 20 05:19:24.262: INFO: deleting PVC "azurefile-5194"/"pvc-rclzp"
May 20 05:19:24.262: INFO: Deleting PersistentVolumeClaim "pvc-rclzp"
... skipping 34 lines ...
May 20 05:19:26.838: INFO: PersistentVolumeClaim pvc-66dtj found but phase is Pending instead of Bound.
May 20 05:19:28.942: INFO: PersistentVolumeClaim pvc-66dtj found and phase=Bound (2.205688469s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:19:29.253: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bgwbg" in namespace "azurefile-1353" to be "Succeeded or Failed"
May 20 05:19:29.355: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Pending", Reason="", readiness=false. Elapsed: 101.979811ms
May 20 05:19:31.459: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.20653605s
May 20 05:19:33.565: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.312646567s
May 20 05:19:35.670: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.417920241s
May 20 05:19:37.775: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.522820924s
May 20 05:19:39.880: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.627781802s
... skipping 2 lines ...
May 20 05:19:46.195: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Running", Reason="", readiness=true. Elapsed: 16.942363481s
May 20 05:19:48.300: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Running", Reason="", readiness=true. Elapsed: 19.047728533s
May 20 05:19:50.404: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Running", Reason="", readiness=true. Elapsed: 21.151732247s
May 20 05:19:52.508: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Running", Reason="", readiness=true. Elapsed: 23.255055102s
May 20 05:19:54.612: INFO: Pod "azurefile-volume-tester-bgwbg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 25.359682795s
STEP: Saw pod success
May 20 05:19:54.612: INFO: Pod "azurefile-volume-tester-bgwbg" satisfied condition "Succeeded or Failed"
May 20 05:19:54.612: INFO: deleting Pod "azurefile-1353"/"azurefile-volume-tester-bgwbg"
May 20 05:19:54.727: INFO: Pod azurefile-volume-tester-bgwbg has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-bgwbg in namespace azurefile-1353
May 20 05:19:54.928: INFO: deleting PVC "azurefile-1353"/"pvc-66dtj"
May 20 05:19:54.928: INFO: Deleting PersistentVolumeClaim "pvc-66dtj"
... skipping 120 lines ...
May 20 05:21:12.368: INFO: PersistentVolumeClaim pvc-4twxc found but phase is Pending instead of Bound.
May 20 05:21:14.472: INFO: PersistentVolumeClaim pvc-4twxc found and phase=Bound (31.673772063s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with an error
May 20 05:21:14.785: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-tkgvc" in namespace "azurefile-156" to be "Error status code"
May 20 05:21:14.888: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Pending", Reason="", readiness=false. Elapsed: 102.491691ms
May 20 05:21:16.991: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205671293s
May 20 05:21:19.095: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309500583s
May 20 05:21:21.199: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.413155631s
May 20 05:21:23.302: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Pending", Reason="", readiness=false. Elapsed: 8.516632507s
May 20 05:21:25.407: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Pending", Reason="", readiness=false. Elapsed: 10.621458665s
May 20 05:21:27.511: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Pending", Reason="", readiness=false. Elapsed: 12.725736121s
May 20 05:21:29.615: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Running", Reason="", readiness=true. Elapsed: 14.829720193s
May 20 05:21:31.721: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Running", Reason="", readiness=true. Elapsed: 16.935210818s
May 20 05:21:33.826: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Running", Reason="", readiness=true. Elapsed: 19.040700902s
May 20 05:21:35.930: INFO: Pod "azurefile-volume-tester-tkgvc": Phase="Failed", Reason="", readiness=false. Elapsed: 21.14439825s
STEP: Saw pod failure
May 20 05:21:35.930: INFO: Pod "azurefile-volume-tester-tkgvc" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
May 20 05:21:36.050: INFO: deleting Pod "azurefile-156"/"azurefile-volume-tester-tkgvc"
May 20 05:21:36.157: INFO: Pod azurefile-volume-tester-tkgvc has the following logs: out-file : Access to the path 'C:\mnt\test-1\data' is denied.
At line:1 char:1
+ echo $null >> C:\mnt\test-1\data
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 202 lines ...
May 20 05:22:52.164: INFO: PersistentVolumeClaim pvc-8q6fc found but phase is Pending instead of Bound.
May 20 05:22:54.270: INFO: PersistentVolumeClaim pvc-8q6fc found and phase=Bound (2.208230637s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:22:54.582: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-fdznv" in namespace "azurefile-2546" to be "Succeeded or Failed"
May 20 05:22:54.684: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Pending", Reason="", readiness=false. Elapsed: 102.226931ms
May 20 05:22:56.788: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206576247s
May 20 05:22:58.893: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311133066s
May 20 05:23:00.998: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415973608s
May 20 05:23:03.105: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.523575849s
May 20 05:23:05.210: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Pending", Reason="", readiness=false. Elapsed: 10.627992274s
May 20 05:23:07.314: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Running", Reason="", readiness=true. Elapsed: 12.732146418s
May 20 05:23:09.418: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Running", Reason="", readiness=true. Elapsed: 14.836719645s
May 20 05:23:11.523: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Running", Reason="", readiness=true. Elapsed: 16.941708411s
May 20 05:23:13.628: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Running", Reason="", readiness=true. Elapsed: 19.046743992s
May 20 05:23:15.733: INFO: Pod "azurefile-volume-tester-fdznv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.151619178s
STEP: Saw pod success
May 20 05:23:15.733: INFO: Pod "azurefile-volume-tester-fdznv" satisfied condition "Succeeded or Failed"
STEP: resizing the pvc
STEP: sleep 30s waiting for resize complete
STEP: checking the resizing result
STEP: checking the resizing PV result
STEP: checking the resizing azurefile result
May 20 05:23:46.869: INFO: deleting Pod "azurefile-2546"/"azurefile-volume-tester-fdznv"
... skipping 302 lines ...
May 20 05:24:15.205: INFO: PersistentVolumeClaim pvc-pkxtl found but phase is Pending instead of Bound.
May 20 05:24:17.308: INFO: PersistentVolumeClaim pvc-pkxtl found and phase=Bound (2.205582424s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:24:17.624: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-xg4mt" in namespace "azurefile-9183" to be "Succeeded or Failed"
May 20 05:24:17.728: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Pending", Reason="", readiness=false. Elapsed: 103.708494ms
May 20 05:24:19.834: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.209568598s
May 20 05:24:21.940: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.315330992s
May 20 05:24:24.045: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.420412287s
May 20 05:24:26.150: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.525492899s
May 20 05:24:28.253: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.629242327s
... skipping 2 lines ...
May 20 05:24:34.567: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Running", Reason="", readiness=true. Elapsed: 16.942662274s
May 20 05:24:36.672: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Running", Reason="", readiness=true. Elapsed: 19.048150625s
May 20 05:24:38.777: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Running", Reason="", readiness=true. Elapsed: 21.152989488s
May 20 05:24:40.883: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Running", Reason="", readiness=true. Elapsed: 23.258636333s
May 20 05:24:42.989: INFO: Pod "azurefile-volume-tester-xg4mt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 25.364768389s
STEP: Saw pod success
May 20 05:24:42.989: INFO: Pod "azurefile-volume-tester-xg4mt" satisfied condition "Succeeded or Failed"
May 20 05:24:42.989: INFO: deleting Pod "azurefile-9183"/"azurefile-volume-tester-xg4mt"
May 20 05:24:43.107: INFO: Pod azurefile-volume-tester-xg4mt has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-xg4mt in namespace azurefile-9183
May 20 05:24:43.221: INFO: deleting PVC "azurefile-9183"/"pvc-pkxtl"
May 20 05:24:43.221: INFO: Deleting PersistentVolumeClaim "pvc-pkxtl"
... skipping 90 lines ...
check the driver pods if restarts ...
======================================================================================
2022/05/20 05:24:50 Check successfully
May 20 05:24:50.106: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/05/20 05:24:50 run script: test/utils/get_storage_account_secret_name.sh
2022/05/20 05:24:50 got output: azure-storage-account-fc4b4aa9ef3184432ab402b-secret
, error: <nil>
2022/05/20 05:24:50 got storage account secret name: azure-storage-account-fc4b4aa9ef3184432ab402b-secret
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
May 20 05:24:50.759: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-ssnqf] to have phase Bound
May 20 05:24:50.863: INFO: PersistentVolumeClaim pvc-ssnqf found but phase is Pending instead of Bound.
May 20 05:24:52.967: INFO: PersistentVolumeClaim pvc-ssnqf found and phase=Bound (2.207731275s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:24:53.277: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n62jq" in namespace "azurefile-1968" to be "Succeeded or Failed"
May 20 05:24:53.379: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Pending", Reason="", readiness=false. Elapsed: 102.05063ms
May 20 05:24:55.482: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205564163s
May 20 05:24:57.587: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310653856s
May 20 05:24:59.692: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415140951s
May 20 05:25:01.798: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.521318647s
May 20 05:25:03.903: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.625902667s
May 20 05:25:06.339: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Running", Reason="", readiness=true. Elapsed: 13.062083166s
May 20 05:25:08.444: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Running", Reason="", readiness=true. Elapsed: 15.166848157s
May 20 05:25:10.548: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Running", Reason="", readiness=true. Elapsed: 17.271066885s
May 20 05:25:12.652: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Running", Reason="", readiness=true. Elapsed: 19.375234915s
May 20 05:25:14.757: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.479765725s
STEP: Saw pod success
May 20 05:25:14.757: INFO: Pod "azurefile-volume-tester-n62jq" satisfied condition "Succeeded or Failed"
May 20 05:25:14.757: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n62jq" in namespace "azurefile-1968" to be "Succeeded or Failed"
May 20 05:25:14.861: INFO: Pod "azurefile-volume-tester-n62jq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 103.938807ms
STEP: Saw pod success
May 20 05:25:14.861: INFO: Pod "azurefile-volume-tester-n62jq" satisfied condition "Succeeded or Failed"
May 20 05:25:14.861: INFO: deleting Pod "azurefile-1968"/"azurefile-volume-tester-n62jq"
May 20 05:25:14.975: INFO: Pod azurefile-volume-tester-n62jq has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-n62jq in namespace azurefile-1968
May 20 05:25:15.103: INFO: deleting PVC "azurefile-1968"/"pvc-ssnqf"
May 20 05:25:15.103: INFO: Deleting PersistentVolumeClaim "pvc-ssnqf"
... skipping 43 lines ...
May 20 05:25:36.640: INFO: PersistentVolumeClaim pvc-4dtmg found but phase is Pending instead of Bound.
May 20 05:25:38.742: INFO: PersistentVolumeClaim pvc-4dtmg found and phase=Bound (21.146097663s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:25:39.052: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n5x72" in namespace "azurefile-4657" to be "Succeeded or Failed"
May 20 05:25:39.154: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Pending", Reason="", readiness=false. Elapsed: 101.75225ms
May 20 05:25:41.257: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205550485s
May 20 05:25:43.363: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311209449s
May 20 05:25:45.467: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415596626s
May 20 05:25:47.572: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Pending", Reason="", readiness=false. Elapsed: 8.519854586s
May 20 05:25:49.676: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Pending", Reason="", readiness=false. Elapsed: 10.623633847s
May 20 05:25:51.786: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Running", Reason="", readiness=true. Elapsed: 12.734241174s
May 20 05:25:53.891: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Running", Reason="", readiness=true. Elapsed: 14.839583856s
May 20 05:25:55.996: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Running", Reason="", readiness=true. Elapsed: 16.943726853s
May 20 05:25:58.101: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Running", Reason="", readiness=true. Elapsed: 19.049499907s
May 20 05:26:00.207: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.154866261s
STEP: Saw pod success
May 20 05:26:00.207: INFO: Pod "azurefile-volume-tester-n5x72" satisfied condition "Succeeded or Failed"
May 20 05:26:00.207: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n5x72" in namespace "azurefile-4657" to be "Succeeded or Failed"
May 20 05:26:00.310: INFO: Pod "azurefile-volume-tester-n5x72": Phase="Succeeded", Reason="", readiness=false. Elapsed: 103.512686ms
STEP: Saw pod success
May 20 05:26:00.310: INFO: Pod "azurefile-volume-tester-n5x72" satisfied condition "Succeeded or Failed"
May 20 05:26:00.310: INFO: deleting Pod "azurefile-4657"/"azurefile-volume-tester-n5x72"
May 20 05:26:00.426: INFO: Pod azurefile-volume-tester-n5x72 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-n5x72 in namespace azurefile-4657
May 20 05:26:00.541: INFO: deleting PVC "azurefile-4657"/"pvc-4dtmg"
May 20 05:26:00.541: INFO: Deleting PersistentVolumeClaim "pvc-4dtmg"
... skipping 39 lines ...
I0520 05:26:15.163784   37448 testsuites.go:629] 0/1 replicas in the StatefulSet are ready
I0520 05:26:17.161715   37448 testsuites.go:629] 1/1 replicas in the StatefulSet are ready
STEP: checking that the pod is running
STEP: check pod exec
May 20 05:26:17.369: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-1359 exec azurefile-volume-tester-dt76p-0 -- cmd /c type C:\mnt\test-1\data.txt'
May 20 05:26:18.717: INFO: rc: 1
May 20 05:26:18.717: INFO: Error waiting for output "hello world\r\n" in pod "azurefile-volume-tester-dt76p-0": error running /usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-1359 exec azurefile-volume-tester-dt76p-0 -- cmd /c type C:\mnt\test-1\data.txt:
Command stdout:

stderr:
The system cannot find the file specified.
command terminated with exit code 1

error:
exit status 1.
May 20 05:26:20.719: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-1359 exec azurefile-volume-tester-dt76p-0 -- cmd /c type C:\mnt\test-1\data.txt'
May 20 05:26:21.909: INFO: stderr: ""
May 20 05:26:21.909: INFO: stdout: "hello world\r\n"
STEP: deleting the pod for statefulset
May 20 05:26:21.909: INFO: Deleting pod "azurefile-volume-tester-dt76p-0" in namespace "azurefile-1359"
... skipping 26 lines ...
check the driver pods if restarts ...
======================================================================================
2022/05/20 05:27:25 Check successfully
May 20 05:27:25.261: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/05/20 05:27:25 run script: test/utils/get_storage_account_secret_name.sh
2022/05/20 05:27:25 got output: azure-storage-account-fc4b4aa9ef3184432ab402b-secret
, error: <nil>
2022/05/20 05:27:25 got storage account secret name: azure-storage-account-fc4b4aa9ef3184432ab402b-secret
STEP: Successfully provisioned AzureFile volume: "capz-bfmcxl#fc4b4aa9ef3184432ab402b#csi-inline-smb-volume##csi-inline-smb-volume#azurefile-4162"

STEP: deploying the pod
STEP: checking that the pods command exits with no error
May 20 05:27:27.258: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-hgkgh" in namespace "azurefile-4162" to be "Succeeded or Failed"
May 20 05:27:27.360: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Pending", Reason="", readiness=false. Elapsed: 101.449026ms
May 20 05:27:29.463: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.20443451s
May 20 05:27:31.566: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Pending", Reason="", readiness=false. Elapsed: 4.307867518s
May 20 05:27:33.670: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.411409186s
May 20 05:27:35.775: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Pending", Reason="", readiness=false. Elapsed: 8.516413855s
May 20 05:27:37.881: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Pending", Reason="", readiness=false. Elapsed: 10.622239008s
May 20 05:27:39.985: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Pending", Reason="", readiness=false. Elapsed: 12.726339942s
May 20 05:27:42.088: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Pending", Reason="", readiness=false. Elapsed: 14.829563689s
May 20 05:27:44.192: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Running", Reason="", readiness=true. Elapsed: 16.934052459s
May 20 05:27:46.296: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Running", Reason="", readiness=true. Elapsed: 19.037863859s
May 20 05:27:48.400: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Running", Reason="", readiness=true. Elapsed: 21.142058127s
May 20 05:27:50.503: INFO: Pod "azurefile-volume-tester-hgkgh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 23.244807413s
STEP: Saw pod success
May 20 05:27:50.503: INFO: Pod "azurefile-volume-tester-hgkgh" satisfied condition "Succeeded or Failed"
May 20 05:27:50.503: INFO: deleting Pod "azurefile-4162"/"azurefile-volume-tester-hgkgh"
May 20 05:27:50.625: INFO: Pod azurefile-volume-tester-hgkgh has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-hgkgh in namespace azurefile-4162
May 20 05:27:50.743: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "azurefile-4162" for this suite.
... skipping 229 lines ...
Platform: linux/amd64

Streaming logs below:
I0520 05:05:25.491819       1 azurefile.go:274] driver userAgent: file.csi.azure.com/e2e-7c75002423fc579c4a5870e30aea9e5666557c59 gc/go1.18.2 (amd64-linux) e2e-test
I0520 05:05:25.492380       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0520 05:05:25.535433       1 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 42 milliseconds
I0520 05:05:25.536058       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
I0520 05:05:25.536101       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0520 05:05:25.536118       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0520 05:05:25.536194       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0520 05:05:25.537162       1 azure_auth.go:245] Using AzurePublicCloud environment
I0520 05:05:25.537227       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0520 05:05:25.537354       1 azure_diskclient.go:68] Azure DisksClient using API version: 2021-04-01
... skipping 4001 lines ...
Platform: windows/amd64

Streaming logs below:
I0520 05:05:49.220484    7164 azurefile.go:274] driver userAgent: file.csi.azure.com/e2e-7c75002423fc579c4a5870e30aea9e5666557c59 gc/go1.18.2 (amd64-windows) e2e-test
I0520 05:05:49.237791    7164 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0520 05:05:49.263748    7164 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 15 milliseconds
I0520 05:05:49.266267    7164 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
I0520 05:05:49.266309    7164 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0520 05:05:49.266344    7164 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0520 05:05:49.266643    7164 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0520 05:05:49.269561    7164 azure_auth.go:245] Using AzurePublicCloud environment
I0520 05:05:49.269561    7164 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0520 05:05:49.271847    7164 azure_diskclient.go:68] Azure DisksClient using API version: 2021-04-01
... skipping 155 lines ...
I0520 05:13:54.197501    7164 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0520 05:13:54.197501    7164 utils.go:77] GRPC request: {}
I0520 05:13:54.197501    7164 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0520 05:13:54.208164    7164 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0520 05:13:54.208164    7164 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\azurefile-2540-file.csi.azure.com-preprovsioned-pv-pznq4\\globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_id":"capz-bfmcxl#fc4b4aa9ef3184432ab402b#pre-provisioned-multiple-pods##pre-provisioned-multiple-pods#azurefile-25401"}
I0520 05:13:54.223841    7164 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-25401/secrets/azure-storage-account-fc4b4aa9ef3184432ab402b-secret 404 Not Found in 14 milliseconds
I0520 05:13:54.224571    7164 azurefile.go:634] could not get account(fc4b4aa9ef3184432ab402b) key from secret(azure-storage-account-fc4b4aa9ef3184432ab402b-secret), error: could not get secret(azure-storage-account-fc4b4aa9ef3184432ab402b-secret): secrets "azure-storage-account-fc4b4aa9ef3184432ab402b-secret" not found, use cluster identity to get account key instead
(2022-05-20T05:13:54.2258786Z) INFO: REQUEST: POST https://login.microsoftonline.com/097f89a0-9286-43d2-9a1a-08f1d49b1af8/oauth2/token
Content-Type: application/x-www-form-urlencoded
User-Agent: Go/go1.18.2 (amd64-windows) go-autorest/adal/v1.0.0
(2022-05-20T05:13:54.5550771Z) INFO: RESPONSE: 200 https://login.microsoftonline.com/097f89a0-9286-43d2-9a1a-08f1d49b1af8/oauth2/token
Expires: -1
X-Content-Type-Options: nosniff
... skipping 1772 lines ...
I0520 05:27:27.481754    7164 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0520 05:27:27.481754    7164 utils.go:77] GRPC request: {}
I0520 05:27:27.482449    7164 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0520 05:27:27.483630    7164 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0520 05:27:27.483630    7164 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\287822b3-d763-4003-b9df-d5d8d0b6af65\\volumes\\kubernetes.io~csi\\test-volume-1\\mount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/ephemeral":"true","csi.storage.k8s.io/pod.name":"azurefile-volume-tester-hgkgh","csi.storage.k8s.io/pod.namespace":"azurefile-4162","csi.storage.k8s.io/pod.uid":"287822b3-d763-4003-b9df-d5d8d0b6af65","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"azure-storage-account-fc4b4aa9ef3184432ab402b-secret","server":"","shareName":"csi-inline-smb-volume"},"volume_id":"csi-925e0bb9beb3c2f650de38b655f61c970316cbca55639e0aa04b031ecf8f985a"}
I0520 05:27:27.483630    7164 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-925e0bb9beb3c2f650de38b655f61c970316cbca55639e0aa04b031ecf8f985a) mount on c:\var\lib\kubelet\pods\287822b3-d763-4003-b9df-d5d8d0b6af65\volumes\kubernetes.io~csi\test-volume-1\mount, VolumeContext: map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-hgkgh csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:287822b3-d763-4003-b9df-d5d8d0b6af65 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-fc4b4aa9ef3184432ab402b-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]
W0520 05:27:27.483630    7164 azurefile.go:564] parsing volumeID(csi-925e0bb9beb3c2f650de38b655f61c970316cbca55639e0aa04b031ecf8f985a) return with error: error parsing volume id: "csi-925e0bb9beb3c2f650de38b655f61c970316cbca55639e0aa04b031ecf8f985a", should at least contain two #
I0520 05:27:27.502185    7164 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-4162/secrets/azure-storage-account-fc4b4aa9ef3184432ab402b-secret 200 OK in 17 milliseconds
I0520 05:27:27.502185    7164 nodeserver.go:289] cifsMountPath(c:\var\lib\kubelet\pods\287822b3-d763-4003-b9df-d5d8d0b6af65\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-925e0bb9beb3c2f650de38b655f61c970316cbca55639e0aa04b031ecf8f985a) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-hgkgh csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:287822b3-d763-4003-b9df-d5d8d0b6af65 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-fc4b4aa9ef3184432ab402b-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]) mountflags([]) mountOptions([AZURE\fc4b4aa9ef3184432ab402b]) volumeMountGroup()
I0520 05:27:27.502185    7164 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\287822b3-d763-4003-b9df-d5d8d0b6af65\volumes\kubernetes.io~csi\test-volume-1\mount
I0520 05:27:27.502185    7164 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\287822b3-d763-4003-b9df-d5d8d0b6af65\volumes\kubernetes.io~csi\test-volume-1\mount
I0520 05:27:27.508620    7164 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\287822b3-d763-4003-b9df-d5d8d0b6af65\volumes\kubernetes.io~csi\test-volume-1\mount
I0520 05:27:27.509619    7164 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\287822b3-d763-4003-b9df-d5d8d0b6af65\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 129 lines ...
Platform: windows/amd64

Streaming logs below:
I0520 05:05:43.990942    6468 azurefile.go:274] driver userAgent: file.csi.azure.com/e2e-7c75002423fc579c4a5870e30aea9e5666557c59 gc/go1.18.2 (amd64-windows) e2e-test
I0520 05:05:44.026110    6468 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0520 05:05:45.061880    6468 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 1032 milliseconds
I0520 05:05:45.064509    6468 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
I0520 05:05:45.064509    6468 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0520 05:05:45.064509    6468 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0520 05:05:45.064509    6468 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0520 05:05:45.066458    6468 azure_auth.go:245] Using AzurePublicCloud environment
I0520 05:05:45.067617    6468 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0520 05:05:45.070309    6468 azure_diskclient.go:68] Azure DisksClient using API version: 2021-04-01
... skipping 652 lines ...

JUnit report was created: /logs/artifacts/junit_01.xml


Summarizing 1 Failure:

[Fail] Pre-Provisioned [It] should use a pre-provisioned volume and mount it as readOnly in a pod [file.csi.azure.com] [Windows] 
/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/pre_provisioned_read_only_volume_tester.go:59

Ran 19 of 34 Specs in 1468.185 seconds
FAIL! -- 18 Passed | 1 Failed | 0 Pending | 15 Skipped

You're using deprecated Ginkgo functionality:
=============================================
Ginkgo 2.0 is under active development and will introduce several new features, improvements, and a small handful of breaking changes.
A release candidate for 2.0 is now available and 2.0 should GA in Fall 2021.  Please give the RC a try and send us feedback!
  - To learn more, view the migration guide at https://github.com/onsi/ginkgo/blob/ver2/docs/MIGRATING_TO_V2.md
... skipping 5 lines ...
  If this change will be impactful to you please leave a comment on https://github.com/onsi/ginkgo/issues/711
  Learn more at: https://github.com/onsi/ginkgo/blob/ver2/docs/MIGRATING_TO_V2.md#removed-custom-reporters

To silence deprecations that can be silenced set the following environment variable:
  ACK_GINKGO_DEPRECATIONS=1.16.5

--- FAIL: TestE2E (1468.21s)
FAIL
FAIL	sigs.k8s.io/azurefile-csi-driver/test/e2e	1468.421s
FAIL
make: *** [Makefile:85: e2e-test] Error 1
make: Nothing to be done for 'kubectl'.
================ DUMPING LOGS FOR MANAGEMENT CLUSTER ================
Exported logs for cluster "capz" to:
/logs/artifacts/management-cluster
================ DUMPING LOGS FOR WORKLOAD CLUSTER (Linux) ==========
Deploying log-dump-daemonset
... skipping 89 lines ...