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-18 04:57
Elapsed53m33s
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] 10m51s

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 | 0xc0001331a0>: {
        s: "pod \"azurefile-volume-tester-kj7h2\" failed with status: {Phase:Failed Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason: Message:} {Type:Ready Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [volume-tester]} {Type:ContainersReady Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [volume-tester]} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:10.1.0.6 PodIP:192.168.8.4 PodIPs:[{IP:192.168.8.4}] StartTime:2022-04-18 05:20:11 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:volume-tester State:{Waiting:&ContainerStateWaiting{Reason:RunContainerError,Message:context deadline exceeded,} Running:nil Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:&ContainerStateTerminated{ExitCode:0,Signal:0,Reason:,Message:,StartedAt:0001-01-01 00:00:00 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,ContainerID:containerd://57fff19a33210b914be162fff39ce14939af73a13396b9419a62ed97ad12ea67,}} Ready:false RestartCount:0 Image:mcr.microsoft.com/windows/servercore:ltsc2022 ImageID:mcr.microsoft.com/windows/servercore@sha256:378d85bd8e7388a777d25009f8523d1e95a5f544f131eaada83171045d5b2c1e ContainerID:containerd://57fff19a33210b914be162fff39ce14939af73a13396b9419a62ed97ad12ea67 Started:0xc000685588}] QOSClass:BestEffort EphemeralContainerStatuses:[]}",
    }
    pod "azurefile-volume-tester-kj7h2" failed with status: {Phase:Failed Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason: Message:} {Type:Ready Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [volume-tester]} {Type:ContainersReady Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [volume-tester]} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:10.1.0.6 PodIP:192.168.8.4 PodIPs:[{IP:192.168.8.4}] StartTime:2022-04-18 05:20:11 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:volume-tester State:{Waiting:&ContainerStateWaiting{Reason:RunContainerError,Message:context deadline exceeded,} Running:nil Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:&ContainerStateTerminated{ExitCode:0,Signal:0,Reason:,Message:,StartedAt:0001-01-01 00:00:00 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,ContainerID:containerd://57fff19a33210b914be162fff39ce14939af73a13396b9419a62ed97ad12ea67,}} Ready:false RestartCount:0 Image:mcr.microsoft.com/windows/servercore:ltsc2022 ImageID:mcr.microsoft.com/windows/servercore@sha256:378d85bd8e7388a777d25009f8523d1e95a5f544f131eaada83171045d5b2c1e ContainerID:containerd://57fff19a33210b914be162fff39ce14939af73a13396b9419a62ed97ad12ea67 Started:0xc000685588}] QOSClass:BestEffort EphemeralContainerStatuses:[]}
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-kj7h2 mentions in log files | View test history on testgrid


Show 19 Passed Tests

Show 14 Skipped Tests

Error lines from build-log.txt

... skipping 668 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-3nyk7j-kubeconfig; do sleep 1; done"
capz-3nyk7j-kubeconfig                 cluster.x-k8s.io/secret               1      1s
# Get kubeconfig and store it locally.
kubectl get secrets capz-3nyk7j-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-3nyk7j-control-plane-vmgzm   NotReady   control-plane,master   5s    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-3nyk-dt49s condition met
node/capz-3nyk-q6tgv condition met
... skipping 1041 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
W0418 05:18:07.999086   37077 azure.go:78] InitializeCloudFromSecret: failed to get cloud config from secret /: failed to get secret /: resource name may not be empty
I0418 05:18:08.000454   37077 driver.go:93] Enabling controller service capability: CREATE_DELETE_VOLUME
I0418 05:18:08.000481   37077 driver.go:93] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME
I0418 05:18:08.000488   37077 driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0418 05:18:08.000493   37077 driver.go:93] Enabling controller service capability: EXPAND_VOLUME
I0418 05:18:08.000502   37077 driver.go:93] Enabling controller service capability: SINGLE_NODE_MULTI_WRITER
I0418 05:18:08.000510   37077 driver.go:112] Enabling volume access mode: SINGLE_NODE_WRITER
... skipping 117 lines ...
Apr 18 05:20:09.555: INFO: PersistentVolumeClaim pvc-wk5t8 found but phase is Pending instead of Bound.
Apr 18 05:20:11.659: INFO: PersistentVolumeClaim pvc-wk5t8 found and phase=Bound (1m36.928901569s)
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 18 05:20:11.983: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-kj7h2" in namespace "azurefile-2540" to be "Succeeded or Failed"
Apr 18 05:20:12.085: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 102.140474ms
Apr 18 05:20:14.189: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206118771s
Apr 18 05:20:16.293: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310346337s
Apr 18 05:20:18.398: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.414965327s
Apr 18 05:20:20.506: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.523196033s
Apr 18 05:20:22.610: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.627202693s
... skipping 245 lines ...
Apr 18 05:29:01.338: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 8m49.354760946s
Apr 18 05:29:03.449: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 8m51.466205291s
Apr 18 05:29:05.564: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 8m53.581590851s
Apr 18 05:29:07.673: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 8m55.690244575s
Apr 18 05:29:09.782: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 8m57.799469396s
Apr 18 05:29:11.892: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Pending", Reason="", readiness=false. Elapsed: 8m59.908968023s
Apr 18 05:29:14.001: INFO: Pod "azurefile-volume-tester-kj7h2": Phase="Failed", Reason="", readiness=false. Elapsed: 9m2.018029987s
Apr 18 05:29:14.001: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-kj7h2"
Apr 18 05:29:14.193: INFO: Pod azurefile-volume-tester-kj7h2 has the following logs: 
STEP: Deleting pod azurefile-volume-tester-kj7h2 in namespace azurefile-2540
Apr 18 05:29:14.396: INFO: deleting PVC "azurefile-2540"/"pvc-wk5t8"
Apr 18 05:29:14.396: INFO: Deleting PersistentVolumeClaim "pvc-wk5t8"
STEP: waiting for claim's PV "pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" to be deleted
... skipping 6 lines ...
STEP: Collecting events from namespace "azurefile-2540".
STEP: Found 12 events.
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:18:34 +0000 UTC - event for pvc-wk5t8: {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 18 05:29:20.244: INFO: At 2022-04-18 05:18:34 +0000 UTC - event for pvc-wk5t8: {file.csi.azure.com_capz-3nyk7j-md-0-rnh99_5a6647ff-8d27-41de-8209-271f484ee634 } Provisioning: External provisioner is provisioning volume for claim "azurefile-2540/pvc-wk5t8"
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:20:11 +0000 UTC - event for azurefile-volume-tester-kj7h2: {default-scheduler } Scheduled: Successfully assigned azurefile-2540/azurefile-volume-tester-kj7h2 to capz-3nyk-q6tgv
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:20:11 +0000 UTC - event for pvc-wk5t8: {file.csi.azure.com_capz-3nyk7j-md-0-rnh99_5a6647ff-8d27-41de-8209-271f484ee634 } ProvisioningSucceeded: Successfully provisioned volume pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:20:20 +0000 UTC - event for azurefile-volume-tester-kj7h2: {kubelet capz-3nyk-q6tgv} FailedMount: MountVolume.MountDevice failed for volume "pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" : rpc error: code = Internal desc = volume(capz-3nyk7j#f95c191289a424df79dee3d#pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791#) mount "\\\\f95c191289a424df79dee3d.privatelink.file.core.windows.net\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\\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
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:21:47 +0000 UTC - event for azurefile-volume-tester-kj7h2: {kubelet capz-3nyk-q6tgv} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:27:13 +0000 UTC - event for azurefile-volume-tester-kj7h2: {kubelet capz-3nyk-q6tgv} Pulled: Successfully pulled image "mcr.microsoft.com/windows/servercore:ltsc2022" in 5m26.000392s
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:27:13 +0000 UTC - event for azurefile-volume-tester-kj7h2: {kubelet capz-3nyk-q6tgv} Created: Created container volume-tester
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:29:13 +0000 UTC - event for azurefile-volume-tester-kj7h2: {kubelet capz-3nyk-q6tgv} Pulled: Container image "mcr.microsoft.com/windows/servercore:ltsc2022" already present on machine
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:29:13 +0000 UTC - event for azurefile-volume-tester-kj7h2: {kubelet capz-3nyk-q6tgv} Failed: Error: context deadline exceeded
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:29:19 +0000 UTC - event for azurefile-volume-tester-kj7h2: {kubelet capz-3nyk-q6tgv} Started: Started container volume-tester
Apr 18 05:29:20.244: INFO: At 2022-04-18 05:29:20 +0000 UTC - event for azurefile-volume-tester-kj7h2: {kubelet capz-3nyk-q6tgv} Killing: Stopping container volume-tester
Apr 18 05:29:20.346: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Apr 18 05:29:20.346: INFO: 
Apr 18 05:29:20.502: INFO: 
Logging node info for node capz-3nyk-dt49s
... skipping 114 lines ...
• Failure [651.708 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 | 0xc0001331a0>: {
          s: "pod \"azurefile-volume-tester-kj7h2\" failed with status: {Phase:Failed Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason: Message:} {Type:Ready Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [volume-tester]} {Type:ContainersReady Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [volume-tester]} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:10.1.0.6 PodIP:192.168.8.4 PodIPs:[{IP:192.168.8.4}] StartTime:2022-04-18 05:20:11 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:volume-tester State:{Waiting:&ContainerStateWaiting{Reason:RunContainerError,Message:context deadline exceeded,} Running:nil Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:&ContainerStateTerminated{ExitCode:0,Signal:0,Reason:,Message:,StartedAt:0001-01-01 00:00:00 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,ContainerID:containerd://57fff19a33210b914be162fff39ce14939af73a13396b9419a62ed97ad12ea67,}} Ready:false RestartCount:0 Image:mcr.microsoft.com/windows/servercore:ltsc2022 ImageID:mcr.microsoft.com/windows/servercore@sha256:378d85bd8e7388a777d25009f8523d1e95a5f544f131eaada83171045d5b2c1e ContainerID:containerd://57fff19a33210b914be162fff39ce14939af73a13396b9419a62ed97ad12ea67 Started:0xc000685588}] QOSClass:BestEffort EphemeralContainerStatuses:[]}",
      }
      pod "azurefile-volume-tester-kj7h2" failed with status: {Phase:Failed Conditions:[{Type:Initialized Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason: Message:} {Type:Ready Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [volume-tester]} {Type:ContainersReady Status:False LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason:ContainersNotReady Message:containers with unready status: [volume-tester]} {Type:PodScheduled Status:True LastProbeTime:0001-01-01 00:00:00 +0000 UTC LastTransitionTime:2022-04-18 05:20:11 +0000 UTC Reason: Message:}] Message: Reason: NominatedNodeName: HostIP:10.1.0.6 PodIP:192.168.8.4 PodIPs:[{IP:192.168.8.4}] StartTime:2022-04-18 05:20:11 +0000 UTC InitContainerStatuses:[] ContainerStatuses:[{Name:volume-tester State:{Waiting:&ContainerStateWaiting{Reason:RunContainerError,Message:context deadline exceeded,} Running:nil Terminated:nil} LastTerminationState:{Waiting:nil Running:nil Terminated:&ContainerStateTerminated{ExitCode:0,Signal:0,Reason:,Message:,StartedAt:0001-01-01 00:00:00 +0000 UTC,FinishedAt:0001-01-01 00:00:00 +0000 UTC,ContainerID:containerd://57fff19a33210b914be162fff39ce14939af73a13396b9419a62ed97ad12ea67,}} Ready:false RestartCount:0 Image:mcr.microsoft.com/windows/servercore:ltsc2022 ImageID:mcr.microsoft.com/windows/servercore@sha256:378d85bd8e7388a777d25009f8523d1e95a5f544f131eaada83171045d5b2c1e ContainerID:containerd://57fff19a33210b914be162fff39ce14939af73a13396b9419a62ed97ad12ea67 Started:0xc000685588}] QOSClass:BestEffort EphemeralContainerStatuses:[]}
  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 18 05:29:45.882: INFO: PersistentVolumeClaim pvc-kz7g2 found but phase is Pending instead of Bound.
Apr 18 05:29:47.985: INFO: PersistentVolumeClaim pvc-kz7g2 found and phase=Bound (21.149552928s)
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 18 05:29:48.296: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-lpbs9" in namespace "azurefile-4728" to be "Succeeded or Failed"
Apr 18 05:29:48.401: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Pending", Reason="", readiness=false. Elapsed: 105.225346ms
Apr 18 05:29:50.508: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.211886446s
Apr 18 05:29:52.614: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.318613558s
Apr 18 05:29:54.721: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.425514126s
Apr 18 05:29:56.828: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.532175803s
Apr 18 05:29:58.936: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.640009304s
... skipping 2 lines ...
Apr 18 05:30:05.257: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Running", Reason="", readiness=true. Elapsed: 16.961631699s
Apr 18 05:30:07.365: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Running", Reason="", readiness=true. Elapsed: 19.068886495s
Apr 18 05:30:09.472: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Running", Reason="", readiness=true. Elapsed: 21.175812357s
Apr 18 05:30:11.582: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Running", Reason="", readiness=true. Elapsed: 23.28630623s
Apr 18 05:30:13.689: INFO: Pod "azurefile-volume-tester-lpbs9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 25.392844281s
STEP: Saw pod success
Apr 18 05:30:13.689: INFO: Pod "azurefile-volume-tester-lpbs9" satisfied condition "Succeeded or Failed"
Apr 18 05:30:13.689: INFO: deleting Pod "azurefile-4728"/"azurefile-volume-tester-lpbs9"
Apr 18 05:30:13.807: INFO: Pod azurefile-volume-tester-lpbs9 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-lpbs9 in namespace azurefile-4728
Apr 18 05:30:13.924: INFO: deleting PVC "azurefile-4728"/"pvc-kz7g2"
Apr 18 05:30:13.924: INFO: Deleting PersistentVolumeClaim "pvc-kz7g2"
... skipping 115 lines ...
Apr 18 05:31:22.827: INFO: PersistentVolumeClaim pvc-zc2rv found but phase is Pending instead of Bound.
Apr 18 05:31:24.933: INFO: PersistentVolumeClaim pvc-zc2rv found and phase=Bound (21.140551459s)
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 18 05:31:25.252: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-nbqhp" in namespace "azurefile-2790" to be "Error status code"
Apr 18 05:31:25.355: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Pending", Reason="", readiness=false. Elapsed: 102.499587ms
Apr 18 05:31:27.458: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205815484s
Apr 18 05:31:29.564: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311349225s
Apr 18 05:31:31.674: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.421443343s
Apr 18 05:31:33.780: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.527722875s
Apr 18 05:31:35.887: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.634848874s
Apr 18 05:31:37.993: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Running", Reason="", readiness=true. Elapsed: 12.741001553s
Apr 18 05:31:40.103: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Running", Reason="", readiness=true. Elapsed: 14.850742949s
Apr 18 05:31:42.209: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Running", Reason="", readiness=true. Elapsed: 16.95651425s
Apr 18 05:31:44.315: INFO: Pod "azurefile-volume-tester-nbqhp": Phase="Failed", Reason="", readiness=false. Elapsed: 19.06306579s
STEP: Saw pod failure
Apr 18 05:31:44.315: INFO: Pod "azurefile-volume-tester-nbqhp" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 18 05:31:44.431: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-nbqhp"
Apr 18 05:31:44.538: INFO: Pod azurefile-volume-tester-nbqhp 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 203 lines ...
Apr 18 05:33:02.059: INFO: PersistentVolumeClaim pvc-8xx89 found but phase is Pending instead of Bound.
Apr 18 05:33:04.163: INFO: PersistentVolumeClaim pvc-8xx89 found and phase=Bound (2.206091356s)
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 18 05:33:04.475: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-pjjb6" in namespace "azurefile-4538" to be "Succeeded or Failed"
Apr 18 05:33:04.580: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Pending", Reason="", readiness=false. Elapsed: 104.682526ms
Apr 18 05:33:06.688: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.2125871s
Apr 18 05:33:08.794: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.31883737s
Apr 18 05:33:10.902: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.426874138s
Apr 18 05:33:13.009: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.534082824s
Apr 18 05:33:15.116: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.641083037s
Apr 18 05:33:17.223: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Running", Reason="", readiness=true. Elapsed: 12.747636575s
Apr 18 05:33:19.329: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Running", Reason="", readiness=true. Elapsed: 14.853827541s
Apr 18 05:33:21.435: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Running", Reason="", readiness=true. Elapsed: 16.959845139s
Apr 18 05:33:23.541: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Running", Reason="", readiness=true. Elapsed: 19.06643267s
Apr 18 05:33:25.651: INFO: Pod "azurefile-volume-tester-pjjb6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.175958722s
STEP: Saw pod success
Apr 18 05:33:25.651: INFO: Pod "azurefile-volume-tester-pjjb6" 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 18 05:33:56.348: INFO: deleting Pod "azurefile-4538"/"azurefile-volume-tester-pjjb6"
... skipping 302 lines ...
Apr 18 05:34:25.092: INFO: PersistentVolumeClaim pvc-6xl94 found but phase is Pending instead of Bound.
Apr 18 05:34:27.197: INFO: PersistentVolumeClaim pvc-6xl94 found and phase=Bound (2.20729921s)
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 18 05:34:27.511: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-z7qsc" in namespace "azurefile-7726" to be "Succeeded or Failed"
Apr 18 05:34:27.617: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Pending", Reason="", readiness=false. Elapsed: 105.881825ms
Apr 18 05:34:29.725: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.21397565s
Apr 18 05:34:31.831: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.320568527s
Apr 18 05:34:33.937: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.426615833s
Apr 18 05:34:36.044: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Pending", Reason="", readiness=false. Elapsed: 8.533420464s
Apr 18 05:34:38.151: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Pending", Reason="", readiness=false. Elapsed: 10.640247705s
... skipping 2 lines ...
Apr 18 05:34:44.474: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Pending", Reason="", readiness=false. Elapsed: 16.963077948s
Apr 18 05:34:46.580: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Running", Reason="", readiness=true. Elapsed: 19.069629381s
Apr 18 05:34:48.687: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Running", Reason="", readiness=true. Elapsed: 21.176690959s
Apr 18 05:34:50.795: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Running", Reason="", readiness=true. Elapsed: 23.283726595s
Apr 18 05:34:52.901: INFO: Pod "azurefile-volume-tester-z7qsc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 25.390694783s
STEP: Saw pod success
Apr 18 05:34:52.902: INFO: Pod "azurefile-volume-tester-z7qsc" satisfied condition "Succeeded or Failed"
Apr 18 05:34:52.902: INFO: deleting Pod "azurefile-7726"/"azurefile-volume-tester-z7qsc"
Apr 18 05:34:53.020: INFO: Pod azurefile-volume-tester-z7qsc has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-z7qsc in namespace azurefile-7726
Apr 18 05:34:53.148: INFO: deleting PVC "azurefile-7726"/"pvc-6xl94"
Apr 18 05:34:53.148: INFO: Deleting PersistentVolumeClaim "pvc-6xl94"
... skipping 90 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/18 05:35:00 Check successfully
Apr 18 05:35:00.106: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/18 05:35:00 run script: test/utils/get_storage_account_secret_name.sh
2022/04/18 05:35:00 got output: azure-storage-account-f50d92259b65b4d2a9c271c-secret
, error: <nil>
2022/04/18 05:35:00 got storage account secret name: azure-storage-account-f50d92259b65b4d2a9c271c-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 18 05:35:00.745: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-2xnqq] to have phase Bound
Apr 18 05:35:00.847: INFO: PersistentVolumeClaim pvc-2xnqq found but phase is Pending instead of Bound.
Apr 18 05:35:02.951: INFO: PersistentVolumeClaim pvc-2xnqq found and phase=Bound (2.206288064s)
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 18 05:35:03.263: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-v2fcg" in namespace "azurefile-1387" to be "Succeeded or Failed"
Apr 18 05:35:03.365: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 102.305661ms
Apr 18 05:35:05.469: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206622912s
Apr 18 05:35:07.575: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.312281132s
Apr 18 05:35:09.685: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.422888556s
Apr 18 05:35:11.792: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.529584262s
Apr 18 05:35:13.899: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.636160425s
Apr 18 05:35:16.007: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Running", Reason="", readiness=true. Elapsed: 12.744726989s
Apr 18 05:35:18.113: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Running", Reason="", readiness=true. Elapsed: 14.850923058s
Apr 18 05:35:20.221: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Running", Reason="", readiness=true. Elapsed: 16.958175607s
Apr 18 05:35:22.327: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Running", Reason="", readiness=true. Elapsed: 19.064472674s
Apr 18 05:35:24.436: INFO: Pod "azurefile-volume-tester-v2fcg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.173082143s
STEP: Saw pod success
Apr 18 05:35:24.436: INFO: Pod "azurefile-volume-tester-v2fcg" satisfied condition "Succeeded or Failed"
Apr 18 05:35:24.436: INFO: deleting Pod "azurefile-1387"/"azurefile-volume-tester-v2fcg"
Apr 18 05:35:24.552: INFO: Pod azurefile-volume-tester-v2fcg has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-v2fcg in namespace azurefile-1387
Apr 18 05:35:24.673: INFO: deleting PVC "azurefile-1387"/"pvc-2xnqq"
Apr 18 05:35:24.673: INFO: Deleting PersistentVolumeClaim "pvc-2xnqq"
... skipping 43 lines ...
Apr 18 05:35:46.157: INFO: PersistentVolumeClaim pvc-j8bgr found but phase is Pending instead of Bound.
Apr 18 05:35:48.261: INFO: PersistentVolumeClaim pvc-j8bgr found and phase=Bound (21.153598323s)
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 18 05:35:48.573: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-4qvw4" in namespace "azurefile-4547" to be "Succeeded or Failed"
Apr 18 05:35:48.676: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Pending", Reason="", readiness=false. Elapsed: 103.293512ms
Apr 18 05:35:50.780: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207746646s
Apr 18 05:35:52.888: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.315100803s
Apr 18 05:35:54.995: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.422095596s
Apr 18 05:35:57.101: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.528433341s
Apr 18 05:35:59.207: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.634804203s
Apr 18 05:36:01.315: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Running", Reason="", readiness=true. Elapsed: 12.741926817s
Apr 18 05:36:03.422: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Running", Reason="", readiness=true. Elapsed: 14.849258708s
Apr 18 05:36:05.527: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Running", Reason="", readiness=true. Elapsed: 16.954886047s
Apr 18 05:36:07.657: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Running", Reason="", readiness=true. Elapsed: 19.084141906s
Apr 18 05:36:09.765: INFO: Pod "azurefile-volume-tester-4qvw4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.192623011s
STEP: Saw pod success
Apr 18 05:36:09.765: INFO: Pod "azurefile-volume-tester-4qvw4" satisfied condition "Succeeded or Failed"
Apr 18 05:36:09.765: INFO: deleting Pod "azurefile-4547"/"azurefile-volume-tester-4qvw4"
Apr 18 05:36:09.879: INFO: Pod azurefile-volume-tester-4qvw4 has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-4qvw4 in namespace azurefile-4547
Apr 18 05:36:09.991: INFO: deleting PVC "azurefile-4547"/"pvc-j8bgr"
Apr 18 05:36:09.991: INFO: Deleting PersistentVolumeClaim "pvc-j8bgr"
... skipping 74 lines ...
check the driver pods if restarts ...
======================================================================================
2022/04/18 05:37:37 Check successfully
Apr 18 05:37:37.500: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
2022/04/18 05:37:37 run script: test/utils/get_storage_account_secret_name.sh
2022/04/18 05:37:37 got output: azure-storage-account-f50d92259b65b4d2a9c271c-secret
, error: <nil>
2022/04/18 05:37:37 got storage account secret name: azure-storage-account-f50d92259b65b4d2a9c271c-secret
STEP: Successfully provisioned AzureFile volume: "capz-3nyk7j#f50d92259b65b4d2a9c271c#csi-inline-smb-volume##csi-inline-smb-volume"

STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 18 05:37:39.522: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-dbw5r" in namespace "azurefile-4801" to be "Succeeded or Failed"
Apr 18 05:37:39.630: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Pending", Reason="", readiness=false. Elapsed: 108.006921ms
Apr 18 05:37:41.735: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Pending", Reason="", readiness=false. Elapsed: 2.212926539s
Apr 18 05:37:43.842: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Pending", Reason="", readiness=false. Elapsed: 4.319704707s
Apr 18 05:37:45.949: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Pending", Reason="", readiness=false. Elapsed: 6.427118529s
Apr 18 05:37:48.057: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Pending", Reason="", readiness=false. Elapsed: 8.534855802s
Apr 18 05:37:50.166: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Pending", Reason="", readiness=false. Elapsed: 10.644505255s
Apr 18 05:37:52.274: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Running", Reason="", readiness=true. Elapsed: 12.752143842s
Apr 18 05:37:54.381: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Running", Reason="", readiness=true. Elapsed: 14.85873116s
Apr 18 05:37:56.489: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Running", Reason="", readiness=true. Elapsed: 16.967157099s
Apr 18 05:37:58.596: INFO: Pod "azurefile-volume-tester-dbw5r": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.073751649s
STEP: Saw pod success
Apr 18 05:37:58.596: INFO: Pod "azurefile-volume-tester-dbw5r" satisfied condition "Succeeded or Failed"
Apr 18 05:37:58.596: INFO: deleting Pod "azurefile-4801"/"azurefile-volume-tester-dbw5r"
Apr 18 05:37:58.710: INFO: Pod azurefile-volume-tester-dbw5r has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-dbw5r in namespace azurefile-4801
Apr 18 05:37:58.831: 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/18 05:38:02 Check successfully
Apr 18 05:38:02.043: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
STEP: creating secret smbcreds in namespace azurefile-1166
2022/04/18 05:38:02 run script: test/utils/get_smb_svc_public_ip.sh
2022/04/18 05:38:02 got output: 20.223.16.246
, error: <nil>
2022/04/18 05:38:02 use server on Windows: 20.223.16.246
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Apr 18 05:38:02.689: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-h696h" in namespace "azurefile-1166" to be "Succeeded or Failed"
Apr 18 05:38:02.800: INFO: Pod "azurefile-volume-tester-h696h": Phase="Pending", Reason="", readiness=false. Elapsed: 111.359423ms
Apr 18 05:38:04.907: INFO: Pod "azurefile-volume-tester-h696h": Phase="Pending", Reason="", readiness=false. Elapsed: 2.218279073s
Apr 18 05:38:07.016: INFO: Pod "azurefile-volume-tester-h696h": Phase="Pending", Reason="", readiness=false. Elapsed: 4.326840266s
Apr 18 05:38:09.126: INFO: Pod "azurefile-volume-tester-h696h": Phase="Pending", Reason="", readiness=false. Elapsed: 6.436983854s
Apr 18 05:38:11.234: INFO: Pod "azurefile-volume-tester-h696h": Phase="Pending", Reason="", readiness=false. Elapsed: 8.545269327s
Apr 18 05:38:13.341: INFO: Pod "azurefile-volume-tester-h696h": Phase="Pending", Reason="", readiness=false. Elapsed: 10.652278689s
Apr 18 05:38:15.448: INFO: Pod "azurefile-volume-tester-h696h": Phase="Running", Reason="", readiness=true. Elapsed: 12.759522803s
Apr 18 05:38:17.557: INFO: Pod "azurefile-volume-tester-h696h": Phase="Running", Reason="", readiness=true. Elapsed: 14.868259219s
Apr 18 05:38:19.666: INFO: Pod "azurefile-volume-tester-h696h": Phase="Running", Reason="", readiness=true. Elapsed: 16.976690532s
Apr 18 05:38:21.773: INFO: Pod "azurefile-volume-tester-h696h": Phase="Running", Reason="", readiness=true. Elapsed: 19.083764073s
Apr 18 05:38:23.880: INFO: Pod "azurefile-volume-tester-h696h": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.191410728s
STEP: Saw pod success
Apr 18 05:38:23.880: INFO: Pod "azurefile-volume-tester-h696h" satisfied condition "Succeeded or Failed"
Apr 18 05:38:23.880: INFO: deleting Pod "azurefile-1166"/"azurefile-volume-tester-h696h"
Apr 18 05:38:23.994: INFO: Pod azurefile-volume-tester-h696h has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-h696h in namespace azurefile-1166
Apr 18 05:38:24.122: INFO: deleting Secret smbcreds
Apr 18 05:38:24.229: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 132 lines ...
Apr 18 05:38:33.756: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-7n2kk] to have phase Bound
Apr 18 05:38:33.860: INFO: PersistentVolumeClaim pvc-7n2kk found and phase=Bound (104.019522ms)
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 18 05:38:34.175: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-dcghp" in namespace "azurefile-5320" to be "Error status code"
Apr 18 05:38:34.278: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Pending", Reason="", readiness=false. Elapsed: 103.487936ms
Apr 18 05:38:36.390: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.214701213s
Apr 18 05:38:38.497: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.32208608s
Apr 18 05:38:40.621: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.446125119s
Apr 18 05:38:42.729: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.554234461s
Apr 18 05:38:44.836: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.661589778s
Apr 18 05:38:46.946: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Running", Reason="", readiness=true. Elapsed: 12.770725127s
Apr 18 05:38:49.053: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Running", Reason="", readiness=true. Elapsed: 14.877932621s
Apr 18 05:38:51.162: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Running", Reason="", readiness=true. Elapsed: 16.986963438s
Apr 18 05:38:53.271: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Running", Reason="", readiness=true. Elapsed: 19.095800361s
Apr 18 05:38:55.378: INFO: Pod "azurefile-volume-tester-dcghp": Phase="Failed", Reason="", readiness=false. Elapsed: 21.203399365s
STEP: Saw pod failure
Apr 18 05:38:55.378: INFO: Pod "azurefile-volume-tester-dcghp" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Apr 18 05:38:55.506: INFO: deleting Pod "azurefile-5320"/"azurefile-volume-tester-dcghp"
Apr 18 05:38:55.620: INFO: Pod azurefile-volume-tester-dcghp 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 18 05:38:59.542: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-57xvn] to have phase Bound
Apr 18 05:38:59.645: INFO: PersistentVolumeClaim pvc-57xvn found and phase=Bound (103.109526ms)
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 18 05:38:59.964: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-bjb59" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 18 05:39:00.067: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Pending", Reason="", readiness=false. Elapsed: 103.318843ms
Apr 18 05:39:02.176: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Pending", Reason="", readiness=false. Elapsed: 2.211500239s
Apr 18 05:39:04.282: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Pending", Reason="", readiness=false. Elapsed: 4.318249727s
Apr 18 05:39:06.390: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Pending", Reason="", readiness=false. Elapsed: 6.42625342s
Apr 18 05:39:08.498: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Pending", Reason="", readiness=false. Elapsed: 8.534445911s
Apr 18 05:39:10.607: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Pending", Reason="", readiness=false. Elapsed: 10.643293957s
Apr 18 05:39:12.715: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Running", Reason="", readiness=true. Elapsed: 12.751307726s
Apr 18 05:39:14.823: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Running", Reason="", readiness=true. Elapsed: 14.858855608s
Apr 18 05:39:16.932: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Running", Reason="", readiness=true. Elapsed: 16.967690635s
Apr 18 05:39:19.041: INFO: Pod "azurefile-volume-tester-bjb59": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.076783087s
STEP: Saw pod success
Apr 18 05:39:19.041: INFO: Pod "azurefile-volume-tester-bjb59" 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 18 05:39:19.254: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-t687t] to have phase Bound
Apr 18 05:39:19.361: INFO: PersistentVolumeClaim pvc-t687t found and phase=Bound (107.766414ms)
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 18 05:39:19.677: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-lxtfn" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 18 05:39:19.781: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Pending", Reason="", readiness=false. Elapsed: 103.952263ms
Apr 18 05:39:21.886: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.20853929s
Apr 18 05:39:23.994: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.316664697s
Apr 18 05:39:26.104: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.42661383s
Apr 18 05:39:28.216: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.538398528s
Apr 18 05:39:30.324: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Running", Reason="", readiness=true. Elapsed: 10.646989605s
Apr 18 05:39:32.433: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Running", Reason="", readiness=true. Elapsed: 12.75574217s
Apr 18 05:39:34.542: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Running", Reason="", readiness=true. Elapsed: 14.864220789s
Apr 18 05:39:36.649: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Running", Reason="", readiness=true. Elapsed: 16.972037705s
Apr 18 05:39:38.758: INFO: Pod "azurefile-volume-tester-lxtfn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.080938653s
STEP: Saw pod success
Apr 18 05:39:38.758: INFO: Pod "azurefile-volume-tester-lxtfn" 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 18 05:39:38.981: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-qndt8] to have phase Bound
Apr 18 05:39:39.084: INFO: PersistentVolumeClaim pvc-qndt8 found and phase=Bound (103.33705ms)
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 18 05:39:39.402: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-cb666" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 18 05:39:39.506: INFO: Pod "azurefile-volume-tester-cb666": Phase="Pending", Reason="", readiness=false. Elapsed: 104.198055ms
Apr 18 05:39:41.610: INFO: Pod "azurefile-volume-tester-cb666": Phase="Pending", Reason="", readiness=false. Elapsed: 2.207810216s
Apr 18 05:39:43.718: INFO: Pod "azurefile-volume-tester-cb666": Phase="Pending", Reason="", readiness=false. Elapsed: 4.31622518s
Apr 18 05:39:45.827: INFO: Pod "azurefile-volume-tester-cb666": Phase="Pending", Reason="", readiness=false. Elapsed: 6.424369903s
Apr 18 05:39:47.935: INFO: Pod "azurefile-volume-tester-cb666": Phase="Pending", Reason="", readiness=false. Elapsed: 8.532732766s
Apr 18 05:39:50.044: INFO: Pod "azurefile-volume-tester-cb666": Phase="Pending", Reason="", readiness=false. Elapsed: 10.641352918s
Apr 18 05:39:52.152: INFO: Pod "azurefile-volume-tester-cb666": Phase="Running", Reason="", readiness=true. Elapsed: 12.749601191s
Apr 18 05:39:54.259: INFO: Pod "azurefile-volume-tester-cb666": Phase="Running", Reason="", readiness=true. Elapsed: 14.856809234s
Apr 18 05:39:56.367: INFO: Pod "azurefile-volume-tester-cb666": Phase="Running", Reason="", readiness=true. Elapsed: 16.964740063s
Apr 18 05:39:58.475: INFO: Pod "azurefile-volume-tester-cb666": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.072360055s
STEP: Saw pod success
Apr 18 05:39:58.475: INFO: Pod "azurefile-volume-tester-cb666" 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 18 05:39:58.693: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-htczt] to have phase Bound
Apr 18 05:39:58.796: INFO: PersistentVolumeClaim pvc-htczt found and phase=Bound (103.249901ms)
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 18 05:39:59.114: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-9ntcf" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 18 05:39:59.219: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Pending", Reason="", readiness=false. Elapsed: 104.45497ms
Apr 18 05:40:01.324: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.210176042s
Apr 18 05:40:03.432: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.318192217s
Apr 18 05:40:05.540: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.425454834s
Apr 18 05:40:07.648: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.533474747s
Apr 18 05:40:09.754: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.64017277s
Apr 18 05:40:11.863: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Running", Reason="", readiness=true. Elapsed: 12.748401246s
Apr 18 05:40:13.969: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Running", Reason="", readiness=true. Elapsed: 14.855184517s
Apr 18 05:40:16.077: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Running", Reason="", readiness=true. Elapsed: 16.96295851s
Apr 18 05:40:18.184: INFO: Pod "azurefile-volume-tester-9ntcf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.070079867s
STEP: Saw pod success
Apr 18 05:40:18.184: INFO: Pod "azurefile-volume-tester-9ntcf" 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 18 05:40:18.399: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-bnmxq] to have phase Bound
Apr 18 05:40:18.503: INFO: PersistentVolumeClaim pvc-bnmxq found and phase=Bound (103.792747ms)
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 18 05:40:18.828: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-87hj4" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 18 05:40:18.933: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Pending", Reason="", readiness=false. Elapsed: 105.081694ms
Apr 18 05:40:21.037: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.209107613s
Apr 18 05:40:23.144: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.31653986s
Apr 18 05:40:25.252: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.424075085s
Apr 18 05:40:27.360: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.532200518s
Apr 18 05:40:29.467: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.639256224s
Apr 18 05:40:31.573: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Running", Reason="", readiness=true. Elapsed: 12.74535165s
Apr 18 05:40:33.681: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Running", Reason="", readiness=true. Elapsed: 14.853088198s
Apr 18 05:40:35.787: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Running", Reason="", readiness=true. Elapsed: 16.959679146s
Apr 18 05:40:37.894: INFO: Pod "azurefile-volume-tester-87hj4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.066257751s
STEP: Saw pod success
Apr 18 05:40:37.894: INFO: Pod "azurefile-volume-tester-87hj4" 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 18 05:40:38.105: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-ts4n4] to have phase Bound
Apr 18 05:40:38.209: INFO: PersistentVolumeClaim pvc-ts4n4 found and phase=Bound (103.989104ms)
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 18 05:40:38.526: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-s5bql" in namespace "azurefile-9103" to be "Succeeded or Failed"
Apr 18 05:40:38.633: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Pending", Reason="", readiness=false. Elapsed: 106.676708ms
Apr 18 05:40:40.737: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Pending", Reason="", readiness=false. Elapsed: 2.210754566s
Apr 18 05:40:42.849: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Pending", Reason="", readiness=false. Elapsed: 4.322914502s
Apr 18 05:40:44.956: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Pending", Reason="", readiness=false. Elapsed: 6.429688227s
Apr 18 05:40:47.063: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Pending", Reason="", readiness=false. Elapsed: 8.536871311s
Apr 18 05:40:49.170: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Running", Reason="", readiness=true. Elapsed: 10.644569509s
Apr 18 05:40:51.277: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Running", Reason="", readiness=true. Elapsed: 12.751489038s
Apr 18 05:40:53.385: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Running", Reason="", readiness=true. Elapsed: 14.859428837s
Apr 18 05:40:55.493: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Running", Reason="", readiness=true. Elapsed: 16.967183421s
Apr 18 05:40:57.600: INFO: Pod "azurefile-volume-tester-s5bql": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.07372821s
STEP: Saw pod success
Apr 18 05:40:57.600: INFO: Pod "azurefile-volume-tester-s5bql" satisfied condition "Succeeded or Failed"
Apr 18 05:40:57.600: INFO: deleting Pod "azurefile-9103"/"azurefile-volume-tester-s5bql"
Apr 18 05:40:57.728: INFO: Pod azurefile-volume-tester-s5bql has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-s5bql in namespace azurefile-9103
Apr 18 05:40:57.847: INFO: deleting PVC "azurefile-9103"/"pvc-ts4n4"
Apr 18 05:40:57.847: INFO: Deleting PersistentVolumeClaim "pvc-ts4n4"
... skipping 148 lines ...
Apr 18 05:41:10.178: INFO: PersistentVolumeClaim pvc-6sffb found but phase is Pending instead of Bound.
Apr 18 05:41:12.283: INFO: PersistentVolumeClaim pvc-6sffb found and phase=Bound (2.208463947s)
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 18 05:41:12.595: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-xz7pf" in namespace "azurefile-8470" to be "Succeeded or Failed"
Apr 18 05:41:12.704: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Pending", Reason="", readiness=false. Elapsed: 109.079198ms
Apr 18 05:41:14.809: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.213281608s
Apr 18 05:41:16.912: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.316878389s
Apr 18 05:41:19.019: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.423869942s
Apr 18 05:41:21.127: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.532104672s
Apr 18 05:41:23.235: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.63968585s
Apr 18 05:41:25.343: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Pending", Reason="", readiness=false. Elapsed: 12.747727229s
Apr 18 05:41:27.450: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Pending", Reason="", readiness=false. Elapsed: 14.854956059s
Apr 18 05:41:29.562: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Running", Reason="", readiness=true. Elapsed: 16.9666787s
Apr 18 05:41:31.669: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Running", Reason="", readiness=true. Elapsed: 19.073688463s
Apr 18 05:41:33.777: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Running", Reason="", readiness=true. Elapsed: 21.181323206s
Apr 18 05:41:35.884: INFO: Pod "azurefile-volume-tester-xz7pf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 23.289071257s
STEP: Saw pod success
Apr 18 05:41:35.884: INFO: Pod "azurefile-volume-tester-xz7pf" satisfied condition "Succeeded or Failed"
Apr 18 05:41:35.885: INFO: deleting Pod "azurefile-8470"/"azurefile-volume-tester-xz7pf"
Apr 18 05:41:36.001: INFO: Pod azurefile-volume-tester-xz7pf has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-xz7pf in namespace azurefile-8470
Apr 18 05:41:36.123: INFO: deleting PVC "azurefile-8470"/"pvc-6sffb"
Apr 18 05:41:36.123: INFO: Deleting PersistentVolumeClaim "pvc-6sffb"
... skipping 33 lines ...
Apr 18 05:41:39.390: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-mk94d] to have phase Bound
Apr 18 05:41:39.493: INFO: PersistentVolumeClaim pvc-mk94d found and phase=Bound (103.601768ms)
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 18 05:41:39.806: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-7bqdt" in namespace "azurefile-7029" to be "Succeeded or Failed"
Apr 18 05:41:39.909: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Pending", Reason="", readiness=false. Elapsed: 103.08613ms
Apr 18 05:41:42.019: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.213369873s
Apr 18 05:41:44.126: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.320514219s
Apr 18 05:41:46.233: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.427483953s
Apr 18 05:41:48.341: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.535635495s
Apr 18 05:41:50.449: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.643032766s
Apr 18 05:41:52.557: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Running", Reason="", readiness=true. Elapsed: 12.751533963s
Apr 18 05:41:54.666: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Running", Reason="", readiness=true. Elapsed: 14.860565349s
Apr 18 05:41:56.775: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Running", Reason="", readiness=true. Elapsed: 16.969564124s
Apr 18 05:41:58.887: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Running", Reason="", readiness=true. Elapsed: 19.081678169s
Apr 18 05:42:00.995: INFO: Pod "azurefile-volume-tester-7bqdt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 21.189171502s
STEP: Saw pod success
Apr 18 05:42:00.995: INFO: Pod "azurefile-volume-tester-7bqdt" satisfied condition "Succeeded or Failed"
Apr 18 05:42:00.995: INFO: deleting Pod "azurefile-7029"/"azurefile-volume-tester-7bqdt"
Apr 18 05:42:01.108: INFO: Pod azurefile-volume-tester-7bqdt has the following logs: hello world

STEP: Deleting pod azurefile-volume-tester-7bqdt in namespace azurefile-7029
Apr 18 05:42:01.226: INFO: deleting PVC "azurefile-7029"/"pvc-mk94d"
Apr 18 05:42:01.226: INFO: Deleting PersistentVolumeClaim "pvc-mk94d"
... skipping 86 lines ...
Platform: linux/amd64

Streaming logs below:
I0418 05:16:48.711365       1 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-92b6b36980c6d5b3569bdf7138de57ac800caf1c gc/go1.18.1 (amd64-linux) e2e-test
I0418 05:16:48.711724       1 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0418 05:16:48.730500       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 18 milliseconds
W0418 05:16:48.730782       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
I0418 05:16:48.730821       1 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0418 05:16:48.730833       1 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0418 05:16:48.730870       1 azure.go:101] read cloud config from file: /etc/kubernetes/azure.json successfully
I0418 05:16:48.732252       1 azure_auth.go:245] Using AzurePublicCloud environment
I0418 05:16:48.732327       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0418 05:16:48.732438       1 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 2918 lines ...
Platform: windows/amd64

Streaming logs below:
I0418 05:19:48.630096    6596 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-92b6b36980c6d5b3569bdf7138de57ac800caf1c gc/go1.18.1 (amd64-windows) e2e-test
I0418 05:19:48.646908    6596 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0418 05:19:58.655913    6596 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider  in 10006 milliseconds
W0418 05:19:58.655913    6596 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: Get "https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider": net/http: TLS handshake timeout
I0418 05:19:58.655913    6596 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0418 05:19:58.655913    6596 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0418 05:19:58.656564    6596 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0418 05:19:58.659283    6596 azure_auth.go:245] Using AzurePublicCloud environment
I0418 05:19:58.659915    6596 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0418 05:19:58.661578    6596 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 44 lines ...
I0418 05:20:12.278008    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:12.279282    6596 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:12.279609    6596 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:12.280418    6596 safe_mounter_windows.go:70] SMBMount: remote path: \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:12.280418    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791
I0418 05:20:12.281145    6596 safe_mounter_windows.go:97] begin to mount \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
E0418 05:20:20.235175    6596 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-3nyk7j#f95c191289a424df79dee3d#pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791#) mount "\\\\f95c191289a424df79dee3d.privatelink.file.core.windows.net\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\\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
I0418 05:20:20.816248    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:20.816248    6596 utils.go:77] GRPC request: {}
I0418 05:20:20.816248    6596 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0418 05:20:20.821128    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:20.821128    6596 utils.go:77] GRPC request: {}
I0418 05:20:20.821128    6596 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 ...
I0418 05:20:20.827618    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:20.828593    6596 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:20.828593    6596 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:20.829174    6596 safe_mounter_windows.go:70] SMBMount: remote path: \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:20.829174    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791
I0418 05:20:20.829264    6596 safe_mounter_windows.go:97] begin to mount \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
E0418 05:20:23.552021    6596 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-3nyk7j#f95c191289a424df79dee3d#pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791#) mount "\\\\f95c191289a424df79dee3d.privatelink.file.core.windows.net\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\\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
I0418 05:20:24.583467    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:24.583467    6596 utils.go:77] GRPC request: {}
I0418 05:20:24.583467    6596 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0418 05:20:24.586976    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:24.586976    6596 utils.go:77] GRPC request: {}
I0418 05:20:24.586976    6596 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 ...
I0418 05:20:24.593927    6596 safe_mounter_windows.go:70] SMBMount: remote path: \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:24.593927    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791
I0418 05:20:24.594096    6596 safe_mounter_windows.go:97] begin to mount \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:26.067296    6596 utils.go:76] GRPC call: /csi.v1.Identity/Probe
I0418 05:20:26.067296    6596 utils.go:77] GRPC request: {}
I0418 05:20:26.067702    6596 utils.go:83] GRPC response: {"ready":{"value":true}}
E0418 05:20:27.321417    6596 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-3nyk7j#f95c191289a424df79dee3d#pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791#) mount "\\\\f95c191289a424df79dee3d.privatelink.file.core.windows.net\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\\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
I0418 05:20:29.401764    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:29.401764    6596 utils.go:77] GRPC request: {}
I0418 05:20:29.401764    6596 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0418 05:20:29.404788    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:29.404788    6596 utils.go:77] GRPC request: {}
I0418 05:20:29.404788    6596 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 ...
I0418 05:20:29.416371    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:29.417001    6596 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:29.417001    6596 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:29.417596    6596 safe_mounter_windows.go:70] SMBMount: remote path: \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:29.417596    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791
I0418 05:20:29.418468    6596 safe_mounter_windows.go:97] begin to mount \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
E0418 05:20:32.068619    6596 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-3nyk7j#f95c191289a424df79dee3d#pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791#) mount "\\\\f95c191289a424df79dee3d.privatelink.file.core.windows.net\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\\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
I0418 05:20:36.080567    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:36.080567    6596 utils.go:77] GRPC request: {}
I0418 05:20:36.080567    6596 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0418 05:20:36.087179    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:36.087179    6596 utils.go:77] GRPC request: {}
I0418 05:20:36.087179    6596 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 ...
I0418 05:20:36.093153    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:36.093796    6596 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:36.093796    6596 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:36.094632    6596 safe_mounter_windows.go:70] SMBMount: remote path: \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:36.094789    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791
I0418 05:20:36.095161    6596 safe_mounter_windows.go:97] begin to mount \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
E0418 05:20:38.813472    6596 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-3nyk7j#f95c191289a424df79dee3d#pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791#) mount "\\\\f95c191289a424df79dee3d.privatelink.file.core.windows.net\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\\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
I0418 05:20:46.826708    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:46.826708    6596 utils.go:77] GRPC request: {}
I0418 05:20:46.826708    6596 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0418 05:20:46.829870    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:20:46.829947    6596 utils.go:77] GRPC request: {}
I0418 05:20:46.829987    6596 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 ...
I0418 05:20:46.835049    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:46.839664    6596 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:46.839664    6596 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:46.841759    6596 safe_mounter_windows.go:70] SMBMount: remote path: \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:20:46.841759    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791
I0418 05:20:46.842468    6596 safe_mounter_windows.go:97] begin to mount \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
E0418 05:20:49.484575    6596 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-3nyk7j#f95c191289a424df79dee3d#pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791#) mount "\\\\f95c191289a424df79dee3d.privatelink.file.core.windows.net\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\\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
I0418 05:20:56.069644    6596 utils.go:76] GRPC call: /csi.v1.Identity/Probe
I0418 05:20:56.069689    6596 utils.go:77] GRPC request: {}
I0418 05:20:56.069689    6596 utils.go:83] GRPC response: {"ready":{"value":true}}
I0418 05:21:05.562367    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:21:05.562417    6596 utils.go:77] GRPC request: {}
I0418 05:21:05.562508    6596 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 ...
I0418 05:21:05.569642    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:21:05.570782    6596 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:21:05.570782    6596 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:21:05.570983    6596 safe_mounter_windows.go:70] SMBMount: remote path: \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 local path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
I0418 05:21:05.570983    6596 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791
I0418 05:21:05.571694    6596 safe_mounter_windows.go:97] begin to mount \\f95c191289a424df79dee3d.privatelink.file.core.windows.net\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791 on c:\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\globalmount
E0418 05:21:08.492635    6596 utils.go:81] GRPC error: rpc error: code = Internal desc = volume(capz-3nyk7j#f95c191289a424df79dee3d#pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791#) mount "\\\\f95c191289a424df79dee3d.privatelink.file.core.windows.net\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791" on "\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-6f1996aa-e2a1-414d-9f2d-1d57dd850791\\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
I0418 05:21:26.069359    6596 utils.go:76] GRPC call: /csi.v1.Identity/Probe
I0418 05:21:26.069359    6596 utils.go:77] GRPC request: {}
I0418 05:21:26.069359    6596 utils.go:83] GRPC response: {"ready":{"value":true}}
I0418 05:21:40.566962    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:21:40.566962    6596 utils.go:77] GRPC request: {}
I0418 05:21:40.566962    6596 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
... skipping 1216 lines ...
I0418 05:37:39.749341    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:37:39.749341    6596 utils.go:77] GRPC request: {}
I0418 05:37:39.749341    6596 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0418 05:37:39.750681    6596 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0418 05:37:39.750681    6596 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\c3fcd991-7230-46d8-9b87-f327ac141fe0\\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-dbw5r","csi.storage.k8s.io/pod.namespace":"azurefile-4801","csi.storage.k8s.io/pod.uid":"c3fcd991-7230-46d8-9b87-f327ac141fe0","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"azure-storage-account-f50d92259b65b4d2a9c271c-secret","server":"","shareName":"csi-inline-smb-volume"},"volume_id":"csi-b333ca0f1ae3bc0ecfe9faa97878d2389ecaf51ef7fb4fd6f8e115f590b680c0"}
I0418 05:37:39.750681    6596 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-b333ca0f1ae3bc0ecfe9faa97878d2389ecaf51ef7fb4fd6f8e115f590b680c0) mount on c:\var\lib\kubelet\pods\c3fcd991-7230-46d8-9b87-f327ac141fe0\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-dbw5r csi.storage.k8s.io/pod.namespace:azurefile-4801 csi.storage.k8s.io/pod.uid:c3fcd991-7230-46d8-9b87-f327ac141fe0 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-f50d92259b65b4d2a9c271c-secret secretnamespace:azurefile-4801 server: shareName:csi-inline-smb-volume storageaccount:]
W0418 05:37:39.751487    6596 azurefile.go:546] parsing volumeID(csi-b333ca0f1ae3bc0ecfe9faa97878d2389ecaf51ef7fb4fd6f8e115f590b680c0) return with error: error parsing volume id: "csi-b333ca0f1ae3bc0ecfe9faa97878d2389ecaf51ef7fb4fd6f8e115f590b680c0", should at least contain two #
I0418 05:37:39.761941    6596 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-4801/secrets/azure-storage-account-f50d92259b65b4d2a9c271c-secret 200 OK in 9 milliseconds
I0418 05:37:39.763495    6596 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\c3fcd991-7230-46d8-9b87-f327ac141fe0\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-b333ca0f1ae3bc0ecfe9faa97878d2389ecaf51ef7fb4fd6f8e115f590b680c0) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-dbw5r csi.storage.k8s.io/pod.namespace:azurefile-4801 csi.storage.k8s.io/pod.uid:c3fcd991-7230-46d8-9b87-f327ac141fe0 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:azure-storage-account-f50d92259b65b4d2a9c271c-secret secretnamespace:azurefile-4801 server: shareName:csi-inline-smb-volume storageaccount:]) mountflags([]) mountOptions([AZURE\f50d92259b65b4d2a9c271c]) volumeMountGroup()
I0418 05:37:39.763495    6596 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\c3fcd991-7230-46d8-9b87-f327ac141fe0\volumes\kubernetes.io~csi\test-volume-1\mount
I0418 05:37:39.763495    6596 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\c3fcd991-7230-46d8-9b87-f327ac141fe0\volumes\kubernetes.io~csi\test-volume-1\mount
I0418 05:37:39.765274    6596 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\c3fcd991-7230-46d8-9b87-f327ac141fe0\volumes\kubernetes.io~csi\test-volume-1\mount
I0418 05:37:39.765543    6596 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\c3fcd991-7230-46d8-9b87-f327ac141fe0\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 20 lines ...
I0418 05:38:02.878545    6596 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0418 05:38:02.878577    6596 utils.go:77] GRPC request: {}
I0418 05:38:02.878654    6596 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]}
I0418 05:38:02.880346    6596 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume
I0418 05:38:02.880346    6596 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\2c7d1ad9-752b-475d-8b48-58c382a541ce\\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-h696h","csi.storage.k8s.io/pod.namespace":"azurefile-1166","csi.storage.k8s.io/pod.uid":"2c7d1ad9-752b-475d-8b48-58c382a541ce","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"cache=singleclient","secretName":"smbcreds","server":"20.223.16.246","shareName":"share"},"volume_id":"csi-1a2c25d7b2924e69c3df16147b22d8ef1b7048ffb53c40f81fa312a6329b993c"}
I0418 05:38:02.880569    6596 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-1a2c25d7b2924e69c3df16147b22d8ef1b7048ffb53c40f81fa312a6329b993c) mount on c:\var\lib\kubelet\pods\2c7d1ad9-752b-475d-8b48-58c382a541ce\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-h696h csi.storage.k8s.io/pod.namespace:azurefile-1166 csi.storage.k8s.io/pod.uid:2c7d1ad9-752b-475d-8b48-58c382a541ce csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:smbcreds secretnamespace:azurefile-1166 server:20.223.16.246 shareName:share storageaccount:]
W0418 05:38:02.880634    6596 azurefile.go:546] parsing volumeID(csi-1a2c25d7b2924e69c3df16147b22d8ef1b7048ffb53c40f81fa312a6329b993c) return with error: error parsing volume id: "csi-1a2c25d7b2924e69c3df16147b22d8ef1b7048ffb53c40f81fa312a6329b993c", should at least contain two #
I0418 05:38:02.883895    6596 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-1166/secrets/smbcreds 200 OK in 3 milliseconds
I0418 05:38:02.883895    6596 nodeserver.go:268] cifsMountPath(c:\var\lib\kubelet\pods\2c7d1ad9-752b-475d-8b48-58c382a541ce\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-1a2c25d7b2924e69c3df16147b22d8ef1b7048ffb53c40f81fa312a6329b993c) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-h696h csi.storage.k8s.io/pod.namespace:azurefile-1166 csi.storage.k8s.io/pod.uid:2c7d1ad9-752b-475d-8b48-58c382a541ce csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:cache=singleclient secretName:smbcreds secretnamespace:azurefile-1166 server:20.223.16.246 shareName:share storageaccount:]) mountflags([]) mountOptions([AZURE\USERNAME]) volumeMountGroup()
I0418 05:38:02.883895    6596 safe_mounter_windows.go:163] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\2c7d1ad9-752b-475d-8b48-58c382a541ce\volumes\kubernetes.io~csi\test-volume-1\mount
I0418 05:38:02.883895    6596 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\2c7d1ad9-752b-475d-8b48-58c382a541ce\volumes\kubernetes.io~csi\test-volume-1\mount
I0418 05:38:02.886324    6596 safe_mounter_windows.go:220] Exists path: c:\var\lib\kubelet\pods\2c7d1ad9-752b-475d-8b48-58c382a541ce\volumes\kubernetes.io~csi\test-volume-1\mount
I0418 05:38:02.886596    6596 azure_common_windows.go:73] Removing path: c:\var\lib\kubelet\pods\2c7d1ad9-752b-475d-8b48-58c382a541ce\volumes\kubernetes.io~csi\test-volume-1\mount
... skipping 710 lines ...
Platform: windows/amd64

Streaming logs below:
I0418 05:18:04.495067    1344 azurefile.go:267] driver userAgent: file.csi.azure.com/e2e-92b6b36980c6d5b3569bdf7138de57ac800caf1c gc/go1.18.1 (amd64-windows) e2e-test
I0418 05:18:04.508232    1344 azure.go:71] reading cloud config from secret kube-system/azure-cloud-provider
I0418 05:18:04.528219    1344 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 18 milliseconds
W0418 05:18:04.531373    1344 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
I0418 05:18:04.531654    1344 azure.go:83] could not read cloud config from secret kube-system/azure-cloud-provider
I0418 05:18:04.531654    1344 azure.go:93] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0418 05:18:04.531654    1344 azure.go:101] read cloud config from file: C:\k\azure.json successfully
I0418 05:18:04.538339    1344 azure_auth.go:245] Using AzurePublicCloud environment
I0418 05:18:04.538845    1344 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0418 05:18:04.540510    1344 azure_diskclient.go:67] Azure DisksClient using API version: 2021-04-01
... skipping 592 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 1619.951 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 (1619.96s)
FAIL
FAIL	sigs.k8s.io/azurefile-csi-driver/test/e2e	1620.011s
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 99 lines ...