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 14:32
Elapsed59m16s
Revision59749427e6f8cf35a4eb23553e9a03ca204807b5
Refs 988

Test Failures

AzureFile CSI Driver End-to-End Tests Dynamic Provisioning should create a volume on demand with mount options [kubernetes.io/azure-file] [file.csi.azure.com] [Windows] 20m34s

go run hack/e2e.go -v --test --test_args='--ginkgo.focus=AzureFile\sCSI\sDriver\sEnd\-to\-End\sTests\sDynamic\sProvisioning\sshould\screate\sa\svolume\son\sdemand\swith\smount\soptions\s\[kubernetes\.io\/azure\-file\]\s\[file\.csi\.azure\.com\]\s\[Windows\]$'
/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/dynamic_provisioning_test.go:104
Unexpected error:
    <*errors.errorString | 0xc0005227d0>: {
        s: "Gave up after waiting 15m0s for pod \"azurefile-volume-tester-8s97w\" to be \"Succeeded or Failed\"",
    }
    Gave up after waiting 15m0s for pod "azurefile-volume-tester-8s97w" to be "Succeeded or Failed"
occurred
/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/testsuites.go:691
				
				Click to see stdout/stderrfrom junit_01.xml

Find azurefile-volume-tester-8s97w mentions in log files | View test history on testgrid

Show 19 Passed Tests
Show 14 Skipped Tests

Error lines from build-log.txt

... skipping 671 lines ...
certificate.cert-manager.io "selfsigned-cert" deleted
# Create secret for AzureClusterIdentity
./hack/create-identity-secret.sh
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
make[2]: Nothing to be done for 'kubectl'.
make[2]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
Error from server (NotFound): secrets "cluster-identity-secret" not found
secret/cluster-identity-secret created
secret/cluster-identity-secret labeled
# Deploy CAPI
curl --retry 3 -sSL https://github.com/kubernetes-sigs/cluster-api/releases/download/v1.1.2/cluster-api-components.yaml | /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/envsubst-v2.0.0-20210730161058-179042472c46 | kubectl apply -f -
namespace/capi-system created
customresourcedefinition.apiextensions.k8s.io/clusterclasses.cluster.x-k8s.io created
... skipping 129 lines ...
# Wait for the kubeconfig to become available.
timeout --foreground 300 bash -c "while ! kubectl get secrets | grep capz-r8im5f-kubeconfig; do sleep 1; done"
capz-r8im5f-kubeconfig                 cluster.x-k8s.io/secret               1      1s
# Get kubeconfig and store it locally.
kubectl get secrets capz-r8im5f-kubeconfig -o json | jq -r .data.value | base64 --decode > ./kubeconfig
timeout --foreground 600 bash -c "while ! kubectl --kubeconfig=./kubeconfig get nodes | grep control-plane; do sleep 1; done"
error: the server doesn't have a resource type "nodes"
capz-r8im5f-control-plane-t7tq8   NotReady   <none>   2s    v1.23.5
run "kubectl --kubeconfig=./kubeconfig ..." to work with the new target cluster
make[1]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
Waiting for 1 control plane machine(s), 2 worker machine(s), and 2 windows machine(s) to become Ready
node/capz-r8im-qhkfx condition met
node/capz-r8im-qkqh6 condition met
... skipping 1032 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 14:50:43.441942   37032 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret /: failed to get secret /: resource name may not be empty
I0417 14:50:43.461098   37032 driver.go:93] Enabling controller service capability: CREATE_DELETE_VOLUME
I0417 14:50:43.461277   37032 driver.go:93] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME
I0417 14:50:43.461334   37032 driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0417 14:50:43.461391   37032 driver.go:93] Enabling controller service capability: EXPAND_VOLUME
I0417 14:50:43.461464   37032 driver.go:93] Enabling controller service capability: SINGLE_NODE_MULTI_WRITER
I0417 14:50:43.461523   37032 driver.go:112] Enabling volume access mode: SINGLE_NODE_WRITER
... skipping 117 lines ...
Apr 17 14:52:44.368: INFO: PersistentVolumeClaim pvc-74ssj found but phase is Pending instead of Bound.
Apr 17 14:52:46.471: INFO: PersistentVolumeClaim pvc-74ssj found and phase=Bound (1m36.82024468s)
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 14:52:46.779: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-8s97w" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 17 14:52:46.881: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 101.601937ms
Apr 17 14:52:48.984: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.204580288s
Apr 17 14:52:51.086: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 4.306798429s
Apr 17 14:52:53.189: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 6.409508122s
Apr 17 14:52:55.291: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 8.512179055s
Apr 17 14:52:57.395: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 10.615353154s
... skipping 417 lines ...
Apr 17 15:07:37.379: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.600156493s
Apr 17 15:07:39.486: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.706938403s
Apr 17 15:07:41.595: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.815516869s
Apr 17 15:07:43.702: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.922376841s
Apr 17 15:07:45.808: INFO: Pod "azurefile-volume-tester-8s97w": Phase="Pending", Reason="", readiness=false. Elapsed: 14m59.028397817s
Apr 17 15:07:47.808: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-8s97w"
Apr 17 15:07:47.939: INFO: Error getting logs for pod azurefile-volume-tester-8s97w: the server rejected our request for an unknown reason (get pods azurefile-volume-tester-8s97w)
STEP: Deleting pod azurefile-volume-tester-8s97w in namespace azurefile-2540
Apr 17 15:07:48.047: INFO: deleting PVC "azurefile-2540"/"pvc-74ssj"
Apr 17 15:07:48.047: INFO: Deleting PersistentVolumeClaim "pvc-74ssj"
STEP: waiting for claim's PV "pvc-90a702a9-632a-4e13-bdc7-426df104b36e" to be deleted
Apr 17 15:07:48.356: INFO: Waiting up to 10m0s for PersistentVolume pvc-90a702a9-632a-4e13-bdc7-426df104b36e to get deleted
Apr 17 15:07:48.457: INFO: PersistentVolume pvc-90a702a9-632a-4e13-bdc7-426df104b36e found and phase=Bound (101.613251ms)
... skipping 48 lines ...
STEP: Collecting events from namespace "azurefile-2540".
STEP: Found 11 events.
Apr 17 15:11:38.421: INFO: At 2022-04-17 14:51:09 +0000 UTC - event for pvc-74ssj: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "file.csi.azure.com" or manually created by system administrator
Apr 17 15:11:38.421: INFO: At 2022-04-17 14:51:09 +0000 UTC - event for pvc-74ssj: {file.csi.azure.com_capz-r8im5f-md-0-p6jgc_ce59e9bb-f91f-43ba-a180-dfb480ff33aa } Provisioning: External provisioner is provisioning volume for claim "azurefile-2540/pvc-74ssj"
Apr 17 15:11:38.421: INFO: At 2022-04-17 14:52:46 +0000 UTC - event for azurefile-volume-tester-8s97w: {default-scheduler } Scheduled: Successfully assigned azurefile-2540/azurefile-volume-tester-8s97w to capz-r8im-qhkfx
Apr 17 15:11:38.421: INFO: At 2022-04-17 14:52:46 +0000 UTC - event for pvc-74ssj: {file.csi.azure.com_capz-r8im5f-md-0-p6jgc_ce59e9bb-f91f-43ba-a180-dfb480ff33aa } ProvisioningSucceeded: Successfully provisioned volume pvc-90a702a9-632a-4e13-bdc7-426df104b36e
Apr 17 15:11:38.421: INFO: At 2022-04-17 14:52:47 +0000 UTC - event for azurefile-volume-tester-8s97w: {kubelet capz-r8im-qhkfx} FailedMount: MountVolume.MountDevice failed for volume "pvc-90a702a9-632a-4e13-bdc7-426df104b36e" : kubernetes.io/csi: attacher.MountDevice failed to create newCsiDriverClient: driver name file.csi.azure.com not found in the list of registered CSI drivers
Apr 17 15:11:38.421: INFO: At 2022-04-17 14:54:49 +0000 UTC - event for azurefile-volume-tester-8s97w: {kubelet capz-r8im-qhkfx} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume-1], unattached volumes=[test-volume-1]: timed out waiting for the condition
Apr 17 15:11:38.421: INFO: At 2022-04-17 15:03:13 +0000 UTC - event for azurefile-volume-tester-8s97w: {kubelet capz-r8im-qhkfx} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Apr 17 15:11:38.421: INFO: At 2022-04-17 15:07:25 +0000 UTC - event for azurefile-volume-tester-8s97w: {kubelet capz-r8im-qhkfx} Pulled: Successfully pulled image "mcr.microsoft.com/windows/servercore:ltsc2022" in 4m12.2575332s
Apr 17 15:11:38.421: INFO: At 2022-04-17 15:07:26 +0000 UTC - event for azurefile-volume-tester-8s97w: {kubelet capz-r8im-qhkfx} Created: Created container volume-tester
Apr 17 15:11:38.421: INFO: At 2022-04-17 15:09:26 +0000 UTC - event for azurefile-volume-tester-8s97w: {kubelet capz-r8im-qhkfx} Failed: Error: context deadline exceeded
Apr 17 15:11:38.421: INFO: At 2022-04-17 15:11:26 +0000 UTC - event for azurefile-volume-tester-8s97w: {kubelet capz-r8im-qhkfx} FailedKillPod: error killing pod: failed to "KillPodSandbox" for "780eef6f-406b-4151-8935-80dda84e6f89" with KillPodSandboxError: "rpc error: code = DeadlineExceeded desc = context deadline exceeded"
Apr 17 15:11:38.523: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Apr 17 15:11:38.523: INFO: 
Apr 17 15:11:38.661: INFO: 
Logging node info for node capz-r8im-qhkfx
Apr 17 15:11:38.770: INFO: Node Info: &Node{ObjectMeta:{capz-r8im-qhkfx    9990aedb-1945-4bc9-b43f-58a27d6032e8 4491 0 2022-04-17 14:45:48 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:northeurope failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-r8im-qhkfx kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.20348 topology.kubernetes.io/region:northeurope topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-r8im5f cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-r8im5f-md-win-587d9fbbc-wsxcx cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-r8im5f-md-win-587d9fbbc csi.volume.kubernetes.io/nodeid:{"file.csi.azure.com":"capz-r8im-qhkfx"} 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.154.65 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:91:d0:6c volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{Go-http-client Update v1 2022-04-17 14:45:49 +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 14:45:57 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-04-17 14:46:02 +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 14:47:23 +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 15:02:53 +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-r8im5f/providers/Microsoft.Compute/virtualMachines/capz-r8im-qhkfx,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 15:07:56 +0000 UTC,LastTransitionTime:2022-04-17 14:45:48 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-04-17 15:07:56 +0000 UTC,LastTransitionTime:2022-04-17 14:45:48 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-04-17 15:07:56 +0000 UTC,LastTransitionTime:2022-04-17 14:45:48 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-04-17 15:07:56 +0000 UTC,LastTransitionTime:2022-04-17 14:46:39 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-r8im-qhkfx,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-r8im-qhkfx,SystemUUID:B7DB395B-0625-4832-BAB6-B5682CCC467D,BootID:,KernelVersion:10.0.20348.405,OSImage:Windows Server 2022 Datacenter,ContainerRuntimeVersion:containerd://1.6.1,KubeletVersion:v1.23.5,KubeProxyVersion:v1.23.5,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[mcr.microsoft.com/windows/servercore@sha256:378d85bd8e7388a777d25009f8523d1e95a5f544f131eaada83171045d5b2c1e mcr.microsoft.com/windows/servercore:ltsc2022],SizeBytes:2226956779,},ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:141afecd724eb757ee41593cc73f35fb19a2ce13cad73179cf3b1cef81a637d1 docker.io/sigwindowstools/calico-install:v3.22.1-hostprocess],SizeBytes:148096127,},ContainerImage{Names:[capzci.azurecr.io/azurefile-csi@sha256:e44632008767b4c4190478a0d30fbbc0542c1ad77ba19f21eba2e4e7821a5afb capzci.azurecr.io/azurefile-csi:e2e-92b6b36980c6d5b3569bdf7138de57ac800caf1c],SizeBytes:130280703,},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 15:11:38.771: INFO: 
... skipping 112 lines ...
• Failure [1234.825 seconds]
Dynamic Provisioning
/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/dynamic_provisioning_test.go:42
  should create a volume on demand with mount options [kubernetes.io/azure-file] [file.csi.azure.com] [Windows] [It]
  /home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/dynamic_provisioning_test.go:104

  Unexpected error:
      <*errors.errorString | 0xc0005227d0>: {
          s: "Gave up after waiting 15m0s for pod \"azurefile-volume-tester-8s97w\" to be \"Succeeded or Failed\"",
      }
      Gave up after waiting 15m0s for pod "azurefile-volume-tester-8s97w" to be "Succeeded or Failed"
  occurred

  /home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/testsuites.go:691
------------------------------
Dynamic Provisioning 
  should create a pod with volume mount subpath [file.csi.azure.com] [Windows]
... skipping 26 lines ...
Apr 17 15:12:04.000: INFO: PersistentVolumeClaim pvc-5gzcm found but phase is Pending instead of Bound.
Apr 17 15:12:06.103: INFO: PersistentVolumeClaim pvc-5gzcm found and phase=Bound (21.125544917s)
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 15:12:06.410: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-rxzr5" in namespace "azurefile-4728" to be "Succeeded or Failed"
Apr 17 15:12:06.511: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Pending", Reason="", readiness=false. Elapsed: 101.583571ms
Apr 17 15:12:08.614: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.204218917s
Apr 17 15:12:10.719: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309272381s
Apr 17 15:12:12.825: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415025934s
Apr 17 15:12:14.933: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.523632139s
Apr 17 15:12:17.038: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.628267056s
Apr 17 15:12:19.143: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Pending", Reason="", readiness=false. Elapsed: 12.733023209s
Apr 17 15:12:21.248: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Running", Reason="", readiness=true. Elapsed: 14.838895242s
Apr 17 15:12:23.353: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Running", Reason="", readiness=true. Elapsed: 16.943604264s
Apr 17 15:12:25.458: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Running", Reason="", readiness=true. Elapsed: 19.04868016s
Apr 17 15:12:27.563: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Running", Reason="", readiness=true. Elapsed: 21.153743757s
Apr 17 15:12:29.668: INFO: Pod "azurefile-volume-tester-rxzr5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 23.25855199s
STEP: Saw pod success
Apr 17 15:12:29.668: INFO: Pod "azurefile-volume-tester-rxzr5" satisfied condition "Succeeded or Failed"
Apr 17 15:12:29.668: INFO: deleting Pod "azurefile-4728"/"azurefile-volume-tester-rxzr5"
Apr 17 15:12:29.779: INFO: Pod azurefile-volume-tester-rxzr5 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-rxzr5 in namespace azurefile-4728
Apr 17 15:12:29.893: INFO: deleting PVC "azurefile-4728"/"pvc-5gzcm"
Apr 17 15:12:29.893: INFO: Deleting PersistentVolumeClaim "pvc-5gzcm"
... skipping 115 lines ...
Apr 17 15:13:32.619: INFO: PersistentVolumeClaim pvc-lk9xf found but phase is Pending instead of Bound.
Apr 17 15:13:34.722: INFO: PersistentVolumeClaim pvc-lk9xf found and phase=Bound (21.126257622s)
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 15:13:35.030: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-fp2d6" in namespace "azurefile-2790" to be "Error status code"
Apr 17 15:13:35.131: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Pending", Reason="", readiness=false. Elapsed: 101.273767ms
Apr 17 15:13:37.234: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.203952833s
Apr 17 15:13:39.337: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.306724217s
Apr 17 15:13:41.445: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.414606529s
Apr 17 15:13:43.549: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.519463135s
Apr 17 15:13:45.654: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.623875926s
Apr 17 15:13:47.760: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Running", Reason="", readiness=true. Elapsed: 12.729967067s
Apr 17 15:13:49.866: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Running", Reason="", readiness=true. Elapsed: 14.836021715s
Apr 17 15:13:51.970: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Running", Reason="", readiness=true. Elapsed: 16.940570852s
Apr 17 15:13:54.076: INFO: Pod "azurefile-volume-tester-fp2d6": Phase="Failed", Reason="", readiness=false. Elapsed: 19.045758801s
STEP: Saw pod failure
Apr 17 15:13:54.076: INFO: Pod "azurefile-volume-tester-fp2d6" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 17 15:13:54.191: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-fp2d6"
Apr 17 15:13:54.295: INFO: Pod azurefile-volume-tester-fp2d6 has the following logs: out-file : Access to the path 'C:\mnt\test-1\data' is denied.
At line:1 char:1
+ echo $null >> C:\mnt\test-1\data
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 202 lines ...
Apr 17 15:15:06.997: INFO: PersistentVolumeClaim pvc-ls5pq found but phase is Pending instead of Bound.
Apr 17 15:15:09.099: INFO: PersistentVolumeClaim pvc-ls5pq found and phase=Bound (2.203449632s)
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 15:15:09.413: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-kv8m9" in namespace "azurefile-4538" to be "Succeeded or Failed"
Apr 17 15:15:09.514: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Pending", Reason="", readiness=false. Elapsed: 101.518044ms
Apr 17 15:15:11.617: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.203968444s
Apr 17 15:15:13.722: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309156995s
Apr 17 15:15:15.828: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.414846458s
Apr 17 15:15:17.934: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.52081732s
Apr 17 15:15:20.041: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Running", Reason="", readiness=true. Elapsed: 10.62829874s
Apr 17 15:15:22.146: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Running", Reason="", readiness=true. Elapsed: 12.732992895s
Apr 17 15:15:24.251: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Running", Reason="", readiness=true. Elapsed: 14.838371465s
Apr 17 15:15:26.356: INFO: Pod "azurefile-volume-tester-kv8m9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.943303203s
STEP: Saw pod success
Apr 17 15:15:26.356: INFO: Pod "azurefile-volume-tester-kv8m9" 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 15:15:57.010: INFO: deleting Pod "azurefile-4538"/"azurefile-volume-tester-kv8m9"
... skipping 302 lines ...
Apr 17 15:16:25.549: INFO: PersistentVolumeClaim pvc-2f5pg found but phase is Pending instead of Bound.
Apr 17 15:16:27.652: INFO: PersistentVolumeClaim pvc-2f5pg found and phase=Bound (2.204218895s)
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 15:16:27.960: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-7fqln" in namespace "azurefile-7726" to be "Succeeded or Failed"
Apr 17 15:16:28.063: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Pending", Reason="", readiness=false. Elapsed: 103.572095ms
Apr 17 15:16:30.168: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Pending", Reason="", readiness=false. Elapsed: 2.20810979s
Apr 17 15:16:32.274: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Pending", Reason="", readiness=false. Elapsed: 4.314028785s
Apr 17 15:16:34.379: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Pending", Reason="", readiness=false. Elapsed: 6.419562541s
Apr 17 15:16:36.483: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Pending", Reason="", readiness=false. Elapsed: 8.523652822s
Apr 17 15:16:38.590: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Pending", Reason="", readiness=false. Elapsed: 10.629979384s
Apr 17 15:16:40.695: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Pending", Reason="", readiness=false. Elapsed: 12.735363875s
Apr 17 15:16:42.800: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Running", Reason="", readiness=true. Elapsed: 14.840600621s
Apr 17 15:16:44.906: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Running", Reason="", readiness=true. Elapsed: 16.946726834s
Apr 17 15:16:47.012: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Running", Reason="", readiness=true. Elapsed: 19.05187461s
Apr 17 15:16:49.117: INFO: Pod "azurefile-volume-tester-7fqln": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.156963769s
STEP: Saw pod success
Apr 17 15:16:49.117: INFO: Pod "azurefile-volume-tester-7fqln" satisfied condition "Succeeded or Failed"
Apr 17 15:16:49.117: INFO: deleting Pod "azurefile-7726"/"azurefile-volume-tester-7fqln"
Apr 17 15:16:49.228: INFO: Pod azurefile-volume-tester-7fqln has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-7fqln in namespace azurefile-7726
Apr 17 15:16:49.344: INFO: deleting PVC "azurefile-7726"/"pvc-2f5pg"
Apr 17 15:16:49.344: INFO: Deleting PersistentVolumeClaim "pvc-2f5pg"
... skipping 90 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/17 15:16:56 Check successfully
Apr 17 15:16:56.179: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/17 15:16:56 run script: test/utils/get_storage_account_secret_name.sh
2022/04/17 15:16:56 got output: azure-storage-account-faacc73a142694714985508-secret
, error: <nil>
2022/04/17 15:16:56 got storage account secret name: azure-storage-account-faacc73a142694714985508-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 15:16:56.814: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-rwh48] to have phase Bound
Apr 17 15:16:56.917: INFO: PersistentVolumeClaim pvc-rwh48 found and phase=Bound (102.232066ms)
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 15:16:57.224: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-vktfr" in namespace "azurefile-1387" to be "Succeeded or Failed"
Apr 17 15:16:57.326: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Pending", Reason="", readiness=false. Elapsed: 101.130142ms
Apr 17 15:16:59.427: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.202811365s
Apr 17 15:17:01.535: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310931173s
Apr 17 15:17:03.640: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415438505s
Apr 17 15:17:05.745: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.520871588s
Apr 17 15:17:07.850: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Running", Reason="", readiness=true. Elapsed: 10.625785775s
Apr 17 15:17:09.955: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Running", Reason="", readiness=true. Elapsed: 12.730303039s
Apr 17 15:17:12.059: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Running", Reason="", readiness=true. Elapsed: 14.835039655s
Apr 17 15:17:14.165: INFO: Pod "azurefile-volume-tester-vktfr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.940396619s
STEP: Saw pod success
Apr 17 15:17:14.165: INFO: Pod "azurefile-volume-tester-vktfr" satisfied condition "Succeeded or Failed"
Apr 17 15:17:14.165: INFO: deleting Pod "azurefile-1387"/"azurefile-volume-tester-vktfr"
Apr 17 15:17:14.278: INFO: Pod azurefile-volume-tester-vktfr has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-vktfr in namespace azurefile-1387
Apr 17 15:17:14.390: INFO: deleting PVC "azurefile-1387"/"pvc-rwh48"
Apr 17 15:17:14.390: INFO: Deleting PersistentVolumeClaim "pvc-rwh48"
... skipping 43 lines ...
Apr 17 15:17:35.814: INFO: PersistentVolumeClaim pvc-72pm5 found but phase is Pending instead of Bound.
Apr 17 15:17:37.917: INFO: PersistentVolumeClaim pvc-72pm5 found and phase=Bound (21.124031179s)
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 15:17:38.223: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-rlf6f" in namespace "azurefile-4547" to be "Succeeded or Failed"
Apr 17 15:17:38.325: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Pending", Reason="", readiness=false. Elapsed: 101.863286ms
Apr 17 15:17:40.427: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Pending", Reason="", readiness=false. Elapsed: 2.203934007s
Apr 17 15:17:42.533: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309374469s
Apr 17 15:17:44.637: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Pending", Reason="", readiness=false. Elapsed: 6.414113909s
Apr 17 15:17:46.742: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Pending", Reason="", readiness=false. Elapsed: 8.51899981s
Apr 17 15:17:48.847: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Running", Reason="", readiness=true. Elapsed: 10.623488085s
Apr 17 15:17:50.952: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Running", Reason="", readiness=true. Elapsed: 12.72856879s
Apr 17 15:17:53.058: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Running", Reason="", readiness=true. Elapsed: 14.834512747s
Apr 17 15:17:55.162: INFO: Pod "azurefile-volume-tester-rlf6f": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.939009079s
STEP: Saw pod success
Apr 17 15:17:55.162: INFO: Pod "azurefile-volume-tester-rlf6f" satisfied condition "Succeeded or Failed"
Apr 17 15:17:55.162: INFO: deleting Pod "azurefile-4547"/"azurefile-volume-tester-rlf6f"
Apr 17 15:17:55.274: INFO: Pod azurefile-volume-tester-rlf6f has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-rlf6f in namespace azurefile-4547
Apr 17 15:17:55.386: INFO: deleting PVC "azurefile-4547"/"pvc-72pm5"
Apr 17 15:17:55.386: INFO: Deleting PersistentVolumeClaim "pvc-72pm5"
... skipping 73 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/17 15:19:20 Check successfully
Apr 17 15:19:20.673: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/17 15:19:20 run script: test/utils/get_storage_account_secret_name.sh
2022/04/17 15:19:21 got output: azure-storage-account-faacc73a142694714985508-secret
, error: <nil>
2022/04/17 15:19:21 got storage account secret name: azure-storage-account-faacc73a142694714985508-secret
STEP: Successfully provisioned AzureFile volume: "capz-r8im5f#faacc73a142694714985508#csi-inline-smb-volume##csi-inline-smb-volume"

STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 17 15:19:22.542: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-ck5fr" in namespace "azurefile-4801" to be "Succeeded or Failed"
Apr 17 15:19:22.644: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Pending", Reason="", readiness=false. Elapsed: 101.927623ms
Apr 17 15:19:24.747: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205034334s
Apr 17 15:19:26.853: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.31067688s
Apr 17 15:19:28.959: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.41724409s
Apr 17 15:19:31.065: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.523277588s
Apr 17 15:19:33.170: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Running", Reason="", readiness=true. Elapsed: 10.628190037s
Apr 17 15:19:35.276: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Running", Reason="", readiness=true. Elapsed: 12.733465996s
Apr 17 15:19:37.381: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Running", Reason="", readiness=true. Elapsed: 14.838960068s
Apr 17 15:19:39.486: INFO: Pod "azurefile-volume-tester-ck5fr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.943843837s
STEP: Saw pod success
Apr 17 15:19:39.486: INFO: Pod "azurefile-volume-tester-ck5fr" satisfied condition "Succeeded or Failed"
Apr 17 15:19:39.486: INFO: deleting Pod "azurefile-4801"/"azurefile-volume-tester-ck5fr"
Apr 17 15:19:39.599: INFO: Pod azurefile-volume-tester-ck5fr has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-ck5fr in namespace azurefile-4801
Apr 17 15:19:39.710: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "azurefile-4801" for this suite.
... skipping 43 lines ...
======================================================================================
2022/04/17 15:19:42 Check successfully
Apr 17 15:19:42.862: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
STEP: creating secret smbcreds in namespace azurefile-1166
2022/04/17 15:19:42 run script: test/utils/get_smb_svc_public_ip.sh
2022/04/17 15:19:43 got output: 20.223.18.245
, error: <nil>
2022/04/17 15:19:43 use server on Windows: 20.223.18.245
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 17 15:19:43.506: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-jvbzf" in namespace "azurefile-1166" to be "Succeeded or Failed"
Apr 17 15:19:43.607: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Pending", Reason="", readiness=false. Elapsed: 101.340691ms
Apr 17 15:19:45.709: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.203105315s
Apr 17 15:19:47.814: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.307906456s
Apr 17 15:19:49.919: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.413226734s
Apr 17 15:19:52.025: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.519480379s
Apr 17 15:19:54.131: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Running", Reason="", readiness=true. Elapsed: 10.624792422s
Apr 17 15:19:56.236: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Running", Reason="", readiness=true. Elapsed: 12.73006434s
Apr 17 15:19:58.347: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Running", Reason="", readiness=true. Elapsed: 14.841562303s
Apr 17 15:20:00.453: INFO: Pod "azurefile-volume-tester-jvbzf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.946913841s
STEP: Saw pod success
Apr 17 15:20:00.453: INFO: Pod "azurefile-volume-tester-jvbzf" satisfied condition "Succeeded or Failed"
Apr 17 15:20:00.453: INFO: deleting Pod "azurefile-1166"/"azurefile-volume-tester-jvbzf"
Apr 17 15:20:00.563: INFO: Pod azurefile-volume-tester-jvbzf has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-jvbzf in namespace azurefile-1166
Apr 17 15:20:00.672: INFO: deleting Secret smbcreds
Apr 17 15:20:00.775: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 132 lines ...
Apr 17 15:20:10.023: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-wx4ng] to have phase Bound
Apr 17 15:20:10.124: INFO: PersistentVolumeClaim pvc-wx4ng found and phase=Bound (101.252626ms)
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 15:20:10.435: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-5mr6b" in namespace "azurefile-5320" to be "Error status code"
Apr 17 15:20:10.537: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Pending", Reason="", readiness=false. Elapsed: 101.232297ms
Apr 17 15:20:12.639: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Pending", Reason="", readiness=false. Elapsed: 2.203685782s
Apr 17 15:20:14.744: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Pending", Reason="", readiness=false. Elapsed: 4.308649351s
Apr 17 15:20:16.850: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Pending", Reason="", readiness=false. Elapsed: 6.414272482s
Apr 17 15:20:18.954: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Pending", Reason="", readiness=false. Elapsed: 8.519121333s
Apr 17 15:20:21.059: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Pending", Reason="", readiness=false. Elapsed: 10.623421226s
Apr 17 15:20:23.163: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Running", Reason="", readiness=true. Elapsed: 12.728122379s
Apr 17 15:20:25.269: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Running", Reason="", readiness=true. Elapsed: 14.833349666s
Apr 17 15:20:27.374: INFO: Pod "azurefile-volume-tester-5mr6b": Phase="Failed", Reason="", readiness=false. Elapsed: 16.938984619s
STEP: Saw pod failure
Apr 17 15:20:27.374: INFO: Pod "azurefile-volume-tester-5mr6b" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 17 15:20:27.491: INFO: deleting Pod "azurefile-5320"/"azurefile-volume-tester-5mr6b"
Apr 17 15:20:27.596: INFO: Pod azurefile-volume-tester-5mr6b has the following logs: Out-File : Access to the path 'C:\mnt\test-1\data.txt' is denied.
At line:1 char:22
+ ... cho 'hello world' | Out-File -FilePath C:\mnt\test-1\data.txt; Get-Co ...
+                         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 55 lines ...
Apr 17 15:20:31.695: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-rx4m4] to have phase Bound
Apr 17 15:20:31.797: INFO: PersistentVolumeClaim pvc-rx4m4 found and phase=Bound (101.677159ms)
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 15:20:32.104: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-db2j4" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 17 15:20:32.205: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Pending", Reason="", readiness=false. Elapsed: 101.086817ms
Apr 17 15:20:34.308: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.203458533s
Apr 17 15:20:36.413: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309108066s
Apr 17 15:20:38.519: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.41496769s
Apr 17 15:20:40.624: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.519810635s
Apr 17 15:20:42.730: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Running", Reason="", readiness=true. Elapsed: 10.625717s
Apr 17 15:20:44.835: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Running", Reason="", readiness=true. Elapsed: 12.730570581s
Apr 17 15:20:46.941: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Running", Reason="", readiness=true. Elapsed: 14.836376626s
Apr 17 15:20:49.045: INFO: Pod "azurefile-volume-tester-db2j4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.940397173s
STEP: Saw pod success
Apr 17 15:20:49.045: INFO: Pod "azurefile-volume-tester-db2j4" 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 15:20:49.250: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-zp82c] to have phase Bound
Apr 17 15:20:49.352: INFO: PersistentVolumeClaim pvc-zp82c found and phase=Bound (101.578897ms)
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 15:20:49.660: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-kfwdv" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 17 15:20:49.761: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Pending", Reason="", readiness=false. Elapsed: 101.387011ms
Apr 17 15:20:51.866: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.2060314s
Apr 17 15:20:53.976: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.316082019s
Apr 17 15:20:56.082: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.421684371s
Apr 17 15:20:58.186: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.526242659s
Apr 17 15:21:00.291: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Running", Reason="", readiness=true. Elapsed: 10.631092445s
Apr 17 15:21:02.397: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Running", Reason="", readiness=true. Elapsed: 12.736861669s
Apr 17 15:21:04.502: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Running", Reason="", readiness=true. Elapsed: 14.841773882s
Apr 17 15:21:06.606: INFO: Pod "azurefile-volume-tester-kfwdv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.946269327s
STEP: Saw pod success
Apr 17 15:21:06.606: INFO: Pod "azurefile-volume-tester-kfwdv" 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 15:21:06.816: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-dm5c9] to have phase Bound
Apr 17 15:21:06.921: INFO: PersistentVolumeClaim pvc-dm5c9 found and phase=Bound (104.855796ms)
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 15:21:07.231: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-gqkb7" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 17 15:21:07.333: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Pending", Reason="", readiness=false. Elapsed: 101.601821ms
Apr 17 15:21:09.435: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.203468588s
Apr 17 15:21:11.540: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.308511921s
Apr 17 15:21:13.644: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.413221805s
Apr 17 15:21:15.750: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.518764033s
Apr 17 15:21:17.855: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Running", Reason="", readiness=true. Elapsed: 10.623851121s
Apr 17 15:21:19.961: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Running", Reason="", readiness=true. Elapsed: 12.729837351s
Apr 17 15:21:22.066: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Running", Reason="", readiness=true. Elapsed: 14.834884885s
Apr 17 15:21:24.174: INFO: Pod "azurefile-volume-tester-gqkb7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.943064298s
STEP: Saw pod success
Apr 17 15:21:24.174: INFO: Pod "azurefile-volume-tester-gqkb7" 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 15:21:24.379: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-4z549] to have phase Bound
Apr 17 15:21:24.481: INFO: PersistentVolumeClaim pvc-4z549 found and phase=Bound (101.421899ms)
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 15:21:24.787: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-mrdv5" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 17 15:21:24.888: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Pending", Reason="", readiness=false. Elapsed: 101.307809ms
Apr 17 15:21:26.992: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205735982s
Apr 17 15:21:29.098: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311247367s
Apr 17 15:21:31.203: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.416146309s
Apr 17 15:21:33.308: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.521373555s
Apr 17 15:21:35.413: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Running", Reason="", readiness=true. Elapsed: 10.626067014s
Apr 17 15:21:37.517: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Running", Reason="", readiness=true. Elapsed: 12.730612545s
Apr 17 15:21:39.622: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Running", Reason="", readiness=true. Elapsed: 14.835378189s
Apr 17 15:21:41.727: INFO: Pod "azurefile-volume-tester-mrdv5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.940817091s
STEP: Saw pod success
Apr 17 15:21:41.727: INFO: Pod "azurefile-volume-tester-mrdv5" 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 15:21:41.939: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-jx2mx] to have phase Bound
Apr 17 15:21:42.040: INFO: PersistentVolumeClaim pvc-jx2mx found and phase=Bound (101.184894ms)
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 15:21:42.346: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-xl65j" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 17 15:21:42.447: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Pending", Reason="", readiness=false. Elapsed: 101.200044ms
Apr 17 15:21:44.552: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206726176s
Apr 17 15:21:46.657: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311366455s
Apr 17 15:21:48.762: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Pending", Reason="", readiness=false. Elapsed: 6.416095083s
Apr 17 15:21:50.866: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Pending", Reason="", readiness=false. Elapsed: 8.520868009s
Apr 17 15:21:52.972: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Running", Reason="", readiness=true. Elapsed: 10.626176879s
Apr 17 15:21:55.076: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Running", Reason="", readiness=true. Elapsed: 12.730433177s
Apr 17 15:21:57.181: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Running", Reason="", readiness=true. Elapsed: 14.835217127s
Apr 17 15:21:59.286: INFO: Pod "azurefile-volume-tester-xl65j": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.940493501s
STEP: Saw pod success
Apr 17 15:21:59.286: INFO: Pod "azurefile-volume-tester-xl65j" 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 15:21:59.491: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-r2zs7] to have phase Bound
Apr 17 15:21:59.593: INFO: PersistentVolumeClaim pvc-r2zs7 found and phase=Bound (101.433742ms)
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 15:21:59.904: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bppvv" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 17 15:22:00.006: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Pending", Reason="", readiness=false. Elapsed: 101.566673ms
Apr 17 15:22:02.111: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207053963s
Apr 17 15:22:04.216: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311529386s
Apr 17 15:22:06.321: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.416501643s
Apr 17 15:22:08.427: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.522594288s
Apr 17 15:22:10.533: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Running", Reason="", readiness=true. Elapsed: 10.628761684s
Apr 17 15:22:12.638: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Running", Reason="", readiness=true. Elapsed: 12.734169723s
Apr 17 15:22:14.743: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Running", Reason="", readiness=true. Elapsed: 14.838976217s
Apr 17 15:22:16.848: INFO: Pod "azurefile-volume-tester-bppvv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.943844231s
STEP: Saw pod success
Apr 17 15:22:16.848: INFO: Pod "azurefile-volume-tester-bppvv" satisfied condition "Succeeded or Failed"
Apr 17 15:22:16.848: INFO: deleting Pod "azurefile-9103"/"azurefile-volume-tester-bppvv"
Apr 17 15:22:16.966: INFO: Pod azurefile-volume-tester-bppvv has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-bppvv in namespace azurefile-9103
Apr 17 15:22:17.076: INFO: deleting PVC "azurefile-9103"/"pvc-r2zs7"
Apr 17 15:22:17.076: INFO: Deleting PersistentVolumeClaim "pvc-r2zs7"
... skipping 143 lines ...
Apr 17 15:22:29.263: INFO: PersistentVolumeClaim pvc-r5czv found but phase is Pending instead of Bound.
Apr 17 15:22:31.366: INFO: PersistentVolumeClaim pvc-r5czv found and phase=Bound (2.203901218s)
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 15:22:31.671: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-qmj59" in namespace "azurefile-8470" to be "Succeeded or Failed"
Apr 17 15:22:31.773: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Pending", Reason="", readiness=false. Elapsed: 101.600392ms
Apr 17 15:22:33.876: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Pending", Reason="", readiness=false. Elapsed: 2.204462341s
Apr 17 15:22:35.986: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Pending", Reason="", readiness=false. Elapsed: 4.314491085s
Apr 17 15:22:38.091: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Pending", Reason="", readiness=false. Elapsed: 6.420383566s
Apr 17 15:22:40.196: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Pending", Reason="", readiness=false. Elapsed: 8.524924047s
Apr 17 15:22:42.302: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Running", Reason="", readiness=true. Elapsed: 10.630729521s
Apr 17 15:22:44.407: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Running", Reason="", readiness=true. Elapsed: 12.735527907s
Apr 17 15:22:46.512: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Running", Reason="", readiness=true. Elapsed: 14.841277981s
Apr 17 15:22:48.617: INFO: Pod "azurefile-volume-tester-qmj59": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.945938823s
STEP: Saw pod success
Apr 17 15:22:48.617: INFO: Pod "azurefile-volume-tester-qmj59" satisfied condition "Succeeded or Failed"
Apr 17 15:22:48.617: INFO: deleting Pod "azurefile-8470"/"azurefile-volume-tester-qmj59"
Apr 17 15:22:48.727: INFO: Pod azurefile-volume-tester-qmj59 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-qmj59 in namespace azurefile-8470
Apr 17 15:22:48.838: INFO: deleting PVC "azurefile-8470"/"pvc-r5czv"
Apr 17 15:22:48.838: INFO: Deleting PersistentVolumeClaim "pvc-r5czv"
... skipping 33 lines ...
Apr 17 15:22:52.405: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-sglpb] to have phase Bound
Apr 17 15:22:52.506: INFO: PersistentVolumeClaim pvc-sglpb found and phase=Bound (101.29343ms)
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 15:22:52.819: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-6dsjj" in namespace "azurefile-7029" to be "Succeeded or Failed"
Apr 17 15:22:52.921: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Pending", Reason="", readiness=false. Elapsed: 102.470168ms
Apr 17 15:22:55.024: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205036705s
Apr 17 15:22:57.129: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310462175s
Apr 17 15:22:59.235: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Pending", Reason="", readiness=false. Elapsed: 6.416587372s
Apr 17 15:23:01.340: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Pending", Reason="", readiness=false. Elapsed: 8.521294739s
Apr 17 15:23:03.446: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Pending", Reason="", readiness=false. Elapsed: 10.626925268s
Apr 17 15:23:05.551: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Running", Reason="", readiness=true. Elapsed: 12.732048645s
Apr 17 15:23:07.656: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Running", Reason="", readiness=true. Elapsed: 14.837242971s
Apr 17 15:23:09.762: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Running", Reason="", readiness=true. Elapsed: 16.943169155s
Apr 17 15:23:11.867: INFO: Pod "azurefile-volume-tester-6dsjj": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.0478966s
STEP: Saw pod success
Apr 17 15:23:11.867: INFO: Pod "azurefile-volume-tester-6dsjj" satisfied condition "Succeeded or Failed"
Apr 17 15:23:11.867: INFO: deleting Pod "azurefile-7029"/"azurefile-volume-tester-6dsjj"
Apr 17 15:23:11.977: INFO: Pod azurefile-volume-tester-6dsjj has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-6dsjj in namespace azurefile-7029
Apr 17 15:23:12.177: INFO: deleting PVC "azurefile-7029"/"pvc-sglpb"
Apr 17 15:23:12.177: INFO: Deleting PersistentVolumeClaim "pvc-sglpb"
... skipping 86 lines ...
Platform: linux/amd64

Streaming logs below:
I0417 14:49:39.737375       1 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-92b6b36980c6d5b3569bdf7138de57ac800caf1c gc/go1.18.1 (amd64-linux) e2e-test
I0417 14:49:39.737891       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0417 14:49:39.747371       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 9 milliseconds
W0417 14:49:39.747616       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 14:49:39.747636       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0417 14:49:39.747647       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0417 14:49:39.747678       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0417 14:49:39.749900       1 azure_auth.go:245] Using AzurePublicCloud environment
I0417 14:49:39.749954       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0417 14:49:39.750019       1 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 2966 lines ...
Platform: windows/amd64

Streaming logs below:
I0417 15:02:51.693303    5760 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-92b6b36980c6d5b3569bdf7138de57ac800caf1c gc/go1.18.1 (amd64-windows) e2e-test
I0417 15:02:51.705756    5760 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0417 15:02:51.723213    5760 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 16 milliseconds
W0417 15:02:51.724804    5760 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 15:02:51.724804    5760 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0417 15:02:51.724804    5760 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0417 15:02:51.725125    5760 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0417 15:02:51.726969    5760 azure_auth.go:245] Using AzurePublicCloud environment
I0417 15:02:51.727538    5760 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0417 15:02:51.728693    5760 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 1310 lines ...
I0417 15:19:22.783112    5760 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 15:19:22.783112    5760 utils.go:77] GRPC request: {}
I0417 15:19:22.783112    5760 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 15:19:22.784830    5760 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0417 15:19:22.784865    5760 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\2472e011-ff58-4c0f-aca5-d524fe8a0fff\\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-ck5fr","csi.storage.k8s.io/pod.namespace":"azurefile-4801","csi.storage.k8s.io/pod.uid":"2472e011-ff58-4c0f-aca5-d524fe8a0fff","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"azure-storage-account-faacc73a142694714985508-secret","server":"","shareName":"csi-inline-smb-volume"},"volume_id":"csi-8a34fa162e934ede63ea91f16db11589a878f0a931573cd862e347c0d31d9b7b"}
I0417 15:19:22.785054    5760 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-8a34fa162e934ede63ea91f16db11589a878f0a931573cd862e347c0d31d9b7b) mount on c:\var\lib\kubelet\pods\2472e011-ff58-4c0f-aca5-d524fe8a0fff\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-ck5fr csi.storage.k8s.io/pod.namespace:azurefile-4801 csi.storage.k8s.io/pod.uid:2472e011-ff58-4c0f-aca5-d524fe8a0fff csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-faacc73a142694714985508-secret secretnamespace:azurefile-4801 server: shareName:csi-inline-smb-volume storageaccount:]
W0417 15:19:22.785118    5760 azurefile.go:546] parsing volumeID(csi-8a34fa162e934ede63ea91f16db11589a878f0a931573cd862e347c0d31d9b7b) return with error: error parsing volume id: "csi-8a34fa162e934ede63ea91f16db11589a878f0a931573cd862e347c0d31d9b7b", should at least contain two #
I0417 15:19:22.794689    5760 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-4801/secrets/azure-storage-account-faacc73a142694714985508-secret 200 OK in 9 milliseconds
I0417 15:19:22.794689    5760 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\2472e011-ff58-4c0f-aca5-d524fe8a0fff\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-8a34fa162e934ede63ea91f16db11589a878f0a931573cd862e347c0d31d9b7b) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-ck5fr csi.storage.k8s.io/pod.namespace:azurefile-4801 csi.storage.k8s.io/pod.uid:2472e011-ff58-4c0f-aca5-d524fe8a0fff csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-faacc73a142694714985508-secret secretnamespace:azurefile-4801 server: shareName:csi-inline-smb-volume storageaccount:]) mountflags([]) mountOptions([AZURE\faacc73a142694714985508]) volumeMountGroup()
I0417 15:19:22.794689    5760 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\2472e011-ff58-4c0f-aca5-d524fe8a0fff\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 15:19:22.794689    5760 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\2472e011-ff58-4c0f-aca5-d524fe8a0fff\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 15:19:22.796138    5760 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\2472e011-ff58-4c0f-aca5-d524fe8a0fff\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 15:19:22.796733    5760 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\2472e011-ff58-4c0f-aca5-d524fe8a0fff\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 17 lines ...
I0417 15:19:43.757973    5760 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0417 15:19:43.757973    5760 utils.go:77] GRPC request: {}
I0417 15:19:43.757973    5760 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0417 15:19:43.760697    5760 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0417 15:19:43.760725    5760 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a\\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-jvbzf","csi.storage.k8s.io/pod.namespace":"azurefile-1166","csi.storage.k8s.io/pod.uid":"bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"smbcreds","server":"20.223.18.245","shareName":"share"},"volume_id":"csi-c54425bb37656352679944048cd763752a66b5c88bddd73faa9c695e5a8ed449"}
I0417 15:19:43.760953    5760 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-c54425bb37656352679944048cd763752a66b5c88bddd73faa9c695e5a8ed449) mount on c:\var\lib\kubelet\pods\bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a\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-jvbzf csi.storage.k8s.io/pod.namespace:azurefile-1166 csi.storage.k8s.io/pod.uid:bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:smbcreds secretnamespace:azurefile-1166 server:20.223.18.245 shareName:share storageaccount:]
W0417 15:19:43.761018    5760 azurefile.go:546] parsing volumeID(csi-c54425bb37656352679944048cd763752a66b5c88bddd73faa9c695e5a8ed449) return with error: error parsing volume id: "csi-c54425bb37656352679944048cd763752a66b5c88bddd73faa9c695e5a8ed449", should at least contain two #
I0417 15:19:43.764458    5760 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-1166/secrets/smbcreds 200 OK in 3 milliseconds
I0417 15:19:43.766369    5760 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-c54425bb37656352679944048cd763752a66b5c88bddd73faa9c695e5a8ed449) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-jvbzf csi.storage.k8s.io/pod.namespace:azurefile-1166 csi.storage.k8s.io/pod.uid:bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:smbcreds secretnamespace:azurefile-1166 server:20.223.18.245 shareName:share storageaccount:]) mountflags([]) mountOptions([AZURE\USERNAME]) volumeMountGroup()
I0417 15:19:43.766369    5760 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 15:19:43.766369    5760 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 15:19:43.767349    5760 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a\volumes\kubernetes.io~csi\test-volume-1\mount
I0417 15:19:43.768057    5760 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\bd46c14d-bc75-4a2f-af8c-b7b28d3fad7a\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 719 lines ...
Platform: windows/amd64

Streaming logs below:
I0417 14:50:39.264674    2388 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-92b6b36980c6d5b3569bdf7138de57ac800caf1c gc/go1.18.1 (amd64-windows) e2e-test
I0417 14:50:39.280945    2388 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0417 14:50:39.316152    2388 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 31 milliseconds
W0417 14:50:39.323475    2388 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 14:50:39.323475    2388 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0417 14:50:39.323475    2388 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0417 14:50:39.323475    2388 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0417 14:50:39.330567    2388 azure_auth.go:245] Using AzurePublicCloud environment
I0417 14:50:39.330790    2388 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0417 14:50:39.335586    2388 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 643 lines ...

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


Summarizing 1 Failure:

[Fail] Dynamic Provisioning [It] should create a volume on demand with mount options [kubernetes.io/azure-file] [file.csi.azure.com] [Windows] 
/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/testsuites.go:691

Ran 20 of 34 Specs in 2114.832 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 (2114.84s)
FAIL
FAIL	sigs.k8s.io/azurefile-csi-driver/test/e2e	2114.918s
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 95 lines ...