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-17 11:05
Elapsed45m56s
Revision6ef34dea3391800ae98f85f6700d7af3463efd40
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] 7m6s

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 673 lines ...
certificate.cert-manager.io "selfsigned-cert" deleted
# Create secret for AzureClusterIdentity
./hack/create-identity-secret.sh
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
make[2]: Nothing to be done for 'kubectl'.
make[2]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
Error from server (NotFound): secrets "cluster-identity-secret" not found
secret/cluster-identity-secret created
secret/cluster-identity-secret labeled
# Deploy CAPI
curl --retry 3 -sSL https://github.com/kubernetes-sigs/cluster-api/releases/download/v1.1.2/cluster-api-components.yaml | /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/envsubst-v2.0.0-20210730161058-179042472c46 | kubectl apply -f -
namespace/capi-system created
customresourcedefinition.apiextensions.k8s.io/clusterclasses.cluster.x-k8s.io created
... skipping 1165 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
W0417 11:22:04.144388   36498 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret /: failed to get secret /: resource name may not be empty
I0417 11:22:04.146466   36498 driver.go:93] Enabling controller service capability: CREATE_DELETE_VOLUME
I0417 11:22:04.146493   36498 driver.go:93] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME
I0417 11:22:04.146499   36498 driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0417 11:22:04.146504   36498 driver.go:93] Enabling controller service capability: EXPAND_VOLUME
I0417 11:22:04.146507   36498 driver.go:93] Enabling controller service capability: SINGLE_NODE_MULTI_WRITER
I0417 11:22:04.146514   36498 driver.go:112] Enabling volume access mode: SINGLE_NODE_WRITER
... skipping 23 lines ...
Apr 17 11:22:26.053: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-76kkj] to have phase Bound
Apr 17 11:22:26.085: INFO: PersistentVolumeClaim pvc-76kkj found and phase=Bound (32.500284ms)
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 17 11:22:26.186: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-vscx9" in namespace "azurefile-8081" to be "Error status code"
Apr 17 11:22:26.221: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 35.42273ms
Apr 17 11:22:28.256: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.070270039s
Apr 17 11:22:30.292: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.1063825s
Apr 17 11:22:32.326: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.140375496s
Apr 17 11:22:34.360: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.174226049s
Apr 17 11:22:36.397: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.211188177s
... skipping 185 lines ...
Apr 17 11:28:55.208: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 6m29.021846345s
Apr 17 11:28:57.245: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 6m31.058814512s
Apr 17 11:28:59.281: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 6m33.095559068s
Apr 17 11:29:01.318: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 6m35.131873772s
Apr 17 11:29:03.354: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 6m37.167655707s
Apr 17 11:29:05.391: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Pending", Reason="", readiness=false. Elapsed: 6m39.204689229s
Apr 17 11:29:07.427: INFO: Pod "azurefile-volume-tester-vscx9": Phase="Failed", Reason="", readiness=false. Elapsed: 6m41.241414462s
STEP: Saw pod failure
Apr 17 11:29:07.427: INFO: Pod "azurefile-volume-tester-vscx9" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 17 11:29:07.511: INFO: deleting Pod "azurefile-8081"/"azurefile-volume-tester-vscx9"
Apr 17 11:29:07.548: INFO: Pod azurefile-volume-tester-vscx9 has the following logs: 
STEP: Deleting pod azurefile-volume-tester-vscx9 in namespace azurefile-8081
Apr 17 11:29:07.600: INFO: deleting PVC "azurefile-8081"/"pvc-76kkj"
Apr 17 11:29:07.600: INFO: Deleting PersistentVolumeClaim "pvc-76kkj"
... skipping 7 lines ...
STEP: Collecting events from namespace "azurefile-8081".
STEP: Found 7 events.
Apr 17 11:29:07.773: INFO: At 2022-04-17 11:22:26 +0000 UTC - event for azurefile-volume-tester-vscx9: {default-scheduler } Scheduled: Successfully assigned azurefile-8081/azurefile-volume-tester-vscx9 to capz-h6v6-6r4f8
Apr 17 11:29:07.773: INFO: At 2022-04-17 11:22:37 +0000 UTC - event for azurefile-volume-tester-vscx9: {kubelet capz-h6v6-6r4f8} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Apr 17 11:29:07.773: INFO: At 2022-04-17 11:27:05 +0000 UTC - event for azurefile-volume-tester-vscx9: {kubelet capz-h6v6-6r4f8} Pulled: Successfully pulled image "mcr.microsoft.com/windows/servercore:ltsc2022" in 4m28.0604563s
Apr 17 11:29:07.773: INFO: At 2022-04-17 11:27:05 +0000 UTC - event for azurefile-volume-tester-vscx9: {kubelet capz-h6v6-6r4f8} Created: Created container volume-tester
Apr 17 11:29:07.773: INFO: At 2022-04-17 11:29:05 +0000 UTC - event for azurefile-volume-tester-vscx9: {kubelet capz-h6v6-6r4f8} Failed: Error: context deadline exceeded
Apr 17 11:29:07.773: INFO: At 2022-04-17 11:29:05 +0000 UTC - event for azurefile-volume-tester-vscx9: {kubelet capz-h6v6-6r4f8} Pulled: Container image "mcr.microsoft.com/windows/servercore:ltsc2022" already present on machine
Apr 17 11:29:07.773: INFO: At 2022-04-17 11:29:06 +0000 UTC - event for azurefile-volume-tester-vscx9: {kubelet capz-h6v6-6r4f8} FailedMount: MountVolume.SetUp failed for volume "kube-api-access-qc9nw" : object "azurefile-8081"/"kube-root-ca.crt" not registered
Apr 17 11:29:07.808: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Apr 17 11:29:07.808: INFO: 
Apr 17 11:29:07.874: INFO: 
Logging node info for node capz-h6v6-56577
Apr 17 11:29:07.908: INFO: Node Info: &Node{ObjectMeta:{capz-h6v6-56577    dc64c535-d38d-41da-bd83-e9598372a23b 2610 0 2022-04-17 11:16:58 +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:eastus failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-h6v6-56577 kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.20348 topology.kubernetes.io/region:eastus topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-h6v6as cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-h6v6as-md-win-8578c8fd8b-662fd cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-h6v6as-md-win-8578c8fd8b csi.volume.kubernetes.io/nodeid:{"file.csi.azure.com":"capz-h6v6-56577"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.36.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:a7:e9:ea volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{Go-http-client Update v1 2022-04-17 11:16:58 +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-17 11:17:17 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-04-17 11:17:17 +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-17 11:18:30 +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-17 11:22:03 +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-h6v6as/providers/Microsoft.Compute/virtualMachines/capz-h6v6-56577,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-17 11:27:12 +0000 UTC,LastTransitionTime:2022-04-17 11:16:58 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-04-17 11:27:12 +0000 UTC,LastTransitionTime:2022-04-17 11:16:58 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-04-17 11:27:12 +0000 UTC,LastTransitionTime:2022-04-17 11:16:58 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-04-17 11:27:12 +0000 UTC,LastTransitionTime:2022-04-17 11:18:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-h6v6-56577,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-h6v6-56577,SystemUUID:37EA617D-3668-4AC0-AF08-75A192DECEBB,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:f81c333532006dc1b95dc04ee7443ea5c31d06043c3907e84a13d51bcbbdaf39 capzci.azurecr.io/azurefile-csi:e2e-a3f61a5e163bc4536ff4e8a3aac2b0f5e7027564],SizeBytes:130280746,},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,},}
Apr 17 11:29:07.909: INFO: 
... skipping 145 lines ...
Apr 17 11:29:11.620: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-wczv5] to have phase Bound
Apr 17 11:29:11.653: INFO: PersistentVolumeClaim pvc-wczv5 found and phase=Bound (32.72607ms)
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 17 11:29:11.755: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-54r7f" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 17 11:29:11.787: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Pending", Reason="", readiness=false. Elapsed: 32.808652ms
Apr 17 11:29:13.822: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Pending", Reason="", readiness=false. Elapsed: 2.067413752s
Apr 17 11:29:15.856: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Pending", Reason="", readiness=false. Elapsed: 4.101896317s
Apr 17 11:29:17.891: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Pending", Reason="", readiness=false. Elapsed: 6.13670967s
Apr 17 11:29:19.927: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Pending", Reason="", readiness=false. Elapsed: 8.172196922s
Apr 17 11:29:21.962: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Pending", Reason="", readiness=false. Elapsed: 10.207268111s
Apr 17 11:29:23.997: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Running", Reason="", readiness=true. Elapsed: 12.242227031s
Apr 17 11:29:26.032: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Running", Reason="", readiness=true. Elapsed: 14.277798967s
Apr 17 11:29:28.070: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Running", Reason="", readiness=true. Elapsed: 16.315487033s
Apr 17 11:29:30.106: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Running", Reason="", readiness=true. Elapsed: 18.35136365s
Apr 17 11:29:32.141: INFO: Pod "azurefile-volume-tester-54r7f": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.386783717s
STEP: Saw pod success
Apr 17 11:29:32.141: INFO: Pod "azurefile-volume-tester-54r7f" 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 17 11:29:32.209: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-hbb8d] to have phase Bound
Apr 17 11:29:32.244: INFO: PersistentVolumeClaim pvc-hbb8d found and phase=Bound (34.207365ms)
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 17 11:29:32.346: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-8nq2w" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 17 11:29:32.379: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Pending", Reason="", readiness=false. Elapsed: 32.996847ms
Apr 17 11:29:34.417: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071256342s
Apr 17 11:29:36.452: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Pending", Reason="", readiness=false. Elapsed: 4.105731779s
Apr 17 11:29:38.487: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Pending", Reason="", readiness=false. Elapsed: 6.140862263s
Apr 17 11:29:40.521: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Pending", Reason="", readiness=false. Elapsed: 8.175137408s
Apr 17 11:29:42.556: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Running", Reason="", readiness=true. Elapsed: 10.210167507s
Apr 17 11:29:44.591: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Running", Reason="", readiness=true. Elapsed: 12.244647619s
Apr 17 11:29:46.625: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Running", Reason="", readiness=true. Elapsed: 14.279356282s
Apr 17 11:29:48.661: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Running", Reason="", readiness=true. Elapsed: 16.314923816s
Apr 17 11:29:50.697: INFO: Pod "azurefile-volume-tester-8nq2w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.350624673s
STEP: Saw pod success
Apr 17 11:29:50.697: INFO: Pod "azurefile-volume-tester-8nq2w" 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 17 11:29:50.778: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-rtfbq] to have phase Bound
Apr 17 11:29:50.812: INFO: PersistentVolumeClaim pvc-rtfbq found and phase=Bound (33.931749ms)
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 17 11:29:50.913: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-6t4xl" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 17 11:29:50.946: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Pending", Reason="", readiness=false. Elapsed: 32.740418ms
Apr 17 11:29:52.980: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.066533335s
Apr 17 11:29:55.014: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.10089313s
Apr 17 11:29:57.050: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.136693847s
Apr 17 11:29:59.085: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.171322768s
Apr 17 11:30:01.120: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Running", Reason="", readiness=true. Elapsed: 10.206317856s
Apr 17 11:30:03.154: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Running", Reason="", readiness=true. Elapsed: 12.240939575s
Apr 17 11:30:05.190: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Running", Reason="", readiness=true. Elapsed: 14.276715813s
Apr 17 11:30:07.224: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Running", Reason="", readiness=true. Elapsed: 16.311074307s
Apr 17 11:30:09.259: INFO: Pod "azurefile-volume-tester-6t4xl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.346033573s
STEP: Saw pod success
Apr 17 11:30:09.259: INFO: Pod "azurefile-volume-tester-6t4xl" 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 17 11:30:09.331: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-bwrvb] to have phase Bound
Apr 17 11:30:09.364: INFO: PersistentVolumeClaim pvc-bwrvb found and phase=Bound (32.824094ms)
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 17 11:30:09.465: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-2225v" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 17 11:30:09.498: INFO: Pod "azurefile-volume-tester-2225v": Phase="Pending", Reason="", readiness=false. Elapsed: 32.670774ms
Apr 17 11:30:11.531: INFO: Pod "azurefile-volume-tester-2225v": Phase="Pending", Reason="", readiness=false. Elapsed: 2.066260095s
Apr 17 11:30:13.567: INFO: Pod "azurefile-volume-tester-2225v": Phase="Pending", Reason="", readiness=false. Elapsed: 4.101667313s
Apr 17 11:30:15.602: INFO: Pod "azurefile-volume-tester-2225v": Phase="Pending", Reason="", readiness=false. Elapsed: 6.137105654s
Apr 17 11:30:17.637: INFO: Pod "azurefile-volume-tester-2225v": Phase="Pending", Reason="", readiness=false. Elapsed: 8.171805061s
Apr 17 11:30:19.671: INFO: Pod "azurefile-volume-tester-2225v": Phase="Running", Reason="", readiness=true. Elapsed: 10.206300012s
Apr 17 11:30:21.706: INFO: Pod "azurefile-volume-tester-2225v": Phase="Running", Reason="", readiness=true. Elapsed: 12.241055749s
Apr 17 11:30:23.741: INFO: Pod "azurefile-volume-tester-2225v": Phase="Running", Reason="", readiness=true. Elapsed: 14.276026552s
Apr 17 11:30:25.776: INFO: Pod "azurefile-volume-tester-2225v": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.311430028s
STEP: Saw pod success
Apr 17 11:30:25.776: INFO: Pod "azurefile-volume-tester-2225v" 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 17 11:30:25.849: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-zt7rr] to have phase Bound
Apr 17 11:30:25.881: INFO: PersistentVolumeClaim pvc-zt7rr found and phase=Bound (32.620558ms)
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 17 11:30:25.982: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-gf8vt" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 17 11:30:26.015: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Pending", Reason="", readiness=false. Elapsed: 32.900377ms
Apr 17 11:30:28.049: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.067020052s
Apr 17 11:30:30.084: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.101932155s
Apr 17 11:30:32.119: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.137436084s
Apr 17 11:30:34.155: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.173064256s
Apr 17 11:30:36.190: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Running", Reason="", readiness=true. Elapsed: 10.208324629s
Apr 17 11:30:38.226: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Running", Reason="", readiness=true. Elapsed: 12.243733463s
Apr 17 11:30:40.261: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Running", Reason="", readiness=true. Elapsed: 14.279482319s
Apr 17 11:30:42.297: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Running", Reason="", readiness=true. Elapsed: 16.314898241s
Apr 17 11:30:44.332: INFO: Pod "azurefile-volume-tester-gf8vt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.350095927s
STEP: Saw pod success
Apr 17 11:30:44.332: INFO: Pod "azurefile-volume-tester-gf8vt" 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 17 11:30:44.401: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-f5vhp] to have phase Bound
Apr 17 11:30:44.434: INFO: PersistentVolumeClaim pvc-f5vhp found and phase=Bound (32.928645ms)
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 17 11:30:44.536: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-hj6pt" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 17 11:30:44.569: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Pending", Reason="", readiness=false. Elapsed: 33.027755ms
Apr 17 11:30:46.604: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.067983144s
Apr 17 11:30:48.640: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.103499209s
Apr 17 11:30:50.674: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.138042047s
Apr 17 11:30:52.710: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.174042796s
Apr 17 11:30:54.746: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Running", Reason="", readiness=true. Elapsed: 10.209631824s
Apr 17 11:30:56.782: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Running", Reason="", readiness=true. Elapsed: 12.24562982s
Apr 17 11:30:58.817: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Running", Reason="", readiness=true. Elapsed: 14.281049261s
Apr 17 11:31:00.852: INFO: Pod "azurefile-volume-tester-hj6pt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.315518262s
STEP: Saw pod success
Apr 17 11:31:00.852: INFO: Pod "azurefile-volume-tester-hj6pt" satisfied condition "Succeeded or Failed"
Apr 17 11:31:00.852: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-hj6pt"
Apr 17 11:31:00.902: INFO: Pod azurefile-volume-tester-hj6pt has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-hj6pt in namespace azurefile-2540
Apr 17 11:31:00.947: INFO: deleting PVC "azurefile-2540"/"pvc-f5vhp"
Apr 17 11:31:00.947: INFO: Deleting PersistentVolumeClaim "pvc-f5vhp"
... skipping 143 lines ...
Apr 17 11:31:06.119: INFO: PersistentVolumeClaim pvc-9lrtt found but phase is Pending instead of Bound.
Apr 17 11:31:08.153: INFO: PersistentVolumeClaim pvc-9lrtt found and phase=Bound (2.066903117s)
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 17 11:31:08.255: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-rmc8n" in namespace "azurefile-5466" to be "Succeeded or Failed"
Apr 17 11:31:08.310: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Pending", Reason="", readiness=false. Elapsed: 54.338947ms
Apr 17 11:31:10.344: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Pending", Reason="", readiness=false. Elapsed: 2.088991643s
Apr 17 11:31:12.379: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Pending", Reason="", readiness=false. Elapsed: 4.123870886s
Apr 17 11:31:14.414: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Pending", Reason="", readiness=false. Elapsed: 6.159012503s
Apr 17 11:31:16.450: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Pending", Reason="", readiness=false. Elapsed: 8.194511037s
Apr 17 11:31:18.485: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Pending", Reason="", readiness=false. Elapsed: 10.229296824s
Apr 17 11:31:20.520: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Running", Reason="", readiness=true. Elapsed: 12.264273582s
Apr 17 11:31:22.554: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Running", Reason="", readiness=true. Elapsed: 14.298900995s
Apr 17 11:31:24.590: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Running", Reason="", readiness=true. Elapsed: 16.334461238s
Apr 17 11:31:26.625: INFO: Pod "azurefile-volume-tester-rmc8n": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.369503847s
STEP: Saw pod success
Apr 17 11:31:26.625: INFO: Pod "azurefile-volume-tester-rmc8n" satisfied condition "Succeeded or Failed"
Apr 17 11:31:26.625: INFO: deleting Pod "azurefile-5466"/"azurefile-volume-tester-rmc8n"
Apr 17 11:31:26.669: INFO: Pod azurefile-volume-tester-rmc8n has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-rmc8n in namespace azurefile-5466
Apr 17 11:31:26.709: INFO: deleting PVC "azurefile-5466"/"pvc-9lrtt"
Apr 17 11:31:26.709: INFO: Deleting PersistentVolumeClaim "pvc-9lrtt"
... skipping 33 lines ...
Apr 17 11:31:28.267: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-5kjpr] to have phase Bound
Apr 17 11:31:28.301: INFO: PersistentVolumeClaim pvc-5kjpr found and phase=Bound (34.087931ms)
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 17 11:31:28.402: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-hh5cn" in namespace "azurefile-2790" to be "Succeeded or Failed"
Apr 17 11:31:28.435: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Pending", Reason="", readiness=false. Elapsed: 32.695073ms
Apr 17 11:31:30.470: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.068425017s
Apr 17 11:31:32.506: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.104068486s
Apr 17 11:31:34.541: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.139007143s
Apr 17 11:31:36.576: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.174127018s
Apr 17 11:31:38.612: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.210123127s
Apr 17 11:31:40.648: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Running", Reason="", readiness=true. Elapsed: 12.24570907s
Apr 17 11:31:42.682: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Running", Reason="", readiness=true. Elapsed: 14.279910462s
Apr 17 11:31:44.717: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Running", Reason="", readiness=true. Elapsed: 16.315244544s
Apr 17 11:31:46.751: INFO: Pod "azurefile-volume-tester-hh5cn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.349339739s
STEP: Saw pod success
Apr 17 11:31:46.751: INFO: Pod "azurefile-volume-tester-hh5cn" satisfied condition "Succeeded or Failed"
Apr 17 11:31:46.751: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-hh5cn"
Apr 17 11:31:46.795: INFO: Pod azurefile-volume-tester-hh5cn has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-hh5cn in namespace azurefile-2790
Apr 17 11:31:46.834: INFO: deleting PVC "azurefile-2790"/"pvc-5kjpr"
Apr 17 11:31:46.834: INFO: Deleting PersistentVolumeClaim "pvc-5kjpr"
... skipping 136 lines ...
Apr 17 11:33:54.426: INFO: PersistentVolumeClaim pvc-6msq4 found but phase is Pending instead of Bound.
Apr 17 11:33:56.460: INFO: PersistentVolumeClaim pvc-6msq4 found and phase=Bound (1m39.711468628s)
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 17 11:33:56.563: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-5mdb2" in namespace "azurefile-5194" to be "Succeeded or Failed"
Apr 17 11:33:56.597: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Pending", Reason="", readiness=false. Elapsed: 33.164731ms
Apr 17 11:33:58.631: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.067157284s
Apr 17 11:34:00.666: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.102470643s
Apr 17 11:34:02.701: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.137323861s
Apr 17 11:34:04.735: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.171240161s
Apr 17 11:34:06.769: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.205477745s
... skipping 40 lines ...
Apr 17 11:35:30.193: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Pending", Reason="", readiness=false. Elapsed: 1m33.629766384s
Apr 17 11:35:32.228: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Running", Reason="", readiness=true. Elapsed: 1m35.66432453s
Apr 17 11:35:34.263: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Running", Reason="", readiness=true. Elapsed: 1m37.699519206s
Apr 17 11:35:36.298: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Running", Reason="", readiness=true. Elapsed: 1m39.734541267s
Apr 17 11:35:38.333: INFO: Pod "azurefile-volume-tester-5mdb2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m41.769558554s
STEP: Saw pod success
Apr 17 11:35:38.333: INFO: Pod "azurefile-volume-tester-5mdb2" satisfied condition "Succeeded or Failed"
Apr 17 11:35:38.333: INFO: deleting Pod "azurefile-5194"/"azurefile-volume-tester-5mdb2"
Apr 17 11:35:38.396: INFO: Pod azurefile-volume-tester-5mdb2 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-5mdb2 in namespace azurefile-5194
Apr 17 11:35:38.438: INFO: deleting PVC "azurefile-5194"/"pvc-6msq4"
Apr 17 11:35:38.438: INFO: Deleting PersistentVolumeClaim "pvc-6msq4"
... skipping 35 lines ...
Apr 17 11:35:44.366: INFO: PersistentVolumeClaim pvc-jtxks found but phase is Pending instead of Bound.
Apr 17 11:35:46.400: INFO: PersistentVolumeClaim pvc-jtxks found and phase=Bound (2.06640618s)
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 17 11:35:46.501: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-x9tn7" in namespace "azurefile-1353" to be "Succeeded or Failed"
Apr 17 11:35:46.535: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Pending", Reason="", readiness=false. Elapsed: 34.695966ms
Apr 17 11:35:48.570: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069112114s
Apr 17 11:35:50.605: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.104740343s
Apr 17 11:35:52.640: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.139357343s
Apr 17 11:35:54.675: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.174038752s
Apr 17 11:35:56.710: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Pending", Reason="", readiness=false. Elapsed: 10.209822797s
Apr 17 11:35:58.745: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Pending", Reason="", readiness=false. Elapsed: 12.244501221s
Apr 17 11:36:00.781: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Pending", Reason="", readiness=false. Elapsed: 14.280621699s
Apr 17 11:36:02.816: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Running", Reason="", readiness=true. Elapsed: 16.315730823s
Apr 17 11:36:04.851: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Running", Reason="", readiness=true. Elapsed: 18.350280673s
Apr 17 11:36:06.887: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Running", Reason="", readiness=true. Elapsed: 20.386642552s
Apr 17 11:36:08.923: INFO: Pod "azurefile-volume-tester-x9tn7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.422139286s
STEP: Saw pod success
Apr 17 11:36:08.923: INFO: Pod "azurefile-volume-tester-x9tn7" satisfied condition "Succeeded or Failed"
Apr 17 11:36:08.923: INFO: deleting Pod "azurefile-1353"/"azurefile-volume-tester-x9tn7"
Apr 17 11:36:08.965: INFO: Pod azurefile-volume-tester-x9tn7 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-x9tn7 in namespace azurefile-1353
Apr 17 11:36:09.006: INFO: deleting PVC "azurefile-1353"/"pvc-jtxks"
Apr 17 11:36:09.006: INFO: Deleting PersistentVolumeClaim "pvc-jtxks"
... skipping 117 lines ...
Apr 17 11:37:15.183: INFO: PersistentVolumeClaim pvc-8vlm7 found but phase is Pending instead of Bound.
Apr 17 11:37:17.217: INFO: PersistentVolumeClaim pvc-8vlm7 found and phase=Bound (22.411861604s)
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 17 11:37:17.319: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-mttsx" in namespace "azurefile-156" to be "Error status code"
Apr 17 11:37:17.352: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Pending", Reason="", readiness=false. Elapsed: 33.005085ms
Apr 17 11:37:19.387: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.067862204s
Apr 17 11:37:21.422: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.103174841s
Apr 17 11:37:23.458: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.138598766s
Apr 17 11:37:25.493: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.174358398s
Apr 17 11:37:27.528: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.209263786s
Apr 17 11:37:29.564: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Running", Reason="", readiness=true. Elapsed: 12.244597297s
Apr 17 11:37:31.599: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Running", Reason="", readiness=true. Elapsed: 14.280206661s
Apr 17 11:37:33.636: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Running", Reason="", readiness=true. Elapsed: 16.316970907s
Apr 17 11:37:35.671: INFO: Pod "azurefile-volume-tester-mttsx": Phase="Failed", Reason="", readiness=false. Elapsed: 18.352169163s
STEP: Saw pod failure
Apr 17 11:37:35.671: INFO: Pod "azurefile-volume-tester-mttsx" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 17 11:37:35.723: INFO: deleting Pod "azurefile-156"/"azurefile-volume-tester-mttsx"
Apr 17 11:37:35.762: INFO: Pod azurefile-volume-tester-mttsx 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 17 11:38:50.738: INFO: PersistentVolumeClaim pvc-tqdvg found but phase is Pending instead of Bound.
Apr 17 11:38:52.772: INFO: PersistentVolumeClaim pvc-tqdvg found and phase=Bound (2.067477907s)
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 17 11:38:52.877: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-smbmb" in namespace "azurefile-2546" to be "Succeeded or Failed"
Apr 17 11:38:52.909: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Pending", Reason="", readiness=false. Elapsed: 32.627087ms
Apr 17 11:38:54.944: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.067298333s
Apr 17 11:38:56.979: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.102110825s
Apr 17 11:38:59.014: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.137157954s
Apr 17 11:39:01.049: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.172392081s
Apr 17 11:39:03.084: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.207333205s
Apr 17 11:39:05.118: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Running", Reason="", readiness=true. Elapsed: 12.241586625s
Apr 17 11:39:07.154: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Running", Reason="", readiness=true. Elapsed: 14.277807208s
Apr 17 11:39:09.190: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Running", Reason="", readiness=true. Elapsed: 16.313013638s
Apr 17 11:39:11.223: INFO: Pod "azurefile-volume-tester-smbmb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.346723207s
STEP: Saw pod success
Apr 17 11:39:11.223: INFO: Pod "azurefile-volume-tester-smbmb" 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 17 11:39:41.775: INFO: deleting Pod "azurefile-2546"/"azurefile-volume-tester-smbmb"
... skipping 303 lines ...
Apr 17 11:40:03.497: INFO: PersistentVolumeClaim pvc-dgpnb found but phase is Pending instead of Bound.
Apr 17 11:40:05.532: INFO: PersistentVolumeClaim pvc-dgpnb found and phase=Bound (2.068582707s)
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 17 11:40:05.638: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-6dqdj" in namespace "azurefile-9183" to be "Succeeded or Failed"
Apr 17 11:40:05.674: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Pending", Reason="", readiness=false. Elapsed: 35.745595ms
Apr 17 11:40:07.709: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Pending", Reason="", readiness=false. Elapsed: 2.070832499s
Apr 17 11:40:09.744: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Pending", Reason="", readiness=false. Elapsed: 4.106008007s
Apr 17 11:40:11.780: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Pending", Reason="", readiness=false. Elapsed: 6.142025562s
Apr 17 11:40:13.817: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Pending", Reason="", readiness=false. Elapsed: 8.178500956s
Apr 17 11:40:15.853: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Pending", Reason="", readiness=false. Elapsed: 10.214473062s
Apr 17 11:40:17.887: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Pending", Reason="", readiness=false. Elapsed: 12.249110948s
Apr 17 11:40:19.922: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Pending", Reason="", readiness=false. Elapsed: 14.284234293s
Apr 17 11:40:21.958: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Running", Reason="", readiness=true. Elapsed: 16.320212989s
Apr 17 11:40:23.993: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Running", Reason="", readiness=true. Elapsed: 18.354854104s
Apr 17 11:40:26.027: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Running", Reason="", readiness=true. Elapsed: 20.38925086s
Apr 17 11:40:28.062: INFO: Pod "azurefile-volume-tester-6dqdj": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.424067795s
STEP: Saw pod success
Apr 17 11:40:28.062: INFO: Pod "azurefile-volume-tester-6dqdj" satisfied condition "Succeeded or Failed"
Apr 17 11:40:28.062: INFO: deleting Pod "azurefile-9183"/"azurefile-volume-tester-6dqdj"
Apr 17 11:40:28.119: INFO: Pod azurefile-volume-tester-6dqdj has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-6dqdj in namespace azurefile-9183
Apr 17 11:40:28.162: INFO: deleting PVC "azurefile-9183"/"pvc-dgpnb"
Apr 17 11:40:28.162: INFO: Deleting PersistentVolumeClaim "pvc-dgpnb"
... skipping 96 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/17 11:41:00 Check successfully
Apr 17 11:41:00.756: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/17 11:41:00 run script: test/utils/get_storage_account_secret_name.sh
2022/04/17 11:41:00 got output: azure-storage-account-f4083f9c722264ef6bad268-secret
, error: <nil>
2022/04/17 11:41:00 got storage account secret name: azure-storage-account-f4083f9c722264ef6bad268-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 17 11:41:01.025: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-cf85q] to have phase Bound
Apr 17 11:41:01.057: INFO: PersistentVolumeClaim pvc-cf85q found but phase is Pending instead of Bound.
Apr 17 11:41:03.091: INFO: PersistentVolumeClaim pvc-cf85q found and phase=Bound (2.066387604s)
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 17 11:41:03.196: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-zp4ng" in namespace "azurefile-1968" to be "Succeeded or Failed"
Apr 17 11:41:03.229: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Pending", Reason="", readiness=false. Elapsed: 32.684712ms
Apr 17 11:41:05.262: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Pending", Reason="", readiness=false. Elapsed: 2.065945199s
Apr 17 11:41:07.296: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Pending", Reason="", readiness=false. Elapsed: 4.10015966s
Apr 17 11:41:09.331: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Pending", Reason="", readiness=false. Elapsed: 6.134981309s
Apr 17 11:41:11.367: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Pending", Reason="", readiness=false. Elapsed: 8.171003411s
Apr 17 11:41:13.402: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Pending", Reason="", readiness=false. Elapsed: 10.206003202s
Apr 17 11:41:15.437: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Running", Reason="", readiness=true. Elapsed: 12.24129691s
Apr 17 11:41:17.472: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Running", Reason="", readiness=true. Elapsed: 14.275861294s
Apr 17 11:41:19.507: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Running", Reason="", readiness=true. Elapsed: 16.311419715s
Apr 17 11:41:21.543: INFO: Pod "azurefile-volume-tester-zp4ng": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.347109952s
STEP: Saw pod success
Apr 17 11:41:21.543: INFO: Pod "azurefile-volume-tester-zp4ng" satisfied condition "Succeeded or Failed"
Apr 17 11:41:21.543: INFO: deleting Pod "azurefile-1968"/"azurefile-volume-tester-zp4ng"
Apr 17 11:41:21.591: INFO: Pod azurefile-volume-tester-zp4ng has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-zp4ng in namespace azurefile-1968
Apr 17 11:41:21.633: INFO: deleting PVC "azurefile-1968"/"pvc-cf85q"
Apr 17 11:41:21.633: INFO: Deleting PersistentVolumeClaim "pvc-cf85q"
... skipping 44 lines ...
Apr 17 11:41:46.125: INFO: PersistentVolumeClaim pvc-s8lkx found but phase is Pending instead of Bound.
Apr 17 11:41:48.159: INFO: PersistentVolumeClaim pvc-s8lkx found and phase=Bound (20.376395841s)
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 17 11:41:48.261: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-cmc8r" in namespace "azurefile-4657" to be "Succeeded or Failed"
Apr 17 11:41:48.301: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Pending", Reason="", readiness=false. Elapsed: 40.123029ms
Apr 17 11:41:50.335: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074317388s
Apr 17 11:41:52.369: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Pending", Reason="", readiness=false. Elapsed: 4.10895807s
Apr 17 11:41:54.405: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Pending", Reason="", readiness=false. Elapsed: 6.144316544s
Apr 17 11:41:56.440: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Pending", Reason="", readiness=false. Elapsed: 8.179043784s
Apr 17 11:41:58.475: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Pending", Reason="", readiness=false. Elapsed: 10.213980971s
Apr 17 11:42:00.512: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Running", Reason="", readiness=true. Elapsed: 12.251021722s
Apr 17 11:42:02.547: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Running", Reason="", readiness=true. Elapsed: 14.286585566s
Apr 17 11:42:04.583: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Running", Reason="", readiness=true. Elapsed: 16.322523877s
Apr 17 11:42:06.619: INFO: Pod "azurefile-volume-tester-cmc8r": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.358011609s
STEP: Saw pod success
Apr 17 11:42:06.619: INFO: Pod "azurefile-volume-tester-cmc8r" satisfied condition "Succeeded or Failed"
Apr 17 11:42:06.619: INFO: deleting Pod "azurefile-4657"/"azurefile-volume-tester-cmc8r"
Apr 17 11:42:06.665: INFO: Pod azurefile-volume-tester-cmc8r has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-cmc8r in namespace azurefile-4657
Apr 17 11:42:06.706: INFO: deleting PVC "azurefile-4657"/"pvc-s8lkx"
Apr 17 11:42:06.706: INFO: Deleting PersistentVolumeClaim "pvc-s8lkx"
... skipping 74 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/17 11:43:29 Check successfully
Apr 17 11:43:29.717: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/17 11:43:29 run script: test/utils/get_storage_account_secret_name.sh
2022/04/17 11:43:29 got output: azure-storage-account-f4083f9c722264ef6bad268-secret
, error: <nil>
2022/04/17 11:43:29 got storage account secret name: azure-storage-account-f4083f9c722264ef6bad268-secret
STEP: Successfully provisioned AzureFile volume: "capz-h6v6as#f4083f9c722264ef6bad268#csi-inline-smb-volume##csi-inline-smb-volume"

STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 17 11:43:30.656: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-vkrdk" in namespace "azurefile-4162" to be "Succeeded or Failed"
Apr 17 11:43:30.689: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Pending", Reason="", readiness=false. Elapsed: 33.646946ms
Apr 17 11:43:32.726: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069843559s
Apr 17 11:43:34.761: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.10543429s
Apr 17 11:43:36.796: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.140704478s
Apr 17 11:43:38.832: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.176538244s
Apr 17 11:43:40.868: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Pending", Reason="", readiness=false. Elapsed: 10.211822704s
Apr 17 11:43:42.902: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Running", Reason="", readiness=true. Elapsed: 12.246553851s
Apr 17 11:43:44.937: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Running", Reason="", readiness=true. Elapsed: 14.28141639s
Apr 17 11:43:46.973: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Running", Reason="", readiness=true. Elapsed: 16.317279218s
Apr 17 11:43:49.008: INFO: Pod "azurefile-volume-tester-vkrdk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.352642534s
STEP: Saw pod success
Apr 17 11:43:49.008: INFO: Pod "azurefile-volume-tester-vkrdk" satisfied condition "Succeeded or Failed"
Apr 17 11:43:49.008: INFO: deleting Pod "azurefile-4162"/"azurefile-volume-tester-vkrdk"
Apr 17 11:43:49.055: INFO: Pod azurefile-volume-tester-vkrdk has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-vkrdk in namespace azurefile-4162
Apr 17 11:43:49.100: 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/17 11:43:50 Check successfully
Apr 17 11:43:50.260: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
STEP: creating secret smbcreds in namespace azurefile-5320
2022/04/17 11:43:50 run script: test/utils/get_smb_svc_public_ip.sh
2022/04/17 11:43:50 got output: 20.102.37.230
, error: <nil>
2022/04/17 11:43:50 use server on Windows: 20.102.37.230
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 17 11:43:50.538: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-qd4sx" in namespace "azurefile-5320" to be "Succeeded or Failed"
Apr 17 11:43:50.571: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Pending", Reason="", readiness=false. Elapsed: 33.513789ms
Apr 17 11:43:52.607: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069046662s
Apr 17 11:43:54.645: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.107393638s
Apr 17 11:43:56.680: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.141851359s
Apr 17 11:43:58.714: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.176226881s
Apr 17 11:44:00.750: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.211935055s
Apr 17 11:44:02.784: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Running", Reason="", readiness=true. Elapsed: 12.24660236s
Apr 17 11:44:04.820: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Running", Reason="", readiness=true. Elapsed: 14.28183473s
Apr 17 11:44:06.855: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Running", Reason="", readiness=true. Elapsed: 16.316909293s
Apr 17 11:44:08.890: INFO: Pod "azurefile-volume-tester-qd4sx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.352276745s
STEP: Saw pod success
Apr 17 11:44:08.890: INFO: Pod "azurefile-volume-tester-qd4sx" satisfied condition "Succeeded or Failed"
Apr 17 11:44:08.890: INFO: deleting Pod "azurefile-5320"/"azurefile-volume-tester-qd4sx"
Apr 17 11:44:08.933: INFO: Pod azurefile-volume-tester-qd4sx has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-qd4sx in namespace azurefile-5320
Apr 17 11:44:08.978: INFO: deleting Secret smbcreds
Apr 17 11:44:09.012: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 181 lines ...
Platform: linux/amd64

Streaming logs below:
I0417 11:21:20.990651       1 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-a3f61a5e163bc4536ff4e8a3aac2b0f5e7027564 gc/go1.18.1 (amd64-linux) e2e-test
I0417 11:21:20.991098       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0417 11:21:21.003511       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 12 milliseconds
W0417 11:21:21.003820       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
I0417 11:21:21.003839       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0417 11:21:21.003849       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0417 11:21:21.003882       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0417 11:21:21.004383       1 azure_auth.go:245] Using AzurePublicCloud environment
I0417 11:21:21.004432       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0417 11:21:21.004497       1 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 2866 lines ...
Platform: windows/amd64

Streaming logs below:
I0417 11:22:01.649616    2404 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-a3f61a5e163bc4536ff4e8a3aac2b0f5e7027564 gc/go1.18.1 (amd64-windows) e2e-test
I0417 11:22:01.664639    2404 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0417 11:22:01.680541    2404 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 14 milliseconds
W0417 11:22:01.685936    2404 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
I0417 11:22:01.686486    2404 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0417 11:22:01.686486    2404 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0417 11:22:01.686651    2404 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0417 11:22:01.688600    2404 azure_auth.go:245] Using AzurePublicCloud environment
I0417 11:22:01.688600    2404 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0417 11:22:01.689783    2404 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 35 lines ...
I0417 11:22:26.510219    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:22:26.510219    2404 utils.go:77] GRPC request: {}
I0417 11:22:26.510219    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:22:26.512472    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0417 11:22:26.512472    2404 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\azurefile-8081-file.csi.azure.com-preprovsioned-pv-fhstj\\globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_id":"capz-h6v6as#f4083f9c722264ef6bad268#pre-provisioned-readonly##pre-provisioned-readonly"}
I0417 11:22:26.518432    2404 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/default/secrets/azure-storage-account-f4083f9c722264ef6bad268-secret 404 Not Found in 5 milliseconds
I0417 11:22:26.518432    2404 azurefile.go:616] could not get account(f4083f9c722264ef6bad268) key from secret(azure-storage-account-f4083f9c722264ef6bad268-secret), error: could not get secret(azure-storage-account-f4083f9c722264ef6bad268-secret): secrets "azure-storage-account-f4083f9c722264ef6bad268-secret" not found, use cluster identity to get account key instead
(2022-04-17T11:22:26.5195117Z) 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-17T11:22:27.1293030Z) INFO: RESPONSE: 200 https://login.microsoftonline.com/097f89a0-9286-43d2-9a1a-08f1d49b1af8/oauth2/token
P3p: CP="DSP CUR OTPi IND OTRi ONL FIN"
X-Xss-Protection: 0
... skipping 137 lines ...
I0417 11:29:11.996120    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:29:11.996120    2404 utils.go:77] GRPC request: {}
I0417 11:29:11.996120    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:29:11.998535    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume
I0417 11:29:11.998535    2404 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\azurefile-2540-file.csi.azure.com-preprovsioned-pv-xlxcr\\globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_id":"capz-h6v6as#f4083f9c722264ef6bad268#pre-provisioned-multiple-pods##pre-provisioned-multiple-pods1"}
I0417 11:29:12.008334    2404 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/default/secrets/azure-storage-account-f4083f9c722264ef6bad268-secret 404 Not Found in 9 milliseconds
I0417 11:29:12.010449    2404 azurefile.go:616] could not get account(f4083f9c722264ef6bad268) key from secret(azure-storage-account-f4083f9c722264ef6bad268-secret), error: could not get secret(azure-storage-account-f4083f9c722264ef6bad268-secret): secrets "azure-storage-account-f4083f9c722264ef6bad268-secret" not found, use cluster identity to get account key instead
(2022-04-17T11:29:12.0104496Z) INFO: REQUEST: POST https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-h6v6as/providers/Microsoft.Storage/storageAccounts/f4083f9c722264ef6bad268/listKeys?api-version=2021-02-01
User-Agent: Go/go1.18.1 (amd64-windows) go-autorest/v14.2.1 file.csi.azure.com/e2e-a3f61a5e163bc4536ff4e8a3aac2b0f5e7027564 gc/go1.18.1 (amd64-windows) e2e-test
Authorization: **REDACTED**
Content-Type: application/json; charset=utf-8
(2022-04-17T11:29:12.1212851Z) INFO: RESPONSE: 200 https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-h6v6as/providers/Microsoft.Storage/storageAccounts/f4083f9c722264ef6bad268/listKeys?api-version=2021-02-01
X-Ms-Request-Id: a718f46c-163e-4fc5-9214-215cd8c0f001
... skipping 562 lines ...
I0417 11:33:56.910922    2404 safe_mounter_windows.go:70] SMBMount: remote path: \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:33:56.910922    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de
I0417 11:33:56.910922    2404 safe_mounter_windows.go:97] begin to mount \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:33:58.470169    2404 utils.go:76] GRPC call: /csi.v1.Identity/Probe
I0417 11:33:58.470169    2404 utils.go:77] GRPC request: {}
I0417 11:33:58.470169    2404 utils.go:83] GRPC response: {"ready":{"value":true}}
E0417 11:34:01.873331    2404 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-h6v6as#fb312ce02658c4ff8b52954#pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de#) mount "\\\\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\\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
I0417 11:34:02.465321    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:02.465321    2404 utils.go:77] GRPC request: {}
I0417 11:34:02.465321    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:34:02.467616    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:02.467616    2404 utils.go:77] GRPC request: {}
I0417 11:34:02.467616    2404 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 ...
I0417 11:34:02.476450    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:02.477214    2404 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:02.477214    2404 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:02.477999    2404 safe_mounter_windows.go:70] SMBMount: remote path: \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:02.478024    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de
I0417 11:34:02.478479    2404 safe_mounter_windows.go:97] begin to mount \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
E0417 11:34:04.967835    2404 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-h6v6as#fb312ce02658c4ff8b52954#pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de#) mount "\\\\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\\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
I0417 11:34:06.033942    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:06.033942    2404 utils.go:77] GRPC request: {}
I0417 11:34:06.033942    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:34:06.037550    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:06.037550    2404 utils.go:77] GRPC request: {}
I0417 11:34:06.037550    2404 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 ...
I0417 11:34:06.042672    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:06.042672    2404 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:06.042672    2404 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:06.043355    2404 safe_mounter_windows.go:70] SMBMount: remote path: \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:06.043355    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de
I0417 11:34:06.044179    2404 safe_mounter_windows.go:97] begin to mount \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
E0417 11:34:08.511581    2404 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-h6v6as#fb312ce02658c4ff8b52954#pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de#) mount "\\\\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\\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
I0417 11:34:10.546186    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:10.546186    2404 utils.go:77] GRPC request: {}
I0417 11:34:10.546186    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:34:10.549279    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:10.549279    2404 utils.go:77] GRPC request: {}
I0417 11:34:10.549279    2404 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 ...
I0417 11:34:10.554481    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:10.555291    2404 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:10.555291    2404 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:10.556038    2404 safe_mounter_windows.go:70] SMBMount: remote path: \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:10.556068    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de
I0417 11:34:10.556237    2404 safe_mounter_windows.go:97] begin to mount \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
E0417 11:34:13.021532    2404 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-h6v6as#fb312ce02658c4ff8b52954#pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de#) mount "\\\\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\\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
I0417 11:34:17.135386    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:17.135386    2404 utils.go:77] GRPC request: {}
I0417 11:34:17.135386    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:34:17.138115    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:17.138115    2404 utils.go:77] GRPC request: {}
I0417 11:34:17.138115    2404 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 ...
I0417 11:34:17.146902    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:17.147483    2404 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:17.147483    2404 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:17.148138    2404 safe_mounter_windows.go:70] SMBMount: remote path: \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:17.148138    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de
I0417 11:34:17.148711    2404 safe_mounter_windows.go:97] begin to mount \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
E0417 11:34:19.669831    2404 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-h6v6as#fb312ce02658c4ff8b52954#pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de#) mount "\\\\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\\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
I0417 11:34:27.707964    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:27.707964    2404 utils.go:77] GRPC request: {}
I0417 11:34:27.707964    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:34:27.710435    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:27.710435    2404 utils.go:77] GRPC request: {}
I0417 11:34:27.710435    2404 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 ...
I0417 11:34:27.719908    2404 safe_mounter_windows.go:70] SMBMount: remote path: \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:27.719908    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de
I0417 11:34:27.720471    2404 safe_mounter_windows.go:97] begin to mount \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:28.478860    2404 utils.go:76] GRPC call: /csi.v1.Identity/Probe
I0417 11:34:28.478860    2404 utils.go:77] GRPC request: {}
I0417 11:34:28.478860    2404 utils.go:83] GRPC response: {"ready":{"value":true}}
E0417 11:34:30.223137    2404 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-h6v6as#fb312ce02658c4ff8b52954#pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de#) mount "\\\\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\\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
I0417 11:34:46.284940    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:46.285565    2404 utils.go:77] GRPC request: {}
I0417 11:34:46.285565    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:34:46.289333    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:34:46.289333    2404 utils.go:77] GRPC request: {}
I0417 11:34:46.289431    2404 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 ...
I0417 11:34:46.294171    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:46.296603    2404 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:46.296603    2404 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:46.297411    2404 safe_mounter_windows.go:70] SMBMount: remote path: \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
I0417 11:34:46.297411    2404 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de
I0417 11:34:46.297960    2404 safe_mounter_windows.go:97] begin to mount \\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\globalmount
E0417 11:34:48.761362    2404 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-h6v6as#fb312ce02658c4ff8b52954#pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de#) mount "\\\\fb312ce02658c4ff8b52954.privatelink.file.core.windows.net\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-593a7d0e-8865-43e0-9f1f-d9cd354474de\\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
I0417 11:34:58.481291    2404 utils.go:76] GRPC call: /csi.v1.Identity/Probe
I0417 11:34:58.481291    2404 utils.go:77] GRPC request: {}
I0417 11:34:58.481291    2404 utils.go:83] GRPC response: {"ready":{"value":true}}
I0417 11:35:20.873193    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:35:20.873193    2404 utils.go:77] GRPC request: {}
I0417 11:35:20.873193    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
... skipping 1147 lines ...
I0417 11:43:30.944679    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:43:30.944679    2404 utils.go:77] GRPC request: {}
I0417 11:43:30.944679    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:43:30.946844    2404 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0417 11:43:30.946844    2404 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\040ebdc7-7e2b-433d-8aeb-70593fe23cea\\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-vkrdk","csi.storage.k8s.io/pod.namespace":"azurefile-4162","csi.storage.k8s.io/pod.uid":"040ebdc7-7e2b-433d-8aeb-70593fe23cea","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"azure-storage-account-f4083f9c722264ef6bad268-secret","server":"","shareName":"csi-inline-smb-volume"},"volume_id":"csi-8293266bc4e474aaf8a63dc357d4145e8f0cb9556d03548b6476c3d15ac370de"}
I0417 11:43:30.946844    2404 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-8293266bc4e474aaf8a63dc357d4145e8f0cb9556d03548b6476c3d15ac370de) mount on c:\var\lib\kubelet\pods\040ebdc7-7e2b-433d-8aeb-70593fe23cea\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-vkrdk csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:040ebdc7-7e2b-433d-8aeb-70593fe23cea csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-f4083f9c722264ef6bad268-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]
W0417 11:43:30.946844    2404 azurefile.go:546] parsing volumeID(csi-8293266bc4e474aaf8a63dc357d4145e8f0cb9556d03548b6476c3d15ac370de) return with error: error parsing volume id: "csi-8293266bc4e474aaf8a63dc357d4145e8f0cb9556d03548b6476c3d15ac370de", should at least contain two #
I0417 11:43:30.958335    2404 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-4162/secrets/azure-storage-account-f4083f9c722264ef6bad268-secret 200 OK in 10 milliseconds
I0417 11:43:30.958335    2404 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\040ebdc7-7e2b-433d-8aeb-70593fe23cea\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-8293266bc4e474aaf8a63dc357d4145e8f0cb9556d03548b6476c3d15ac370de) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-vkrdk csi.storage.k8s.io/pod.namespace:azurefile-4162 csi.storage.k8s.io/pod.uid:040ebdc7-7e2b-433d-8aeb-70593fe23cea csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-f4083f9c722264ef6bad268-secret secretnamespace:azurefile-4162 server: shareName:csi-inline-smb-volume storageaccount:]) mountflags([]) mountOptions([AZURE\f4083f9c722264ef6bad268]) volumeMountGroup()
I0417 11:43:30.958335    2404 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\040ebdc7-7e2b-433d-8aeb-70593fe23cea\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 11:43:30.958335    2404 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\040ebdc7-7e2b-433d-8aeb-70593fe23cea\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 11:43:30.959671    2404 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\040ebdc7-7e2b-433d-8aeb-70593fe23cea\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 11:43:30.960352    2404 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\040ebdc7-7e2b-433d-8aeb-70593fe23cea\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 36 lines ...
I0417 11:43:50.840412    2404 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 11:43:50.840412    2404 utils.go:77] GRPC request: {}
I0417 11:43:50.840412    2404 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 11:43:50.842153    2404 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0417 11:43:50.842153    2404 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445\\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-qd4sx","csi.storage.k8s.io/pod.namespace":"azurefile-5320","csi.storage.k8s.io/pod.uid":"8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"smbcreds","server":"20.102.37.230","shareName":"share"},"volume_id":"csi-0591a20085bfa443588d533e038cbe9b2e7096d798960e2587ebdbee96f3cc22"}
I0417 11:43:50.842153    2404 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-0591a20085bfa443588d533e038cbe9b2e7096d798960e2587ebdbee96f3cc22) mount on c:\var\lib\kubelet\pods\8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445\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-qd4sx csi.storage.k8s.io/pod.namespace:azurefile-5320 csi.storage.k8s.io/pod.uid:8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:smbcreds secretnamespace:azurefile-5320 server:20.102.37.230 shareName:share storageaccount:]
W0417 11:43:50.842153    2404 azurefile.go:546] parsing volumeID(csi-0591a20085bfa443588d533e038cbe9b2e7096d798960e2587ebdbee96f3cc22) return with error: error parsing volume id: "csi-0591a20085bfa443588d533e038cbe9b2e7096d798960e2587ebdbee96f3cc22", should at least contain two #
I0417 11:43:50.846979    2404 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-5320/secrets/smbcreds 200 OK in 4 milliseconds
I0417 11:43:50.847270    2404 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-0591a20085bfa443588d533e038cbe9b2e7096d798960e2587ebdbee96f3cc22) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-qd4sx csi.storage.k8s.io/pod.namespace:azurefile-5320 csi.storage.k8s.io/pod.uid:8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:smbcreds secretnamespace:azurefile-5320 server:20.102.37.230 shareName:share storageaccount:]) mountflags([]) mountOptions([AZURE\USERNAME]) volumeMountGroup()
I0417 11:43:50.847357    2404 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 11:43:50.847357    2404 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 11:43:50.848929    2404 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 11:43:50.849015    2404 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\8bcbd32b-aa1a-4d1d-bcca-b054b3d2c445\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 124 lines ...
Platform: windows/amd64

Streaming logs below:
I0417 11:22:01.221899    6220 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-a3f61a5e163bc4536ff4e8a3aac2b0f5e7027564 gc/go1.18.1 (amd64-windows) e2e-test
I0417 11:22:01.235822    6220 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0417 11:22:01.264888    6220 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 24 milliseconds
W0417 11:22:01.270857    6220 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
I0417 11:22:01.271610    6220 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0417 11:22:01.271610    6220 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0417 11:22:01.272305    6220 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0417 11:22:01.274088    6220 azure_auth.go:245] Using AzurePublicCloud environment
I0417 11:22:01.274854    6220 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0417 11:22:01.276806    6220 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 580 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 1449.387 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 (1449.40s)
FAIL
FAIL	sigs.k8s.io/azurefile-csi-driver/test/e2e	1449.530s
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 103 lines ...