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 / 19 succeeded
Started2022-04-19 01:08
Elapsed48m59s
Revision406a0d30aff10d48525d3e58710a2b1ac4047aa0
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] 7m14s

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 19 Passed Tests

Show 14 Skipped Tests

Error lines from build-log.txt

... skipping 675 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 129 lines ...
# Wait for the kubeconfig to become available.
timeout --foreground 300 bash -c "while ! kubectl get secrets | grep capz-i0pppa-kubeconfig; do sleep 1; done"
capz-i0pppa-kubeconfig                 cluster.x-k8s.io/secret               1      1s
# Get kubeconfig and store it locally.
kubectl get secrets capz-i0pppa-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-i0pppa-control-plane-bccn2   NotReady   control-plane,master   3s    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), 2 worker machine(s), and 2 windows machine(s) to become Ready
node/capz-i0pp-pb68h condition met
node/capz-i0pp-vg8kq condition met
... skipping 1031 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
W0419 01:26:11.363197   36461 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret /: failed to get secret /: resource name may not be empty
I0419 01:26:11.366817   36461 driver.go:93] Enabling controller service capability: CREATE_DELETE_VOLUME
I0419 01:26:11.366877   36461 driver.go:93] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME
I0419 01:26:11.366882   36461 driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0419 01:26:11.366887   36461 driver.go:93] Enabling controller service capability: EXPAND_VOLUME
I0419 01:26:11.366890   36461 driver.go:93] Enabling controller service capability: SINGLE_NODE_MULTI_WRITER
I0419 01:26:11.366909   36461 driver.go:112] Enabling volume access mode: SINGLE_NODE_WRITER
... skipping 23 lines ...
Apr 19 01:26:34.736: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-vpshb] to have phase Bound
Apr 19 01:26:34.789: INFO: PersistentVolumeClaim pvc-vpshb found and phase=Bound (53.243256ms)
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 19 01:26:34.950: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-r9q7g" in namespace "azurefile-8081" to be "Error status code"
Apr 19 01:26:35.005: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 55.10608ms
Apr 19 01:26:37.059: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108841545s
Apr 19 01:26:39.116: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 4.16621835s
Apr 19 01:26:41.171: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 6.221287708s
Apr 19 01:26:43.225: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 8.275182583s
Apr 19 01:26:45.285: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 10.334675247s
... skipping 186 lines ...
Apr 19 01:33:10.155: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 6m35.204580364s
Apr 19 01:33:12.213: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 6m37.262895677s
Apr 19 01:33:14.270: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 6m39.32036332s
Apr 19 01:33:16.328: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 6m41.378339722s
Apr 19 01:33:18.387: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 6m43.436542995s
Apr 19 01:33:20.445: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Pending", Reason="", readiness=false. Elapsed: 6m45.494907252s
Apr 19 01:33:22.502: INFO: Pod "azurefile-volume-tester-r9q7g": Phase="Failed", Reason="", readiness=false. Elapsed: 6m47.55241152s
STEP: Saw pod failure
Apr 19 01:33:22.503: INFO: Pod "azurefile-volume-tester-r9q7g" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 19 01:33:22.572: INFO: deleting Pod "azurefile-8081"/"azurefile-volume-tester-r9q7g"
Apr 19 01:33:22.630: INFO: Pod azurefile-volume-tester-r9q7g has the following logs: 
STEP: Deleting pod azurefile-volume-tester-r9q7g in namespace azurefile-8081
Apr 19 01:33:22.694: INFO: deleting PVC "azurefile-8081"/"pvc-vpshb"
Apr 19 01:33:22.694: INFO: Deleting PersistentVolumeClaim "pvc-vpshb"
... skipping 7 lines ...
STEP: Collecting events from namespace "azurefile-8081".
STEP: Found 6 events.
Apr 19 01:33:22.972: INFO: At 2022-04-19 01:26:34 +0000 UTC - event for azurefile-volume-tester-r9q7g: {default-scheduler } Scheduled: Successfully assigned azurefile-8081/azurefile-volume-tester-r9q7g to capz-i0pp-vg8kq
Apr 19 01:33:22.972: INFO: At 2022-04-19 01:26:46 +0000 UTC - event for azurefile-volume-tester-r9q7g: {kubelet capz-i0pp-vg8kq} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Apr 19 01:33:22.972: INFO: At 2022-04-19 01:31:21 +0000 UTC - event for azurefile-volume-tester-r9q7g: {kubelet capz-i0pp-vg8kq} Pulled: Successfully pulled image "mcr.microsoft.com/windows/servercore:ltsc2022" in 4m34.5955602s
Apr 19 01:33:22.972: INFO: At 2022-04-19 01:31:21 +0000 UTC - event for azurefile-volume-tester-r9q7g: {kubelet capz-i0pp-vg8kq} Created: Created container volume-tester
Apr 19 01:33:22.972: INFO: At 2022-04-19 01:33:21 +0000 UTC - event for azurefile-volume-tester-r9q7g: {kubelet capz-i0pp-vg8kq} Failed: Error: context deadline exceeded
Apr 19 01:33:22.972: INFO: At 2022-04-19 01:33:21 +0000 UTC - event for azurefile-volume-tester-r9q7g: {kubelet capz-i0pp-vg8kq} Pulled: Container image "mcr.microsoft.com/windows/servercore:ltsc2022" already present on machine
Apr 19 01:33:23.025: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Apr 19 01:33:23.025: INFO: 
Apr 19 01:33:23.132: INFO: 
Logging node info for node capz-i0pp-pb68h
Apr 19 01:33:23.187: INFO: Node Info: &Node{ObjectMeta:{capz-i0pp-pb68h    a460279a-61e8-4d35-b06d-8d58f0811fae 2686 0 2022-04-19 01:21:32 +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-i0pp-pb68h 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-i0pppa cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-i0pppa-md-win-6cff467c54-ngg4g cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-i0pppa-md-win-6cff467c54 csi.volume.kubernetes.io/nodeid:{"file.csi.azure.com":"capz-i0pp-pb68h"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.6/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.49.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:11:e2:d2 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{Go-http-client Update v1 2022-04-19 01:21:33 +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-19 01:21:36 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-04-19 01:21:48 +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-19 01:23:20 +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-19 01:26:08 +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-i0pppa/providers/Microsoft.Compute/virtualMachines/capz-i0pp-pb68h,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-19 01:31:46 +0000 UTC,LastTransitionTime:2022-04-19 01:21:32 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-04-19 01:31:46 +0000 UTC,LastTransitionTime:2022-04-19 01:21:32 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-04-19 01:31:46 +0000 UTC,LastTransitionTime:2022-04-19 01:21:32 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-04-19 01:31:46 +0000 UTC,LastTransitionTime:2022-04-19 01:22:54 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-i0pp-pb68h,},NodeAddress{Type:InternalIP,Address:10.1.0.6,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-i0pp-pb68h,SystemUUID:84EFEEA2-C980-4777-95AD-41FA8B6F3A3E,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:4de4ce0615b7baa1c61f09c34929bfeb58103425f19f85ef53dc971478ee6221 capzci.azurecr.io/azurefile-csi:e2e-e26e7de71127b97f66755f201ba28bd77d2fa10e],SizeBytes:130280733,},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 146 lines ...
Apr 19 01:33:27.941: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-c5xvv] to have phase Bound
Apr 19 01:33:27.994: INFO: PersistentVolumeClaim pvc-c5xvv found and phase=Bound (52.857434ms)
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 19 01:33:28.154: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-n9lvn" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 19 01:33:28.207: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Pending", Reason="", readiness=false. Elapsed: 52.840588ms
Apr 19 01:33:30.263: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108535881s
Apr 19 01:33:32.319: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.16432151s
Apr 19 01:33:34.374: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.21965093s
Apr 19 01:33:36.429: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.2747433s
Apr 19 01:33:38.485: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330534683s
Apr 19 01:33:40.540: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Running", Reason="", readiness=true. Elapsed: 12.385609168s
Apr 19 01:33:42.597: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Running", Reason="", readiness=true. Elapsed: 14.442809132s
Apr 19 01:33:44.653: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Running", Reason="", readiness=true. Elapsed: 16.49881624s
Apr 19 01:33:46.718: INFO: Pod "azurefile-volume-tester-n9lvn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.563988801s
STEP: Saw pod success
Apr 19 01:33:46.718: INFO: Pod "azurefile-volume-tester-n9lvn" 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 19 01:33:46.827: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-xl999] to have phase Bound
Apr 19 01:33:46.880: INFO: PersistentVolumeClaim pvc-xl999 found and phase=Bound (52.821853ms)
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 19 01:33:47.053: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-9t4zq" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 19 01:33:47.113: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Pending", Reason="", readiness=false. Elapsed: 59.759711ms
Apr 19 01:33:49.167: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113424166s
Apr 19 01:33:51.222: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.168395083s
Apr 19 01:33:53.277: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.224008962s
Apr 19 01:33:55.333: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.279992984s
Apr 19 01:33:57.389: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Running", Reason="", readiness=true. Elapsed: 10.336017261s
Apr 19 01:33:59.444: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Running", Reason="", readiness=true. Elapsed: 12.391245351s
Apr 19 01:34:01.499: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Running", Reason="", readiness=true. Elapsed: 14.446259566s
Apr 19 01:34:03.554: INFO: Pod "azurefile-volume-tester-9t4zq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.501234385s
STEP: Saw pod success
Apr 19 01:34:03.554: INFO: Pod "azurefile-volume-tester-9t4zq" 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 19 01:34:03.665: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-xhhvm] to have phase Bound
Apr 19 01:34:03.719: INFO: PersistentVolumeClaim pvc-xhhvm found and phase=Bound (54.76105ms)
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 19 01:34:03.880: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-wj855" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 19 01:34:03.932: INFO: Pod "azurefile-volume-tester-wj855": Phase="Pending", Reason="", readiness=false. Elapsed: 52.508092ms
Apr 19 01:34:05.987: INFO: Pod "azurefile-volume-tester-wj855": Phase="Pending", Reason="", readiness=false. Elapsed: 2.10718091s
Apr 19 01:34:08.042: INFO: Pod "azurefile-volume-tester-wj855": Phase="Pending", Reason="", readiness=false. Elapsed: 4.162543542s
Apr 19 01:34:10.098: INFO: Pod "azurefile-volume-tester-wj855": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218455079s
Apr 19 01:34:12.153: INFO: Pod "azurefile-volume-tester-wj855": Phase="Pending", Reason="", readiness=false. Elapsed: 8.273191804s
Apr 19 01:34:14.209: INFO: Pod "azurefile-volume-tester-wj855": Phase="Running", Reason="", readiness=true. Elapsed: 10.328897358s
Apr 19 01:34:16.264: INFO: Pod "azurefile-volume-tester-wj855": Phase="Running", Reason="", readiness=true. Elapsed: 12.384324189s
Apr 19 01:34:18.320: INFO: Pod "azurefile-volume-tester-wj855": Phase="Running", Reason="", readiness=true. Elapsed: 14.440004621s
Apr 19 01:34:20.375: INFO: Pod "azurefile-volume-tester-wj855": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.494965519s
STEP: Saw pod success
Apr 19 01:34:20.375: INFO: Pod "azurefile-volume-tester-wj855" 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 19 01:34:20.484: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-v27hc] to have phase Bound
Apr 19 01:34:20.536: INFO: PersistentVolumeClaim pvc-v27hc found and phase=Bound (52.75647ms)
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 19 01:34:20.700: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-gnl2p" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 19 01:34:20.753: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Pending", Reason="", readiness=false. Elapsed: 52.75564ms
Apr 19 01:34:22.808: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107836907s
Apr 19 01:34:24.862: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Pending", Reason="", readiness=false. Elapsed: 4.162514809s
Apr 19 01:34:26.918: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218067205s
Apr 19 01:34:28.973: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Pending", Reason="", readiness=false. Elapsed: 8.273348025s
Apr 19 01:34:31.028: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Running", Reason="", readiness=true. Elapsed: 10.328658904s
Apr 19 01:34:33.084: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Running", Reason="", readiness=true. Elapsed: 12.38432234s
Apr 19 01:34:35.139: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Running", Reason="", readiness=true. Elapsed: 14.439301991s
Apr 19 01:34:37.204: INFO: Pod "azurefile-volume-tester-gnl2p": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.504402848s
STEP: Saw pod success
Apr 19 01:34:37.204: INFO: Pod "azurefile-volume-tester-gnl2p" 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 19 01:34:37.319: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-q2kjg] to have phase Bound
Apr 19 01:34:37.372: INFO: PersistentVolumeClaim pvc-q2kjg found and phase=Bound (52.932002ms)
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 19 01:34:37.534: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-mv252" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 19 01:34:37.587: INFO: Pod "azurefile-volume-tester-mv252": Phase="Pending", Reason="", readiness=false. Elapsed: 52.932836ms
Apr 19 01:34:39.641: INFO: Pod "azurefile-volume-tester-mv252": Phase="Pending", Reason="", readiness=false. Elapsed: 2.106649861s
Apr 19 01:34:41.696: INFO: Pod "azurefile-volume-tester-mv252": Phase="Pending", Reason="", readiness=false. Elapsed: 4.161665913s
Apr 19 01:34:43.751: INFO: Pod "azurefile-volume-tester-mv252": Phase="Pending", Reason="", readiness=false. Elapsed: 6.217280062s
Apr 19 01:34:45.806: INFO: Pod "azurefile-volume-tester-mv252": Phase="Pending", Reason="", readiness=false. Elapsed: 8.272165808s
Apr 19 01:34:47.862: INFO: Pod "azurefile-volume-tester-mv252": Phase="Running", Reason="", readiness=true. Elapsed: 10.327928968s
Apr 19 01:34:49.917: INFO: Pod "azurefile-volume-tester-mv252": Phase="Running", Reason="", readiness=true. Elapsed: 12.382816877s
Apr 19 01:34:51.972: INFO: Pod "azurefile-volume-tester-mv252": Phase="Running", Reason="", readiness=true. Elapsed: 14.438113419s
Apr 19 01:34:54.028: INFO: Pod "azurefile-volume-tester-mv252": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.49357934s
STEP: Saw pod success
Apr 19 01:34:54.028: INFO: Pod "azurefile-volume-tester-mv252" 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 19 01:34:54.136: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-dxnxl] to have phase Bound
Apr 19 01:34:54.213: INFO: PersistentVolumeClaim pvc-dxnxl found and phase=Bound (77.595768ms)
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 19 01:34:54.374: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-tvthw" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 19 01:34:54.426: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Pending", Reason="", readiness=false. Elapsed: 52.409487ms
Apr 19 01:34:56.480: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.106276398s
Apr 19 01:34:58.535: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.161503073s
Apr 19 01:35:00.591: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.216951576s
Apr 19 01:35:02.647: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.272872548s
Apr 19 01:35:04.702: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Running", Reason="", readiness=true. Elapsed: 10.327872858s
Apr 19 01:35:06.757: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Running", Reason="", readiness=true. Elapsed: 12.383030044s
Apr 19 01:35:08.813: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Running", Reason="", readiness=true. Elapsed: 14.439057063s
Apr 19 01:35:10.868: INFO: Pod "azurefile-volume-tester-tvthw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.494088468s
STEP: Saw pod success
Apr 19 01:35:10.868: INFO: Pod "azurefile-volume-tester-tvthw" satisfied condition "Succeeded or Failed"
Apr 19 01:35:10.868: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-tvthw"
Apr 19 01:35:10.937: INFO: Pod azurefile-volume-tester-tvthw has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-tvthw in namespace azurefile-2540
Apr 19 01:35:11.004: INFO: deleting PVC "azurefile-2540"/"pvc-dxnxl"
Apr 19 01:35:11.004: INFO: Deleting PersistentVolumeClaim "pvc-dxnxl"
... skipping 143 lines ...
Apr 19 01:35:18.071: INFO: PersistentVolumeClaim pvc-8sttw found but phase is Pending instead of Bound.
Apr 19 01:35:20.129: INFO: PersistentVolumeClaim pvc-8sttw found and phase=Bound (2.110353594s)
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 19 01:35:20.291: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-lsssx" in namespace "azurefile-5466" to be "Succeeded or Failed"
Apr 19 01:35:20.350: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Pending", Reason="", readiness=false. Elapsed: 58.592127ms
Apr 19 01:35:22.405: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113721351s
Apr 19 01:35:24.460: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.168420712s
Apr 19 01:35:26.515: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.2241767s
Apr 19 01:35:28.570: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.279206479s
Apr 19 01:35:30.625: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.334234375s
Apr 19 01:35:32.681: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Running", Reason="", readiness=true. Elapsed: 12.39016628s
Apr 19 01:35:34.736: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Running", Reason="", readiness=true. Elapsed: 14.444681316s
Apr 19 01:35:36.791: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Running", Reason="", readiness=true. Elapsed: 16.499717961s
Apr 19 01:35:38.846: INFO: Pod "azurefile-volume-tester-lsssx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.554678139s
STEP: Saw pod success
Apr 19 01:35:38.846: INFO: Pod "azurefile-volume-tester-lsssx" satisfied condition "Succeeded or Failed"
Apr 19 01:35:38.846: INFO: deleting Pod "azurefile-5466"/"azurefile-volume-tester-lsssx"
Apr 19 01:35:38.908: INFO: Pod azurefile-volume-tester-lsssx has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-lsssx in namespace azurefile-5466
Apr 19 01:35:38.972: INFO: deleting PVC "azurefile-5466"/"pvc-8sttw"
Apr 19 01:35:38.972: INFO: Deleting PersistentVolumeClaim "pvc-8sttw"
... skipping 33 lines ...
Apr 19 01:35:41.212: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-nnldn] to have phase Bound
Apr 19 01:35:41.264: INFO: PersistentVolumeClaim pvc-nnldn found and phase=Bound (52.41561ms)
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 19 01:35:41.426: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bzzv6" in namespace "azurefile-2790" to be "Succeeded or Failed"
Apr 19 01:35:41.479: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Pending", Reason="", readiness=false. Elapsed: 52.735054ms
Apr 19 01:35:43.533: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.106524445s
Apr 19 01:35:45.588: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.16232218s
Apr 19 01:35:47.644: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.217931733s
Apr 19 01:35:49.699: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.272904503s
Apr 19 01:35:51.755: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.328702736s
Apr 19 01:35:53.810: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Running", Reason="", readiness=true. Elapsed: 12.383714107s
Apr 19 01:35:55.864: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Running", Reason="", readiness=true. Elapsed: 14.438426593s
Apr 19 01:35:57.920: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Running", Reason="", readiness=true. Elapsed: 16.493575172s
Apr 19 01:35:59.975: INFO: Pod "azurefile-volume-tester-bzzv6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.549010432s
STEP: Saw pod success
Apr 19 01:35:59.975: INFO: Pod "azurefile-volume-tester-bzzv6" satisfied condition "Succeeded or Failed"
Apr 19 01:35:59.975: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-bzzv6"
Apr 19 01:36:00.038: INFO: Pod azurefile-volume-tester-bzzv6 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-bzzv6 in namespace azurefile-2790
Apr 19 01:36:00.117: INFO: deleting PVC "azurefile-2790"/"pvc-nnldn"
Apr 19 01:36:00.117: INFO: Deleting PersistentVolumeClaim "pvc-nnldn"
... skipping 135 lines ...
Apr 19 01:38:07.960: INFO: PersistentVolumeClaim pvc-rkg8k found and phase=Bound (1m38.655861738s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: sleep 1s waiting for volume ready in windows-2022
STEP: checking that the pods command exits with no error
Apr 19 01:38:09.125: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-x9c49" in namespace "azurefile-5194" to be "Succeeded or Failed"
Apr 19 01:38:09.178: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Pending", Reason="", readiness=false. Elapsed: 53.625236ms
Apr 19 01:38:11.235: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109896395s
Apr 19 01:38:13.288: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163561744s
Apr 19 01:38:15.342: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Pending", Reason="", readiness=false. Elapsed: 6.217395889s
Apr 19 01:38:17.396: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Pending", Reason="", readiness=false. Elapsed: 8.271222779s
Apr 19 01:38:19.451: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Pending", Reason="", readiness=false. Elapsed: 10.326232836s
... skipping 7 lines ...
Apr 19 01:38:35.887: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Pending", Reason="", readiness=false. Elapsed: 26.762282949s
Apr 19 01:38:37.943: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Running", Reason="", readiness=true. Elapsed: 28.818249869s
Apr 19 01:38:39.998: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Running", Reason="", readiness=true. Elapsed: 30.87318264s
Apr 19 01:38:42.053: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Running", Reason="", readiness=true. Elapsed: 32.92855997s
Apr 19 01:38:44.109: INFO: Pod "azurefile-volume-tester-x9c49": Phase="Succeeded", Reason="", readiness=false. Elapsed: 34.984167831s
STEP: Saw pod success
Apr 19 01:38:44.109: INFO: Pod "azurefile-volume-tester-x9c49" satisfied condition "Succeeded or Failed"
Apr 19 01:38:44.109: INFO: deleting Pod "azurefile-5194"/"azurefile-volume-tester-x9c49"
Apr 19 01:38:44.184: INFO: Pod azurefile-volume-tester-x9c49 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-x9c49 in namespace azurefile-5194
Apr 19 01:38:44.251: INFO: deleting PVC "azurefile-5194"/"pvc-rkg8k"
Apr 19 01:38:44.251: INFO: Deleting PersistentVolumeClaim "pvc-rkg8k"
... skipping 35 lines ...
Apr 19 01:38:50.693: INFO: PersistentVolumeClaim pvc-qvf6l found but phase is Pending instead of Bound.
Apr 19 01:38:52.748: INFO: PersistentVolumeClaim pvc-qvf6l found and phase=Bound (2.107348506s)
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 19 01:38:52.909: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-x2cmh" in namespace "azurefile-1353" to be "Succeeded or Failed"
Apr 19 01:38:52.961: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Pending", Reason="", readiness=false. Elapsed: 52.623869ms
Apr 19 01:38:55.016: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107057874s
Apr 19 01:38:57.072: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Pending", Reason="", readiness=false. Elapsed: 4.162987557s
Apr 19 01:38:59.127: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218509585s
Apr 19 01:39:01.182: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Pending", Reason="", readiness=false. Elapsed: 8.273459229s
Apr 19 01:39:03.238: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Pending", Reason="", readiness=false. Elapsed: 10.3298148s
Apr 19 01:39:05.293: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Pending", Reason="", readiness=false. Elapsed: 12.384717698s
Apr 19 01:39:07.349: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Running", Reason="", readiness=true. Elapsed: 14.44028913s
Apr 19 01:39:09.405: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Running", Reason="", readiness=true. Elapsed: 16.496142298s
Apr 19 01:39:11.461: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Running", Reason="", readiness=true. Elapsed: 18.551988523s
Apr 19 01:39:13.516: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Running", Reason="", readiness=true. Elapsed: 20.607129355s
Apr 19 01:39:15.570: INFO: Pod "azurefile-volume-tester-x2cmh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.661801859s
STEP: Saw pod success
Apr 19 01:39:15.570: INFO: Pod "azurefile-volume-tester-x2cmh" satisfied condition "Succeeded or Failed"
Apr 19 01:39:15.570: INFO: deleting Pod "azurefile-1353"/"azurefile-volume-tester-x2cmh"
Apr 19 01:39:15.632: INFO: Pod azurefile-volume-tester-x2cmh has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-x2cmh in namespace azurefile-1353
Apr 19 01:39:15.695: INFO: deleting PVC "azurefile-1353"/"pvc-qvf6l"
Apr 19 01:39:15.695: INFO: Deleting PersistentVolumeClaim "pvc-qvf6l"
... skipping 116 lines ...
Apr 19 01:40:21.489: INFO: PersistentVolumeClaim pvc-4jpth found but phase is Pending instead of Bound.
Apr 19 01:40:23.543: INFO: PersistentVolumeClaim pvc-4jpth found and phase=Bound (20.596775585s)
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 19 01:40:23.706: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-kcbvp" in namespace "azurefile-156" to be "Error status code"
Apr 19 01:40:23.760: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Pending", Reason="", readiness=false. Elapsed: 53.431585ms
Apr 19 01:40:25.814: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107967282s
Apr 19 01:40:27.870: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163477323s
Apr 19 01:40:29.925: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218956122s
Apr 19 01:40:31.981: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.274939549s
Apr 19 01:40:34.036: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330000801s
Apr 19 01:40:36.093: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Running", Reason="", readiness=true. Elapsed: 12.386956487s
Apr 19 01:40:38.150: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Running", Reason="", readiness=true. Elapsed: 14.443280101s
Apr 19 01:40:40.204: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Running", Reason="", readiness=true. Elapsed: 16.498090769s
Apr 19 01:40:42.260: INFO: Pod "azurefile-volume-tester-kcbvp": Phase="Failed", Reason="", readiness=false. Elapsed: 18.553289638s
STEP: Saw pod failure
Apr 19 01:40:42.264: INFO: Pod "azurefile-volume-tester-kcbvp" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 19 01:40:42.330: INFO: deleting Pod "azurefile-156"/"azurefile-volume-tester-kcbvp"
Apr 19 01:40:42.387: INFO: Pod azurefile-volume-tester-kcbvp 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 199 lines ...
Apr 19 01:41:58.102: INFO: PersistentVolumeClaim pvc-2wl7p found but phase is Pending instead of Bound.
Apr 19 01:42:00.156: INFO: PersistentVolumeClaim pvc-2wl7p found and phase=Bound (2.107613904s)
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 19 01:42:00.319: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-nc8l9" in namespace "azurefile-2546" to be "Succeeded or Failed"
Apr 19 01:42:00.372: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Pending", Reason="", readiness=false. Elapsed: 52.698414ms
Apr 19 01:42:02.427: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107602967s
Apr 19 01:42:04.482: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163209782s
Apr 19 01:42:06.538: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219031672s
Apr 19 01:42:08.593: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.273805276s
Apr 19 01:42:10.648: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.329031294s
Apr 19 01:42:12.704: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Running", Reason="", readiness=true. Elapsed: 12.384823599s
Apr 19 01:42:14.759: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Running", Reason="", readiness=true. Elapsed: 14.439746131s
Apr 19 01:42:16.814: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Running", Reason="", readiness=true. Elapsed: 16.495135334s
Apr 19 01:42:18.869: INFO: Pod "azurefile-volume-tester-nc8l9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.550479685s
STEP: Saw pod success
Apr 19 01:42:18.870: INFO: Pod "azurefile-volume-tester-nc8l9" 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 19 01:42:49.474: INFO: deleting Pod "azurefile-2546"/"azurefile-volume-tester-nc8l9"
... skipping 303 lines ...
Apr 19 01:43:14.720: INFO: PersistentVolumeClaim pvc-8djgf found but phase is Pending instead of Bound.
Apr 19 01:43:16.775: INFO: PersistentVolumeClaim pvc-8djgf found and phase=Bound (2.107824839s)
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 19 01:43:16.936: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-nqx7d" in namespace "azurefile-9183" to be "Succeeded or Failed"
Apr 19 01:43:16.990: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Pending", Reason="", readiness=false. Elapsed: 53.876084ms
Apr 19 01:43:19.045: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Pending", Reason="", readiness=false. Elapsed: 2.10886283s
Apr 19 01:43:21.100: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163940224s
Apr 19 01:43:23.166: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Pending", Reason="", readiness=false. Elapsed: 6.230456127s
Apr 19 01:43:25.222: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Pending", Reason="", readiness=false. Elapsed: 8.285581198s
Apr 19 01:43:27.277: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Pending", Reason="", readiness=false. Elapsed: 10.341335465s
Apr 19 01:43:29.334: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Pending", Reason="", readiness=false. Elapsed: 12.397535473s
Apr 19 01:43:31.389: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Running", Reason="", readiness=true. Elapsed: 14.453322866s
Apr 19 01:43:33.445: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Running", Reason="", readiness=true. Elapsed: 16.508704226s
Apr 19 01:43:35.502: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Running", Reason="", readiness=true. Elapsed: 18.565723397s
Apr 19 01:43:37.557: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Running", Reason="", readiness=true. Elapsed: 20.621326048s
Apr 19 01:43:39.613: INFO: Pod "azurefile-volume-tester-nqx7d": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.677343654s
STEP: Saw pod success
Apr 19 01:43:39.613: INFO: Pod "azurefile-volume-tester-nqx7d" satisfied condition "Succeeded or Failed"
Apr 19 01:43:39.614: INFO: deleting Pod "azurefile-9183"/"azurefile-volume-tester-nqx7d"
Apr 19 01:43:39.676: INFO: Pod azurefile-volume-tester-nqx7d has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-nqx7d in namespace azurefile-9183
Apr 19 01:43:39.741: INFO: deleting PVC "azurefile-9183"/"pvc-8djgf"
Apr 19 01:43:39.741: INFO: Deleting PersistentVolumeClaim "pvc-8djgf"
... skipping 93 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/19 01:43:58 Check successfully
Apr 19 01:43:58.680: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/19 01:43:58 run script: test/utils/get_storage_account_secret_name.sh
2022/04/19 01:43:58 got output: azure-storage-account-fecdc75e23b6b47f7b78efd-secret
, error: <nil>
2022/04/19 01:43:58 got storage account secret name: azure-storage-account-fecdc75e23b6b47f7b78efd-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"
... skipping 2 lines ...
Apr 19 01:44:01.132: INFO: PersistentVolumeClaim pvc-dkc6v found and phase=Bound (2.107092691s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: sleep 1s waiting for volume ready in windows-2022
STEP: checking that the pods command exits with no error
Apr 19 01:44:02.293: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bjbzl" in namespace "azurefile-1968" to be "Succeeded or Failed"
Apr 19 01:44:02.347: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Pending", Reason="", readiness=false. Elapsed: 54.059473ms
Apr 19 01:44:04.401: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107687374s
Apr 19 01:44:06.457: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163781427s
Apr 19 01:44:08.512: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219059829s
Apr 19 01:44:10.568: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.274907075s
Apr 19 01:44:12.624: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330948481s
Apr 19 01:44:14.680: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Running", Reason="", readiness=true. Elapsed: 12.386615164s
Apr 19 01:44:16.738: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Running", Reason="", readiness=true. Elapsed: 14.444581633s
Apr 19 01:44:18.793: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Running", Reason="", readiness=true. Elapsed: 16.499980847s
Apr 19 01:44:20.848: INFO: Pod "azurefile-volume-tester-bjbzl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.55469523s
STEP: Saw pod success
Apr 19 01:44:20.848: INFO: Pod "azurefile-volume-tester-bjbzl" satisfied condition "Succeeded or Failed"
Apr 19 01:44:20.848: INFO: deleting Pod "azurefile-1968"/"azurefile-volume-tester-bjbzl"
Apr 19 01:44:20.917: INFO: Pod azurefile-volume-tester-bjbzl has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-bjbzl in namespace azurefile-1968
Apr 19 01:44:21.020: INFO: deleting PVC "azurefile-1968"/"pvc-dkc6v"
Apr 19 01:44:21.020: INFO: Deleting PersistentVolumeClaim "pvc-dkc6v"
... skipping 44 lines ...
Apr 19 01:44:42.952: INFO: PersistentVolumeClaim pvc-5ljxn found and phase=Bound (20.594515423s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: sleep 1s waiting for volume ready in windows-2022
STEP: checking that the pods command exits with no error
Apr 19 01:44:44.114: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bfmr7" in namespace "azurefile-4657" to be "Succeeded or Failed"
Apr 19 01:44:44.168: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Pending", Reason="", readiness=false. Elapsed: 53.954735ms
Apr 19 01:44:46.222: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108326685s
Apr 19 01:44:48.278: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164088896s
Apr 19 01:44:50.334: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.220042844s
Apr 19 01:44:52.389: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.275667665s
Apr 19 01:44:54.444: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Running", Reason="", readiness=true. Elapsed: 10.330678708s
Apr 19 01:44:56.499: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Running", Reason="", readiness=true. Elapsed: 12.385808483s
Apr 19 01:44:58.555: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Running", Reason="", readiness=true. Elapsed: 14.441489191s
Apr 19 01:45:00.611: INFO: Pod "azurefile-volume-tester-bfmr7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.497324438s
STEP: Saw pod success
Apr 19 01:45:00.611: INFO: Pod "azurefile-volume-tester-bfmr7" satisfied condition "Succeeded or Failed"
Apr 19 01:45:00.611: INFO: deleting Pod "azurefile-4657"/"azurefile-volume-tester-bfmr7"
Apr 19 01:45:00.675: INFO: Pod azurefile-volume-tester-bfmr7 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-bfmr7 in namespace azurefile-4657
Apr 19 01:45:00.778: INFO: deleting PVC "azurefile-4657"/"pvc-5ljxn"
Apr 19 01:45:00.778: INFO: Deleting PersistentVolumeClaim "pvc-5ljxn"
... skipping 74 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/19 01:46:25 Check successfully
Apr 19 01:46:25.456: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/19 01:46:25 run script: test/utils/get_storage_account_secret_name.sh
2022/04/19 01:46:25 got output: azure-storage-account-fecdc75e23b6b47f7b78efd-secret
, error: <nil>
2022/04/19 01:46:25 got storage account secret name: azure-storage-account-fecdc75e23b6b47f7b78efd-secret
STEP: Successfully provisioned AzureFile volume: "capz-i0pppa#fecdc75e23b6b47f7b78efd#csi-inline-smb-volume##csi-inline-smb-volume"

STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 19 01:46:26.753: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-9mw85" in namespace "azurefile-4162" to be "Succeeded or Failed"
Apr 19 01:46:26.807: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Pending", Reason="", readiness=false. Elapsed: 53.727105ms
Apr 19 01:46:28.862: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108763462s
Apr 19 01:46:30.918: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164987631s
Apr 19 01:46:32.975: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Pending", Reason="", readiness=false. Elapsed: 6.22192039s
Apr 19 01:46:35.031: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Pending", Reason="", readiness=false. Elapsed: 8.27739981s
Apr 19 01:46:37.087: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Pending", Reason="", readiness=false. Elapsed: 10.333496442s
Apr 19 01:46:39.143: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Running", Reason="", readiness=true. Elapsed: 12.389663734s
Apr 19 01:46:41.199: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Running", Reason="", readiness=true. Elapsed: 14.446261336s
Apr 19 01:46:43.255: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Running", Reason="", readiness=true. Elapsed: 16.501837649s
Apr 19 01:46:45.310: INFO: Pod "azurefile-volume-tester-9mw85": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.557253685s
STEP: Saw pod success
Apr 19 01:46:45.310: INFO: Pod "azurefile-volume-tester-9mw85" satisfied condition "Succeeded or Failed"
Apr 19 01:46:45.310: INFO: deleting Pod "azurefile-4162"/"azurefile-volume-tester-9mw85"
Apr 19 01:46:45.374: INFO: Pod azurefile-volume-tester-9mw85 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-9mw85 in namespace azurefile-4162
Apr 19 01:46:45.435: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "azurefile-4162" for this suite.
... skipping 43 lines ...
======================================================================================
2022/04/19 01:46:47 Check successfully
Apr 19 01:46:47.254: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
STEP: creating secret smbcreds in namespace azurefile-5320
2022/04/19 01:46:47 run script: test/utils/get_smb_svc_public_ip.sh
2022/04/19 01:46:47 got output: 20.99.254.223
, error: <nil>
2022/04/19 01:46:47 use server on Windows: 20.99.254.223
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 19 01:46:47.653: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-dmfpf" in namespace "azurefile-5320" to be "Succeeded or Failed"
Apr 19 01:46:47.706: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Pending", Reason="", readiness=false. Elapsed: 53.312907ms
Apr 19 01:46:49.761: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107956281s
Apr 19 01:46:51.817: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164000609s
Apr 19 01:46:53.873: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.220370351s
Apr 19 01:46:55.931: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.277878734s
Apr 19 01:46:57.986: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.333254323s
Apr 19 01:47:00.042: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Running", Reason="", readiness=true. Elapsed: 12.389374474s
Apr 19 01:47:02.099: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Running", Reason="", readiness=true. Elapsed: 14.446008406s
Apr 19 01:47:04.156: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Running", Reason="", readiness=true. Elapsed: 16.503736653s
Apr 19 01:47:06.212: INFO: Pod "azurefile-volume-tester-dmfpf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.559313686s
STEP: Saw pod success
Apr 19 01:47:06.212: INFO: Pod "azurefile-volume-tester-dmfpf" satisfied condition "Succeeded or Failed"
Apr 19 01:47:06.212: INFO: deleting Pod "azurefile-5320"/"azurefile-volume-tester-dmfpf"
Apr 19 01:47:06.276: INFO: Pod azurefile-volume-tester-dmfpf has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-dmfpf in namespace azurefile-5320
Apr 19 01:47:06.342: INFO: deleting Secret smbcreds
Apr 19 01:47:06.397: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 181 lines ...
Platform: linux/amd64

Streaming logs below:
I0419 01:25:13.201622       1 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-e26e7de71127b97f66755f201ba28bd77d2fa10e gc/go1.18.1 (amd64-linux) e2e-test
I0419 01:25:13.201941       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0419 01:25:13.217108       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
W0419 01:25:13.217380       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
I0419 01:25:13.217403       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0419 01:25:13.217413       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0419 01:25:13.217442       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0419 01:25:13.219311       1 azure_auth.go:245] Using AzurePublicCloud environment
I0419 01:25:13.219387       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0419 01:25:13.219466       1 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 2840 lines ...
Platform: windows/amd64

Streaming logs below:
I0419 01:26:12.830408    1380 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-e26e7de71127b97f66755f201ba28bd77d2fa10e gc/go1.18.1 (amd64-windows) e2e-test
I0419 01:26:12.843050    1380 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0419 01:26:12.868484    1380 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 23 milliseconds
W0419 01:26:12.870579    1380 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
I0419 01:26:12.870579    1380 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0419 01:26:12.870579    1380 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0419 01:26:12.870579    1380 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0419 01:26:12.872562    1380 azure_auth.go:245] Using AzurePublicCloud environment
I0419 01:26:12.874954    1380 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0419 01:26:12.876374    1380 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 35 lines ...
I0419 01:26:35.239276    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:26:35.239276    1380 utils.go:77] GRPC request: {}
I0419 01:26:35.239276    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0419 01:26:35.240721    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0419 01:26:35.241353    1380 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\azurefile-8081-file.csi.azure.com-preprovsioned-pv-fxfw4\\globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_id":"capz-i0pppa#fecdc75e23b6b47f7b78efd#pre-provisioned-readonly##pre-provisioned-readonly"}
I0419 01:26:35.243664    1380 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/default/secrets/azure-storage-account-fecdc75e23b6b47f7b78efd-secret 404 Not Found in 1 milliseconds
I0419 01:26:35.243664    1380 azurefile.go:616] could not get account(fecdc75e23b6b47f7b78efd) key from secret(azure-storage-account-fecdc75e23b6b47f7b78efd-secret), error: could not get secret(azure-storage-account-fecdc75e23b6b47f7b78efd-secret): secrets "azure-storage-account-fecdc75e23b6b47f7b78efd-secret" not found, use cluster identity to get account key instead
(2022-04-19T01:26:35.2465831Z) 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-19T01:26:35.7884864Z) INFO: RESPONSE: 200 https://login.microsoftonline.com/097f89a0-9286-43d2-9a1a-08f1d49b1af8/oauth2/token
Cache-Control: no-store, no-cache
Pragma: no-cache
... skipping 140 lines ...
I0419 01:33:28.444028    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:33:28.444088    1380 utils.go:77] GRPC request: {}
I0419 01:33:28.444143    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0419 01:33:28.446494    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0419 01:33:28.446525    1380 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\azurefile-2540-file.csi.azure.com-preprovsioned-pv-7zbdq\\globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_id":"capz-i0pppa#fecdc75e23b6b47f7b78efd#pre-provisioned-multiple-pods##pre-provisioned-multiple-pods1"}
I0419 01:33:28.454668    1380 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/default/secrets/azure-storage-account-fecdc75e23b6b47f7b78efd-secret 404 Not Found in 8 milliseconds
I0419 01:33:28.454668    1380 azurefile.go:616] could not get account(fecdc75e23b6b47f7b78efd) key from secret(azure-storage-account-fecdc75e23b6b47f7b78efd-secret), error: could not get secret(azure-storage-account-fecdc75e23b6b47f7b78efd-secret): secrets "azure-storage-account-fecdc75e23b6b47f7b78efd-secret" not found, use cluster identity to get account key instead
(2022-04-19T01:33:28.4546685Z) INFO: REQUEST: POST https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-i0pppa/providers/Microsoft.Storage/storageAccounts/fecdc75e23b6b47f7b78efd/listKeys?api-version=2021-02-01
Content-Type: application/json; charset=utf-8
User-Agent: Go/go1.18.1 (amd64-windows) go-autorest/v14.2.1 file.csi.azure.com/e2e-e26e7de71127b97f66755f201ba28bd77d2fa10e gc/go1.18.1 (amd64-windows) e2e-test
Authorization: **REDACTED**
(2022-04-19T01:33:28.5299030Z) INFO: RESPONSE: 200 https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-i0pppa/providers/Microsoft.Storage/storageAccounts/fecdc75e23b6b47f7b78efd/listKeys?api-version=2021-02-01
X-Ms-Ratelimit-Remaining-Subscription-Resource-Requests: 11999
... skipping 541 lines ...
I0419 01:38:08.443745    1380 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:08.443808    1380 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:08.443808    1380 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:08.444755    1380 safe_mounter_windows.go:70] SMBMount: remote path: \\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:08.444755    1380 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02
I0419 01:38:08.444755    1380 safe_mounter_windows.go:97] begin to mount \\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
E0419 01:38:13.089166    1380 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-i0pppa#fe8321e65fbd049e58865c6#pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02#) mount "\\\\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\\globalmount" failed with smb mapping failed with error: rpc error: code = Unknown desc = NewSmbGlobalMapping failed. output: "New-SmbGlobalMapping : Access is denied. \r\nAt line:1 char:190\r\n+ ... ser, $PWord;New-SmbGlobalMapping -RemotePath $Env:smbremotepath -Cred ...\r\n+                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~\r\n    + CategoryInfo          : PermissionDenied: (MSFT_SmbGlobalMapping:ROOT/Microsoft/...mbGlobalMapping) [New-SmbGlob \r\n   alMapping], CimException\r\n    + FullyQualifiedErrorId : Windows System Error 5,New-SmbGlobalMapping\r\n \r\n", err: exit status 1
I0419 01:38:13.654469    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:38:13.654469    1380 utils.go:77] GRPC request: {}
I0419 01:38:13.654469    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0419 01:38:13.657452    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:38:13.657516    1380 utils.go:77] GRPC request: {}
I0419 01:38:13.657620    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
... skipping 8 lines ...
I0419 01:38:13.664320    1380 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:13.664320    1380 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:13.664888    1380 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:13.664960    1380 safe_mounter_windows.go:70] SMBMount: remote path: \\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:13.665498    1380 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02
I0419 01:38:13.665580    1380 safe_mounter_windows.go:97] begin to mount \\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
E0419 01:38:15.857443    1380 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-i0pppa#fe8321e65fbd049e58865c6#pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02#) mount "\\\\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\\globalmount" failed with smb mapping failed with error: rpc error: code = Unknown desc = NewSmbGlobalMapping failed. output: "New-SmbGlobalMapping : Access is denied. \r\nAt line:1 char:190\r\n+ ... ser, $PWord;New-SmbGlobalMapping -RemotePath $Env:smbremotepath -Cred ...\r\n+                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~\r\n    + CategoryInfo          : PermissionDenied: (MSFT_SmbGlobalMapping:ROOT/Microsoft/...mbGlobalMapping) [New-SmbGlob \r\n   alMapping], CimException\r\n    + FullyQualifiedErrorId : Windows System Error 5,New-SmbGlobalMapping\r\n \r\n", err: exit status 1
I0419 01:38:16.868106    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:38:16.868106    1380 utils.go:77] GRPC request: {}
I0419 01:38:16.868106    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0419 01:38:16.872532    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:38:16.872532    1380 utils.go:77] GRPC request: {}
I0419 01:38:16.872532    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
... skipping 8 lines ...
I0419 01:38:16.877404    1380 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:16.877429    1380 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:16.877429    1380 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:16.878082    1380 safe_mounter_windows.go:70] SMBMount: remote path: \\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:16.878082    1380 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02
I0419 01:38:16.878649    1380 safe_mounter_windows.go:97] begin to mount \\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
E0419 01:38:19.073671    1380 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-i0pppa#fe8321e65fbd049e58865c6#pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02#) mount "\\\\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\\globalmount" failed with smb mapping failed with error: rpc error: code = Unknown desc = NewSmbGlobalMapping failed. output: "New-SmbGlobalMapping : Access is denied. \r\nAt line:1 char:190\r\n+ ... ser, $PWord;New-SmbGlobalMapping -RemotePath $Env:smbremotepath -Cred ...\r\n+                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~\r\n    + CategoryInfo          : PermissionDenied: (MSFT_SmbGlobalMapping:ROOT/Microsoft/...mbGlobalMapping) [New-SmbGlob \r\n   alMapping], CimException\r\n    + FullyQualifiedErrorId : Windows System Error 5,New-SmbGlobalMapping\r\n \r\n", err: exit status 1
I0419 01:38:19.076824    1380 utils.go:76] GRPC call: /csi.v1.Identity/Probe
I0419 01:38:19.076824    1380 utils.go:77] GRPC request: {}
I0419 01:38:19.076956    1380 utils.go:83] GRPC response: {"ready":{"value":true}}
I0419 01:38:21.178459    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:38:21.178509    1380 utils.go:77] GRPC request: {}
I0419 01:38:21.178617    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
... skipping 11 lines ...
I0419 01:38:21.188233    1380 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:21.189041    1380 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:21.189041    1380 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:21.192300    1380 safe_mounter_windows.go:70] SMBMount: remote path: \\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
I0419 01:38:21.193025    1380 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02
I0419 01:38:21.193025    1380 safe_mounter_windows.go:97] begin to mount \\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\globalmount
E0419 01:38:23.412618    1380 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-i0pppa#fe8321e65fbd049e58865c6#pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02#) mount "\\\\fe8321e65fbd049e58865c6.privatelink.file.core.windows.net\\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-13094c0b-f607-4cd4-a661-d8ed2d2f5f02\\globalmount" failed with smb mapping failed with error: rpc error: code = Unknown desc = NewSmbGlobalMapping failed. output: "New-SmbGlobalMapping : Access is denied. \r\nAt line:1 char:190\r\n+ ... ser, $PWord;New-SmbGlobalMapping -RemotePath $Env:smbremotepath -Cred ...\r\n+                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~\r\n    + CategoryInfo          : PermissionDenied: (MSFT_SmbGlobalMapping:ROOT/Microsoft/...mbGlobalMapping) [New-SmbGlob \r\n   alMapping], CimException\r\n    + FullyQualifiedErrorId : Windows System Error 5,New-SmbGlobalMapping\r\n \r\n", err: exit status 1
I0419 01:38:27.454456    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:38:27.454456    1380 utils.go:77] GRPC request: {}
I0419 01:38:27.454456    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0419 01:38:27.457313    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:38:27.457313    1380 utils.go:77] GRPC request: {}
I0419 01:38:27.457313    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
... skipping 1148 lines ...
I0419 01:46:27.033522    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:46:27.033522    1380 utils.go:77] GRPC request: {}
I0419 01:46:27.033522    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0419 01:46:27.035283    1380 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0419 01:46:27.035355    1380 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\a0b79fdb-9e8f-4472-a032-23a48f333cbc\\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-9mw85","csi.storage.k8s.io/pod.namespace":"azurefile-4162","csi.storage.k8s.io/pod.uid":"a0b79fdb-9e8f-4472-a032-23a48f333cbc","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"azure-storage-account-fecdc75e23b6b47f7b78efd-secret","server":"","shareName":"csi-inline-smb-volume"},"volume_id":"csi-ce929700f04bf093e9459a538338718d45e8ca26ef5f579b20743b1260e2f709"}
I0419 01:46:27.035442    1380 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-ce929700f04bf093e9459a538338718d45e8ca26ef5f579b20743b1260e2f709) mount on c:\var\lib\kubelet\pods\a0b79fdb-9e8f-4472-a032-23a48f333cbc\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-9mw85 csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:a0b79fdb-9e8f-4472-a032-23a48f333cbc csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-fecdc75e23b6b47f7b78efd-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]
W0419 01:46:27.035442    1380 azurefile.go:546] parsing volumeID(csi-ce929700f04bf093e9459a538338718d45e8ca26ef5f579b20743b1260e2f709) return with error: error parsing volume id: "csi-ce929700f04bf093e9459a538338718d45e8ca26ef5f579b20743b1260e2f709", should at least contain two #
I0419 01:46:27.045730    1380 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-4162/secrets/azure-storage-account-fecdc75e23b6b47f7b78efd-secret 200 OK in 9 milliseconds
I0419 01:46:27.045730    1380 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\a0b79fdb-9e8f-4472-a032-23a48f333cbc\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-ce929700f04bf093e9459a538338718d45e8ca26ef5f579b20743b1260e2f709) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-9mw85 csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:a0b79fdb-9e8f-4472-a032-23a48f333cbc csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-fecdc75e23b6b47f7b78efd-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]) mountflags([]) mountOptions([AZURE\fecdc75e23b6b47f7b78efd]) volumeMountGroup()
I0419 01:46:27.045730    1380 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\a0b79fdb-9e8f-4472-a032-23a48f333cbc\volumes\kubernetes.io~csi\test-volume-1\mount
I0419 01:46:27.045730    1380 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\a0b79fdb-9e8f-4472-a032-23a48f333cbc\volumes\kubernetes.io~csi\test-volume-1\mount
I0419 01:46:27.047719    1380 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\a0b79fdb-9e8f-4472-a032-23a48f333cbc\volumes\kubernetes.io~csi\test-volume-1\mount
I0419 01:46:27.047719    1380 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\a0b79fdb-9e8f-4472-a032-23a48f333cbc\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 17 lines ...
I0419 01:46:47.920892    1380 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0419 01:46:47.920939    1380 utils.go:77] GRPC request: {}
I0419 01:46:47.920939    1380 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0419 01:46:47.922255    1380 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0419 01:46:47.922337    1380 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\de4692a0-b05c-4361-9104-392e27417575\\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-dmfpf","csi.storage.k8s.io/pod.namespace":"azurefile-5320","csi.storage.k8s.io/pod.uid":"de4692a0-b05c-4361-9104-392e27417575","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"smbcreds","server":"20.99.254.223","shareName":"share"},"volume_id":"csi-8ea8707dfd2daffdc47123fb041a745097a5567b5ef44ac52fb4e0d9fc602650"}
I0419 01:46:47.922435    1380 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-8ea8707dfd2daffdc47123fb041a745097a5567b5ef44ac52fb4e0d9fc602650) mount on c:\var\lib\kubelet\pods\de4692a0-b05c-4361-9104-392e27417575\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-dmfpf csi.storage.k8s.io/pod.namespace:azurefile-5320 csi.storage.k8s.io/pod.uid:de4692a0-b05c-4361-9104-392e27417575 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:smbcreds secretnamespace:azurefile-5320 server:20.99.254.223 shareName:share storageaccount:]
W0419 01:46:47.922435    1380 azurefile.go:546] parsing volumeID(csi-8ea8707dfd2daffdc47123fb041a745097a5567b5ef44ac52fb4e0d9fc602650) return with error: error parsing volume id: "csi-8ea8707dfd2daffdc47123fb041a745097a5567b5ef44ac52fb4e0d9fc602650", should at least contain two #
I0419 01:46:47.925855    1380 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-5320/secrets/smbcreds 200 OK in 3 milliseconds
I0419 01:46:47.925855    1380 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\de4692a0-b05c-4361-9104-392e27417575\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-8ea8707dfd2daffdc47123fb041a745097a5567b5ef44ac52fb4e0d9fc602650) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-dmfpf csi.storage.k8s.io/pod.namespace:azurefile-5320 csi.storage.k8s.io/pod.uid:de4692a0-b05c-4361-9104-392e27417575 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:smbcreds secretnamespace:azurefile-5320 server:20.99.254.223 shareName:share storageaccount:]) mountflags([]) mountOptions([AZURE\USERNAME]) volumeMountGroup()
I0419 01:46:47.925855    1380 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\de4692a0-b05c-4361-9104-392e27417575\volumes\kubernetes.io~csi\test-volume-1\mount
I0419 01:46:47.925855    1380 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\de4692a0-b05c-4361-9104-392e27417575\volumes\kubernetes.io~csi\test-volume-1\mount
I0419 01:46:47.927102    1380 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\de4692a0-b05c-4361-9104-392e27417575\volumes\kubernetes.io~csi\test-volume-1\mount
I0419 01:46:47.928163    1380 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\de4692a0-b05c-4361-9104-392e27417575\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 123 lines ...
Platform: windows/amd64

Streaming logs below:
I0419 01:26:07.907793    6996 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-e26e7de71127b97f66755f201ba28bd77d2fa10e gc/go1.18.1 (amd64-windows) e2e-test
I0419 01:26:07.919427    6996 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0419 01:26:07.938923    6996 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 12 milliseconds
W0419 01:26:07.944547    6996 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
I0419 01:26:07.944547    6996 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0419 01:26:07.944547    6996 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0419 01:26:07.944547    6996 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0419 01:26:07.946200    6996 azure_auth.go:245] Using AzurePublicCloud environment
I0419 01:26:07.947672    6996 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0419 01:26:07.948997    6996 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 574 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 20 of 34 Specs in 1400.421 seconds
FAIL! -- 19 Passed | 1 Failed | 0 Pending | 14 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 (1400.43s)
FAIL
FAIL	sigs.k8s.io/azurefile-csi-driver/test/e2e	1400.482s
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 97 lines ...