This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: test: support Win2022 test on capz
ResultFAILURE
Tests 1 failed / 18 succeeded
Started2022-04-24 03:21
Elapsed49m54s
Revisiona4adf09cad2fb6f0f2b049dcc975c9958c8f8c03
Refs 988

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] 6m58s

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 1153 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 148 lines ...
Git Commit: N/A
Go Version: go1.18.1
Platform: linux/amd64

Streaming logs below:
STEP: Building a namespace api object, basename azurefile
W0424 03:41:44.012082   37454 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret /: failed to get secret /: resource name may not be empty
I0424 03:41:44.013074   37454 driver.go:93] Enabling controller service capability: CREATE_DELETE_VOLUME
I0424 03:41:44.013098   37454 driver.go:93] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME
I0424 03:41:44.013103   37454 driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0424 03:41:44.013107   37454 driver.go:93] Enabling controller service capability: EXPAND_VOLUME
I0424 03:41:44.013111   37454 driver.go:93] Enabling controller service capability: SINGLE_NODE_MULTI_WRITER
I0424 03:41:44.013117   37454 driver.go:112] Enabling volume access mode: SINGLE_NODE_WRITER
... skipping 23 lines ...
Apr 24 03:42:09.935: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-4lgrw] to have phase Bound
Apr 24 03:42:10.038: INFO: PersistentVolumeClaim pvc-4lgrw found and phase=Bound (102.40296ms)
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
Apr 24 03:42:10.349: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-pmdcq" in namespace "azurefile-8081" to be "Error status code"
Apr 24 03:42:10.452: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 102.831332ms
Apr 24 03:42:12.555: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205817843s
Apr 24 03:42:14.659: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309647087s
Apr 24 03:42:16.765: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415472096s
Apr 24 03:42:18.878: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.529270582s
Apr 24 03:42:20.990: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.640569573s
... skipping 171 lines ...
Apr 24 03:48:24.087: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 6m13.737679525s
Apr 24 03:48:26.197: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 6m15.848301042s
Apr 24 03:48:28.308: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 6m17.95901096s
Apr 24 03:48:30.418: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 6m20.06902574s
Apr 24 03:48:32.528: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 6m22.178561676s
Apr 24 03:48:34.639: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Pending", Reason="", readiness=false. Elapsed: 6m24.289568147s
Apr 24 03:48:36.748: INFO: Pod "azurefile-volume-tester-pmdcq": Phase="Failed", Reason="", readiness=false. Elapsed: 6m26.399357042s
STEP: Saw pod failure
Apr 24 03:48:36.748: INFO: Pod "azurefile-volume-tester-pmdcq" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 24 03:48:36.917: INFO: deleting Pod "azurefile-8081"/"azurefile-volume-tester-pmdcq"
Apr 24 03:48:37.023: INFO: Pod azurefile-volume-tester-pmdcq has the following logs: 
STEP: Deleting pod azurefile-volume-tester-pmdcq in namespace azurefile-8081
Apr 24 03:48:37.156: INFO: deleting PVC "azurefile-8081"/"pvc-4lgrw"
Apr 24 03:48:37.156: INFO: Deleting PersistentVolumeClaim "pvc-4lgrw"
... skipping 7 lines ...
STEP: Collecting events from namespace "azurefile-8081".
STEP: Found 6 events.
Apr 24 03:48:37.683: INFO: At 2022-04-24 03:42:10 +0000 UTC - event for azurefile-volume-tester-pmdcq: {default-scheduler } Scheduled: Successfully assigned azurefile-8081/azurefile-volume-tester-pmdcq to capz-ugr6-9pcv2
Apr 24 03:48:37.683: INFO: At 2022-04-24 03:42:20 +0000 UTC - event for azurefile-volume-tester-pmdcq: {kubelet capz-ugr6-9pcv2} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Apr 24 03:48:37.683: INFO: At 2022-04-24 03:46:35 +0000 UTC - event for azurefile-volume-tester-pmdcq: {kubelet capz-ugr6-9pcv2} Pulled: Successfully pulled image "mcr.microsoft.com/windows/servercore:ltsc2022" in 4m14.0994017s
Apr 24 03:48:37.683: INFO: At 2022-04-24 03:46:35 +0000 UTC - event for azurefile-volume-tester-pmdcq: {kubelet capz-ugr6-9pcv2} Created: Created container volume-tester
Apr 24 03:48:37.683: INFO: At 2022-04-24 03:48:35 +0000 UTC - event for azurefile-volume-tester-pmdcq: {kubelet capz-ugr6-9pcv2} Failed: Error: context deadline exceeded
Apr 24 03:48:37.683: INFO: At 2022-04-24 03:48:35 +0000 UTC - event for azurefile-volume-tester-pmdcq: {kubelet capz-ugr6-9pcv2} Pulled: Container image "mcr.microsoft.com/windows/servercore:ltsc2022" already present on machine
Apr 24 03:48:37.785: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Apr 24 03:48:37.785: INFO: 
Apr 24 03:48:37.930: INFO: 
Logging node info for node capz-ugr6-7rrzc
Apr 24 03:48:38.048: INFO: Node Info: &Node{ObjectMeta:{capz-ugr6-7rrzc    31fecb08-240c-456a-b376-f85d7fdc7e16 2387 0 2022-04-24 03:36:27 +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-ugr6-7rrzc 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-ugr69h cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-ugr69h-md-win-6f86848d97-79r72 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-ugr69h-md-win-6f86848d97 csi.volume.kubernetes.io/nodeid:{"file.csi.azure.com":"capz-ugr6-7rrzc"} 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.109.65 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:9f:ed:6c volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{Go-http-client Update v1 2022-04-24 03:36:29 +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-04-24 03:36:31 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-04-24 03:37:46 +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":{}}}} } {calico-node.exe Update v1 2022-04-24 03:38:03 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {Go-http-client Update v1 2022-04-24 03:41:43 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{}}},"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-ugr69h/providers/Microsoft.Compute/virtualMachines/capz-ugr6-7rrzc,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-04-24 03:47:12 +0000 UTC,LastTransitionTime:2022-04-24 03:36:27 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-04-24 03:47:12 +0000 UTC,LastTransitionTime:2022-04-24 03:36:27 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-04-24 03:47:12 +0000 UTC,LastTransitionTime:2022-04-24 03:36:27 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-04-24 03:47:12 +0000 UTC,LastTransitionTime:2022-04-24 03:37:18 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-ugr6-7rrzc,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-ugr6-7rrzc,SystemUUID:0DC87077-2B59-49A6-8194-812BE028A3C3,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:[docker.io/sigwindowstools/calico-install@sha256:141afecd724eb757ee41593cc73f35fb19a2ce13cad73179cf3b1cef81a637d1 docker.io/sigwindowstools/calico-install:v3.22.1-hostprocess],SizeBytes:148096127,},ContainerImage{Names:[capzci.azurecr.io/azurefile-csi@sha256:b2a4dbd6161069ed2d330ae4f47a0228f2ce93597978b6f1bd8710ca2f4bb87b capzci.azurecr.io/azurefile-csi:e2e-dc18ffd8eae59dfd1bdb994fea7002b4fea6848c],SizeBytes:130302804,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:b8e6e2f190e58d6b61b7f2a19b0e2e17a377e5b9d7b9528e9b7953d9f9ab59bb docker.io/sigwindowstools/calico-node:v3.22.1-hostprocess],SizeBytes:128793648,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:dbec3a8166686b09b242176ab5b99e993da4126438bbce68147c3fd654f35662 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.4.0],SizeBytes:125554391,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:c96a6255c42766f6b8bb1a7cda02b0060ab1b20b2e2dafcc64ec09e7646745a6 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.5.0],SizeBytes:124471446,},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 112 lines ...
Apr 24 03:48:45.410: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-8f7sq] to have phase Bound
Apr 24 03:48:45.513: INFO: PersistentVolumeClaim pvc-8f7sq found and phase=Bound (102.664146ms)
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
Apr 24 03:48:45.824: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-9nxwm" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 24 03:48:45.927: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Pending", Reason="", readiness=false. Elapsed: 102.720166ms
Apr 24 03:48:48.034: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.210374823s
Apr 24 03:48:50.144: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.320043572s
Apr 24 03:48:52.249: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.425334665s
Apr 24 03:48:54.354: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.529786113s
Apr 24 03:48:56.458: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.634177318s
Apr 24 03:48:58.563: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Running", Reason="", readiness=true. Elapsed: 12.739057103s
Apr 24 03:49:00.668: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Running", Reason="", readiness=true. Elapsed: 14.843765355s
Apr 24 03:49:02.772: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Running", Reason="", readiness=true. Elapsed: 16.948335598s
Apr 24 03:49:04.876: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Running", Reason="", readiness=true. Elapsed: 19.052296533s
Apr 24 03:49:06.982: INFO: Pod "azurefile-volume-tester-9nxwm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.157648136s
STEP: Saw pod success
Apr 24 03:49:06.982: INFO: Pod "azurefile-volume-tester-9nxwm" 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"
Apr 24 03:49:07.192: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-t7q98] to have phase Bound
Apr 24 03:49:07.294: INFO: PersistentVolumeClaim pvc-t7q98 found and phase=Bound (102.233312ms)
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
Apr 24 03:49:07.603: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-8hgdr" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 24 03:49:07.707: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Pending", Reason="", readiness=false. Elapsed: 103.295536ms
Apr 24 03:49:09.811: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207278397s
Apr 24 03:49:11.915: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311756822s
Apr 24 03:49:14.020: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.416644887s
Apr 24 03:49:16.125: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.521716911s
Apr 24 03:49:18.229: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Running", Reason="", readiness=true. Elapsed: 10.626010543s
Apr 24 03:49:20.335: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Running", Reason="", readiness=true. Elapsed: 12.731794304s
Apr 24 03:49:22.439: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Running", Reason="", readiness=true. Elapsed: 14.836115666s
Apr 24 03:49:24.543: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Running", Reason="", readiness=true. Elapsed: 16.939959059s
Apr 24 03:49:26.647: INFO: Pod "azurefile-volume-tester-8hgdr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.043939071s
STEP: Saw pod success
Apr 24 03:49:26.647: INFO: Pod "azurefile-volume-tester-8hgdr" 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"
Apr 24 03:49:26.859: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-bcfn6] to have phase Bound
Apr 24 03:49:26.964: INFO: PersistentVolumeClaim pvc-bcfn6 found and phase=Bound (105.435853ms)
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
Apr 24 03:49:27.274: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-ttsw2" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 24 03:49:27.376: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Pending", Reason="", readiness=false. Elapsed: 102.325237ms
Apr 24 03:49:29.481: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.20667353s
Apr 24 03:49:31.585: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311409946s
Apr 24 03:49:33.691: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.417066687s
Apr 24 03:49:35.796: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.521861679s
Apr 24 03:49:37.900: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Running", Reason="", readiness=true. Elapsed: 10.62652821s
Apr 24 03:49:40.005: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Running", Reason="", readiness=true. Elapsed: 12.731240019s
Apr 24 03:49:42.110: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Running", Reason="", readiness=true. Elapsed: 14.836246899s
Apr 24 03:49:44.215: INFO: Pod "azurefile-volume-tester-ttsw2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.940714037s
STEP: Saw pod success
Apr 24 03:49:44.215: INFO: Pod "azurefile-volume-tester-ttsw2" 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"
Apr 24 03:49:44.425: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-mqv9l] to have phase Bound
Apr 24 03:49:44.527: INFO: PersistentVolumeClaim pvc-mqv9l found and phase=Bound (102.005244ms)
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
Apr 24 03:49:44.847: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-dmw5g" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 24 03:49:44.949: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Pending", Reason="", readiness=false. Elapsed: 101.60253ms
Apr 24 03:49:47.052: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205264746s
Apr 24 03:49:49.157: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309734824s
Apr 24 03:49:51.261: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Pending", Reason="", readiness=false. Elapsed: 6.413990923s
Apr 24 03:49:53.365: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Pending", Reason="", readiness=false. Elapsed: 8.5179406s
Apr 24 03:49:55.472: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Running", Reason="", readiness=true. Elapsed: 10.625083911s
Apr 24 03:49:57.577: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Running", Reason="", readiness=true. Elapsed: 12.729927821s
Apr 24 03:49:59.682: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Running", Reason="", readiness=true. Elapsed: 14.834576007s
Apr 24 03:50:01.787: INFO: Pod "azurefile-volume-tester-dmw5g": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.939676346s
STEP: Saw pod success
Apr 24 03:50:01.787: INFO: Pod "azurefile-volume-tester-dmw5g" 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"
Apr 24 03:50:01.998: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-kjlfg] to have phase Bound
Apr 24 03:50:02.100: INFO: PersistentVolumeClaim pvc-kjlfg found and phase=Bound (101.716273ms)
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
Apr 24 03:50:02.411: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-pmdtd" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 24 03:50:02.513: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Pending", Reason="", readiness=false. Elapsed: 102.079768ms
Apr 24 03:50:04.625: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.214126988s
Apr 24 03:50:06.729: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.318286373s
Apr 24 03:50:08.835: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Pending", Reason="", readiness=false. Elapsed: 6.423802334s
Apr 24 03:50:10.939: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Pending", Reason="", readiness=false. Elapsed: 8.52860742s
Apr 24 03:50:13.046: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Running", Reason="", readiness=true. Elapsed: 10.635351839s
Apr 24 03:50:15.151: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Running", Reason="", readiness=true. Elapsed: 12.740617658s
Apr 24 03:50:17.256: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Running", Reason="", readiness=true. Elapsed: 14.845684022s
Apr 24 03:50:19.360: INFO: Pod "azurefile-volume-tester-pmdtd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.949027252s
STEP: Saw pod success
Apr 24 03:50:19.360: INFO: Pod "azurefile-volume-tester-pmdtd" 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"
Apr 24 03:50:19.566: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-tmsnn] to have phase Bound
Apr 24 03:50:19.668: INFO: PersistentVolumeClaim pvc-tmsnn found and phase=Bound (102.565981ms)
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
Apr 24 03:50:19.978: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-x5h5c" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 24 03:50:20.080: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Pending", Reason="", readiness=false. Elapsed: 102.451984ms
Apr 24 03:50:22.185: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207255457s
Apr 24 03:50:24.289: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311266961s
Apr 24 03:50:26.393: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415489685s
Apr 24 03:50:28.498: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Pending", Reason="", readiness=false. Elapsed: 8.520235175s
Apr 24 03:50:30.603: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Running", Reason="", readiness=true. Elapsed: 10.625155707s
Apr 24 03:50:32.708: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Running", Reason="", readiness=true. Elapsed: 12.730526812s
Apr 24 03:50:34.813: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Running", Reason="", readiness=true. Elapsed: 14.835146155s
Apr 24 03:50:36.918: INFO: Pod "azurefile-volume-tester-x5h5c": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.93981682s
STEP: Saw pod success
Apr 24 03:50:36.918: INFO: Pod "azurefile-volume-tester-x5h5c" satisfied condition "Succeeded or Failed"
Apr 24 03:50:36.918: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-x5h5c"
Apr 24 03:50:37.040: INFO: Pod azurefile-volume-tester-x5h5c has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-x5h5c in namespace azurefile-2540
Apr 24 03:50:37.157: INFO: deleting PVC "azurefile-2540"/"pvc-tmsnn"
Apr 24 03:50:37.157: INFO: Deleting PersistentVolumeClaim "pvc-tmsnn"
... skipping 148 lines ...
Apr 24 03:50:49.475: INFO: PersistentVolumeClaim pvc-rhfv6 found but phase is Pending instead of Bound.
Apr 24 03:50:51.581: INFO: PersistentVolumeClaim pvc-rhfv6 found and phase=Bound (2.208376897s)
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
Apr 24 03:50:51.891: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-7vclv" in namespace "azurefile-5466" to be "Succeeded or Failed"
Apr 24 03:50:51.994: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Pending", Reason="", readiness=false. Elapsed: 103.295057ms
Apr 24 03:50:54.099: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207934804s
Apr 24 03:50:56.205: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.313723723s
Apr 24 03:50:58.310: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.419325096s
Apr 24 03:51:00.415: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.523915319s
Apr 24 03:51:02.520: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Running", Reason="", readiness=true. Elapsed: 10.629415608s
Apr 24 03:51:04.625: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Running", Reason="", readiness=true. Elapsed: 12.734058804s
Apr 24 03:51:06.729: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Running", Reason="", readiness=true. Elapsed: 14.837912349s
Apr 24 03:51:08.833: INFO: Pod "azurefile-volume-tester-7vclv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.941643089s
STEP: Saw pod success
Apr 24 03:51:08.833: INFO: Pod "azurefile-volume-tester-7vclv" satisfied condition "Succeeded or Failed"
Apr 24 03:51:08.833: INFO: deleting Pod "azurefile-5466"/"azurefile-volume-tester-7vclv"
Apr 24 03:51:08.956: INFO: Pod azurefile-volume-tester-7vclv has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-7vclv in namespace azurefile-5466
Apr 24 03:51:09.068: INFO: deleting PVC "azurefile-5466"/"pvc-rhfv6"
Apr 24 03:51:09.068: INFO: Deleting PersistentVolumeClaim "pvc-rhfv6"
... skipping 33 lines ...
Apr 24 03:51:12.821: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-kw6h9] to have phase Bound
Apr 24 03:51:12.923: INFO: PersistentVolumeClaim pvc-kw6h9 found and phase=Bound (102.341125ms)
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
Apr 24 03:51:13.231: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bzv8f" in namespace "azurefile-2790" to be "Succeeded or Failed"
Apr 24 03:51:13.333: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Pending", Reason="", readiness=false. Elapsed: 102.16139ms
Apr 24 03:51:15.436: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Pending", Reason="", readiness=false. Elapsed: 2.204814493s
Apr 24 03:51:17.540: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309432709s
Apr 24 03:51:19.645: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Pending", Reason="", readiness=false. Elapsed: 6.41403358s
Apr 24 03:51:21.749: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Pending", Reason="", readiness=false. Elapsed: 8.518184035s
Apr 24 03:51:23.854: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Running", Reason="", readiness=true. Elapsed: 10.622710577s
Apr 24 03:51:25.958: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Running", Reason="", readiness=true. Elapsed: 12.726578768s
Apr 24 03:51:28.062: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Running", Reason="", readiness=true. Elapsed: 14.830534967s
Apr 24 03:51:30.166: INFO: Pod "azurefile-volume-tester-bzv8f": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.935346377s
STEP: Saw pod success
Apr 24 03:51:30.166: INFO: Pod "azurefile-volume-tester-bzv8f" satisfied condition "Succeeded or Failed"
Apr 24 03:51:30.166: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-bzv8f"
Apr 24 03:51:30.279: INFO: Pod azurefile-volume-tester-bzv8f has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-bzv8f in namespace azurefile-2790
Apr 24 03:51:30.392: INFO: deleting PVC "azurefile-2790"/"pvc-kw6h9"
Apr 24 03:51:30.393: INFO: Deleting PersistentVolumeClaim "pvc-kw6h9"
... skipping 131 lines ...
Apr 24 03:53:31.994: INFO: PersistentVolumeClaim pvc-9v4w8 found but phase is Pending instead of Bound.
Apr 24 03:53:34.098: INFO: PersistentVolumeClaim pvc-9v4w8 found and phase=Bound (1m36.895604717s)
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
Apr 24 03:53:34.408: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-vvc2c" in namespace "azurefile-5194" to be "Succeeded or Failed"
Apr 24 03:53:34.511: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Pending", Reason="", readiness=false. Elapsed: 102.575596ms
Apr 24 03:53:36.614: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Pending", Reason="", readiness=false. Elapsed: 2.20583672s
Apr 24 03:53:38.717: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Pending", Reason="", readiness=false. Elapsed: 4.308206906s
Apr 24 03:53:40.821: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Pending", Reason="", readiness=false. Elapsed: 6.412602941s
Apr 24 03:53:42.932: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Pending", Reason="", readiness=false. Elapsed: 8.52337358s
Apr 24 03:53:45.041: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Pending", Reason="", readiness=false. Elapsed: 10.632894919s
Apr 24 03:53:47.145: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Running", Reason="", readiness=true. Elapsed: 12.736824314s
Apr 24 03:53:49.250: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Running", Reason="", readiness=true. Elapsed: 14.841302931s
Apr 24 03:53:51.354: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Running", Reason="", readiness=true. Elapsed: 16.945372271s
Apr 24 03:53:53.458: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Running", Reason="", readiness=true. Elapsed: 19.049852152s
Apr 24 03:53:55.562: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.153632811s
STEP: Saw pod success
Apr 24 03:53:55.562: INFO: Pod "azurefile-volume-tester-vvc2c" satisfied condition "Succeeded or Failed"
Apr 24 03:53:55.562: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-vvc2c" in namespace "azurefile-5194" to be "Succeeded or Failed"
Apr 24 03:53:55.666: INFO: Pod "azurefile-volume-tester-vvc2c": Phase="Succeeded", Reason="", readiness=false. Elapsed: 103.774731ms
STEP: Saw pod success
Apr 24 03:53:55.666: INFO: Pod "azurefile-volume-tester-vvc2c" satisfied condition "Succeeded or Failed"
Apr 24 03:53:55.666: INFO: deleting Pod "azurefile-5194"/"azurefile-volume-tester-vvc2c"
Apr 24 03:53:55.795: INFO: Pod azurefile-volume-tester-vvc2c has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-vvc2c in namespace azurefile-5194
Apr 24 03:53:55.912: INFO: deleting PVC "azurefile-5194"/"pvc-9v4w8"
Apr 24 03:53:55.912: INFO: Deleting PersistentVolumeClaim "pvc-9v4w8"
... skipping 34 lines ...
Apr 24 03:53:58.770: INFO: PersistentVolumeClaim pvc-jt666 found but phase is Pending instead of Bound.
Apr 24 03:54:00.873: INFO: PersistentVolumeClaim pvc-jt666 found and phase=Bound (2.206537638s)
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
Apr 24 03:54:01.190: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-52h4z" in namespace "azurefile-1353" to be "Succeeded or Failed"
Apr 24 03:54:01.292: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Pending", Reason="", readiness=false. Elapsed: 102.123002ms
Apr 24 03:54:03.396: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206176653s
Apr 24 03:54:05.501: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310888136s
Apr 24 03:54:07.605: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415136586s
Apr 24 03:54:09.709: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Pending", Reason="", readiness=false. Elapsed: 8.519518767s
Apr 24 03:54:11.814: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Pending", Reason="", readiness=false. Elapsed: 10.624435057s
Apr 24 03:54:13.919: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Pending", Reason="", readiness=false. Elapsed: 12.728989505s
Apr 24 03:54:16.023: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Running", Reason="", readiness=true. Elapsed: 14.833219952s
Apr 24 03:54:18.128: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Running", Reason="", readiness=true. Elapsed: 16.93840971s
Apr 24 03:54:20.232: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Running", Reason="", readiness=true. Elapsed: 19.042059708s
Apr 24 03:54:22.341: INFO: Pod "azurefile-volume-tester-52h4z": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.150968387s
STEP: Saw pod success
Apr 24 03:54:22.341: INFO: Pod "azurefile-volume-tester-52h4z" satisfied condition "Succeeded or Failed"
Apr 24 03:54:22.341: INFO: deleting Pod "azurefile-1353"/"azurefile-volume-tester-52h4z"
Apr 24 03:54:22.459: INFO: Pod azurefile-volume-tester-52h4z has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-52h4z in namespace azurefile-1353
Apr 24 03:54:22.580: INFO: deleting PVC "azurefile-1353"/"pvc-jt666"
Apr 24 03:54:22.580: INFO: Deleting PersistentVolumeClaim "pvc-jt666"
... skipping 115 lines ...
Apr 24 03:55:25.431: INFO: PersistentVolumeClaim pvc-4cv2b found but phase is Pending instead of Bound.
Apr 24 03:55:27.534: INFO: PersistentVolumeClaim pvc-4cv2b found and phase=Bound (21.140229204s)
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
Apr 24 03:55:27.848: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-lcp2w" in namespace "azurefile-156" to be "Error status code"
Apr 24 03:55:27.952: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Pending", Reason="", readiness=false. Elapsed: 103.874558ms
Apr 24 03:55:30.055: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206897237s
Apr 24 03:55:32.160: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311758844s
Apr 24 03:55:34.264: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415503867s
Apr 24 03:55:36.369: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Pending", Reason="", readiness=false. Elapsed: 8.520948396s
Apr 24 03:55:38.473: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Running", Reason="", readiness=true. Elapsed: 10.62506278s
Apr 24 03:55:40.582: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Running", Reason="", readiness=true. Elapsed: 12.733289517s
Apr 24 03:55:42.688: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Running", Reason="", readiness=true. Elapsed: 14.839460131s
Apr 24 03:55:44.793: INFO: Pod "azurefile-volume-tester-lcp2w": Phase="Failed", Reason="", readiness=false. Elapsed: 16.944327683s
STEP: Saw pod failure
Apr 24 03:55:44.793: INFO: Pod "azurefile-volume-tester-lcp2w" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 24 03:55:44.908: INFO: deleting Pod "azurefile-156"/"azurefile-volume-tester-lcp2w"
Apr 24 03:55:45.014: INFO: Pod azurefile-volume-tester-lcp2w 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 ...
Apr 24 03:56:58.902: INFO: PersistentVolumeClaim pvc-lqpzc found but phase is Pending instead of Bound.
Apr 24 03:57:01.006: INFO: PersistentVolumeClaim pvc-lqpzc found and phase=Bound (2.208146426s)
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
Apr 24 03:57:01.315: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-scvq4" in namespace "azurefile-2546" to be "Succeeded or Failed"
Apr 24 03:57:01.422: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Pending", Reason="", readiness=false. Elapsed: 107.16503ms
Apr 24 03:57:03.525: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.210836848s
Apr 24 03:57:05.635: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.320088145s
Apr 24 03:57:07.740: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.425396829s
Apr 24 03:57:09.846: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.53124219s
Apr 24 03:57:11.950: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Running", Reason="", readiness=true. Elapsed: 10.635924944s
Apr 24 03:57:14.057: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Running", Reason="", readiness=true. Elapsed: 12.742618337s
Apr 24 03:57:16.161: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Running", Reason="", readiness=true. Elapsed: 14.846038043s
Apr 24 03:57:18.266: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Running", Reason="", readiness=true. Elapsed: 16.951169384s
Apr 24 03:57:20.370: INFO: Pod "azurefile-volume-tester-scvq4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.055201633s
STEP: Saw pod success
Apr 24 03:57:20.370: INFO: Pod "azurefile-volume-tester-scvq4" 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
Apr 24 03:57:51.546: INFO: deleting Pod "azurefile-2546"/"azurefile-volume-tester-scvq4"
... skipping 302 lines ...
Apr 24 03:58:22.421: INFO: PersistentVolumeClaim pvc-z5g5n found but phase is Pending instead of Bound.
Apr 24 03:58:24.529: INFO: PersistentVolumeClaim pvc-z5g5n found and phase=Bound (2.210764553s)
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
Apr 24 03:58:24.845: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-s9zg5" in namespace "azurefile-9183" to be "Succeeded or Failed"
Apr 24 03:58:24.949: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Pending", Reason="", readiness=false. Elapsed: 103.85051ms
Apr 24 03:58:27.054: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.208529124s
Apr 24 03:58:29.158: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.312579757s
Apr 24 03:58:31.263: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.417229823s
Apr 24 03:58:33.368: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.523111414s
Apr 24 03:58:35.477: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.63189692s
Apr 24 03:58:37.582: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Pending", Reason="", readiness=false. Elapsed: 12.736583845s
Apr 24 03:58:39.688: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Running", Reason="", readiness=true. Elapsed: 14.842891478s
Apr 24 03:58:41.793: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Running", Reason="", readiness=true. Elapsed: 16.948152916s
Apr 24 03:58:43.898: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Running", Reason="", readiness=true. Elapsed: 19.053124353s
Apr 24 03:58:46.002: INFO: Pod "azurefile-volume-tester-s9zg5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.157088792s
STEP: Saw pod success
Apr 24 03:58:46.002: INFO: Pod "azurefile-volume-tester-s9zg5" satisfied condition "Succeeded or Failed"
Apr 24 03:58:46.002: INFO: deleting Pod "azurefile-9183"/"azurefile-volume-tester-s9zg5"
Apr 24 03:58:46.117: INFO: Pod azurefile-volume-tester-s9zg5 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-s9zg5 in namespace azurefile-9183
Apr 24 03:58:46.245: INFO: deleting PVC "azurefile-9183"/"pvc-z5g5n"
Apr 24 03:58:46.246: INFO: Deleting PersistentVolumeClaim "pvc-z5g5n"
... skipping 90 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/24 03:58:53 Check successfully
Apr 24 03:58:53.613: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/24 03:58:53 run script: test/utils/get_storage_account_secret_name.sh
2022/04/24 03:58:54 got output: azure-storage-account-f4d63fe6e172c4030b75bab-secret
, error: <nil>
2022/04/24 03:58:54 got storage account secret name: azure-storage-account-f4d63fe6e172c4030b75bab-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"
Apr 24 03:58:54.438: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-2rlph] to have phase Bound
Apr 24 03:58:54.545: INFO: PersistentVolumeClaim pvc-2rlph found but phase is Pending instead of Bound.
Apr 24 03:58:56.648: INFO: PersistentVolumeClaim pvc-2rlph found and phase=Bound (2.210544628s)
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
Apr 24 03:58:56.962: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n5tfz" in namespace "azurefile-1968" to be "Succeeded or Failed"
Apr 24 03:58:57.065: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Pending", Reason="", readiness=false. Elapsed: 102.832294ms
Apr 24 03:58:59.168: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206056497s
Apr 24 03:59:01.273: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310951582s
Apr 24 03:59:03.378: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415736593s
Apr 24 03:59:05.486: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Pending", Reason="", readiness=false. Elapsed: 8.523873206s
Apr 24 03:59:07.590: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Running", Reason="", readiness=true. Elapsed: 10.627857022s
Apr 24 03:59:09.693: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Running", Reason="", readiness=true. Elapsed: 12.731183813s
Apr 24 03:59:11.798: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Running", Reason="", readiness=true. Elapsed: 14.83573577s
Apr 24 03:59:13.902: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.939990645s
STEP: Saw pod success
Apr 24 03:59:13.902: INFO: Pod "azurefile-volume-tester-n5tfz" satisfied condition "Succeeded or Failed"
Apr 24 03:59:13.902: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n5tfz" in namespace "azurefile-1968" to be "Succeeded or Failed"
Apr 24 03:59:14.006: INFO: Pod "azurefile-volume-tester-n5tfz": Phase="Succeeded", Reason="", readiness=false. Elapsed: 103.88416ms
STEP: Saw pod success
Apr 24 03:59:14.006: INFO: Pod "azurefile-volume-tester-n5tfz" satisfied condition "Succeeded or Failed"
Apr 24 03:59:14.006: INFO: deleting Pod "azurefile-1968"/"azurefile-volume-tester-n5tfz"
Apr 24 03:59:14.131: INFO: Pod azurefile-volume-tester-n5tfz has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-n5tfz in namespace azurefile-1968
Apr 24 03:59:14.255: INFO: deleting PVC "azurefile-1968"/"pvc-2rlph"
Apr 24 03:59:14.255: INFO: Deleting PersistentVolumeClaim "pvc-2rlph"
... skipping 43 lines ...
Apr 24 03:59:35.787: INFO: PersistentVolumeClaim pvc-zfn77 found but phase is Pending instead of Bound.
Apr 24 03:59:37.890: INFO: PersistentVolumeClaim pvc-zfn77 found and phase=Bound (21.137575412s)
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
Apr 24 03:59:38.205: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-5xxc5" in namespace "azurefile-4657" to be "Succeeded or Failed"
Apr 24 03:59:38.307: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Pending", Reason="", readiness=false. Elapsed: 101.763988ms
Apr 24 03:59:40.411: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.20567596s
Apr 24 03:59:42.516: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310480716s
Apr 24 03:59:44.621: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.416083529s
Apr 24 03:59:46.725: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.520245999s
Apr 24 03:59:48.830: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Running", Reason="", readiness=true. Elapsed: 10.625009123s
Apr 24 03:59:50.934: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Running", Reason="", readiness=true. Elapsed: 12.729341869s
Apr 24 03:59:53.040: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Running", Reason="", readiness=true. Elapsed: 14.834425435s
Apr 24 03:59:55.144: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.93902916s
STEP: Saw pod success
Apr 24 03:59:55.144: INFO: Pod "azurefile-volume-tester-5xxc5" satisfied condition "Succeeded or Failed"
Apr 24 03:59:55.144: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-5xxc5" in namespace "azurefile-4657" to be "Succeeded or Failed"
Apr 24 03:59:55.248: INFO: Pod "azurefile-volume-tester-5xxc5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 103.888038ms
STEP: Saw pod success
Apr 24 03:59:55.248: INFO: Pod "azurefile-volume-tester-5xxc5" satisfied condition "Succeeded or Failed"
Apr 24 03:59:55.249: INFO: deleting Pod "azurefile-4657"/"azurefile-volume-tester-5xxc5"
Apr 24 03:59:55.364: INFO: Pod azurefile-volume-tester-5xxc5 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-5xxc5 in namespace azurefile-4657
Apr 24 03:59:55.481: INFO: deleting PVC "azurefile-4657"/"pvc-zfn77"
Apr 24 03:59:55.481: INFO: Deleting PersistentVolumeClaim "pvc-zfn77"
... skipping 74 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/24 04:01:24 Check successfully
Apr 24 04:01:24.036: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/24 04:01:24 run script: test/utils/get_storage_account_secret_name.sh
2022/04/24 04:01:24 got output: azure-storage-account-f4d63fe6e172c4030b75bab-secret
, error: <nil>
2022/04/24 04:01:24 got storage account secret name: azure-storage-account-f4d63fe6e172c4030b75bab-secret
STEP: Successfully provisioned AzureFile volume: "capz-ugr69h#f4d63fe6e172c4030b75bab#csi-inline-smb-volume##csi-inline-smb-volume#azurefile-4162"

STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 24 04:01:26.362: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-9s6wn" in namespace "azurefile-4162" to be "Succeeded or Failed"
Apr 24 04:01:26.465: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Pending", Reason="", readiness=false. Elapsed: 103.002108ms
Apr 24 04:01:28.569: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207232831s
Apr 24 04:01:30.674: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.312302078s
Apr 24 04:01:32.783: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.421215544s
Apr 24 04:01:34.897: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.535060566s
Apr 24 04:01:37.002: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Running", Reason="", readiness=true. Elapsed: 10.640083908s
Apr 24 04:01:39.113: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Running", Reason="", readiness=true. Elapsed: 12.751449355s
Apr 24 04:01:41.218: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Running", Reason="", readiness=true. Elapsed: 14.8557824s
Apr 24 04:01:43.323: INFO: Pod "azurefile-volume-tester-9s6wn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.961148507s
STEP: Saw pod success
Apr 24 04:01:43.323: INFO: Pod "azurefile-volume-tester-9s6wn" satisfied condition "Succeeded or Failed"
Apr 24 04:01:43.323: INFO: deleting Pod "azurefile-4162"/"azurefile-volume-tester-9s6wn"
Apr 24 04:01:43.439: INFO: Pod azurefile-volume-tester-9s6wn has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-9s6wn in namespace azurefile-4162
Apr 24 04:01:43.556: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "azurefile-4162" for this suite.
... skipping 227 lines ...
Platform: linux/amd64

Streaming logs below:
I0424 03:41:01.196559       1 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-dc18ffd8eae59dfd1bdb994fea7002b4fea6848c gc/go1.18.1 (amd64-linux) e2e-test
I0424 03:41:01.197282       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0424 03:41:01.210576       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 13 milliseconds
W0424 03:41:01.211198       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
I0424 03:41:01.211232       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0424 03:41:01.211247       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0424 03:41:01.211399       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0424 03:41:01.212403       1 azure_auth.go:245] Using AzurePublicCloud environment
I0424 03:41:01.212473       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0424 03:41:01.212563       1 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 2834 lines ...
Platform: windows/amd64

Streaming logs below:
I0424 03:41:42.563401    4796 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-dc18ffd8eae59dfd1bdb994fea7002b4fea6848c gc/go1.18.1 (amd64-windows) e2e-test
I0424 03:41:42.578916    4796 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0424 03:41:42.603520    4796 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 20 milliseconds
W0424 03:41:42.604176    4796 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
I0424 03:41:42.604176    4796 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0424 03:41:42.604176    4796 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0424 03:41:42.604176    4796 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0424 03:41:42.605734    4796 azure_auth.go:245] Using AzurePublicCloud environment
I0424 03:41:42.606483    4796 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0424 03:41:42.607485    4796 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 160 lines ...
Platform: windows/amd64

Streaming logs below:
I0424 03:41:39.206433    6600 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-dc18ffd8eae59dfd1bdb994fea7002b4fea6848c gc/go1.18.1 (amd64-windows) e2e-test
I0424 03:41:39.220206    6600 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0424 03:41:39.247367    6600 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 25 milliseconds
W0424 03:41:39.248436    6600 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
I0424 03:41:39.248436    6600 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0424 03:41:39.248436    6600 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0424 03:41:39.248436    6600 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0424 03:41:39.250119    6600 azure_auth.go:245] Using AzurePublicCloud environment
I0424 03:41:39.250731    6600 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0424 03:41:39.252473    6600 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 142 lines ...
I0424 03:48:46.038821    6600 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0424 03:48:46.038853    6600 utils.go:77] GRPC request: {}
I0424 03:48:46.038920    6600 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0424 03:48:46.044206    6600 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0424 03:48:46.044206    6600 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\azurefile-2540-file.csi.azure.com-preprovsioned-pv-qnxbt\\globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_id":"capz-ugr69h#f4d63fe6e172c4030b75bab#pre-provisioned-multiple-pods##pre-provisioned-multiple-pods#azurefile-25401"}
I0424 03:48:46.060016    6600 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-25401/secrets/azure-storage-account-f4d63fe6e172c4030b75bab-secret 404 Not Found in 15 milliseconds
I0424 03:48:46.060016    6600 azurefile.go:625] could not get account(f4d63fe6e172c4030b75bab) key from secret(azure-storage-account-f4d63fe6e172c4030b75bab-secret), error: could not get secret(azure-storage-account-f4d63fe6e172c4030b75bab-secret): secrets "azure-storage-account-f4d63fe6e172c4030b75bab-secret" not found, use cluster identity to get account key instead
(2022-04-24T03:48:46.0611585Z) 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.1 (amd64-windows) go-autorest/adal/v1.0.0
(2022-04-24T03:48:46.4728250Z) INFO: RESPONSE: 200 https://login.microsoftonline.com/097f89a0-9286-43d2-9a1a-08f1d49b1af8/oauth2/token
Content-Type: application/json; charset=utf-8
Strict-Transport-Security: max-age=31536000; includeSubDomains
... skipping 1751 lines ...
I0424 04:01:26.609227    6600 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0424 04:01:26.609227    6600 utils.go:77] GRPC request: {}
I0424 04:01:26.609875    6600 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0424 04:01:26.615234    6600 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0424 04:01:26.615234    6600 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\787ef99f-8a9e-4c91-a7ad-e72a6e093283\\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-9s6wn","csi.storage.k8s.io/pod.namespace":"azurefile-4162","csi.storage.k8s.io/pod.uid":"787ef99f-8a9e-4c91-a7ad-e72a6e093283","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"azure-storage-account-f4d63fe6e172c4030b75bab-secret","server":"","shareName":"csi-inline-smb-volume"},"volume_id":"csi-40c684a62814066abadbc8593be994632c6bdceed3edb580994c8b9834609932"}
I0424 04:01:26.615234    6600 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-40c684a62814066abadbc8593be994632c6bdceed3edb580994c8b9834609932) mount on c:\var\lib\kubelet\pods\787ef99f-8a9e-4c91-a7ad-e72a6e093283\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-9s6wn csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:787ef99f-8a9e-4c91-a7ad-e72a6e093283 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-f4d63fe6e172c4030b75bab-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]
W0424 04:01:26.615234    6600 azurefile.go:555] parsing volumeID(csi-40c684a62814066abadbc8593be994632c6bdceed3edb580994c8b9834609932) return with error: error parsing volume id: "csi-40c684a62814066abadbc8593be994632c6bdceed3edb580994c8b9834609932", should at least contain two #
I0424 04:01:26.626936    6600 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-4162/secrets/azure-storage-account-f4d63fe6e172c4030b75bab-secret 200 OK in 11 milliseconds
I0424 04:01:26.627201    6600 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\787ef99f-8a9e-4c91-a7ad-e72a6e093283\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-40c684a62814066abadbc8593be994632c6bdceed3edb580994c8b9834609932) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-9s6wn csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:787ef99f-8a9e-4c91-a7ad-e72a6e093283 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-f4d63fe6e172c4030b75bab-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]) mountflags([]) mountOptions([AZURE\f4d63fe6e172c4030b75bab]) volumeMountGroup()
I0424 04:01:26.627261    6600 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\787ef99f-8a9e-4c91-a7ad-e72a6e093283\volumes\kubernetes.io~csi\test-volume-1\mount
I0424 04:01:26.627287    6600 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\787ef99f-8a9e-4c91-a7ad-e72a6e093283\volumes\kubernetes.io~csi\test-volume-1\mount
I0424 04:01:26.628461    6600 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\787ef99f-8a9e-4c91-a7ad-e72a6e093283\volumes\kubernetes.io~csi\test-volume-1\mount
I0424 04:01:26.629496    6600 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\787ef99f-8a9e-4c91-a7ad-e72a6e093283\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 532 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 1364.511 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 (1364.52s)
FAIL
FAIL	sigs.k8s.io/azurefile-csi-driver/test/e2e	1364.601s
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 85 lines ...