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-28 06:41
Elapsed1h2m
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] 8m23s

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 672 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 131 lines ...
# Wait for the kubeconfig to become available.
timeout --foreground 300 bash -c "while ! kubectl get secrets | grep capz-2yvtmt-kubeconfig; do sleep 1; done"
capz-2yvtmt-kubeconfig                 cluster.x-k8s.io/secret               1      1s
# Get kubeconfig and store it locally.
kubectl get secrets capz-2yvtmt-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-2yvtmt-control-plane-tgbsq   NotReady   <none>   2s    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-2yvt-9hwxh condition met
node/capz-2yvt-gf8tx condition met
... skipping 35 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11156  100 11156    0     0  80840      0 --:--:-- --:--:-- --:--:-- 80840
Downloading https://get.helm.sh/helm-v3.8.2-linux-amd64.tar.gz
Verifying checksum... Done.
Preparing to install helm into /usr/local/bin
helm installed into /usr/local/bin/helm
docker pull capzci.azurecr.io/azurefile-csi:e2e-efeeec97c8f203798d85208d76b8003532bb7e77 || make container-all push-manifest
Error response from daemon: manifest for capzci.azurecr.io/azurefile-csi:e2e-efeeec97c8f203798d85208d76b8003532bb7e77 not found: manifest unknown: manifest tagged by "e2e-efeeec97c8f203798d85208d76b8003532bb7e77" is not found
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver'
CGO_ENABLED=0 GOOS=windows go build -a -ldflags "-X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.driverVersion=e2e-efeeec97c8f203798d85208d76b8003532bb7e77 -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.gitCommit=efeeec97c8f203798d85208d76b8003532bb7e77 -X sigs.k8s.io/azurefile-csi-driver/pkg/azurefile.buildDate=2022-04-28T06:57:49Z -s -w -extldflags '-static'" -mod vendor -o _output/amd64/azurefileplugin.exe ./pkg/azurefileplugin
docker buildx rm container-builder || true
error: no builder "container-builder" found
docker buildx create --use --name=container-builder
container-builder
# enable qemu for arm64 build
# https://github.com/docker/buildx/issues/464#issuecomment-741507760
docker run --privileged --rm tonistiigi/binfmt --uninstall qemu-aarch64
Unable to find image 'tonistiigi/binfmt:latest' locally
... skipping 2392 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
W0428 07:12:58.588921   38491 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret /: failed to get secret /: resource name may not be empty
I0428 07:12:58.591589   38491 driver.go:93] Enabling controller service capability: CREATE_DELETE_VOLUME
I0428 07:12:58.591616   38491 driver.go:93] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME
I0428 07:12:58.591623   38491 driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0428 07:12:58.591629   38491 driver.go:93] Enabling controller service capability: EXPAND_VOLUME
I0428 07:12:58.591635   38491 driver.go:93] Enabling controller service capability: SINGLE_NODE_MULTI_WRITER
I0428 07:12:58.591644   38491 driver.go:112] Enabling volume access mode: SINGLE_NODE_WRITER
... skipping 23 lines ...
Apr 28 07:13:25.156: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-4sh8v] to have phase Bound
Apr 28 07:13:25.210: INFO: PersistentVolumeClaim pvc-4sh8v found and phase=Bound (53.778905ms)
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 28 07:13:25.375: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-7765p" in namespace "azurefile-8081" to be "Error status code"
Apr 28 07:13:25.429: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 53.965979ms
Apr 28 07:13:27.484: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 2.1097596s
Apr 28 07:13:29.538: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163693493s
Apr 28 07:13:31.593: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218598977s
Apr 28 07:13:33.648: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 8.273277446s
Apr 28 07:13:35.707: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 10.33222228s
... skipping 218 lines ...
Apr 28 07:21:06.575: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 7m41.200458925s
Apr 28 07:21:08.634: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 7m43.259628874s
Apr 28 07:21:10.693: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 7m45.31831097s
Apr 28 07:21:12.752: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 7m47.377311314s
Apr 28 07:21:14.812: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 7m49.436901786s
Apr 28 07:21:16.870: INFO: Pod "azurefile-volume-tester-7765p": Phase="Pending", Reason="", readiness=false. Elapsed: 7m51.495209089s
Apr 28 07:21:18.929: INFO: Pod "azurefile-volume-tester-7765p": Phase="Failed", Reason="", readiness=false. Elapsed: 7m53.554479539s
STEP: Saw pod failure
Apr 28 07:21:18.929: INFO: Pod "azurefile-volume-tester-7765p" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 28 07:21:19.004: INFO: deleting Pod "azurefile-8081"/"azurefile-volume-tester-7765p"
Apr 28 07:21:19.062: INFO: Pod azurefile-volume-tester-7765p has the following logs: 
STEP: Deleting pod azurefile-volume-tester-7765p in namespace azurefile-8081
Apr 28 07:21:19.124: INFO: deleting PVC "azurefile-8081"/"pvc-4sh8v"
Apr 28 07:21:19.124: INFO: Deleting PersistentVolumeClaim "pvc-4sh8v"
... skipping 7 lines ...
STEP: Collecting events from namespace "azurefile-8081".
STEP: Found 6 events.
Apr 28 07:21:19.402: INFO: At 2022-04-28 07:13:25 +0000 UTC - event for azurefile-volume-tester-7765p: {default-scheduler } Scheduled: Successfully assigned azurefile-8081/azurefile-volume-tester-7765p to capz-2yvt-9hwxh
Apr 28 07:21:19.402: INFO: At 2022-04-28 07:13:37 +0000 UTC - event for azurefile-volume-tester-7765p: {kubelet capz-2yvt-9hwxh} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Apr 28 07:21:19.402: INFO: At 2022-04-28 07:19:17 +0000 UTC - event for azurefile-volume-tester-7765p: {kubelet capz-2yvt-9hwxh} Pulled: Successfully pulled image "mcr.microsoft.com/windows/servercore:ltsc2022" in 5m39.7130111s
Apr 28 07:21:19.402: INFO: At 2022-04-28 07:19:17 +0000 UTC - event for azurefile-volume-tester-7765p: {kubelet capz-2yvt-9hwxh} Created: Created container volume-tester
Apr 28 07:21:19.402: INFO: At 2022-04-28 07:21:17 +0000 UTC - event for azurefile-volume-tester-7765p: {kubelet capz-2yvt-9hwxh} Failed: Error: context deadline exceeded
Apr 28 07:21:19.402: INFO: At 2022-04-28 07:21:18 +0000 UTC - event for azurefile-volume-tester-7765p: {kubelet capz-2yvt-9hwxh} Pulled: Container image "mcr.microsoft.com/windows/servercore:ltsc2022" already present on machine
Apr 28 07:21:19.456: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Apr 28 07:21:19.456: INFO: 
Apr 28 07:21:19.532: INFO: 
Logging node info for node capz-2yvt-9hwxh
Apr 28 07:21:19.594: INFO: Node Info: &Node{ObjectMeta:{capz-2yvt-9hwxh    8a846f2c-0272-49ee-82c8-0e7910174dd4 3621 0 2022-04-28 06:55:16 +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:westus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-2yvt-9hwxh kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.20348 topology.kubernetes.io/region:westus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-2yvtmt cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-2yvtmt-md-win-588b9bbc78-hd5wk cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-2yvtmt-md-win-588b9bbc78 csi.volume.kubernetes.io/nodeid:{"file.csi.azure.com":"capz-2yvt-9hwxh"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.4/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.11.65 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:d8:e5:b4 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{Go-http-client Update v1 2022-04-28 06:55:17 +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-28 06:55:18 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-04-28 06:56:38 +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-28 06:57:42 +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-28 07:12:55 +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-2yvtmt/providers/Microsoft.Compute/virtualMachines/capz-2yvt-9hwxh,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-28 07:19:27 +0000 UTC,LastTransitionTime:2022-04-28 06:55:16 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-04-28 07:19:27 +0000 UTC,LastTransitionTime:2022-04-28 06:55:16 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-04-28 07:19:27 +0000 UTC,LastTransitionTime:2022-04-28 06:55:16 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-04-28 07:19:27 +0000 UTC,LastTransitionTime:2022-04-28 06:56:59 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-2yvt-9hwxh,},NodeAddress{Type:InternalIP,Address:10.1.0.4,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-2yvt-9hwxh,SystemUUID:2A09ABF3-6C8F-486E-A975-FE6CEB7F811A,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:378d85bd8e7388a777d25009f8523d1e95a5f544f131eaada83171045d5b2c1e mcr.microsoft.com/windows/servercore:ltsc2022],SizeBytes:2226956779,},ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:141afecd724eb757ee41593cc73f35fb19a2ce13cad73179cf3b1cef81a637d1 docker.io/sigwindowstools/calico-install:v3.22.1-hostprocess],SizeBytes:148096127,},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:eb968acbf2a202e8e13a92288849ac34d9e8ad5c254e06dddb9af8005f903d92 capzci.azurecr.io/azurefile-csi:e2e-efeeec97c8f203798d85208d76b8003532bb7e77],SizeBytes:130302726,},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 116 lines ...
Apr 28 07:21:24.214: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-rbmct] to have phase Bound
Apr 28 07:21:24.268: INFO: PersistentVolumeClaim pvc-rbmct found and phase=Bound (53.840841ms)
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 28 07:21:24.431: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-659dk" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 28 07:21:24.484: INFO: Pod "azurefile-volume-tester-659dk": Phase="Pending", Reason="", readiness=false. Elapsed: 53.385269ms
Apr 28 07:21:26.539: INFO: Pod "azurefile-volume-tester-659dk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107928772s
Apr 28 07:21:28.594: INFO: Pod "azurefile-volume-tester-659dk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163443772s
Apr 28 07:21:30.649: INFO: Pod "azurefile-volume-tester-659dk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218683423s
Apr 28 07:21:32.705: INFO: Pod "azurefile-volume-tester-659dk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.274625906s
Apr 28 07:21:34.761: INFO: Pod "azurefile-volume-tester-659dk": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330363124s
... skipping 2 lines ...
Apr 28 07:21:40.928: INFO: Pod "azurefile-volume-tester-659dk": Phase="Running", Reason="", readiness=true. Elapsed: 16.496942626s
Apr 28 07:21:42.982: INFO: Pod "azurefile-volume-tester-659dk": Phase="Running", Reason="", readiness=true. Elapsed: 18.551412358s
Apr 28 07:21:45.037: INFO: Pod "azurefile-volume-tester-659dk": Phase="Running", Reason="", readiness=true. Elapsed: 20.606471633s
Apr 28 07:21:47.092: INFO: Pod "azurefile-volume-tester-659dk": Phase="Running", Reason="", readiness=true. Elapsed: 22.661159823s
Apr 28 07:21:49.147: INFO: Pod "azurefile-volume-tester-659dk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 24.716083355s
STEP: Saw pod success
Apr 28 07:21:49.147: INFO: Pod "azurefile-volume-tester-659dk" 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 28 07:21:49.256: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-dp7gg] to have phase Bound
Apr 28 07:21:49.310: INFO: PersistentVolumeClaim pvc-dp7gg found and phase=Bound (53.680104ms)
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 28 07:21:49.473: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-666cr" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 28 07:21:49.527: INFO: Pod "azurefile-volume-tester-666cr": Phase="Pending", Reason="", readiness=false. Elapsed: 53.958036ms
Apr 28 07:21:51.581: INFO: Pod "azurefile-volume-tester-666cr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108520679s
Apr 28 07:21:53.636: INFO: Pod "azurefile-volume-tester-666cr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.1634943s
Apr 28 07:21:55.692: INFO: Pod "azurefile-volume-tester-666cr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219075582s
Apr 28 07:21:57.748: INFO: Pod "azurefile-volume-tester-666cr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.275028894s
Apr 28 07:21:59.804: INFO: Pod "azurefile-volume-tester-666cr": Phase="Pending", Reason="", readiness=false. Elapsed: 10.331109156s
Apr 28 07:22:01.859: INFO: Pod "azurefile-volume-tester-666cr": Phase="Running", Reason="", readiness=true. Elapsed: 12.386315279s
Apr 28 07:22:03.916: INFO: Pod "azurefile-volume-tester-666cr": Phase="Running", Reason="", readiness=true. Elapsed: 14.442764558s
Apr 28 07:22:05.971: INFO: Pod "azurefile-volume-tester-666cr": Phase="Running", Reason="", readiness=true. Elapsed: 16.49771719s
Apr 28 07:22:08.027: INFO: Pod "azurefile-volume-tester-666cr": Phase="Running", Reason="", readiness=true. Elapsed: 18.554067267s
Apr 28 07:22:10.084: INFO: Pod "azurefile-volume-tester-666cr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.610778392s
STEP: Saw pod success
Apr 28 07:22:10.084: INFO: Pod "azurefile-volume-tester-666cr" 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 28 07:22:10.198: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-4x4x5] to have phase Bound
Apr 28 07:22:10.252: INFO: PersistentVolumeClaim pvc-4x4x5 found and phase=Bound (53.96851ms)
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 28 07:22:10.422: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-v8c4f" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 28 07:22:10.475: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Pending", Reason="", readiness=false. Elapsed: 53.691104ms
Apr 28 07:22:12.531: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109644319s
Apr 28 07:22:14.587: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Pending", Reason="", readiness=false. Elapsed: 4.165204359s
Apr 28 07:22:16.647: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Pending", Reason="", readiness=false. Elapsed: 6.225670189s
Apr 28 07:22:18.703: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Pending", Reason="", readiness=false. Elapsed: 8.281677172s
Apr 28 07:22:20.759: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Pending", Reason="", readiness=false. Elapsed: 10.337190981s
Apr 28 07:22:22.814: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Running", Reason="", readiness=true. Elapsed: 12.392582124s
Apr 28 07:22:24.870: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Running", Reason="", readiness=true. Elapsed: 14.4480232s
Apr 28 07:22:26.927: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Running", Reason="", readiness=true. Elapsed: 16.505717096s
Apr 28 07:22:28.983: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Running", Reason="", readiness=true. Elapsed: 18.56125235s
Apr 28 07:22:31.038: INFO: Pod "azurefile-volume-tester-v8c4f": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.615859137s
STEP: Saw pod success
Apr 28 07:22:31.038: INFO: Pod "azurefile-volume-tester-v8c4f" 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 28 07:22:31.148: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-ntsv2] to have phase Bound
Apr 28 07:22:31.202: INFO: PersistentVolumeClaim pvc-ntsv2 found and phase=Bound (53.901945ms)
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 28 07:22:31.366: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-ng4ww" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 28 07:22:31.421: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Pending", Reason="", readiness=false. Elapsed: 54.925727ms
Apr 28 07:22:33.476: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Pending", Reason="", readiness=false. Elapsed: 2.1097968s
Apr 28 07:22:35.531: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Pending", Reason="", readiness=false. Elapsed: 4.165167369s
Apr 28 07:22:37.587: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Pending", Reason="", readiness=false. Elapsed: 6.221076883s
Apr 28 07:22:39.642: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Pending", Reason="", readiness=false. Elapsed: 8.276492815s
Apr 28 07:22:41.697: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Pending", Reason="", readiness=false. Elapsed: 10.331278608s
Apr 28 07:22:43.753: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Running", Reason="", readiness=true. Elapsed: 12.387182257s
Apr 28 07:22:45.807: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Running", Reason="", readiness=true. Elapsed: 14.441711368s
Apr 28 07:22:47.863: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Running", Reason="", readiness=true. Elapsed: 16.497443998s
Apr 28 07:22:49.919: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Running", Reason="", readiness=true. Elapsed: 18.553282745s
Apr 28 07:22:51.979: INFO: Pod "azurefile-volume-tester-ng4ww": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.613688387s
STEP: Saw pod success
Apr 28 07:22:51.979: INFO: Pod "azurefile-volume-tester-ng4ww" 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 28 07:22:52.095: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-2p2t9] to have phase Bound
Apr 28 07:22:52.149: INFO: PersistentVolumeClaim pvc-2p2t9 found and phase=Bound (54.10396ms)
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 28 07:22:52.313: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-t8fcg" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 28 07:22:52.368: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 54.500463ms
Apr 28 07:22:54.423: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109343159s
Apr 28 07:22:56.478: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164730073s
Apr 28 07:22:58.534: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.220134329s
Apr 28 07:23:00.589: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.275215002s
Apr 28 07:23:02.644: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330259285s
Apr 28 07:23:04.701: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Running", Reason="", readiness=true. Elapsed: 12.387659197s
Apr 28 07:23:06.758: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Running", Reason="", readiness=true. Elapsed: 14.444693108s
Apr 28 07:23:08.813: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Running", Reason="", readiness=true. Elapsed: 16.499593732s
Apr 28 07:23:10.869: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Running", Reason="", readiness=true. Elapsed: 18.555275226s
Apr 28 07:23:12.925: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Running", Reason="", readiness=true. Elapsed: 20.611804497s
Apr 28 07:23:14.980: INFO: Pod "azurefile-volume-tester-t8fcg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.666752211s
STEP: Saw pod success
Apr 28 07:23:14.980: INFO: Pod "azurefile-volume-tester-t8fcg" 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 28 07:23:15.091: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-nfgkf] to have phase Bound
Apr 28 07:23:15.145: INFO: PersistentVolumeClaim pvc-nfgkf found and phase=Bound (54.126994ms)
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 28 07:23:15.308: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-92qsq" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 28 07:23:15.363: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Pending", Reason="", readiness=false. Elapsed: 54.477358ms
Apr 28 07:23:17.418: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.110007878s
Apr 28 07:23:19.474: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.165926777s
Apr 28 07:23:21.550: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.241939857s
Apr 28 07:23:23.609: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.30033832s
Apr 28 07:23:25.664: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.355299797s
Apr 28 07:23:27.719: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Running", Reason="", readiness=true. Elapsed: 12.411044573s
Apr 28 07:23:29.774: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Running", Reason="", readiness=true. Elapsed: 14.465874124s
Apr 28 07:23:31.829: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Running", Reason="", readiness=true. Elapsed: 16.520850221s
Apr 28 07:23:33.885: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Running", Reason="", readiness=true. Elapsed: 18.576539673s
Apr 28 07:23:35.939: INFO: Pod "azurefile-volume-tester-92qsq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.630914991s
STEP: Saw pod success
Apr 28 07:23:35.939: INFO: Pod "azurefile-volume-tester-92qsq" satisfied condition "Succeeded or Failed"
Apr 28 07:23:35.939: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-92qsq"
Apr 28 07:23:36.021: INFO: Pod azurefile-volume-tester-92qsq has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-92qsq in namespace azurefile-2540
Apr 28 07:23:36.084: INFO: deleting PVC "azurefile-2540"/"pvc-nfgkf"
Apr 28 07:23:36.084: INFO: Deleting PersistentVolumeClaim "pvc-nfgkf"
... skipping 143 lines ...
Apr 28 07:23:43.339: INFO: PersistentVolumeClaim pvc-9gx2s found but phase is Pending instead of Bound.
Apr 28 07:23:45.395: INFO: PersistentVolumeClaim pvc-9gx2s found and phase=Bound (2.109172768s)
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 28 07:23:45.559: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-jb6gt" in namespace "azurefile-5466" to be "Succeeded or Failed"
Apr 28 07:23:45.613: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Pending", Reason="", readiness=false. Elapsed: 54.332063ms
Apr 28 07:23:47.668: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109633627s
Apr 28 07:23:49.723: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163996123s
Apr 28 07:23:51.777: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218493236s
Apr 28 07:23:53.834: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.275583271s
Apr 28 07:23:55.889: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330391285s
... skipping 2 lines ...
Apr 28 07:24:02.055: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Running", Reason="", readiness=true. Elapsed: 16.495879904s
Apr 28 07:24:04.110: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Running", Reason="", readiness=true. Elapsed: 18.551441816s
Apr 28 07:24:06.166: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Running", Reason="", readiness=true. Elapsed: 20.607397559s
Apr 28 07:24:08.221: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Running", Reason="", readiness=true. Elapsed: 22.661944663s
Apr 28 07:24:10.276: INFO: Pod "azurefile-volume-tester-jb6gt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 24.716848001s
STEP: Saw pod success
Apr 28 07:24:10.276: INFO: Pod "azurefile-volume-tester-jb6gt" satisfied condition "Succeeded or Failed"
Apr 28 07:24:10.276: INFO: deleting Pod "azurefile-5466"/"azurefile-volume-tester-jb6gt"
Apr 28 07:24:10.344: INFO: Pod azurefile-volume-tester-jb6gt has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-jb6gt in namespace azurefile-5466
Apr 28 07:24:10.409: INFO: deleting PVC "azurefile-5466"/"pvc-9gx2s"
Apr 28 07:24:10.409: INFO: Deleting PersistentVolumeClaim "pvc-9gx2s"
... skipping 33 lines ...
Apr 28 07:24:12.538: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-rfr26] to have phase Bound
Apr 28 07:24:12.592: INFO: PersistentVolumeClaim pvc-rfr26 found and phase=Bound (53.542802ms)
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 28 07:24:12.755: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-lhpcs" in namespace "azurefile-2790" to be "Succeeded or Failed"
Apr 28 07:24:12.809: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Pending", Reason="", readiness=false. Elapsed: 53.918109ms
Apr 28 07:24:14.865: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109351802s
Apr 28 07:24:16.922: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Pending", Reason="", readiness=false. Elapsed: 4.166975402s
Apr 28 07:24:18.977: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Pending", Reason="", readiness=false. Elapsed: 6.221456867s
Apr 28 07:24:21.033: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Pending", Reason="", readiness=false. Elapsed: 8.277399284s
Apr 28 07:24:23.088: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Pending", Reason="", readiness=false. Elapsed: 10.332708868s
Apr 28 07:24:25.143: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Pending", Reason="", readiness=false. Elapsed: 12.388207859s
Apr 28 07:24:27.199: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Pending", Reason="", readiness=false. Elapsed: 14.443770613s
Apr 28 07:24:29.255: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Running", Reason="", readiness=true. Elapsed: 16.499493608s
Apr 28 07:24:31.310: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Running", Reason="", readiness=true. Elapsed: 18.554246712s
Apr 28 07:24:33.364: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Running", Reason="", readiness=true. Elapsed: 20.609047784s
Apr 28 07:24:35.419: INFO: Pod "azurefile-volume-tester-lhpcs": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.664141622s
STEP: Saw pod success
Apr 28 07:24:35.419: INFO: Pod "azurefile-volume-tester-lhpcs" satisfied condition "Succeeded or Failed"
Apr 28 07:24:35.419: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-lhpcs"
Apr 28 07:24:35.489: INFO: Pod azurefile-volume-tester-lhpcs has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-lhpcs in namespace azurefile-2790
Apr 28 07:24:35.549: INFO: deleting PVC "azurefile-2790"/"pvc-rfr26"
Apr 28 07:24:35.549: INFO: Deleting PersistentVolumeClaim "pvc-rfr26"
... skipping 134 lines ...
Apr 28 07:26:41.646: INFO: PersistentVolumeClaim pvc-dx5cp found but phase is Pending instead of Bound.
Apr 28 07:26:43.701: INFO: PersistentVolumeClaim pvc-dx5cp found and phase=Bound (1m38.721070462s)
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 28 07:26:43.864: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-2src8" in namespace "azurefile-5194" to be "Succeeded or Failed"
Apr 28 07:26:43.918: INFO: Pod "azurefile-volume-tester-2src8": Phase="Pending", Reason="", readiness=false. Elapsed: 53.745616ms
Apr 28 07:26:45.973: INFO: Pod "azurefile-volume-tester-2src8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108753142s
Apr 28 07:26:48.028: INFO: Pod "azurefile-volume-tester-2src8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.16364312s
Apr 28 07:26:50.083: INFO: Pod "azurefile-volume-tester-2src8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218664313s
Apr 28 07:26:52.137: INFO: Pod "azurefile-volume-tester-2src8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.273130699s
Apr 28 07:26:54.192: INFO: Pod "azurefile-volume-tester-2src8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.327914596s
Apr 28 07:26:56.248: INFO: Pod "azurefile-volume-tester-2src8": Phase="Pending", Reason="", readiness=false. Elapsed: 12.383338415s
Apr 28 07:26:58.302: INFO: Pod "azurefile-volume-tester-2src8": Phase="Running", Reason="", readiness=true. Elapsed: 14.437985148s
Apr 28 07:27:00.358: INFO: Pod "azurefile-volume-tester-2src8": Phase="Running", Reason="", readiness=true. Elapsed: 16.493321698s
Apr 28 07:27:02.412: INFO: Pod "azurefile-volume-tester-2src8": Phase="Running", Reason="", readiness=true. Elapsed: 18.547921s
Apr 28 07:27:04.467: INFO: Pod "azurefile-volume-tester-2src8": Phase="Running", Reason="", readiness=true. Elapsed: 20.602914694s
Apr 28 07:27:06.523: INFO: Pod "azurefile-volume-tester-2src8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.658334422s
STEP: Saw pod success
Apr 28 07:27:06.523: INFO: Pod "azurefile-volume-tester-2src8" satisfied condition "Succeeded or Failed"
Apr 28 07:27:06.523: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-2src8" in namespace "azurefile-5194" to be "Succeeded or Failed"
Apr 28 07:27:06.577: INFO: Pod "azurefile-volume-tester-2src8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 53.982745ms
STEP: Saw pod success
Apr 28 07:27:06.577: INFO: Pod "azurefile-volume-tester-2src8" satisfied condition "Succeeded or Failed"
Apr 28 07:27:06.577: INFO: deleting Pod "azurefile-5194"/"azurefile-volume-tester-2src8"
Apr 28 07:27:06.664: INFO: Pod azurefile-volume-tester-2src8 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-2src8 in namespace azurefile-5194
Apr 28 07:27:06.728: INFO: deleting PVC "azurefile-5194"/"pvc-dx5cp"
Apr 28 07:27:06.728: INFO: Deleting PersistentVolumeClaim "pvc-dx5cp"
... skipping 35 lines ...
Apr 28 07:27:13.216: INFO: PersistentVolumeClaim pvc-fdwxq found but phase is Pending instead of Bound.
Apr 28 07:27:15.272: INFO: PersistentVolumeClaim pvc-fdwxq found and phase=Bound (2.109514859s)
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 28 07:27:15.439: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-s8vq9" in namespace "azurefile-1353" to be "Succeeded or Failed"
Apr 28 07:27:15.493: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Pending", Reason="", readiness=false. Elapsed: 54.019273ms
Apr 28 07:27:17.548: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109040692s
Apr 28 07:27:19.603: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164139709s
Apr 28 07:27:21.659: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219460391s
Apr 28 07:27:23.714: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.27492357s
Apr 28 07:27:25.769: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330116539s
... skipping 3 lines ...
Apr 28 07:27:33.989: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Running", Reason="", readiness=true. Elapsed: 18.5498774s
Apr 28 07:27:36.044: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Running", Reason="", readiness=true. Elapsed: 20.605070585s
Apr 28 07:27:38.098: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Running", Reason="", readiness=true. Elapsed: 22.659265249s
Apr 28 07:27:40.153: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Running", Reason="", readiness=true. Elapsed: 24.713769135s
Apr 28 07:27:42.208: INFO: Pod "azurefile-volume-tester-s8vq9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.76894886s
STEP: Saw pod success
Apr 28 07:27:42.208: INFO: Pod "azurefile-volume-tester-s8vq9" satisfied condition "Succeeded or Failed"
Apr 28 07:27:42.208: INFO: deleting Pod "azurefile-1353"/"azurefile-volume-tester-s8vq9"
Apr 28 07:27:42.274: INFO: Pod azurefile-volume-tester-s8vq9 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-s8vq9 in namespace azurefile-1353
Apr 28 07:27:42.335: INFO: deleting PVC "azurefile-1353"/"pvc-fdwxq"
Apr 28 07:27:42.335: INFO: Deleting PersistentVolumeClaim "pvc-fdwxq"
... skipping 115 lines ...
Apr 28 07:28:47.277: INFO: PersistentVolumeClaim pvc-scptg found but phase is Pending instead of Bound.
Apr 28 07:28:49.338: INFO: PersistentVolumeClaim pvc-scptg found and phase=Bound (20.632496987s)
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 28 07:28:49.506: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-8csc9" in namespace "azurefile-156" to be "Error status code"
Apr 28 07:28:49.560: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Pending", Reason="", readiness=false. Elapsed: 53.977666ms
Apr 28 07:28:51.616: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109351649s
Apr 28 07:28:53.671: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164369343s
Apr 28 07:28:55.726: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.220102576s
Apr 28 07:28:57.781: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.274924828s
Apr 28 07:28:59.836: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.329588228s
Apr 28 07:29:01.899: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Pending", Reason="", readiness=false. Elapsed: 12.392358114s
Apr 28 07:29:03.958: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Running", Reason="", readiness=true. Elapsed: 14.452052255s
Apr 28 07:29:06.014: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Running", Reason="", readiness=true. Elapsed: 16.507487494s
Apr 28 07:29:08.068: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Running", Reason="", readiness=true. Elapsed: 18.56179662s
Apr 28 07:29:10.122: INFO: Pod "azurefile-volume-tester-8csc9": Phase="Failed", Reason="", readiness=false. Elapsed: 20.616215915s
STEP: Saw pod failure
Apr 28 07:29:10.122: INFO: Pod "azurefile-volume-tester-8csc9" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 28 07:29:10.196: INFO: deleting Pod "azurefile-156"/"azurefile-volume-tester-8csc9"
Apr 28 07:29:10.256: INFO: Pod azurefile-volume-tester-8csc9 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 200 lines ...
Apr 28 07:30:33.474: INFO: PersistentVolumeClaim pvc-wsmwm found but phase is Pending instead of Bound.
Apr 28 07:30:35.533: INFO: PersistentVolumeClaim pvc-wsmwm found and phase=Bound (2.115216058s)
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 28 07:30:35.701: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-gd47n" in namespace "azurefile-2546" to be "Succeeded or Failed"
Apr 28 07:30:35.757: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Pending", Reason="", readiness=false. Elapsed: 56.35037ms
Apr 28 07:30:37.813: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Pending", Reason="", readiness=false. Elapsed: 2.111648583s
Apr 28 07:30:39.867: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Pending", Reason="", readiness=false. Elapsed: 4.166151023s
Apr 28 07:30:41.923: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Pending", Reason="", readiness=false. Elapsed: 6.221659727s
Apr 28 07:30:43.982: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Pending", Reason="", readiness=false. Elapsed: 8.281286466s
Apr 28 07:30:46.037: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Pending", Reason="", readiness=false. Elapsed: 10.336458566s
Apr 28 07:30:48.092: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Pending", Reason="", readiness=false. Elapsed: 12.391100676s
Apr 28 07:30:50.148: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Running", Reason="", readiness=true. Elapsed: 14.446774138s
Apr 28 07:30:52.202: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Running", Reason="", readiness=true. Elapsed: 16.501346379s
Apr 28 07:30:54.257: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Running", Reason="", readiness=true. Elapsed: 18.556319055s
Apr 28 07:30:56.312: INFO: Pod "azurefile-volume-tester-gd47n": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.611381577s
STEP: Saw pod success
Apr 28 07:30:56.312: INFO: Pod "azurefile-volume-tester-gd47n" 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 28 07:31:26.920: INFO: deleting Pod "azurefile-2546"/"azurefile-volume-tester-gd47n"
... skipping 303 lines ...
Apr 28 07:31:52.575: INFO: PersistentVolumeClaim pvc-sxgzk found but phase is Pending instead of Bound.
Apr 28 07:31:54.631: INFO: PersistentVolumeClaim pvc-sxgzk found and phase=Bound (2.113682179s)
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 28 07:31:54.795: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-kqj8q" in namespace "azurefile-9183" to be "Succeeded or Failed"
Apr 28 07:31:54.848: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Pending", Reason="", readiness=false. Elapsed: 53.639126ms
Apr 28 07:31:56.903: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108584127s
Apr 28 07:31:58.960: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164729835s
Apr 28 07:32:01.014: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219220066s
Apr 28 07:32:03.069: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Pending", Reason="", readiness=false. Elapsed: 8.274177753s
Apr 28 07:32:05.124: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Pending", Reason="", readiness=false. Elapsed: 10.329264786s
... skipping 3 lines ...
Apr 28 07:32:13.347: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Running", Reason="", readiness=true. Elapsed: 18.552440307s
Apr 28 07:32:15.403: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Running", Reason="", readiness=true. Elapsed: 20.607768058s
Apr 28 07:32:17.458: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Running", Reason="", readiness=true. Elapsed: 22.663344434s
Apr 28 07:32:19.514: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Running", Reason="", readiness=true. Elapsed: 24.719402965s
Apr 28 07:32:21.570: INFO: Pod "azurefile-volume-tester-kqj8q": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.775207509s
STEP: Saw pod success
Apr 28 07:32:21.570: INFO: Pod "azurefile-volume-tester-kqj8q" satisfied condition "Succeeded or Failed"
Apr 28 07:32:21.570: INFO: deleting Pod "azurefile-9183"/"azurefile-volume-tester-kqj8q"
Apr 28 07:32:21.884: INFO: Pod azurefile-volume-tester-kqj8q has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-kqj8q in namespace azurefile-9183
Apr 28 07:32:21.946: INFO: deleting PVC "azurefile-9183"/"pvc-sxgzk"
Apr 28 07:32:21.946: INFO: Deleting PersistentVolumeClaim "pvc-sxgzk"
... skipping 90 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/28 07:32:25 Check successfully
Apr 28 07:32:25.734: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/28 07:32:25 run script: test/utils/get_storage_account_secret_name.sh
2022/04/28 07:32:26 got output: azure-storage-account-ff584551729b646dcaf811b-secret
, error: <nil>
2022/04/28 07:32:26 got storage account secret name: azure-storage-account-ff584551729b646dcaf811b-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 28 07:32:26.132: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-6rgz8] to have phase Bound
Apr 28 07:32:26.186: INFO: PersistentVolumeClaim pvc-6rgz8 found but phase is Pending instead of Bound.
Apr 28 07:32:28.241: INFO: PersistentVolumeClaim pvc-6rgz8 found and phase=Bound (2.109011327s)
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 28 07:32:28.404: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bf5tw" in namespace "azurefile-1968" to be "Succeeded or Failed"
Apr 28 07:32:28.458: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Pending", Reason="", readiness=false. Elapsed: 53.837428ms
Apr 28 07:32:30.514: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109422366s
Apr 28 07:32:32.568: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163611119s
Apr 28 07:32:34.632: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.227649326s
Apr 28 07:32:36.688: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.283729723s
Apr 28 07:32:38.744: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Pending", Reason="", readiness=false. Elapsed: 10.339720065s
Apr 28 07:32:40.800: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Pending", Reason="", readiness=false. Elapsed: 12.395676189s
Apr 28 07:32:42.855: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Running", Reason="", readiness=true. Elapsed: 14.450908225s
Apr 28 07:32:44.910: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Running", Reason="", readiness=true. Elapsed: 16.506315527s
Apr 28 07:32:46.966: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Running", Reason="", readiness=true. Elapsed: 18.561948744s
Apr 28 07:32:49.021: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Running", Reason="", readiness=true. Elapsed: 20.617231547s
Apr 28 07:32:51.076: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.67182775s
STEP: Saw pod success
Apr 28 07:32:51.076: INFO: Pod "azurefile-volume-tester-bf5tw" satisfied condition "Succeeded or Failed"
Apr 28 07:32:51.076: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bf5tw" in namespace "azurefile-1968" to be "Succeeded or Failed"
Apr 28 07:32:51.130: INFO: Pod "azurefile-volume-tester-bf5tw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 53.86478ms
STEP: Saw pod success
Apr 28 07:32:51.130: INFO: Pod "azurefile-volume-tester-bf5tw" satisfied condition "Succeeded or Failed"
Apr 28 07:32:51.130: INFO: deleting Pod "azurefile-1968"/"azurefile-volume-tester-bf5tw"
Apr 28 07:32:51.193: INFO: Pod azurefile-volume-tester-bf5tw has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-bf5tw in namespace azurefile-1968
Apr 28 07:32:51.253: INFO: deleting PVC "azurefile-1968"/"pvc-6rgz8"
Apr 28 07:32:51.253: INFO: Deleting PersistentVolumeClaim "pvc-6rgz8"
... skipping 45 lines ...
Apr 28 07:33:18.254: INFO: PersistentVolumeClaim pvc-99ch7 found but phase is Pending instead of Bound.
Apr 28 07:33:20.310: INFO: PersistentVolumeClaim pvc-99ch7 found and phase=Bound (22.661129709s)
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 28 07:33:20.474: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-tcg75" in namespace "azurefile-4657" to be "Succeeded or Failed"
Apr 28 07:33:20.528: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Pending", Reason="", readiness=false. Elapsed: 53.895546ms
Apr 28 07:33:22.583: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108630761s
Apr 28 07:33:24.639: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164685642s
Apr 28 07:33:26.695: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Pending", Reason="", readiness=false. Elapsed: 6.220538687s
Apr 28 07:33:28.749: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Pending", Reason="", readiness=false. Elapsed: 8.275204251s
Apr 28 07:33:30.805: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330906005s
Apr 28 07:33:32.861: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Pending", Reason="", readiness=false. Elapsed: 12.386406546s
Apr 28 07:33:34.917: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Running", Reason="", readiness=true. Elapsed: 14.442274746s
Apr 28 07:33:36.971: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Running", Reason="", readiness=true. Elapsed: 16.496485652s
Apr 28 07:33:39.025: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Running", Reason="", readiness=true. Elapsed: 18.551050123s
Apr 28 07:33:41.080: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Running", Reason="", readiness=true. Elapsed: 20.605751184s
Apr 28 07:33:43.135: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.660382225s
STEP: Saw pod success
Apr 28 07:33:43.135: INFO: Pod "azurefile-volume-tester-tcg75" satisfied condition "Succeeded or Failed"
Apr 28 07:33:43.135: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-tcg75" in namespace "azurefile-4657" to be "Succeeded or Failed"
Apr 28 07:33:43.189: INFO: Pod "azurefile-volume-tester-tcg75": Phase="Succeeded", Reason="", readiness=false. Elapsed: 54.021375ms
STEP: Saw pod success
Apr 28 07:33:43.189: INFO: Pod "azurefile-volume-tester-tcg75" satisfied condition "Succeeded or Failed"
Apr 28 07:33:43.189: INFO: deleting Pod "azurefile-4657"/"azurefile-volume-tester-tcg75"
Apr 28 07:33:43.256: INFO: Pod azurefile-volume-tester-tcg75 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-tcg75 in namespace azurefile-4657
Apr 28 07:33:43.315: INFO: deleting PVC "azurefile-4657"/"pvc-99ch7"
Apr 28 07:33:43.315: INFO: Deleting PersistentVolumeClaim "pvc-99ch7"
... skipping 75 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/28 07:35:09 Check successfully
Apr 28 07:35:09.758: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/28 07:35:09 run script: test/utils/get_storage_account_secret_name.sh
2022/04/28 07:35:10 got output: azure-storage-account-ff584551729b646dcaf811b-secret
, error: <nil>
2022/04/28 07:35:10 got storage account secret name: azure-storage-account-ff584551729b646dcaf811b-secret
STEP: Successfully provisioned AzureFile volume: "capz-2yvtmt#ff584551729b646dcaf811b#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 28 07:35:11.130: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-gcwtc" in namespace "azurefile-4162" to be "Succeeded or Failed"
Apr 28 07:35:11.184: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Pending", Reason="", readiness=false. Elapsed: 53.658471ms
Apr 28 07:35:13.238: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108277136s
Apr 28 07:35:15.293: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.162850404s
Apr 28 07:35:17.348: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.2180515s
Apr 28 07:35:19.404: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Pending", Reason="", readiness=false. Elapsed: 8.273307965s
Apr 28 07:35:21.458: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Pending", Reason="", readiness=false. Elapsed: 10.327747896s
... skipping 2 lines ...
Apr 28 07:35:27.624: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Running", Reason="", readiness=true. Elapsed: 16.493859442s
Apr 28 07:35:29.678: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Running", Reason="", readiness=true. Elapsed: 18.548181804s
Apr 28 07:35:31.733: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Running", Reason="", readiness=true. Elapsed: 20.603061976s
Apr 28 07:35:33.788: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Running", Reason="", readiness=true. Elapsed: 22.657957496s
Apr 28 07:35:35.842: INFO: Pod "azurefile-volume-tester-gcwtc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 24.712117914s
STEP: Saw pod success
Apr 28 07:35:35.842: INFO: Pod "azurefile-volume-tester-gcwtc" satisfied condition "Succeeded or Failed"
Apr 28 07:35:35.842: INFO: deleting Pod "azurefile-4162"/"azurefile-volume-tester-gcwtc"
Apr 28 07:35:35.911: INFO: Pod azurefile-volume-tester-gcwtc has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-gcwtc in namespace azurefile-4162
Apr 28 07:35:35.985: 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:
I0428 07:11:45.026390       1 azurefile.go:272] driver userAgent: file.csi.azure.com/e2e-efeeec97c8f203798d85208d76b8003532bb7e77 gc/go1.18.1 (amd64-linux) e2e-test
I0428 07:11:45.026736       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0428 07:11:45.042584       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 15 milliseconds
W0428 07:11:45.042800       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
I0428 07:11:45.042816       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0428 07:11:45.042826       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0428 07:11:45.042855       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0428 07:11:45.043386       1 azure_auth.go:245] Using AzurePublicCloud environment
I0428 07:11:45.043431       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0428 07:11:45.043495       1 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 2852 lines ...
Platform: windows/amd64

Streaming logs below:
I0428 07:12:54.739791    3360 azurefile.go:272] driver userAgent: file.csi.azure.com/e2e-efeeec97c8f203798d85208d76b8003532bb7e77 gc/go1.18.1 (amd64-windows) e2e-test
I0428 07:12:54.751413    3360 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0428 07:12:54.777551    3360 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 19 milliseconds
W0428 07:12:54.779438    3360 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
I0428 07:12:54.779482    3360 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0428 07:12:54.779482    3360 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0428 07:12:54.779685    3360 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0428 07:12:54.781835    3360 azure_auth.go:245] Using AzurePublicCloud environment
I0428 07:12:54.781907    3360 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0428 07:12:54.784513    3360 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 157 lines ...
I0428 07:21:24.715454    3360 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0428 07:21:24.715454    3360 utils.go:77] GRPC request: {}
I0428 07:21:24.715454    3360 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0428 07:21:24.721365    3360 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0428 07:21:24.721365    3360 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\azurefile-2540-file.csi.azure.com-preprovsioned-pv-mdkgm\\globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_id":"capz-2yvtmt#ff584551729b646dcaf811b#pre-provisioned-multiple-pods##pre-provisioned-multiple-pods#azurefile-25401"}
I0428 07:21:24.739620    3360 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-25401/secrets/azure-storage-account-ff584551729b646dcaf811b-secret 404 Not Found in 17 milliseconds
I0428 07:21:24.740159    3360 azurefile.go:630] could not get account(ff584551729b646dcaf811b) key from secret(azure-storage-account-ff584551729b646dcaf811b-secret), error: could not get secret(azure-storage-account-ff584551729b646dcaf811b-secret): secrets "azure-storage-account-ff584551729b646dcaf811b-secret" not found, use cluster identity to get account key instead
(2022-04-28T07:21:24.7472923Z) INFO: REQUEST: POST https://login.microsoftonline.com/097f89a0-9286-43d2-9a1a-08f1d49b1af8/oauth2/token
User-Agent: Go/go1.18.1 (amd64-windows) go-autorest/adal/v1.0.0
Content-Type: application/x-www-form-urlencoded
(2022-04-28T07:21:25.5068487Z) INFO: RESPONSE: 200 https://login.microsoftonline.com/097f89a0-9286-43d2-9a1a-08f1d49b1af8/oauth2/token
Pragma: no-cache
X-Content-Type-Options: nosniff
... skipping 1746 lines ...
I0428 07:35:11.420224    3360 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0428 07:35:11.421251    3360 nodeserver.go:136] NodeUnpublishVolume: unmount volume capz-2yvtmt#ff584551729b646dcaf811b#pvc-2e159892-d70a-4441-8360-9c178a6d2f2b###azurefile-1359 on c:\var\lib\kubelet\pods\31effb4b-585f-4f25-b3f0-e6d1592a5680\volumes\kubernetes.io~csi\pvc-2e159892-d70a-4441-8360-9c178a6d2f2b\mount successfully
I0428 07:35:11.421251    3360 utils.go:83] GRPC response: {}
I0428 07:35:11.423105    3360 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0428 07:35:11.423371    3360 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72\\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-gcwtc","csi.storage.k8s.io/pod.namespace":"azurefile-4162","csi.storage.k8s.io/pod.uid":"6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"azure-storage-account-ff584551729b646dcaf811b-secret","server":"","shareName":"csi-inline-smb-volume"},"volume_id":"csi-790335b3cb7522f9ec4a071ff5b24e5282d88e992809c83bedbb858c87c572d4"}
I0428 07:35:11.423476    3360 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-790335b3cb7522f9ec4a071ff5b24e5282d88e992809c83bedbb858c87c572d4) mount on c:\var\lib\kubelet\pods\6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72\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-gcwtc csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-ff584551729b646dcaf811b-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]
W0428 07:35:11.423476    3360 azurefile.go:560] parsing volumeID(csi-790335b3cb7522f9ec4a071ff5b24e5282d88e992809c83bedbb858c87c572d4) return with error: error parsing volume id: "csi-790335b3cb7522f9ec4a071ff5b24e5282d88e992809c83bedbb858c87c572d4", should at least contain two #
I0428 07:35:11.433515    3360 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-4162/secrets/azure-storage-account-ff584551729b646dcaf811b-secret 200 OK in 9 milliseconds
I0428 07:35:11.433515    3360 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-790335b3cb7522f9ec4a071ff5b24e5282d88e992809c83bedbb858c87c572d4) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-gcwtc csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-ff584551729b646dcaf811b-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]) mountflags([]) mountOptions([AZURE\ff584551729b646dcaf811b]) volumeMountGroup()
I0428 07:35:11.433515    3360 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72\volumes\kubernetes.io~csi\test-volume-1\mount
I0428 07:35:11.433515    3360 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72\volumes\kubernetes.io~csi\test-volume-1\mount
I0428 07:35:11.435611    3360 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72\volumes\kubernetes.io~csi\test-volume-1\mount
I0428 07:35:11.440887    3360 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\6dd6c3e7-38f0-4bd8-9faf-2b142f18eb72\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 136 lines ...
Platform: windows/amd64

Streaming logs below:
I0428 07:12:55.208071    2716 azurefile.go:272] driver userAgent: file.csi.azure.com/e2e-efeeec97c8f203798d85208d76b8003532bb7e77 gc/go1.18.1 (amd64-windows) e2e-test
I0428 07:12:55.218442    2716 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0428 07:12:55.240665    2716 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 16 milliseconds
W0428 07:12:55.250828    2716 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
I0428 07:12:55.250828    2716 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0428 07:12:55.250828    2716 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0428 07:12:55.250828    2716 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0428 07:12:55.254368    2716 azure_auth.go:245] Using AzurePublicCloud environment
I0428 07:12:55.254979    2716 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0428 07:12:55.257833    2716 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 583 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 2181.056 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 (2181.06s)
FAIL
FAIL	sigs.k8s.io/azurefile-csi-driver/test/e2e	2181.116s
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 96 lines ...