kubernetes-sigs/azurefile-csi-driver PR #1155 pull-azurefile-csi-driver-e2e-capz-windows-2019 #1610576089808113664
Recent runs || View in Spyglass
Recent runs || View in Spyglass
| PR | andyzhangx: fix: set ForceAttemptHTTP2 as false to increase ARM throttling limit |
| Result | FAILURE |
| Tests | 0 failed / 0 succeeded |
| Started | |
| Elapsed | 1h9m |
| Revision | 9b2e9a6ab846434f409b84cbf98266f0ae9a8ee3 |
| Refs |
1155 |
... skipping 764 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 # Create customized cloud provider configs ./hack/create-custom-cloud-provider-config.sh make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure' make[2]: Nothing to be done for 'kubectl'. ... skipping 137 lines ... # Wait for the kubeconfig to become available. timeout --foreground 300 bash -c "while ! /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 get secrets | grep capz-fkqvhq-kubeconfig; do sleep 1; done" capz-fkqvhq-kubeconfig cluster.x-k8s.io/secret 1 0s # Get kubeconfig and store it locally. /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 get secrets capz-fkqvhq-kubeconfig -o json | jq -r .data.value | base64 --decode > ./kubeconfig timeout --foreground 600 bash -c "while ! /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 --kubeconfig=./kubeconfig get nodes | grep control-plane; do sleep 1; done" error: the server doesn't have a resource type "nodes" capz-fkqvhq-control-plane-pv9wj NotReady control-plane,master 5s v1.23.16-rc.0.37+548d5d2298c4a5 run "/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 --kubeconfig=./kubeconfig ..." to work with the new target cluster make[1]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure' CCM cluster CIDR: 192.168.0.0/16 Waiting for 1 control plane machine(s), 0 worker machine(s), and 2 windows machine(s) to become Ready node/capz-fkqv-cgjvz condition met ... skipping 1035 lines ... image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.6.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 350 lines ... Jan 4 10:26:57.552: INFO: PersistentVolumeClaim pvc-8tws2 found but phase is Pending instead of Bound. Jan 4 10:26:59.614: INFO: PersistentVolumeClaim pvc-8tws2 found and phase=Bound (1m34.938510115s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:26:59.614[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:26:59.675[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:26:59.737[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:26:59.737[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:26:59.803[0m Jan 4 10:26:59.803: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-95spk" in namespace "azurefile-2540" to be "Succeeded or Failed" Jan 4 10:26:59.865: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 61.52059ms Jan 4 10:27:01.928: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124710349s Jan 4 10:27:03.928: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.125271391s Jan 4 10:27:05.928: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.12472828s Jan 4 10:27:07.933: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.129517006s Jan 4 10:27:09.932: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 10.129217693s ... skipping 177 lines ... Jan 4 10:33:05.932: INFO: Pod "azurefile-volume-tester-95spk": Phase="Running", Reason="", readiness=true. Elapsed: 6m6.129151039s Jan 4 10:33:07.933: INFO: Pod "azurefile-volume-tester-95spk": Phase="Running", Reason="", readiness=true. Elapsed: 6m8.129714027s Jan 4 10:33:09.932: INFO: Pod "azurefile-volume-tester-95spk": Phase="Running", Reason="", readiness=true. Elapsed: 6m10.128657696s Jan 4 10:33:11.933: INFO: Pod "azurefile-volume-tester-95spk": Phase="Running", Reason="", readiness=false. Elapsed: 6m12.129940834s Jan 4 10:33:13.931: INFO: Pod "azurefile-volume-tester-95spk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6m14.127957905s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:33:13.931[0m Jan 4 10:33:13.931: INFO: Pod "azurefile-volume-tester-95spk" satisfied condition "Succeeded or Failed" Jan 4 10:33:13.932: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-95spk" Jan 4 10:33:14.013: INFO: Pod azurefile-volume-tester-95spk has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-95spk in namespace azurefile-2540 [38;5;243m01/04/23 10:33:14.013[0m Jan 4 10:33:14.085: INFO: deleting PVC "azurefile-2540"/"pvc-8tws2" Jan 4 10:33:14.085: INFO: Deleting PersistentVolumeClaim "pvc-8tws2" ... skipping 73 lines ... Jan 4 10:26:57.552: INFO: PersistentVolumeClaim pvc-8tws2 found but phase is Pending instead of Bound. Jan 4 10:26:59.614: INFO: PersistentVolumeClaim pvc-8tws2 found and phase=Bound (1m34.938510115s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:26:59.614[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:26:59.675[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:26:59.737[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:26:59.737[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:26:59.803[0m Jan 4 10:26:59.803: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-95spk" in namespace "azurefile-2540" to be "Succeeded or Failed" Jan 4 10:26:59.865: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 61.52059ms Jan 4 10:27:01.928: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124710349s Jan 4 10:27:03.928: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.125271391s Jan 4 10:27:05.928: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.12472828s Jan 4 10:27:07.933: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.129517006s Jan 4 10:27:09.932: INFO: Pod "azurefile-volume-tester-95spk": Phase="Pending", Reason="", readiness=false. Elapsed: 10.129217693s ... skipping 177 lines ... Jan 4 10:33:05.932: INFO: Pod "azurefile-volume-tester-95spk": Phase="Running", Reason="", readiness=true. Elapsed: 6m6.129151039s Jan 4 10:33:07.933: INFO: Pod "azurefile-volume-tester-95spk": Phase="Running", Reason="", readiness=true. Elapsed: 6m8.129714027s Jan 4 10:33:09.932: INFO: Pod "azurefile-volume-tester-95spk": Phase="Running", Reason="", readiness=true. Elapsed: 6m10.128657696s Jan 4 10:33:11.933: INFO: Pod "azurefile-volume-tester-95spk": Phase="Running", Reason="", readiness=false. Elapsed: 6m12.129940834s Jan 4 10:33:13.931: INFO: Pod "azurefile-volume-tester-95spk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6m14.127957905s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:33:13.931[0m Jan 4 10:33:13.931: INFO: Pod "azurefile-volume-tester-95spk" satisfied condition "Succeeded or Failed" Jan 4 10:33:13.932: INFO: deleting Pod "azurefile-2540"/"azurefile-volume-tester-95spk" Jan 4 10:33:14.013: INFO: Pod azurefile-volume-tester-95spk has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-95spk in namespace azurefile-2540 [38;5;243m01/04/23 10:33:14.013[0m Jan 4 10:33:14.085: INFO: deleting PVC "azurefile-2540"/"pvc-8tws2" Jan 4 10:33:14.085: INFO: Deleting PersistentVolumeClaim "pvc-8tws2" ... skipping 38 lines ... Jan 4 10:33:39.428: INFO: PersistentVolumeClaim pvc-btkgd found but phase is Pending instead of Bound. Jan 4 10:33:41.491: INFO: PersistentVolumeClaim pvc-btkgd found and phase=Bound (20.691517458s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:33:41.491[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:33:41.553[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:33:41.617[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:33:41.617[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:33:41.68[0m Jan 4 10:33:41.681: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-h7dfw" in namespace "azurefile-4728" to be "Succeeded or Failed" Jan 4 10:33:41.745: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 64.68339ms Jan 4 10:33:43.808: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.127416505s Jan 4 10:33:45.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.131825046s Jan 4 10:33:47.811: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.130802754s Jan 4 10:33:49.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.130967257s Jan 4 10:33:51.814: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Running", Reason="", readiness=true. Elapsed: 10.13311597s Jan 4 10:33:53.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Running", Reason="", readiness=true. Elapsed: 12.131502296s Jan 4 10:33:55.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Running", Reason="", readiness=true. Elapsed: 14.131392591s Jan 4 10:33:57.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Running", Reason="", readiness=false. Elapsed: 16.131342466s Jan 4 10:33:59.813: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.132481363s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:33:59.813[0m Jan 4 10:33:59.813: INFO: Pod "azurefile-volume-tester-h7dfw" satisfied condition "Succeeded or Failed" Jan 4 10:33:59.813: INFO: deleting Pod "azurefile-4728"/"azurefile-volume-tester-h7dfw" Jan 4 10:33:59.883: INFO: Pod azurefile-volume-tester-h7dfw has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-h7dfw in namespace azurefile-4728 [38;5;243m01/04/23 10:33:59.883[0m Jan 4 10:33:59.957: INFO: deleting PVC "azurefile-4728"/"pvc-btkgd" Jan 4 10:33:59.957: INFO: Deleting PersistentVolumeClaim "pvc-btkgd" ... skipping 37 lines ... Jan 4 10:33:39.428: INFO: PersistentVolumeClaim pvc-btkgd found but phase is Pending instead of Bound. Jan 4 10:33:41.491: INFO: PersistentVolumeClaim pvc-btkgd found and phase=Bound (20.691517458s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:33:41.491[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:33:41.553[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:33:41.617[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:33:41.617[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:33:41.68[0m Jan 4 10:33:41.681: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-h7dfw" in namespace "azurefile-4728" to be "Succeeded or Failed" Jan 4 10:33:41.745: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 64.68339ms Jan 4 10:33:43.808: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.127416505s Jan 4 10:33:45.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.131825046s Jan 4 10:33:47.811: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.130802754s Jan 4 10:33:49.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.130967257s Jan 4 10:33:51.814: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Running", Reason="", readiness=true. Elapsed: 10.13311597s Jan 4 10:33:53.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Running", Reason="", readiness=true. Elapsed: 12.131502296s Jan 4 10:33:55.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Running", Reason="", readiness=true. Elapsed: 14.131392591s Jan 4 10:33:57.812: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Running", Reason="", readiness=false. Elapsed: 16.131342466s Jan 4 10:33:59.813: INFO: Pod "azurefile-volume-tester-h7dfw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.132481363s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:33:59.813[0m Jan 4 10:33:59.813: INFO: Pod "azurefile-volume-tester-h7dfw" satisfied condition "Succeeded or Failed" Jan 4 10:33:59.813: INFO: deleting Pod "azurefile-4728"/"azurefile-volume-tester-h7dfw" Jan 4 10:33:59.883: INFO: Pod azurefile-volume-tester-h7dfw has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-h7dfw in namespace azurefile-4728 [38;5;243m01/04/23 10:33:59.883[0m Jan 4 10:33:59.957: INFO: deleting PVC "azurefile-4728"/"pvc-btkgd" Jan 4 10:33:59.957: INFO: Deleting PersistentVolumeClaim "pvc-btkgd" ... skipping 183 lines ... Jan 4 10:44:00.201: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m32.281691767s) Jan 4 10:44:05.264: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m37.344077746s) Jan 4 10:44:10.328: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m42.40876283s) Jan 4 10:44:15.394: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m47.474075248s) Jan 4 10:44:20.456: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m52.536363024s) Jan 4 10:44:25.519: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m57.599212283s) Jan 4 10:44:30.521: INFO: Unexpected error: <*errors.errorString | 0xc000d1a050>: { s: "PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f still exists within 10m0s", } Jan 4 10:44:30.521: FAIL: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f still exists within 10m0s Full Stack Trace sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites.(*TestPersistentVolumeClaim).Cleanup(0xc000326060) /home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/testsuites.go:292 +0x1f4 sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites.(*DynamicallyProvisionedCollocatedPodTest).Run(0xc000987ef8?, {0x27d67e0?, 0xc000103ba0?}, 0x9?) /home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/dynamically_provisioned_collocated_pod_tester.go:58 +0x79 ... skipping 12 lines ... Jan 4 10:44:36.053: INFO: Waiting up to 5m0s for PersistentVolumeClaim azurefile-5466 to be removed Jan 4 10:44:36.115: INFO: Claim "azurefile-5466" in namespace "pvc-r9wbp" doesn't exist in the system Jan 4 10:44:36.115: INFO: deleting StorageClass azurefile-5466-file.csi.azure.com-dynamic-sc-rn2h4 [1mSTEP:[0m dump namespace information after failure [38;5;243m01/04/23 10:44:36.18[0m [1mSTEP:[0m Destroying namespace "azurefile-5466" for this suite. [38;5;243m01/04/23 10:44:36.18[0m [38;5;243m------------------------------[0m [38;5;9m• [FAILED] [630.772 seconds][0m Dynamic Provisioning [38;5;243m/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/dynamic_provisioning_test.go:43[0m [38;5;9m[1m[It] should create multiple PV objects, bind to PVCs and attach all to different pods on the same node [kubernetes.io/azure-file] [file.csi.azure.com] [Windows][0m [38;5;243m/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/dynamic_provisioning_test.go:187[0m [38;5;243mBegin Captured GinkgoWriter Output >>[0m ... skipping 166 lines ... Jan 4 10:44:00.201: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m32.281691767s) Jan 4 10:44:05.264: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m37.344077746s) Jan 4 10:44:10.328: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m42.40876283s) Jan 4 10:44:15.394: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m47.474075248s) Jan 4 10:44:20.456: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m52.536363024s) Jan 4 10:44:25.519: INFO: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f found and phase=Bound (9m57.599212283s) Jan 4 10:44:30.521: INFO: Unexpected error: <*errors.errorString | 0xc000d1a050>: { s: "PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f still exists within 10m0s", } Jan 4 10:44:30.521: FAIL: PersistentVolume pvc-b532760a-6b58-45e9-9df5-47aa6578019f still exists within 10m0s Full Stack Trace sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites.(*TestPersistentVolumeClaim).Cleanup(0xc000326060) /home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/testsuites.go:292 +0x1f4 sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites.(*DynamicallyProvisionedCollocatedPodTest).Run(0xc000987ef8?, {0x27d67e0?, 0xc000103ba0?}, 0x9?) /home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/dynamically_provisioned_collocated_pod_tester.go:58 +0x79 ... skipping 21 lines ... [1mThere were additional failures detected after the initial failure:[0m [38;5;13m[PANICKED][0m [38;5;13mTest Panicked[0m [38;5;13mIn [1m[DeferCleanup (Each)][0m[38;5;13m at: [1m/usr/local/go/src/runtime/panic.go:260[0m [38;5;13mruntime error: invalid memory address or nil pointer dereference[0m [38;5;13mFull Stack Trace[0m k8s.io/kubernetes/test/e2e/framework.(*Framework).dumpNamespaceInfo.func1() /home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:274 +0x5c k8s.io/kubernetes/test/e2e/framework.(*Framework).dumpNamespaceInfo(0xc0004a01e0) /home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:271 +0x179 ... skipping 33 lines ... Jan 4 10:44:55.872: INFO: PersistentVolumeClaim pvc-fp5xh found but phase is Pending instead of Bound. Jan 4 10:44:57.934: INFO: PersistentVolumeClaim pvc-fp5xh found and phase=Bound (20.686268273s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:44:57.934[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:44:57.996[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:44:58.058[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:44:58.058[0m [1mSTEP:[0m checking that the pods command exits with an error [38;5;243m01/04/23 10:44:58.123[0m Jan 4 10:44:58.123: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-pll4c" in namespace "azurefile-2790" to be "Error status code" Jan 4 10:44:58.185: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 61.511678ms Jan 4 10:45:00.248: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124597368s Jan 4 10:45:02.249: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 4.12544736s Jan 4 10:45:04.252: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 6.129326706s Jan 4 10:45:06.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 8.127504292s Jan 4 10:45:08.252: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Running", Reason="", readiness=true. Elapsed: 10.129236329s Jan 4 10:45:10.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Running", Reason="", readiness=true. Elapsed: 12.127484888s Jan 4 10:45:12.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Running", Reason="", readiness=true. Elapsed: 14.127831679s Jan 4 10:45:14.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Running", Reason="", readiness=false. Elapsed: 16.127914956s Jan 4 10:45:16.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Failed", Reason="", readiness=false. Elapsed: 18.127658281s [1mSTEP:[0m Saw pod failure [38;5;243m01/04/23 10:45:16.251[0m Jan 4 10:45:16.251: INFO: Pod "azurefile-volume-tester-pll4c" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m01/04/23 10:45:16.251[0m Jan 4 10:45:16.322: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-pll4c" Jan 4 10:45:16.386: INFO: Pod azurefile-volume-tester-pll4c 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 45 lines ... Jan 4 10:44:55.872: INFO: PersistentVolumeClaim pvc-fp5xh found but phase is Pending instead of Bound. Jan 4 10:44:57.934: INFO: PersistentVolumeClaim pvc-fp5xh found and phase=Bound (20.686268273s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:44:57.934[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:44:57.996[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:44:58.058[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:44:58.058[0m [1mSTEP:[0m checking that the pods command exits with an error [38;5;243m01/04/23 10:44:58.123[0m Jan 4 10:44:58.123: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-pll4c" in namespace "azurefile-2790" to be "Error status code" Jan 4 10:44:58.185: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 61.511678ms Jan 4 10:45:00.248: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124597368s Jan 4 10:45:02.249: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 4.12544736s Jan 4 10:45:04.252: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 6.129326706s Jan 4 10:45:06.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Pending", Reason="", readiness=false. Elapsed: 8.127504292s Jan 4 10:45:08.252: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Running", Reason="", readiness=true. Elapsed: 10.129236329s Jan 4 10:45:10.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Running", Reason="", readiness=true. Elapsed: 12.127484888s Jan 4 10:45:12.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Running", Reason="", readiness=true. Elapsed: 14.127831679s Jan 4 10:45:14.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Running", Reason="", readiness=false. Elapsed: 16.127914956s Jan 4 10:45:16.251: INFO: Pod "azurefile-volume-tester-pll4c": Phase="Failed", Reason="", readiness=false. Elapsed: 18.127658281s [1mSTEP:[0m Saw pod failure [38;5;243m01/04/23 10:45:16.251[0m Jan 4 10:45:16.251: INFO: Pod "azurefile-volume-tester-pll4c" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m01/04/23 10:45:16.251[0m Jan 4 10:45:16.322: INFO: deleting Pod "azurefile-2790"/"azurefile-volume-tester-pll4c" Jan 4 10:45:16.386: INFO: Pod azurefile-volume-tester-pll4c 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 320 lines ... Jan 4 10:46:20.161: INFO: PersistentVolumeClaim pvc-nqzgw found but phase is Pending instead of Bound. Jan 4 10:46:22.223: INFO: PersistentVolumeClaim pvc-nqzgw found and phase=Bound (2.123061031s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:46:22.223[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:46:22.284[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:46:22.346[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:46:22.346[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:46:22.411[0m Jan 4 10:46:22.411: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-qlrtv" in namespace "azurefile-4538" to be "Succeeded or Failed" Jan 4 10:46:22.473: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Pending", Reason="", readiness=false. Elapsed: 61.423848ms Jan 4 10:46:24.536: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124480187s Jan 4 10:46:26.540: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128612059s Jan 4 10:46:28.539: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.127674884s Jan 4 10:46:30.539: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Running", Reason="", readiness=true. Elapsed: 8.127694974s Jan 4 10:46:32.541: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Running", Reason="", readiness=true. Elapsed: 10.129682486s Jan 4 10:46:34.541: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Running", Reason="", readiness=false. Elapsed: 12.129336587s Jan 4 10:46:36.539: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127870761s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:46:36.539[0m Jan 4 10:46:36.539: INFO: Pod "azurefile-volume-tester-qlrtv" satisfied condition "Succeeded or Failed" [1mSTEP:[0m resizing the pvc [38;5;243m01/04/23 10:46:36.601[0m [1mSTEP:[0m sleep 30s waiting for resize complete [38;5;243m01/04/23 10:46:36.666[0m [1mSTEP:[0m checking the resizing result [38;5;243m01/04/23 10:47:06.686[0m [1mSTEP:[0m checking the resizing PV result [38;5;243m01/04/23 10:47:06.747[0m [1mSTEP:[0m checking the resizing azurefile result [38;5;243m01/04/23 10:47:06.809[0m Jan 4 10:47:07.543: INFO: deleting Pod "azurefile-4538"/"azurefile-volume-tester-qlrtv" ... skipping 33 lines ... Jan 4 10:46:20.161: INFO: PersistentVolumeClaim pvc-nqzgw found but phase is Pending instead of Bound. Jan 4 10:46:22.223: INFO: PersistentVolumeClaim pvc-nqzgw found and phase=Bound (2.123061031s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:46:22.223[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:46:22.284[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:46:22.346[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:46:22.346[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:46:22.411[0m Jan 4 10:46:22.411: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-qlrtv" in namespace "azurefile-4538" to be "Succeeded or Failed" Jan 4 10:46:22.473: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Pending", Reason="", readiness=false. Elapsed: 61.423848ms Jan 4 10:46:24.536: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124480187s Jan 4 10:46:26.540: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128612059s Jan 4 10:46:28.539: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.127674884s Jan 4 10:46:30.539: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Running", Reason="", readiness=true. Elapsed: 8.127694974s Jan 4 10:46:32.541: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Running", Reason="", readiness=true. Elapsed: 10.129682486s Jan 4 10:46:34.541: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Running", Reason="", readiness=false. Elapsed: 12.129336587s Jan 4 10:46:36.539: INFO: Pod "azurefile-volume-tester-qlrtv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127870761s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:46:36.539[0m Jan 4 10:46:36.539: INFO: Pod "azurefile-volume-tester-qlrtv" satisfied condition "Succeeded or Failed" [1mSTEP:[0m resizing the pvc [38;5;243m01/04/23 10:46:36.601[0m [1mSTEP:[0m sleep 30s waiting for resize complete [38;5;243m01/04/23 10:46:36.666[0m [1mSTEP:[0m checking the resizing result [38;5;243m01/04/23 10:47:06.686[0m [1mSTEP:[0m checking the resizing PV result [38;5;243m01/04/23 10:47:06.747[0m [1mSTEP:[0m checking the resizing azurefile result [38;5;243m01/04/23 10:47:06.809[0m Jan 4 10:47:07.543: INFO: deleting Pod "azurefile-4538"/"azurefile-volume-tester-qlrtv" ... skipping 361 lines ... Jan 4 10:47:33.465: INFO: PersistentVolumeClaim pvc-kfcb9 found but phase is Pending instead of Bound. Jan 4 10:47:35.529: INFO: PersistentVolumeClaim pvc-kfcb9 found and phase=Bound (2.125507704s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:47:35.529[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:47:35.591[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:47:35.653[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:47:35.653[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:47:35.719[0m Jan 4 10:47:35.719: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-xqq87" in namespace "azurefile-7726" to be "Succeeded or Failed" Jan 4 10:47:35.784: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 65.549716ms Jan 4 10:47:37.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 2.132198843s Jan 4 10:47:39.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 4.133064576s Jan 4 10:47:41.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 6.131842364s Jan 4 10:47:43.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 8.13180621s Jan 4 10:47:45.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 10.132623379s Jan 4 10:47:47.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Running", Reason="", readiness=true. Elapsed: 12.132016863s Jan 4 10:47:49.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Running", Reason="", readiness=true. Elapsed: 14.132783464s Jan 4 10:47:51.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Running", Reason="", readiness=true. Elapsed: 16.131852014s Jan 4 10:47:53.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Running", Reason="", readiness=false. Elapsed: 18.133254112s Jan 4 10:47:55.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.133340779s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:47:55.852[0m Jan 4 10:47:55.852: INFO: Pod "azurefile-volume-tester-xqq87" satisfied condition "Succeeded or Failed" Jan 4 10:47:55.852: INFO: deleting Pod "azurefile-7726"/"azurefile-volume-tester-xqq87" Jan 4 10:47:55.925: INFO: Pod azurefile-volume-tester-xqq87 has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-xqq87 in namespace azurefile-7726 [38;5;243m01/04/23 10:47:55.926[0m Jan 4 10:47:56.006: INFO: deleting PVC "azurefile-7726"/"pvc-kfcb9" Jan 4 10:47:56.006: INFO: Deleting PersistentVolumeClaim "pvc-kfcb9" ... skipping 123 lines ... Jan 4 10:47:33.465: INFO: PersistentVolumeClaim pvc-kfcb9 found but phase is Pending instead of Bound. Jan 4 10:47:35.529: INFO: PersistentVolumeClaim pvc-kfcb9 found and phase=Bound (2.125507704s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:47:35.529[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:47:35.591[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:47:35.653[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:47:35.653[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:47:35.719[0m Jan 4 10:47:35.719: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-xqq87" in namespace "azurefile-7726" to be "Succeeded or Failed" Jan 4 10:47:35.784: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 65.549716ms Jan 4 10:47:37.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 2.132198843s Jan 4 10:47:39.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 4.133064576s Jan 4 10:47:41.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 6.131842364s Jan 4 10:47:43.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 8.13180621s Jan 4 10:47:45.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Pending", Reason="", readiness=false. Elapsed: 10.132623379s Jan 4 10:47:47.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Running", Reason="", readiness=true. Elapsed: 12.132016863s Jan 4 10:47:49.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Running", Reason="", readiness=true. Elapsed: 14.132783464s Jan 4 10:47:51.851: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Running", Reason="", readiness=true. Elapsed: 16.131852014s Jan 4 10:47:53.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Running", Reason="", readiness=false. Elapsed: 18.133254112s Jan 4 10:47:55.852: INFO: Pod "azurefile-volume-tester-xqq87": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.133340779s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:47:55.852[0m Jan 4 10:47:55.852: INFO: Pod "azurefile-volume-tester-xqq87" satisfied condition "Succeeded or Failed" Jan 4 10:47:55.852: INFO: deleting Pod "azurefile-7726"/"azurefile-volume-tester-xqq87" Jan 4 10:47:55.925: INFO: Pod azurefile-volume-tester-xqq87 has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-xqq87 in namespace azurefile-7726 [38;5;243m01/04/23 10:47:55.926[0m Jan 4 10:47:56.006: INFO: deleting PVC "azurefile-7726"/"pvc-kfcb9" Jan 4 10:47:56.006: INFO: Deleting PersistentVolumeClaim "pvc-kfcb9" ... skipping 93 lines ... check the driver pods if restarts ... ====================================================================================== 2023/01/04 10:48:05 Check successfully Jan 4 10:48:05.192: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig 2023/01/04 10:48:05 run script: test/utils/get_storage_account_secret_name.sh 2023/01/04 10:48:05 got output: azure-storage-account-ffb5f4fe5568e4ad9a88810-secret , error: <nil> 2023/01/04 10:48:05 got storage account secret name: azure-storage-account-ffb5f4fe5568e4ad9a88810-secret [1mSTEP:[0m setting up the StorageClass [38;5;243m01/04/23 10:48:05.486[0m [1mSTEP:[0m creating a StorageClass [38;5;243m01/04/23 10:48:05.486[0m [1mSTEP:[0m setting up the PVC and PV [38;5;243m01/04/23 10:48:05.55[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:48:05.55[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:48:05.615[0m Jan 4 10:48:05.615: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-8lg2p] to have phase Bound Jan 4 10:48:05.677: INFO: PersistentVolumeClaim pvc-8lg2p found but phase is Pending instead of Bound. Jan 4 10:48:07.739: INFO: PersistentVolumeClaim pvc-8lg2p found and phase=Bound (2.123488451s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:48:07.739[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:48:07.8[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:48:07.862[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:48:07.862[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:48:07.928[0m Jan 4 10:48:07.928: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-kfsgt" in namespace "azurefile-1387" to be "Succeeded or Failed" Jan 4 10:48:07.989: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Pending", Reason="", readiness=false. Elapsed: 61.117838ms Jan 4 10:48:10.052: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124174314s Jan 4 10:48:12.057: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128962065s Jan 4 10:48:14.057: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.128408486s Jan 4 10:48:16.057: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Running", Reason="", readiness=true. Elapsed: 8.128626966s Jan 4 10:48:18.055: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Running", Reason="", readiness=true. Elapsed: 10.127013714s Jan 4 10:48:20.056: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Running", Reason="", readiness=true. Elapsed: 12.127397715s Jan 4 10:48:22.055: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Running", Reason="", readiness=false. Elapsed: 14.127267229s Jan 4 10:48:24.056: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.127533648s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:48:24.056[0m Jan 4 10:48:24.056: INFO: Pod "azurefile-volume-tester-kfsgt" satisfied condition "Succeeded or Failed" Jan 4 10:48:24.056: INFO: deleting Pod "azurefile-1387"/"azurefile-volume-tester-kfsgt" Jan 4 10:48:24.125: INFO: Pod azurefile-volume-tester-kfsgt has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-kfsgt in namespace azurefile-1387 [38;5;243m01/04/23 10:48:24.126[0m Jan 4 10:48:24.200: INFO: deleting PVC "azurefile-1387"/"pvc-8lg2p" Jan 4 10:48:24.200: INFO: Deleting PersistentVolumeClaim "pvc-8lg2p" ... skipping 28 lines ... Jan 4 10:48:05.677: INFO: PersistentVolumeClaim pvc-8lg2p found but phase is Pending instead of Bound. Jan 4 10:48:07.739: INFO: PersistentVolumeClaim pvc-8lg2p found and phase=Bound (2.123488451s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:48:07.739[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:48:07.8[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:48:07.862[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:48:07.862[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:48:07.928[0m Jan 4 10:48:07.928: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-kfsgt" in namespace "azurefile-1387" to be "Succeeded or Failed" Jan 4 10:48:07.989: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Pending", Reason="", readiness=false. Elapsed: 61.117838ms Jan 4 10:48:10.052: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124174314s Jan 4 10:48:12.057: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128962065s Jan 4 10:48:14.057: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.128408486s Jan 4 10:48:16.057: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Running", Reason="", readiness=true. Elapsed: 8.128626966s Jan 4 10:48:18.055: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Running", Reason="", readiness=true. Elapsed: 10.127013714s Jan 4 10:48:20.056: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Running", Reason="", readiness=true. Elapsed: 12.127397715s Jan 4 10:48:22.055: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Running", Reason="", readiness=false. Elapsed: 14.127267229s Jan 4 10:48:24.056: INFO: Pod "azurefile-volume-tester-kfsgt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.127533648s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:48:24.056[0m Jan 4 10:48:24.056: INFO: Pod "azurefile-volume-tester-kfsgt" satisfied condition "Succeeded or Failed" Jan 4 10:48:24.056: INFO: deleting Pod "azurefile-1387"/"azurefile-volume-tester-kfsgt" Jan 4 10:48:24.125: INFO: Pod azurefile-volume-tester-kfsgt has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-kfsgt in namespace azurefile-1387 [38;5;243m01/04/23 10:48:24.126[0m Jan 4 10:48:24.200: INFO: deleting PVC "azurefile-1387"/"pvc-8lg2p" Jan 4 10:48:24.200: INFO: Deleting PersistentVolumeClaim "pvc-8lg2p" ... skipping 38 lines ... Jan 4 10:48:49.309: INFO: PersistentVolumeClaim pvc-78lm6 found but phase is Pending instead of Bound. Jan 4 10:48:51.375: INFO: PersistentVolumeClaim pvc-78lm6 found and phase=Bound (20.690651861s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:48:51.375[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:48:51.437[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:48:51.499[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:48:51.499[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:48:51.564[0m Jan 4 10:48:51.565: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-7z5tq" in namespace "azurefile-4547" to be "Succeeded or Failed" Jan 4 10:48:51.626: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Pending", Reason="", readiness=false. Elapsed: 61.48633ms Jan 4 10:48:53.689: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124123139s Jan 4 10:48:55.693: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.127912521s Jan 4 10:48:57.693: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.128491951s Jan 4 10:48:59.692: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Running", Reason="", readiness=true. Elapsed: 8.127329506s Jan 4 10:49:01.692: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Running", Reason="", readiness=true. Elapsed: 10.127574947s Jan 4 10:49:03.695: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Running", Reason="", readiness=false. Elapsed: 12.129937841s Jan 4 10:49:05.692: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127319545s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:49:05.692[0m Jan 4 10:49:05.692: INFO: Pod "azurefile-volume-tester-7z5tq" satisfied condition "Succeeded or Failed" Jan 4 10:49:05.692: INFO: deleting Pod "azurefile-4547"/"azurefile-volume-tester-7z5tq" Jan 4 10:49:05.761: INFO: Pod azurefile-volume-tester-7z5tq has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-7z5tq in namespace azurefile-4547 [38;5;243m01/04/23 10:49:05.761[0m Jan 4 10:49:05.840: INFO: deleting PVC "azurefile-4547"/"pvc-78lm6" Jan 4 10:49:05.841: INFO: Deleting PersistentVolumeClaim "pvc-78lm6" ... skipping 36 lines ... Jan 4 10:48:49.309: INFO: PersistentVolumeClaim pvc-78lm6 found but phase is Pending instead of Bound. Jan 4 10:48:51.375: INFO: PersistentVolumeClaim pvc-78lm6 found and phase=Bound (20.690651861s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:48:51.375[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:48:51.437[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:48:51.499[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:48:51.499[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:48:51.564[0m Jan 4 10:48:51.565: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-7z5tq" in namespace "azurefile-4547" to be "Succeeded or Failed" Jan 4 10:48:51.626: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Pending", Reason="", readiness=false. Elapsed: 61.48633ms Jan 4 10:48:53.689: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124123139s Jan 4 10:48:55.693: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.127912521s Jan 4 10:48:57.693: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.128491951s Jan 4 10:48:59.692: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Running", Reason="", readiness=true. Elapsed: 8.127329506s Jan 4 10:49:01.692: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Running", Reason="", readiness=true. Elapsed: 10.127574947s Jan 4 10:49:03.695: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Running", Reason="", readiness=false. Elapsed: 12.129937841s Jan 4 10:49:05.692: INFO: Pod "azurefile-volume-tester-7z5tq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127319545s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:49:05.692[0m Jan 4 10:49:05.692: INFO: Pod "azurefile-volume-tester-7z5tq" satisfied condition "Succeeded or Failed" Jan 4 10:49:05.692: INFO: deleting Pod "azurefile-4547"/"azurefile-volume-tester-7z5tq" Jan 4 10:49:05.761: INFO: Pod azurefile-volume-tester-7z5tq has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-7z5tq in namespace azurefile-4547 [38;5;243m01/04/23 10:49:05.761[0m Jan 4 10:49:05.840: INFO: deleting PVC "azurefile-4547"/"pvc-78lm6" Jan 4 10:49:05.841: INFO: Deleting PersistentVolumeClaim "pvc-78lm6" ... skipping 37 lines ... Jan 4 10:49:25.908: INFO: PersistentVolumeClaim pvc-wbmjr found but phase is Pending instead of Bound. Jan 4 10:49:27.971: INFO: PersistentVolumeClaim pvc-wbmjr found and phase=Bound (20.689749461s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:49:27.971[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:49:28.032[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:49:28.094[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:49:28.094[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:49:28.161[0m Jan 4 10:49:28.161: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-trcts" in namespace "azurefile-7051" to be "Succeeded or Failed" Jan 4 10:49:28.223: INFO: Pod "azurefile-volume-tester-trcts": Phase="Pending", Reason="", readiness=false. Elapsed: 61.366525ms Jan 4 10:49:30.286: INFO: Pod "azurefile-volume-tester-trcts": Phase="Pending", Reason="", readiness=false. Elapsed: 2.125215651s Jan 4 10:49:32.289: INFO: Pod "azurefile-volume-tester-trcts": Phase="Pending", Reason="", readiness=false. Elapsed: 4.127601695s Jan 4 10:49:34.289: INFO: Pod "azurefile-volume-tester-trcts": Phase="Pending", Reason="", readiness=false. Elapsed: 6.127927899s Jan 4 10:49:36.290: INFO: Pod "azurefile-volume-tester-trcts": Phase="Running", Reason="", readiness=true. Elapsed: 8.129217862s Jan 4 10:49:38.289: INFO: Pod "azurefile-volume-tester-trcts": Phase="Running", Reason="", readiness=true. Elapsed: 10.127863798s Jan 4 10:49:40.289: INFO: Pod "azurefile-volume-tester-trcts": Phase="Running", Reason="", readiness=false. Elapsed: 12.127747711s Jan 4 10:49:42.290: INFO: Pod "azurefile-volume-tester-trcts": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.128469336s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:49:42.29[0m Jan 4 10:49:42.290: INFO: Pod "azurefile-volume-tester-trcts" satisfied condition "Succeeded or Failed" Jan 4 10:49:42.290: INFO: deleting Pod "azurefile-7051"/"azurefile-volume-tester-trcts" Jan 4 10:49:42.363: INFO: Pod azurefile-volume-tester-trcts has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-trcts in namespace azurefile-7051 [38;5;243m01/04/23 10:49:42.363[0m Jan 4 10:49:42.446: INFO: deleting PVC "azurefile-7051"/"pvc-wbmjr" Jan 4 10:49:42.446: INFO: Deleting PersistentVolumeClaim "pvc-wbmjr" ... skipping 36 lines ... Jan 4 10:49:25.908: INFO: PersistentVolumeClaim pvc-wbmjr found but phase is Pending instead of Bound. Jan 4 10:49:27.971: INFO: PersistentVolumeClaim pvc-wbmjr found and phase=Bound (20.689749461s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:49:27.971[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:49:28.032[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:49:28.094[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:49:28.094[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:49:28.161[0m Jan 4 10:49:28.161: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-trcts" in namespace "azurefile-7051" to be "Succeeded or Failed" Jan 4 10:49:28.223: INFO: Pod "azurefile-volume-tester-trcts": Phase="Pending", Reason="", readiness=false. Elapsed: 61.366525ms Jan 4 10:49:30.286: INFO: Pod "azurefile-volume-tester-trcts": Phase="Pending", Reason="", readiness=false. Elapsed: 2.125215651s Jan 4 10:49:32.289: INFO: Pod "azurefile-volume-tester-trcts": Phase="Pending", Reason="", readiness=false. Elapsed: 4.127601695s Jan 4 10:49:34.289: INFO: Pod "azurefile-volume-tester-trcts": Phase="Pending", Reason="", readiness=false. Elapsed: 6.127927899s Jan 4 10:49:36.290: INFO: Pod "azurefile-volume-tester-trcts": Phase="Running", Reason="", readiness=true. Elapsed: 8.129217862s Jan 4 10:49:38.289: INFO: Pod "azurefile-volume-tester-trcts": Phase="Running", Reason="", readiness=true. Elapsed: 10.127863798s Jan 4 10:49:40.289: INFO: Pod "azurefile-volume-tester-trcts": Phase="Running", Reason="", readiness=false. Elapsed: 12.127747711s Jan 4 10:49:42.290: INFO: Pod "azurefile-volume-tester-trcts": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.128469336s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:49:42.29[0m Jan 4 10:49:42.290: INFO: Pod "azurefile-volume-tester-trcts" satisfied condition "Succeeded or Failed" Jan 4 10:49:42.290: INFO: deleting Pod "azurefile-7051"/"azurefile-volume-tester-trcts" Jan 4 10:49:42.363: INFO: Pod azurefile-volume-tester-trcts has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-trcts in namespace azurefile-7051 [38;5;243m01/04/23 10:49:42.363[0m Jan 4 10:49:42.446: INFO: deleting PVC "azurefile-7051"/"pvc-wbmjr" Jan 4 10:49:42.446: INFO: Deleting PersistentVolumeClaim "pvc-wbmjr" ... skipping 31 lines ... I0104 10:49:52.002555 38597 testsuites.go:627] 0/1 replicas in the StatefulSet are ready I0104 10:49:54.002008 38597 testsuites.go:627] 1/1 replicas in the StatefulSet are ready [1mSTEP:[0m checking that the pod is running [38;5;243m01/04/23 10:49:54.067[0m [1mSTEP:[0m check pod exec [38;5;243m01/04/23 10:49:54.133[0m Jan 4 10:49:54.133: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-9183 exec azurefile-volume-tester-pptrr-0 -- cmd /c type C:\mnt\test-1\data.txt' Jan 4 10:49:54.874: INFO: rc: 1 Jan 4 10:49:54.874: INFO: Error waiting for output "hello world\r\n" in pod "azurefile-volume-tester-pptrr-0": error running /usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-9183 exec azurefile-volume-tester-pptrr-0 -- cmd /c type C:\mnt\test-1\data.txt: Command stdout: stderr: The system cannot find the file specified. command terminated with exit code 1 error: exit status 1. Jan 4 10:49:56.875: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-9183 exec azurefile-volume-tester-pptrr-0 -- cmd /c type C:\mnt\test-1\data.txt' Jan 4 10:49:57.647: INFO: stderr: "" Jan 4 10:49:57.647: INFO: stdout: "hello world\r\n" [1mSTEP:[0m deleting the pod for statefulset [38;5;243m01/04/23 10:49:57.648[0m Jan 4 10:49:57.648: INFO: Deleting pod "azurefile-volume-tester-pptrr-0" in namespace "azurefile-9183" ... skipping 32 lines ... I0104 10:49:52.002555 38597 testsuites.go:627] 0/1 replicas in the StatefulSet are ready I0104 10:49:54.002008 38597 testsuites.go:627] 1/1 replicas in the StatefulSet are ready [1mSTEP:[0m checking that the pod is running [38;5;243m01/04/23 10:49:54.067[0m [1mSTEP:[0m check pod exec [38;5;243m01/04/23 10:49:54.133[0m Jan 4 10:49:54.133: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-9183 exec azurefile-volume-tester-pptrr-0 -- cmd /c type C:\mnt\test-1\data.txt' Jan 4 10:49:54.874: INFO: rc: 1 Jan 4 10:49:54.874: INFO: Error waiting for output "hello world\r\n" in pod "azurefile-volume-tester-pptrr-0": error running /usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-9183 exec azurefile-volume-tester-pptrr-0 -- cmd /c type C:\mnt\test-1\data.txt: Command stdout: stderr: The system cannot find the file specified. command terminated with exit code 1 error: exit status 1. Jan 4 10:49:56.875: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-9183 exec azurefile-volume-tester-pptrr-0 -- cmd /c type C:\mnt\test-1\data.txt' Jan 4 10:49:57.647: INFO: stderr: "" Jan 4 10:49:57.647: INFO: stdout: "hello world\r\n" [1mSTEP:[0m deleting the pod for statefulset [38;5;243m01/04/23 10:49:57.648[0m Jan 4 10:49:57.648: INFO: Deleting pod "azurefile-volume-tester-pptrr-0" in namespace "azurefile-9183" ... skipping 39 lines ... Jan 4 10:51:06.277: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), LastTransitionTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), LastTransitionTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azurefile-volume-tester-jjmd9-c64cf999b\" is progressing."}}, CollisionCount:(*int32)(nil)} Jan 4 10:51:08.278: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), LastTransitionTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), LastTransitionTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azurefile-volume-tester-jjmd9-c64cf999b\" is progressing."}}, CollisionCount:(*int32)(nil)} [1mSTEP:[0m checking that the pod is running [38;5;243m01/04/23 10:51:10.406[0m [1mSTEP:[0m check pod exec [38;5;243m01/04/23 10:51:11.534[0m Jan 4 10:51:11.534: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-8154 exec azurefile-volume-tester-jjmd9-c64cf999b-zlj8q -- cmd /c type C:\mnt\test-1\data.txt' Jan 4 10:51:12.280: INFO: rc: 1 Jan 4 10:51:12.280: INFO: Error waiting for output "hello world\r\n" in pod "azurefile-volume-tester-jjmd9-c64cf999b-zlj8q": error running /usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-8154 exec azurefile-volume-tester-jjmd9-c64cf999b-zlj8q -- cmd /c type C:\mnt\test-1\data.txt: Command stdout: stderr: The system cannot find the file specified. command terminated with exit code 1 error: exit status 1. Jan 4 10:51:14.282: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-8154 exec azurefile-volume-tester-jjmd9-c64cf999b-zlj8q -- cmd /c type C:\mnt\test-1\data.txt' Jan 4 10:51:15.018: INFO: stderr: "" Jan 4 10:51:15.018: INFO: stdout: "hello world\r\n" [1mSTEP:[0m delete volume capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-981bf7a4-eb61-40a0-b694-5861509cd923###azurefile-8154 first, make sure pod could still be terminated [38;5;243m01/04/23 10:51:15.018[0m [1mSTEP:[0m check whether capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-981bf7a4-eb61-40a0-b694-5861509cd923###azurefile-8154 exists [38;5;243m01/04/23 10:51:16.208[0m [1mSTEP:[0m ValidateVolumeCapabilities capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-981bf7a4-eb61-40a0-b694-5861509cd923###azurefile-8154 returned with error: rpc error: code = NotFound desc = the requested volume(capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-981bf7a4-eb61-40a0-b694-5861509cd923###azurefile-8154) does not exist. [38;5;243m01/04/23 10:51:16.751[0m [1mSTEP:[0m deleting the pod for deployment [38;5;243m01/04/23 10:51:16.751[0m Jan 4 10:51:16.751: INFO: Deleting pod "azurefile-volume-tester-jjmd9-c64cf999b-zlj8q" in namespace "azurefile-8154" Jan 4 10:51:16.821: INFO: Waiting for pod "azurefile-volume-tester-jjmd9-c64cf999b-zlj8q" in namespace "azurefile-8154" to be fully deleted Jan 4 10:51:18.953: INFO: deleting Deployment "azurefile-8154"/"azurefile-volume-tester-jjmd9" Jan 4 10:51:19.014: INFO: Error getting logs for pod azurefile-volume-tester-jjmd9-c64cf999b-zlj8q: the server could not find the requested resource (get pods azurefile-volume-tester-jjmd9-c64cf999b-zlj8q) Jan 4 10:51:19.078: INFO: deleting PVC "azurefile-8154"/"pvc-9twjb" Jan 4 10:51:19.078: INFO: Deleting PersistentVolumeClaim "pvc-9twjb" [1mSTEP:[0m waiting for claim's PV "pvc-981bf7a4-eb61-40a0-b694-5861509cd923" to be deleted [38;5;243m01/04/23 10:51:19.27[0m Jan 4 10:51:19.271: INFO: Waiting up to 10m0s for PersistentVolume pvc-981bf7a4-eb61-40a0-b694-5861509cd923 to get deleted Jan 4 10:51:19.332: INFO: PersistentVolume pvc-981bf7a4-eb61-40a0-b694-5861509cd923 found and phase=Bound (61.659716ms) Jan 4 10:51:24.395: INFO: PersistentVolume pvc-981bf7a4-eb61-40a0-b694-5861509cd923 found and phase=Bound (5.124164124s) ... skipping 34 lines ... Jan 4 10:51:06.277: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), LastTransitionTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), LastTransitionTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azurefile-volume-tester-jjmd9-c64cf999b\" is progressing."}}, CollisionCount:(*int32)(nil)} Jan 4 10:51:08.278: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), LastTransitionTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), LastTransitionTime:time.Date(2023, time.January, 4, 10, 51, 2, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azurefile-volume-tester-jjmd9-c64cf999b\" is progressing."}}, CollisionCount:(*int32)(nil)} [1mSTEP:[0m checking that the pod is running [38;5;243m01/04/23 10:51:10.406[0m [1mSTEP:[0m check pod exec [38;5;243m01/04/23 10:51:11.534[0m Jan 4 10:51:11.534: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-8154 exec azurefile-volume-tester-jjmd9-c64cf999b-zlj8q -- cmd /c type C:\mnt\test-1\data.txt' Jan 4 10:51:12.280: INFO: rc: 1 Jan 4 10:51:12.280: INFO: Error waiting for output "hello world\r\n" in pod "azurefile-volume-tester-jjmd9-c64cf999b-zlj8q": error running /usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-8154 exec azurefile-volume-tester-jjmd9-c64cf999b-zlj8q -- cmd /c type C:\mnt\test-1\data.txt: Command stdout: stderr: The system cannot find the file specified. command terminated with exit code 1 error: exit status 1. Jan 4 10:51:14.282: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azurefile-8154 exec azurefile-volume-tester-jjmd9-c64cf999b-zlj8q -- cmd /c type C:\mnt\test-1\data.txt' Jan 4 10:51:15.018: INFO: stderr: "" Jan 4 10:51:15.018: INFO: stdout: "hello world\r\n" [1mSTEP:[0m delete volume capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-981bf7a4-eb61-40a0-b694-5861509cd923###azurefile-8154 first, make sure pod could still be terminated [38;5;243m01/04/23 10:51:15.018[0m [1mSTEP:[0m check whether capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-981bf7a4-eb61-40a0-b694-5861509cd923###azurefile-8154 exists [38;5;243m01/04/23 10:51:16.208[0m [1mSTEP:[0m ValidateVolumeCapabilities capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-981bf7a4-eb61-40a0-b694-5861509cd923###azurefile-8154 returned with error: rpc error: code = NotFound desc = the requested volume(capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-981bf7a4-eb61-40a0-b694-5861509cd923###azurefile-8154) does not exist. [38;5;243m01/04/23 10:51:16.751[0m [1mSTEP:[0m deleting the pod for deployment [38;5;243m01/04/23 10:51:16.751[0m Jan 4 10:51:16.751: INFO: Deleting pod "azurefile-volume-tester-jjmd9-c64cf999b-zlj8q" in namespace "azurefile-8154" Jan 4 10:51:16.821: INFO: Waiting for pod "azurefile-volume-tester-jjmd9-c64cf999b-zlj8q" in namespace "azurefile-8154" to be fully deleted Jan 4 10:51:18.953: INFO: deleting Deployment "azurefile-8154"/"azurefile-volume-tester-jjmd9" Jan 4 10:51:19.014: INFO: Error getting logs for pod azurefile-volume-tester-jjmd9-c64cf999b-zlj8q: the server could not find the requested resource (get pods azurefile-volume-tester-jjmd9-c64cf999b-zlj8q) Jan 4 10:51:19.078: INFO: deleting PVC "azurefile-8154"/"pvc-9twjb" Jan 4 10:51:19.078: INFO: Deleting PersistentVolumeClaim "pvc-9twjb" [1mSTEP:[0m waiting for claim's PV "pvc-981bf7a4-eb61-40a0-b694-5861509cd923" to be deleted [38;5;243m01/04/23 10:51:19.27[0m Jan 4 10:51:19.271: INFO: Waiting up to 10m0s for PersistentVolume pvc-981bf7a4-eb61-40a0-b694-5861509cd923 to get deleted Jan 4 10:51:19.332: INFO: PersistentVolume pvc-981bf7a4-eb61-40a0-b694-5861509cd923 found and phase=Bound (61.659716ms) Jan 4 10:51:24.395: INFO: PersistentVolume pvc-981bf7a4-eb61-40a0-b694-5861509cd923 found and phase=Bound (5.124164124s) ... skipping 50 lines ... check the driver pods if restarts ... ====================================================================================== 2023/01/04 10:51:31 Check successfully Jan 4 10:51:31.448: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig 2023/01/04 10:51:31 run script: test/utils/get_storage_account_secret_name.sh 2023/01/04 10:51:31 got output: azure-storage-account-ffb5f4fe5568e4ad9a88810-secret , error: <nil> 2023/01/04 10:51:31 got storage account secret name: azure-storage-account-ffb5f4fe5568e4ad9a88810-secret [1mSTEP:[0m Successfully provisioned AzureFile volume: "capz-fkqvhq#ffb5f4fe5568e4ad9a88810#csi-inline-smb-volume##csi-inline-smb-volume#azurefile-9371" [38;5;243m01/04/23 10:51:32.85[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:51:32.85[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:51:32.917[0m Jan 4 10:51:32.917: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-8c7rn" in namespace "azurefile-9371" to be "Succeeded or Failed" Jan 4 10:51:32.978: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Pending", Reason="", readiness=false. Elapsed: 61.492317ms Jan 4 10:51:35.040: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.1236215s Jan 4 10:51:37.045: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.127977797s Jan 4 10:51:39.044: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.127687849s Jan 4 10:51:41.045: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Running", Reason="", readiness=true. Elapsed: 8.127897177s Jan 4 10:51:43.044: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Running", Reason="", readiness=true. Elapsed: 10.127679336s Jan 4 10:51:45.044: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Running", Reason="", readiness=true. Elapsed: 12.127665479s Jan 4 10:51:47.045: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Running", Reason="", readiness=false. Elapsed: 14.128302271s Jan 4 10:51:49.046: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.129142038s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:51:49.046[0m Jan 4 10:51:49.046: INFO: Pod "azurefile-volume-tester-8c7rn" satisfied condition "Succeeded or Failed" Jan 4 10:51:49.046: INFO: deleting Pod "azurefile-9371"/"azurefile-volume-tester-8c7rn" Jan 4 10:51:49.115: INFO: Pod azurefile-volume-tester-8c7rn has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-8c7rn in namespace azurefile-9371 [38;5;243m01/04/23 10:51:49.115[0m [1mSTEP:[0m Destroying namespace "azurefile-9371" for this suite. [38;5;243m01/04/23 10:51:49.191[0m [38;5;243m------------------------------[0m ... skipping 10 lines ... [1mSTEP:[0m Waiting for a default service account to be provisioned in namespace [38;5;243m01/04/23 10:51:30.768[0m [1mSTEP:[0m Waiting for kube-root-ca.crt to be provisioned in namespace [38;5;243m01/04/23 10:51:30.89[0m Jan 4 10:51:31.448: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig [1mSTEP:[0m Successfully provisioned AzureFile volume: "capz-fkqvhq#ffb5f4fe5568e4ad9a88810#csi-inline-smb-volume##csi-inline-smb-volume#azurefile-9371" [38;5;243m01/04/23 10:51:32.85[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:51:32.85[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:51:32.917[0m Jan 4 10:51:32.917: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-8c7rn" in namespace "azurefile-9371" to be "Succeeded or Failed" Jan 4 10:51:32.978: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Pending", Reason="", readiness=false. Elapsed: 61.492317ms Jan 4 10:51:35.040: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.1236215s Jan 4 10:51:37.045: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.127977797s Jan 4 10:51:39.044: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.127687849s Jan 4 10:51:41.045: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Running", Reason="", readiness=true. Elapsed: 8.127897177s Jan 4 10:51:43.044: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Running", Reason="", readiness=true. Elapsed: 10.127679336s Jan 4 10:51:45.044: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Running", Reason="", readiness=true. Elapsed: 12.127665479s Jan 4 10:51:47.045: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Running", Reason="", readiness=false. Elapsed: 14.128302271s Jan 4 10:51:49.046: INFO: Pod "azurefile-volume-tester-8c7rn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.129142038s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:51:49.046[0m Jan 4 10:51:49.046: INFO: Pod "azurefile-volume-tester-8c7rn" satisfied condition "Succeeded or Failed" Jan 4 10:51:49.046: INFO: deleting Pod "azurefile-9371"/"azurefile-volume-tester-8c7rn" Jan 4 10:51:49.115: INFO: Pod azurefile-volume-tester-8c7rn has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-8c7rn in namespace azurefile-9371 [38;5;243m01/04/23 10:51:49.115[0m [1mSTEP:[0m Destroying namespace "azurefile-9371" for this suite. [38;5;243m01/04/23 10:51:49.191[0m [38;5;243m<< End Captured GinkgoWriter Output[0m ... skipping 235 lines ... Streaming logs below: I0104 10:24:29.478292 1 azurefile.go:299] driver userAgent: file.csi.azure.com/e2e-a43df1bddbd87e646edd537bc97b8fccfb98fc15 e2e-test I0104 10:24:29.478413 1 azure.go:65] set QPS(25.000000) and QPS Burst(50) for driver kubeClient I0104 10:24:29.478793 1 azure.go:80] reading cloud config from secret kube-system/azure-cloud-provider I0104 10:24:29.486298 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 7 milliseconds I0104 10:24:29.486507 1 azure.go:87] 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 I0104 10:24:29.486516 1 azure.go:92] could not read cloud config from secret kube-system/azure-cloud-provider I0104 10:24:29.486521 1 azure.go:102] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0104 10:24:29.486541 1 azure.go:110] read cloud config from file: /etc/kubernetes/azure.json successfully I0104 10:24:29.487079 1 azure_auth.go:245] Using AzurePublicCloud environment I0104 10:24:29.487108 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0104 10:24:29.487161 1 azure_diskclient.go:68] Azure DisksClient using API version: 2022-03-02 I0104 10:24:29.487204 1 azure_blobclient.go:67] Azure BlobClient using API version: 2021-09-01 I0104 10:24:29.487262 1 azure.go:1008] attach/detach disk operation rate limit QPS: 6.000000, Bucket: 10 I0104 10:24:29.487272 1 azure.go:140] disable UseInstanceMetadata for controller server I0104 10:24:29.487279 1 azure.go:143] starting controller server... I0104 10:24:29.487288 1 azurefile.go:304] cloud: AzurePublicCloud, location: westus3, rg: capz-fkqvhq, VnetName: capz-fkqvhq-vnet, VnetResourceGroup: capz-fkqvhq, SubnetName: node-subnet I0104 10:24:29.490706 1 mount_linux.go:287] 'umount /tmp/kubelet-detect-safe-umount2550662608' failed with: exit status 32, output: umount: /tmp/kubelet-detect-safe-umount2550662608: must be superuser to unmount. I0104 10:24:29.490733 1 mount_linux.go:289] Detected umount with unsafe 'not mounted' behavior I0104 10:24:29.490799 1 driver.go:93] Enabling controller service capability: CREATE_DELETE_VOLUME I0104 10:24:29.490810 1 driver.go:93] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME I0104 10:24:29.490816 1 driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT I0104 10:24:29.490823 1 driver.go:93] Enabling controller service capability: EXPAND_VOLUME I0104 10:24:29.490832 1 driver.go:93] Enabling controller service capability: SINGLE_NODE_MULTI_WRITER ... skipping 447 lines ... Strict-Transport-Security: max-age=31536000; includeSubDomains Content-Length: 250 Pragma: no-cache Content-Type: application/json; charset=utf-8 Expires: -1 I0104 10:25:24.798865 1 util.go:124] Send.sendRequest got response with ContentLength 250, StatusCode 404 and responseBody length 250 I0104 10:25:24.798918 1 azure_privatednsclient.go:215] Received error in privatednszone.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net' under resource group 'capz-fkqvhq' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}} I0104 10:25:24.799176 1 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.014118036 request="private_dns_zones_get" resource_group="capz-fkqvhq" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="" error_code="ResourceNotFound" I0104 10:25:24.799197 1 azure_storageaccount.go:234] get private dns zone privatelink.file.core.windows.net returned with Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net' under resource group 'capz-fkqvhq' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}} I0104 10:25:24.799205 1 azure_storageaccount.go:452] Creating private dns zone(privatelink.file.core.windows.net) in resourceGroup (capz-fkqvhq) (2023-01-04T10:25:24.7992716Z) INFO: REQUEST: PUT https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net?api-version=2018-09-01 Content-Type: application/json; charset=utf-8 User-Agent: Go/go1.19.4 (amd64-linux) go-autorest/v14.2.1 file.csi.azure.com/e2e-a43df1bddbd87e646edd537bc97b8fccfb98fc15 e2e-test Authorization: **REDACTED** (2023-01-04T10:25:24.7993278Z) INFO: REQUEST: PUT https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net?api-version=2018-09-01 ... skipping 140 lines ... X-Content-Type-Options: nosniff Date: Wed, 04 Jan 2023 10:25:55 GMT Content-Length: 296 Pragma: no-cache Expires: -1 I0104 10:25:56.175776 1 util.go:124] Send.sendRequest got response with ContentLength 296, StatusCode 404 and responseBody length 296 I0104 10:25:56.175794 1 azure_virtualnetworklinksclient.go:212] Received error in virtualnetworklink.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink' under resource group 'capz-fkqvhq' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}} I0104 10:25:56.175951 1 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.028760771 request="virtual_network_links_get" resource_group="capz-fkqvhq" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="" error_code="ResourceNotFound" I0104 10:25:56.175974 1 azure_storageaccount.go:244] get virtual link for vnet(capz-fkqvhq-vnet) and DNS Zone(privatelink.file.core.windows.net) returned with Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink' under resource group 'capz-fkqvhq' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}} I0104 10:25:56.175983 1 azure_storageaccount.go:466] Creating virtual link for vnet(capz-fkqvhq-vnet-vnetlink) and DNS Zone(privatelink.file.core.windows.net) in resourceGroup(capz-fkqvhq) (2023-01-04T10:25:56.1761262Z) INFO: REQUEST: PUT https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink?api-version=2020-06-01 Content-Type: application/json; charset=utf-8 User-Agent: Go/go1.19.4 (amd64-linux) go-autorest/v14.2.1 file.csi.azure.com/e2e-a43df1bddbd87e646edd537bc97b8fccfb98fc15 e2e-test Authorization: **REDACTED** (2023-01-04T10:25:56.1761693Z) INFO: REQUEST: PUT https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink?api-version=2020-06-01 ... skipping 3639 lines ... Streaming logs below: I0104 10:24:51.546914 1484 azurefile.go:299] driver userAgent: file.csi.azure.com/e2e-a43df1bddbd87e646edd537bc97b8fccfb98fc15 e2e-test I0104 10:24:51.558274 1484 azure.go:65] set QPS(25.000000) and QPS Burst(50) for driver kubeClient I0104 10:24:51.567815 1484 azure.go:80] reading cloud config from secret kube-system/azure-cloud-provider I0104 10:24:51.685515 1484 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 107 milliseconds I0104 10:24:51.687367 1484 azure.go:87] 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 I0104 10:24:51.687367 1484 azure.go:92] could not read cloud config from secret kube-system/azure-cloud-provider I0104 10:24:51.687367 1484 azure.go:102] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json I0104 10:24:51.687367 1484 azure.go:110] read cloud config from file: C:\k\azure.json successfully I0104 10:24:51.691519 1484 azure_auth.go:245] Using AzurePublicCloud environment I0104 10:24:51.692373 1484 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0104 10:24:51.695227 1484 azure_diskclient.go:68] Azure DisksClient using API version: 2022-03-02 ... skipping 202 lines ... Streaming logs below: I0104 10:24:51.049670 5484 azurefile.go:299] driver userAgent: file.csi.azure.com/e2e-a43df1bddbd87e646edd537bc97b8fccfb98fc15 e2e-test I0104 10:24:51.058176 5484 azure.go:65] set QPS(25.000000) and QPS Burst(50) for driver kubeClient I0104 10:24:51.063670 5484 azure.go:80] reading cloud config from secret kube-system/azure-cloud-provider I0104 10:24:51.088174 5484 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider 404 Not Found in 22 milliseconds I0104 10:24:51.088670 5484 azure.go:87] 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 I0104 10:24:51.089174 5484 azure.go:92] could not read cloud config from secret kube-system/azure-cloud-provider I0104 10:24:51.089174 5484 azure.go:102] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json I0104 10:24:51.089174 5484 azure.go:110] read cloud config from file: C:\k\azure.json successfully I0104 10:24:51.090676 5484 azure_auth.go:245] Using AzurePublicCloud environment I0104 10:24:51.090676 5484 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0104 10:24:51.092170 5484 azure_diskclient.go:68] Azure DisksClient using API version: 2022-03-02 ... skipping 330 lines ... I0104 10:34:22.275403 5484 utils.go:77] GRPC request: {} I0104 10:34:22.275403 5484 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]} I0104 10:34:22.276385 5484 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0104 10:34:22.276385 5484 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\\globalmount","target_path":"c:\\var\\lib\\kubelet\\pods\\f2404562-5718-41f1-8bc6-95eb46ce477e\\volumes\\kubernetes.io~csi\\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\\mount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"accessTier":"TransactionOptimized","allowBlobPublicAccess":"false","csi.storage.k8s.io/ephemeral":"false","csi.storage.k8s.io/pod.name":"azurefile-volume-tester-qfcjj","csi.storage.k8s.io/pod.namespace":"azurefile-5466","csi.storage.k8s.io/pod.uid":"f2404562-5718-41f1-8bc6-95eb46ce477e","csi.storage.k8s.io/pv/name":"pvc-b532760a-6b58-45e9-9df5-47aa6578019f","csi.storage.k8s.io/pvc/name":"pvc-lxlsn","csi.storage.k8s.io/pvc/namespace":"azurefile-5466","csi.storage.k8s.io/serviceAccount.name":"default","matchTags":"true","secretNamespace":"default","shareName":"sharename-${pvc.metadata.name}","skuName":"Standard_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1672827869886-8081-file.csi.azure.com"},"volume_id":"capz-fkqvhq#ffb5f4fe5568e4ad9a88810#sharename-pvc-lxlsn##pvc-b532760a-6b58-45e9-9df5-47aa6578019f#default"} I0104 10:34:22.276897 5484 safe_mounter_windows.go:155] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\f2404562-5718-41f1-8bc6-95eb46ce477e\volumes\kubernetes.io~csi\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\mount I0104 10:34:22.276897 5484 safe_mounter_windows.go:212] Exists path: c:\var\lib\kubelet\pods\f2404562-5718-41f1-8bc6-95eb46ce477e\volumes\kubernetes.io~csi\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\mount W0104 10:34:22.349894 5484 nodeserver.go:529] ReadDir c:\var\lib\kubelet\pods\f2404562-5718-41f1-8bc6-95eb46ce477e\volumes\kubernetes.io~csi\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\mount failed with open c:\var\lib\kubelet\pods\f2404562-5718-41f1-8bc6-95eb46ce477e\volumes\kubernetes.io~csi\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\mount: Access is denied., unmount this directory I0104 10:34:22.350897 5484 safe_mounter_windows.go:139] Unmount: c:\var\lib\kubelet\pods\f2404562-5718-41f1-8bc6-95eb46ce477e\volumes\kubernetes.io~csi\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\mount I0104 10:34:22.350897 5484 safe_mounter_windows.go:125] Remove directory: c:\var\lib\kubelet\pods\f2404562-5718-41f1-8bc6-95eb46ce477e\volumes\kubernetes.io~csi\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\mount E0104 10:34:22.351888 5484 utils.go:81] GRPC error: rpc error: code = Internal desc = Could not mount target c:\var\lib\kubelet\pods\f2404562-5718-41f1-8bc6-95eb46ce477e\volumes\kubernetes.io~csi\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\mount: open c:\var\lib\kubelet\pods\f2404562-5718-41f1-8bc6-95eb46ce477e\volumes\kubernetes.io~csi\pvc-b532760a-6b58-45e9-9df5-47aa6578019f\mount: Access is denied. I0104 10:34:35.416712 5484 utils.go:76] GRPC call: /csi.v1.Identity/Probe I0104 10:34:35.416712 5484 utils.go:77] GRPC request: {} I0104 10:34:35.416712 5484 utils.go:83] GRPC response: {"ready":{"value":true}} I0104 10:34:50.497148 5484 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities I0104 10:34:50.497148 5484 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities I0104 10:34:50.497148 5484 utils.go:77] GRPC request: {} ... skipping 1229 lines ... I0104 10:51:33.045911 5484 utils.go:76] GRPC call: /csi.v1.Node/NodeGetCapabilities I0104 10:51:33.045911 5484 utils.go:77] GRPC request: {} I0104 10:51:33.045911 5484 utils.go:83] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":2}}}]} I0104 10:51:33.046870 5484 utils.go:76] GRPC call: /csi.v1.Node/NodePublishVolume I0104 10:51:33.046870 5484 utils.go:77] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\6dbb9714-ca33-43e5-b9cb-da7eeb9b5155\\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-8c7rn","csi.storage.k8s.io/pod.namespace":"azurefile-9371","csi.storage.k8s.io/pod.uid":"6dbb9714-ca33-43e5-b9cb-da7eeb9b5155","csi.storage.k8s.io/serviceAccount.name":"default","mountOptions":"dir_mode=0755,file_mode=0721,cache=singleclient","secretName":"azure-storage-account-ffb5f4fe5568e4ad9a88810-secret","server":"","shareName":"csi-inline-smb-volume"},"volume_id":"csi-3bcf20a441bb3d0bad10459a1222634416317dc0dc9a401b40b529785c0c3d2d"} I0104 10:51:33.046870 5484 nodeserver.go:68] NodePublishVolume: ephemeral volume(csi-3bcf20a441bb3d0bad10459a1222634416317dc0dc9a401b40b529785c0c3d2d) mount on c:\var\lib\kubelet\pods\6dbb9714-ca33-43e5-b9cb-da7eeb9b5155\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-8c7rn csi.storage.k8s.io/pod.namespace:azurefile-9371 csi.storage.k8s.io/pod.uid:6dbb9714-ca33-43e5-b9cb-da7eeb9b5155 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:dir_mode=0755,file_mode=0721,cache=singleclient secretName:azure-storage-account-ffb5f4fe5568e4ad9a88810-secret secretnamespace:azurefile-9371 server: shareName:csi-inline-smb-volume storageaccount:] W0104 10:51:33.046870 5484 azurefile.go:595] parsing volumeID(csi-3bcf20a441bb3d0bad10459a1222634416317dc0dc9a401b40b529785c0c3d2d) return with error: error parsing volume id: "csi-3bcf20a441bb3d0bad10459a1222634416317dc0dc9a401b40b529785c0c3d2d", should at least contain two # I0104 10:51:33.056365 5484 round_trippers.go:553] GET https://10.96.0.1:443/api/v1/namespaces/azurefile-9371/secrets/azure-storage-account-ffb5f4fe5568e4ad9a88810-secret 200 OK in 8 milliseconds I0104 10:51:33.056365 5484 nodeserver.go:302] cifsMountPath(c:\var\lib\kubelet\pods\6dbb9714-ca33-43e5-b9cb-da7eeb9b5155\volumes\kubernetes.io~csi\test-volume-1\mount) fstype() volumeID(csi-3bcf20a441bb3d0bad10459a1222634416317dc0dc9a401b40b529785c0c3d2d) context(map[csi.storage.k8s.io/ephemeral:true csi.storage.k8s.io/pod.name:azurefile-volume-tester-8c7rn csi.storage.k8s.io/pod.namespace:azurefile-9371 csi.storage.k8s.io/pod.uid:6dbb9714-ca33-43e5-b9cb-da7eeb9b5155 csi.storage.k8s.io/serviceAccount.name:default getaccountkeyfromsecret:true mountOptions:dir_mode=0755,file_mode=0721,cache=singleclient secretName:azure-storage-account-ffb5f4fe5568e4ad9a88810-secret secretnamespace:azurefile-9371 server: shareName:csi-inline-smb-volume storageaccount:]) mountflags([]) mountOptions([AZURE\ffb5f4fe5568e4ad9a88810]) volumeMountGroup() I0104 10:51:33.056365 5484 safe_mounter_windows.go:155] IsLikelyNotMountPoint: c:\var\lib\kubelet\pods\6dbb9714-ca33-43e5-b9cb-da7eeb9b5155\volumes\kubernetes.io~csi\test-volume-1\mount I0104 10:51:33.056365 5484 safe_mounter_windows.go:212] Exists path: c:\var\lib\kubelet\pods\6dbb9714-ca33-43e5-b9cb-da7eeb9b5155\volumes\kubernetes.io~csi\test-volume-1\mount I0104 10:51:33.057376 5484 safe_mounter_windows.go:212] Exists path: c:\var\lib\kubelet\pods\6dbb9714-ca33-43e5-b9cb-da7eeb9b5155\volumes\kubernetes.io~csi\test-volume-1\mount I0104 10:51:33.057869 5484 azure_common_windows.go:52] Removing path: c:\var\lib\kubelet\pods\6dbb9714-ca33-43e5-b9cb-da7eeb9b5155\volumes\kubernetes.io~csi\test-volume-1\mount ... skipping 433 lines ... # HELP go_gc_heap_objects_objects Number of objects, live or unswept, occupying heap memory. # TYPE go_gc_heap_objects_objects gauge go_gc_heap_objects_objects 48684 # HELP go_gc_heap_tiny_allocs_objects_total Count of small allocations that are packed together into blocks. These allocations are counted separately from other allocations because each individual allocation is not tracked by the runtime, only their block. Each block is already accounted for in allocs-by-size and frees-by-size. # TYPE go_gc_heap_tiny_allocs_objects_total counter go_gc_heap_tiny_allocs_objects_total 17927 # HELP go_gc_limiter_last_enabled_gc_cycle GC cycle the last time the GC CPU limiter was enabled. This metric is useful for diagnosing the root cause of an out-of-memory error, because the limiter trades memory for CPU time when the GC's CPU time gets too high. This is most likely to occur with use of SetMemoryLimit. The first GC cycle is cycle 1, so a value of 0 indicates that it was never enabled. # TYPE go_gc_limiter_last_enabled_gc_cycle gauge go_gc_limiter_last_enabled_gc_cycle 0 # HELP go_gc_pauses_seconds Distribution individual GC-related stop-the-world pause latencies. # TYPE go_gc_pauses_seconds histogram go_gc_pauses_seconds_bucket{le="9.999999999999999e-10"} 0 go_gc_pauses_seconds_bucket{le="9.999999999999999e-09"} 0 ... skipping 341 lines ... Jan 4 10:52:54.416: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-9nwp9] to have phase Bound Jan 4 10:52:54.477: INFO: PersistentVolumeClaim pvc-9nwp9 found and phase=Bound (61.09769ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:52:54.477[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:52:54.539[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:52:54.6[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:52:54.601[0m [1mSTEP:[0m checking that the pods command exits with an error [38;5;243m01/04/23 10:52:54.666[0m Jan 4 10:52:54.666: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-zvc97" in namespace "azurefile-60" to be "Error status code" Jan 4 10:52:54.728: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Pending", Reason="", readiness=false. Elapsed: 61.471511ms Jan 4 10:52:56.790: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Pending", Reason="", readiness=false. Elapsed: 2.123626545s Jan 4 10:52:58.790: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Pending", Reason="", readiness=false. Elapsed: 4.123587363s Jan 4 10:53:00.794: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Pending", Reason="", readiness=false. Elapsed: 6.127513567s Jan 4 10:53:02.794: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Running", Reason="", readiness=true. Elapsed: 8.127545968s Jan 4 10:53:04.794: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Running", Reason="", readiness=true. Elapsed: 10.127671271s Jan 4 10:53:06.795: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Running", Reason="", readiness=true. Elapsed: 12.128557706s Jan 4 10:53:08.795: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Running", Reason="", readiness=false. Elapsed: 14.128593874s Jan 4 10:53:10.795: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Failed", Reason="", readiness=false. Elapsed: 16.128731861s [1mSTEP:[0m Saw pod failure [38;5;243m01/04/23 10:53:10.795[0m Jan 4 10:53:10.795: INFO: Pod "azurefile-volume-tester-zvc97" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m01/04/23 10:53:10.795[0m Jan 4 10:53:10.867: INFO: deleting Pod "azurefile-60"/"azurefile-volume-tester-zvc97" Jan 4 10:53:10.932: INFO: Pod azurefile-volume-tester-zvc97 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 48 lines ... Jan 4 10:52:54.416: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-9nwp9] to have phase Bound Jan 4 10:52:54.477: INFO: PersistentVolumeClaim pvc-9nwp9 found and phase=Bound (61.09769ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:52:54.477[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:52:54.539[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:52:54.6[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:52:54.601[0m [1mSTEP:[0m checking that the pods command exits with an error [38;5;243m01/04/23 10:52:54.666[0m Jan 4 10:52:54.666: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-zvc97" in namespace "azurefile-60" to be "Error status code" Jan 4 10:52:54.728: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Pending", Reason="", readiness=false. Elapsed: 61.471511ms Jan 4 10:52:56.790: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Pending", Reason="", readiness=false. Elapsed: 2.123626545s Jan 4 10:52:58.790: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Pending", Reason="", readiness=false. Elapsed: 4.123587363s Jan 4 10:53:00.794: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Pending", Reason="", readiness=false. Elapsed: 6.127513567s Jan 4 10:53:02.794: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Running", Reason="", readiness=true. Elapsed: 8.127545968s Jan 4 10:53:04.794: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Running", Reason="", readiness=true. Elapsed: 10.127671271s Jan 4 10:53:06.795: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Running", Reason="", readiness=true. Elapsed: 12.128557706s Jan 4 10:53:08.795: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Running", Reason="", readiness=false. Elapsed: 14.128593874s Jan 4 10:53:10.795: INFO: Pod "azurefile-volume-tester-zvc97": Phase="Failed", Reason="", readiness=false. Elapsed: 16.128731861s [1mSTEP:[0m Saw pod failure [38;5;243m01/04/23 10:53:10.795[0m Jan 4 10:53:10.795: INFO: Pod "azurefile-volume-tester-zvc97" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m01/04/23 10:53:10.795[0m Jan 4 10:53:10.867: INFO: deleting Pod "azurefile-60"/"azurefile-volume-tester-zvc97" Jan 4 10:53:10.932: INFO: Pod azurefile-volume-tester-zvc97 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 49 lines ... Jan 4 10:53:13.355: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-sgc9s] to have phase Bound Jan 4 10:53:13.417: INFO: PersistentVolumeClaim pvc-sgc9s found and phase=Bound (61.22155ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:53:13.417[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:53:13.478[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:53:13.54[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:53:13.54[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:53:13.607[0m Jan 4 10:53:13.607: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-r84qk" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:53:13.669: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Pending", Reason="", readiness=false. Elapsed: 61.662711ms Jan 4 10:53:15.731: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124528284s Jan 4 10:53:17.736: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.129356732s Jan 4 10:53:19.739: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Running", Reason="", readiness=true. Elapsed: 6.132329408s Jan 4 10:53:21.735: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Running", Reason="", readiness=true. Elapsed: 8.127543394s Jan 4 10:53:23.736: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Running", Reason="", readiness=true. Elapsed: 10.129245864s Jan 4 10:53:25.735: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Running", Reason="", readiness=false. Elapsed: 12.127577572s Jan 4 10:53:27.736: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.129216022s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:53:27.736[0m Jan 4 10:53:27.736: INFO: Pod "azurefile-volume-tester-r84qk" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:53:27.736[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:53:27.736[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:53:27.802[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:53:27.802[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:53:27.866[0m Jan 4 10:53:27.867: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-x4x78] to have phase Bound Jan 4 10:53:27.928: INFO: PersistentVolumeClaim pvc-x4x78 found and phase=Bound (61.471584ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:53:27.928[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:53:27.99[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:53:28.051[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:53:28.052[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:53:28.118[0m Jan 4 10:53:28.118: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-fzgg6" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:53:28.179: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Pending", Reason="", readiness=false. Elapsed: 61.182821ms Jan 4 10:53:30.246: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.12728054s Jan 4 10:53:32.247: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.12898416s Jan 4 10:53:34.245: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Running", Reason="", readiness=true. Elapsed: 6.127171809s Jan 4 10:53:36.246: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Running", Reason="", readiness=true. Elapsed: 8.127267649s Jan 4 10:53:38.247: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Running", Reason="", readiness=true. Elapsed: 10.128678734s Jan 4 10:53:40.246: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Running", Reason="", readiness=false. Elapsed: 12.127291529s Jan 4 10:53:42.245: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127009597s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:53:42.245[0m Jan 4 10:53:42.245: INFO: Pod "azurefile-volume-tester-fzgg6" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:53:42.245[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:53:42.245[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:53:42.311[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:53:42.311[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:53:42.376[0m Jan 4 10:53:42.376: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-mpvwn] to have phase Bound Jan 4 10:53:42.437: INFO: PersistentVolumeClaim pvc-mpvwn found and phase=Bound (61.170521ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:53:42.437[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:53:42.499[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:53:42.561[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:53:42.561[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:53:42.627[0m Jan 4 10:53:42.627: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-b9rnf" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:53:42.688: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Pending", Reason="", readiness=false. Elapsed: 61.156276ms Jan 4 10:53:44.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.126976436s Jan 4 10:53:46.756: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.129173028s Jan 4 10:53:48.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.12738046s Jan 4 10:53:50.756: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Running", Reason="", readiness=true. Elapsed: 8.129128998s Jan 4 10:53:52.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Running", Reason="", readiness=true. Elapsed: 10.127027023s Jan 4 10:53:54.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Running", Reason="", readiness=false. Elapsed: 12.127224273s Jan 4 10:53:56.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127223557s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:53:56.754[0m Jan 4 10:53:56.754: INFO: Pod "azurefile-volume-tester-b9rnf" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:53:56.754[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:53:56.754[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:53:56.818[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:53:56.819[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:53:56.886[0m Jan 4 10:53:56.886: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-g7fn4] to have phase Bound Jan 4 10:53:56.948: INFO: PersistentVolumeClaim pvc-g7fn4 found and phase=Bound (61.785365ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:53:56.948[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:53:57.011[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:53:57.072[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:53:57.073[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:53:57.137[0m Jan 4 10:53:57.137: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-phjtc" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:53:57.199: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Pending", Reason="", readiness=false. Elapsed: 61.452755ms Jan 4 10:53:59.261: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124047594s Jan 4 10:54:01.265: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.127346161s Jan 4 10:54:03.266: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Running", Reason="", readiness=true. Elapsed: 6.1291381s Jan 4 10:54:05.266: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Running", Reason="", readiness=true. Elapsed: 8.128920385s Jan 4 10:54:07.265: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Running", Reason="", readiness=true. Elapsed: 10.127954054s Jan 4 10:54:09.265: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Running", Reason="", readiness=false. Elapsed: 12.128039424s Jan 4 10:54:11.266: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.128447198s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:54:11.266[0m Jan 4 10:54:11.266: INFO: Pod "azurefile-volume-tester-phjtc" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:54:11.266[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:54:11.266[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:54:11.334[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:54:11.334[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:54:11.399[0m Jan 4 10:54:11.399: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-kw6sr] to have phase Bound Jan 4 10:54:11.461: INFO: PersistentVolumeClaim pvc-kw6sr found and phase=Bound (61.807173ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:54:11.461[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:54:11.523[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:54:11.584[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:54:11.584[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:54:11.649[0m Jan 4 10:54:11.649: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-mz55q" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:54:11.711: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Pending", Reason="", readiness=false. Elapsed: 61.571308ms Jan 4 10:54:13.773: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Pending", Reason="", readiness=false. Elapsed: 2.123503103s Jan 4 10:54:15.777: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128294463s Jan 4 10:54:17.778: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Running", Reason="", readiness=true. Elapsed: 6.128352178s Jan 4 10:54:19.778: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Running", Reason="", readiness=true. Elapsed: 8.129193423s Jan 4 10:54:21.778: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Running", Reason="", readiness=true. Elapsed: 10.128853343s Jan 4 10:54:23.777: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Running", Reason="", readiness=false. Elapsed: 12.128082368s Jan 4 10:54:25.778: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.12874028s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:54:25.778[0m Jan 4 10:54:25.778: INFO: Pod "azurefile-volume-tester-mz55q" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:54:25.778[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:54:25.778[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:54:25.843[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:54:25.843[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:54:25.909[0m Jan 4 10:54:25.909: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-jmjtx] to have phase Bound Jan 4 10:54:25.971: INFO: PersistentVolumeClaim pvc-jmjtx found and phase=Bound (61.596462ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:54:25.971[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:54:26.035[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:54:26.097[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:54:26.097[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:54:26.16[0m Jan 4 10:54:26.161: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-c8v8w" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:54:26.222: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Pending", Reason="", readiness=false. Elapsed: 61.215879ms Jan 4 10:54:28.287: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.126808195s Jan 4 10:54:30.289: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128927591s Jan 4 10:54:32.288: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Running", Reason="", readiness=true. Elapsed: 6.12708213s Jan 4 10:54:34.288: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Running", Reason="", readiness=true. Elapsed: 8.127241092s Jan 4 10:54:36.288: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Running", Reason="", readiness=true. Elapsed: 10.127196899s Jan 4 10:54:38.288: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Running", Reason="", readiness=false. Elapsed: 12.127417097s Jan 4 10:54:40.289: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.12826297s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:54:40.289[0m Jan 4 10:54:40.289: INFO: Pod "azurefile-volume-tester-c8v8w" satisfied condition "Succeeded or Failed" Jan 4 10:54:40.289: INFO: deleting Pod "azurefile-1181"/"azurefile-volume-tester-c8v8w" Jan 4 10:54:40.358: INFO: Pod azurefile-volume-tester-c8v8w has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-c8v8w in namespace azurefile-1181 [38;5;243m01/04/23 10:54:40.358[0m Jan 4 10:54:40.432: INFO: deleting PVC "azurefile-1181"/"pvc-jmjtx" Jan 4 10:54:40.432: INFO: Deleting PersistentVolumeClaim "pvc-jmjtx" ... skipping 94 lines ... Jan 4 10:53:13.355: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-sgc9s] to have phase Bound Jan 4 10:53:13.417: INFO: PersistentVolumeClaim pvc-sgc9s found and phase=Bound (61.22155ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:53:13.417[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:53:13.478[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:53:13.54[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:53:13.54[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:53:13.607[0m Jan 4 10:53:13.607: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-r84qk" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:53:13.669: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Pending", Reason="", readiness=false. Elapsed: 61.662711ms Jan 4 10:53:15.731: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124528284s Jan 4 10:53:17.736: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.129356732s Jan 4 10:53:19.739: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Running", Reason="", readiness=true. Elapsed: 6.132329408s Jan 4 10:53:21.735: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Running", Reason="", readiness=true. Elapsed: 8.127543394s Jan 4 10:53:23.736: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Running", Reason="", readiness=true. Elapsed: 10.129245864s Jan 4 10:53:25.735: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Running", Reason="", readiness=false. Elapsed: 12.127577572s Jan 4 10:53:27.736: INFO: Pod "azurefile-volume-tester-r84qk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.129216022s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:53:27.736[0m Jan 4 10:53:27.736: INFO: Pod "azurefile-volume-tester-r84qk" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:53:27.736[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:53:27.736[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:53:27.802[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:53:27.802[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:53:27.866[0m Jan 4 10:53:27.867: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-x4x78] to have phase Bound Jan 4 10:53:27.928: INFO: PersistentVolumeClaim pvc-x4x78 found and phase=Bound (61.471584ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:53:27.928[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:53:27.99[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:53:28.051[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:53:28.052[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:53:28.118[0m Jan 4 10:53:28.118: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-fzgg6" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:53:28.179: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Pending", Reason="", readiness=false. Elapsed: 61.182821ms Jan 4 10:53:30.246: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.12728054s Jan 4 10:53:32.247: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.12898416s Jan 4 10:53:34.245: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Running", Reason="", readiness=true. Elapsed: 6.127171809s Jan 4 10:53:36.246: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Running", Reason="", readiness=true. Elapsed: 8.127267649s Jan 4 10:53:38.247: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Running", Reason="", readiness=true. Elapsed: 10.128678734s Jan 4 10:53:40.246: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Running", Reason="", readiness=false. Elapsed: 12.127291529s Jan 4 10:53:42.245: INFO: Pod "azurefile-volume-tester-fzgg6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127009597s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:53:42.245[0m Jan 4 10:53:42.245: INFO: Pod "azurefile-volume-tester-fzgg6" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:53:42.245[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:53:42.245[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:53:42.311[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:53:42.311[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:53:42.376[0m Jan 4 10:53:42.376: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-mpvwn] to have phase Bound Jan 4 10:53:42.437: INFO: PersistentVolumeClaim pvc-mpvwn found and phase=Bound (61.170521ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:53:42.437[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:53:42.499[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:53:42.561[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:53:42.561[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:53:42.627[0m Jan 4 10:53:42.627: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-b9rnf" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:53:42.688: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Pending", Reason="", readiness=false. Elapsed: 61.156276ms Jan 4 10:53:44.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.126976436s Jan 4 10:53:46.756: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.129173028s Jan 4 10:53:48.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.12738046s Jan 4 10:53:50.756: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Running", Reason="", readiness=true. Elapsed: 8.129128998s Jan 4 10:53:52.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Running", Reason="", readiness=true. Elapsed: 10.127027023s Jan 4 10:53:54.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Running", Reason="", readiness=false. Elapsed: 12.127224273s Jan 4 10:53:56.754: INFO: Pod "azurefile-volume-tester-b9rnf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127223557s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:53:56.754[0m Jan 4 10:53:56.754: INFO: Pod "azurefile-volume-tester-b9rnf" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:53:56.754[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:53:56.754[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:53:56.818[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:53:56.819[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:53:56.886[0m Jan 4 10:53:56.886: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-g7fn4] to have phase Bound Jan 4 10:53:56.948: INFO: PersistentVolumeClaim pvc-g7fn4 found and phase=Bound (61.785365ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:53:56.948[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:53:57.011[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:53:57.072[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:53:57.073[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:53:57.137[0m Jan 4 10:53:57.137: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-phjtc" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:53:57.199: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Pending", Reason="", readiness=false. Elapsed: 61.452755ms Jan 4 10:53:59.261: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124047594s Jan 4 10:54:01.265: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.127346161s Jan 4 10:54:03.266: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Running", Reason="", readiness=true. Elapsed: 6.1291381s Jan 4 10:54:05.266: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Running", Reason="", readiness=true. Elapsed: 8.128920385s Jan 4 10:54:07.265: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Running", Reason="", readiness=true. Elapsed: 10.127954054s Jan 4 10:54:09.265: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Running", Reason="", readiness=false. Elapsed: 12.128039424s Jan 4 10:54:11.266: INFO: Pod "azurefile-volume-tester-phjtc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.128447198s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:54:11.266[0m Jan 4 10:54:11.266: INFO: Pod "azurefile-volume-tester-phjtc" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:54:11.266[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:54:11.266[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:54:11.334[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:54:11.334[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:54:11.399[0m Jan 4 10:54:11.399: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-kw6sr] to have phase Bound Jan 4 10:54:11.461: INFO: PersistentVolumeClaim pvc-kw6sr found and phase=Bound (61.807173ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:54:11.461[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:54:11.523[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:54:11.584[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:54:11.584[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:54:11.649[0m Jan 4 10:54:11.649: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-mz55q" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:54:11.711: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Pending", Reason="", readiness=false. Elapsed: 61.571308ms Jan 4 10:54:13.773: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Pending", Reason="", readiness=false. Elapsed: 2.123503103s Jan 4 10:54:15.777: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128294463s Jan 4 10:54:17.778: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Running", Reason="", readiness=true. Elapsed: 6.128352178s Jan 4 10:54:19.778: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Running", Reason="", readiness=true. Elapsed: 8.129193423s Jan 4 10:54:21.778: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Running", Reason="", readiness=true. Elapsed: 10.128853343s Jan 4 10:54:23.777: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Running", Reason="", readiness=false. Elapsed: 12.128082368s Jan 4 10:54:25.778: INFO: Pod "azurefile-volume-tester-mz55q": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.12874028s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:54:25.778[0m Jan 4 10:54:25.778: INFO: Pod "azurefile-volume-tester-mz55q" satisfied condition "Succeeded or Failed" [1mSTEP:[0m setting up the PV [38;5;243m01/04/23 10:54:25.778[0m [1mSTEP:[0m creating a PV [38;5;243m01/04/23 10:54:25.778[0m [1mSTEP:[0m setting up the PVC [38;5;243m01/04/23 10:54:25.843[0m [1mSTEP:[0m creating a PVC [38;5;243m01/04/23 10:54:25.843[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m01/04/23 10:54:25.909[0m Jan 4 10:54:25.909: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-jmjtx] to have phase Bound Jan 4 10:54:25.971: INFO: PersistentVolumeClaim pvc-jmjtx found and phase=Bound (61.596462ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:54:25.971[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:54:26.035[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:54:26.097[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:54:26.097[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:54:26.16[0m Jan 4 10:54:26.161: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-c8v8w" in namespace "azurefile-1181" to be "Succeeded or Failed" Jan 4 10:54:26.222: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Pending", Reason="", readiness=false. Elapsed: 61.215879ms Jan 4 10:54:28.287: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.126808195s Jan 4 10:54:30.289: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128927591s Jan 4 10:54:32.288: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Running", Reason="", readiness=true. Elapsed: 6.12708213s Jan 4 10:54:34.288: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Running", Reason="", readiness=true. Elapsed: 8.127241092s Jan 4 10:54:36.288: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Running", Reason="", readiness=true. Elapsed: 10.127196899s Jan 4 10:54:38.288: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Running", Reason="", readiness=false. Elapsed: 12.127417097s Jan 4 10:54:40.289: INFO: Pod "azurefile-volume-tester-c8v8w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.12826297s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:54:40.289[0m Jan 4 10:54:40.289: INFO: Pod "azurefile-volume-tester-c8v8w" satisfied condition "Succeeded or Failed" Jan 4 10:54:40.289: INFO: deleting Pod "azurefile-1181"/"azurefile-volume-tester-c8v8w" Jan 4 10:54:40.358: INFO: Pod azurefile-volume-tester-c8v8w has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-c8v8w in namespace azurefile-1181 [38;5;243m01/04/23 10:54:40.358[0m Jan 4 10:54:40.432: INFO: deleting PVC "azurefile-1181"/"pvc-jmjtx" Jan 4 10:54:40.432: INFO: Deleting PersistentVolumeClaim "pvc-jmjtx" ... skipping 174 lines ... Jan 4 10:54:48.647: INFO: PersistentVolumeClaim pvc-99jhh found but phase is Pending instead of Bound. Jan 4 10:54:50.709: INFO: PersistentVolumeClaim pvc-99jhh found and phase=Bound (2.146136945s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:54:50.709[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:54:50.771[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:54:50.833[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:54:50.833[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:54:50.898[0m Jan 4 10:54:50.898: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-qwqrm" in namespace "azurefile-1040" to be "Succeeded or Failed" Jan 4 10:54:50.959: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Pending", Reason="", readiness=false. Elapsed: 61.232812ms Jan 4 10:54:53.021: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.123438042s Jan 4 10:54:55.026: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128361449s Jan 4 10:54:57.027: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.129019547s Jan 4 10:54:59.025: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Running", Reason="", readiness=true. Elapsed: 8.127254605s Jan 4 10:55:01.026: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Running", Reason="", readiness=true. Elapsed: 10.128611029s Jan 4 10:55:03.025: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Running", Reason="", readiness=false. Elapsed: 12.127490746s Jan 4 10:55:05.025: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127755777s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:55:05.026[0m Jan 4 10:55:05.026: INFO: Pod "azurefile-volume-tester-qwqrm" satisfied condition "Succeeded or Failed" Jan 4 10:55:05.026: INFO: deleting Pod "azurefile-1040"/"azurefile-volume-tester-qwqrm" Jan 4 10:55:05.098: INFO: Pod azurefile-volume-tester-qwqrm has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-qwqrm in namespace azurefile-1040 [38;5;243m01/04/23 10:55:05.099[0m Jan 4 10:55:05.171: INFO: deleting PVC "azurefile-1040"/"pvc-99jhh" Jan 4 10:55:05.171: INFO: Deleting PersistentVolumeClaim "pvc-99jhh" ... skipping 27 lines ... Jan 4 10:54:48.647: INFO: PersistentVolumeClaim pvc-99jhh found but phase is Pending instead of Bound. Jan 4 10:54:50.709: INFO: PersistentVolumeClaim pvc-99jhh found and phase=Bound (2.146136945s) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:54:50.709[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:54:50.771[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:54:50.833[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:54:50.833[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:54:50.898[0m Jan 4 10:54:50.898: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-qwqrm" in namespace "azurefile-1040" to be "Succeeded or Failed" Jan 4 10:54:50.959: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Pending", Reason="", readiness=false. Elapsed: 61.232812ms Jan 4 10:54:53.021: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.123438042s Jan 4 10:54:55.026: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128361449s Jan 4 10:54:57.027: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.129019547s Jan 4 10:54:59.025: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Running", Reason="", readiness=true. Elapsed: 8.127254605s Jan 4 10:55:01.026: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Running", Reason="", readiness=true. Elapsed: 10.128611029s Jan 4 10:55:03.025: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Running", Reason="", readiness=false. Elapsed: 12.127490746s Jan 4 10:55:05.025: INFO: Pod "azurefile-volume-tester-qwqrm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.127755777s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:55:05.026[0m Jan 4 10:55:05.026: INFO: Pod "azurefile-volume-tester-qwqrm" satisfied condition "Succeeded or Failed" Jan 4 10:55:05.026: INFO: deleting Pod "azurefile-1040"/"azurefile-volume-tester-qwqrm" Jan 4 10:55:05.098: INFO: Pod azurefile-volume-tester-qwqrm has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-qwqrm in namespace azurefile-1040 [38;5;243m01/04/23 10:55:05.099[0m Jan 4 10:55:05.171: INFO: deleting PVC "azurefile-1040"/"pvc-99jhh" Jan 4 10:55:05.171: INFO: Deleting PersistentVolumeClaim "pvc-99jhh" ... skipping 27 lines ... Jan 4 10:55:07.560: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-mtcbn] to have phase Bound Jan 4 10:55:07.622: INFO: PersistentVolumeClaim pvc-mtcbn found and phase=Bound (61.484626ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:55:07.622[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:55:07.684[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:55:07.745[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:55:07.746[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:55:07.811[0m Jan 4 10:55:07.811: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-xsxph" in namespace "azurefile-6443" to be "Succeeded or Failed" Jan 4 10:55:07.877: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 66.620307ms Jan 4 10:55:09.941: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 2.129729185s Jan 4 10:55:11.940: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128734372s Jan 4 10:55:13.945: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 6.134412133s Jan 4 10:55:15.943: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 8.132616544s Jan 4 10:55:17.944: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Running", Reason="", readiness=true. Elapsed: 10.13325382s Jan 4 10:55:19.944: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Running", Reason="", readiness=true. Elapsed: 12.133618514s Jan 4 10:55:21.943: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Running", Reason="", readiness=false. Elapsed: 14.132393802s Jan 4 10:55:23.943: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.132245089s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:55:23.943[0m Jan 4 10:55:23.943: INFO: Pod "azurefile-volume-tester-xsxph" satisfied condition "Succeeded or Failed" Jan 4 10:55:23.943: INFO: deleting Pod "azurefile-6443"/"azurefile-volume-tester-xsxph" Jan 4 10:55:24.012: INFO: Pod azurefile-volume-tester-xsxph has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-xsxph in namespace azurefile-6443 [38;5;243m01/04/23 10:55:24.012[0m Jan 4 10:55:24.087: INFO: deleting PVC "azurefile-6443"/"pvc-mtcbn" Jan 4 10:55:24.087: INFO: Deleting PersistentVolumeClaim "pvc-mtcbn" ... skipping 31 lines ... Jan 4 10:55:07.560: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-mtcbn] to have phase Bound Jan 4 10:55:07.622: INFO: PersistentVolumeClaim pvc-mtcbn found and phase=Bound (61.484626ms) [1mSTEP:[0m checking the PVC [38;5;243m01/04/23 10:55:07.622[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/04/23 10:55:07.684[0m [1mSTEP:[0m checking the PV [38;5;243m01/04/23 10:55:07.745[0m [1mSTEP:[0m deploying the pod [38;5;243m01/04/23 10:55:07.746[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/04/23 10:55:07.811[0m Jan 4 10:55:07.811: INFO: Waiting up to 15m0s for pod "azurefile-volume-tester-xsxph" in namespace "azurefile-6443" to be "Succeeded or Failed" Jan 4 10:55:07.877: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 66.620307ms Jan 4 10:55:09.941: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 2.129729185s Jan 4 10:55:11.940: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 4.128734372s Jan 4 10:55:13.945: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 6.134412133s Jan 4 10:55:15.943: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Pending", Reason="", readiness=false. Elapsed: 8.132616544s Jan 4 10:55:17.944: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Running", Reason="", readiness=true. Elapsed: 10.13325382s Jan 4 10:55:19.944: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Running", Reason="", readiness=true. Elapsed: 12.133618514s Jan 4 10:55:21.943: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Running", Reason="", readiness=false. Elapsed: 14.132393802s Jan 4 10:55:23.943: INFO: Pod "azurefile-volume-tester-xsxph": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.132245089s [1mSTEP:[0m Saw pod success [38;5;243m01/04/23 10:55:23.943[0m Jan 4 10:55:23.943: INFO: Pod "azurefile-volume-tester-xsxph" satisfied condition "Succeeded or Failed" Jan 4 10:55:23.943: INFO: deleting Pod "azurefile-6443"/"azurefile-volume-tester-xsxph" Jan 4 10:55:24.012: INFO: Pod azurefile-volume-tester-xsxph has the following logs: hello world [1mSTEP:[0m Deleting pod azurefile-volume-tester-xsxph in namespace azurefile-6443 [38;5;243m01/04/23 10:55:24.012[0m Jan 4 10:55:24.087: INFO: deleting PVC "azurefile-6443"/"pvc-mtcbn" Jan 4 10:55:24.087: INFO: Deleting PersistentVolumeClaim "pvc-mtcbn" ... skipping 81 lines ... Streaming logs below: I0104 10:24:29.478292 1 azurefile.go:299] driver userAgent: file.csi.azure.com/e2e-a43df1bddbd87e646edd537bc97b8fccfb98fc15 e2e-test I0104 10:24:29.478413 1 azure.go:65] set QPS(25.000000) and QPS Burst(50) for driver kubeClient I0104 10:24:29.478793 1 azure.go:80] reading cloud config from secret kube-system/azure-cloud-provider I0104 10:24:29.486298 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 7 milliseconds I0104 10:24:29.486507 1 azure.go:87] 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 I0104 10:24:29.486516 1 azure.go:92] could not read cloud config from secret kube-system/azure-cloud-provider I0104 10:24:29.486521 1 azure.go:102] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0104 10:24:29.486541 1 azure.go:110] read cloud config from file: /etc/kubernetes/azure.json successfully I0104 10:24:29.487079 1 azure_auth.go:245] Using AzurePublicCloud environment I0104 10:24:29.487108 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0104 10:24:29.487161 1 azure_diskclient.go:68] Azure DisksClient using API version: 2022-03-02 I0104 10:24:29.487204 1 azure_blobclient.go:67] Azure BlobClient using API version: 2021-09-01 I0104 10:24:29.487262 1 azure.go:1008] attach/detach disk operation rate limit QPS: 6.000000, Bucket: 10 I0104 10:24:29.487272 1 azure.go:140] disable UseInstanceMetadata for controller server I0104 10:24:29.487279 1 azure.go:143] starting controller server... I0104 10:24:29.487288 1 azurefile.go:304] cloud: AzurePublicCloud, location: westus3, rg: capz-fkqvhq, VnetName: capz-fkqvhq-vnet, VnetResourceGroup: capz-fkqvhq, SubnetName: node-subnet I0104 10:24:29.490706 1 mount_linux.go:287] 'umount /tmp/kubelet-detect-safe-umount2550662608' failed with: exit status 32, output: umount: /tmp/kubelet-detect-safe-umount2550662608: must be superuser to unmount. I0104 10:24:29.490733 1 mount_linux.go:289] Detected umount with unsafe 'not mounted' behavior I0104 10:24:29.490799 1 driver.go:93] Enabling controller service capability: CREATE_DELETE_VOLUME I0104 10:24:29.490810 1 driver.go:93] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME I0104 10:24:29.490816 1 driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT I0104 10:24:29.490823 1 driver.go:93] Enabling controller service capability: EXPAND_VOLUME I0104 10:24:29.490832 1 driver.go:93] Enabling controller service capability: SINGLE_NODE_MULTI_WRITER ... skipping 447 lines ... Strict-Transport-Security: max-age=31536000; includeSubDomains Content-Length: 250 Pragma: no-cache Content-Type: application/json; charset=utf-8 Expires: -1 I0104 10:25:24.798865 1 util.go:124] Send.sendRequest got response with ContentLength 250, StatusCode 404 and responseBody length 250 I0104 10:25:24.798918 1 azure_privatednsclient.go:215] Received error in privatednszone.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net' under resource group 'capz-fkqvhq' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}} I0104 10:25:24.799176 1 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.014118036 request="private_dns_zones_get" resource_group="capz-fkqvhq" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="" error_code="ResourceNotFound" I0104 10:25:24.799197 1 azure_storageaccount.go:234] get private dns zone privatelink.file.core.windows.net returned with Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net' under resource group 'capz-fkqvhq' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}} I0104 10:25:24.799205 1 azure_storageaccount.go:452] Creating private dns zone(privatelink.file.core.windows.net) in resourceGroup (capz-fkqvhq) (2023-01-04T10:25:24.7992716Z) INFO: REQUEST: PUT https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net?api-version=2018-09-01 Content-Type: application/json; charset=utf-8 User-Agent: Go/go1.19.4 (amd64-linux) go-autorest/v14.2.1 file.csi.azure.com/e2e-a43df1bddbd87e646edd537bc97b8fccfb98fc15 e2e-test Authorization: **REDACTED** (2023-01-04T10:25:24.7993278Z) INFO: REQUEST: PUT https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net?api-version=2018-09-01 ... skipping 140 lines ... X-Content-Type-Options: nosniff Date: Wed, 04 Jan 2023 10:25:55 GMT Content-Length: 296 Pragma: no-cache Expires: -1 I0104 10:25:56.175776 1 util.go:124] Send.sendRequest got response with ContentLength 296, StatusCode 404 and responseBody length 296 I0104 10:25:56.175794 1 azure_virtualnetworklinksclient.go:212] Received error in virtualnetworklink.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink' under resource group 'capz-fkqvhq' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}} I0104 10:25:56.175951 1 azure_metrics.go:115] "Observed Request Latency" latency_seconds=0.028760771 request="virtual_network_links_get" resource_group="capz-fkqvhq" subscription_id="0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e" source="" error_code="ResourceNotFound" I0104 10:25:56.175974 1 azure_storageaccount.go:244] get virtual link for vnet(capz-fkqvhq-vnet) and DNS Zone(privatelink.file.core.windows.net) returned with Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink' under resource group 'capz-fkqvhq' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}} I0104 10:25:56.175983 1 azure_storageaccount.go:466] Creating virtual link for vnet(capz-fkqvhq-vnet-vnetlink) and DNS Zone(privatelink.file.core.windows.net) in resourceGroup(capz-fkqvhq) (2023-01-04T10:25:56.1761262Z) INFO: REQUEST: PUT https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink?api-version=2020-06-01 Content-Type: application/json; charset=utf-8 User-Agent: Go/go1.19.4 (amd64-linux) go-autorest/v14.2.1 file.csi.azure.com/e2e-a43df1bddbd87e646edd537bc97b8fccfb98fc15 e2e-test Authorization: **REDACTED** (2023-01-04T10:25:56.1761693Z) INFO: REQUEST: PUT https://management.azure.com/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-fkqvhq/providers/Microsoft.Network/privateDnsZones/privatelink.file.core.windows.net/virtualNetworkLinks/capz-fkqvhq-vnet-vnetlink?api-version=2020-06-01 ... skipping 4053 lines ... Platform: linux/amd64 Streaming logs below: I0104 10:52:40.541899 1 azurefile.go:299] driver userAgent: file.csi.azure.com/v1.24.0 I0104 10:52:40.542003 1 azure.go:65] set QPS(25.000000) and QPS Burst(50) for driver kubeClient I0104 10:52:40.542353 1 azure.go:80] reading cloud config from secret kube-system/azure-cloud-provider I0104 10:52:40.551315 1 azure.go:87] 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 I0104 10:52:40.551334 1 azure.go:92] could not read cloud config from secret kube-system/azure-cloud-provider I0104 10:52:40.551343 1 azure.go:102] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json I0104 10:52:40.551365 1 azure.go:110] read cloud config from file: /etc/kubernetes/azure.json successfully I0104 10:52:40.552179 1 azure_auth.go:245] Using AzurePublicCloud environment I0104 10:52:40.552222 1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0104 10:52:40.552298 1 azure_diskclient.go:68] Azure DisksClient using API version: 2022-03-02 ... skipping 42 lines ... Git Commit: b97b1825130f9837731ff25fd878281b0d2288a3 Go Version: go1.18.3 Platform: windows/amd64 Streaming logs below: I0104 10:52:42.898737 9416 azurefile.go:299] driver userAgent: file.csi.azure.com/v1.24.0 W0104 10:52:42.899244 9416 azure.go:73] get kubeconfig(C:\\k\\config) failed with error: CreateFile C:\\k\\config: The system cannot find the file specified. I0104 10:52:42.899759 9416 azure.go:92] could not read cloud config from secret kube-system/azure-cloud-provider I0104 10:52:42.899759 9416 azure.go:102] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json I0104 10:52:42.900240 9416 azure.go:110] read cloud config from file: C:\k\azure.json successfully I0104 10:52:42.901241 9416 azure_auth.go:245] Using AzurePublicCloud environment I0104 10:52:42.901739 9416 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0104 10:52:42.903741 9416 azure_diskclient.go:68] Azure DisksClient using API version: 2022-03-02 ... skipping 43 lines ... I0104 10:52:45.549926 9416 nodeserver.go:393] NodeUnstageVolume: CleanupMountPoint volume capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-d8ee5e17-f4cc-4d58-a81d-bd3acd4232ea###azurefile-8675 on \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-d8ee5e17-f4cc-4d58-a81d-bd3acd4232ea\proxy-mount I0104 10:52:45.549926 9416 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-d8ee5e17-f4cc-4d58-a81d-bd3acd4232ea\proxy-mount I0104 10:52:45.550444 9416 nodeserver.go:397] NodeUnstageVolume: unmount volume capz-fkqvhq#fb9cc2513d8d64827970da6#pvc-d8ee5e17-f4cc-4d58-a81d-bd3acd4232ea###azurefile-8675 on \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-d8ee5e17-f4cc-4d58-a81d-bd3acd4232ea\globalmount successfully I0104 10:52:45.550444 9416 utils.go:83] GRPC response: {} I0104 10:52:54.937022 9416 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume I0104 10:52:54.937022 9416 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\azurefile-60-file.csi.azure.com-preprovsioned-pv-xlpkt\\globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_id":"capz-fkqvhq#fb9cc2513d8d64827970da6#pre-provisioned-readonly##pre-provisioned-readonly#azurefile-60"} W0104 10:52:54.938050 9416 azurefile.go:668] GetStorageAccountFromSecret(azure-storage-account-fb9cc2513d8d64827970da6-secret, azurefile-60) failed with error: could not get account key from secret(azure-storage-account-fb9cc2513d8d64827970da6-secret): KubeClient is nil I0104 10:52:54.938050 9416 azurefile.go:670] use cluster identity to get account key from (0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e, capz-fkqvhq, fb9cc2513d8d64827970da6) I0104 10:52:56.045631 9416 nodeserver.go:302] cifsMountPath(\var\lib\kubelet\plugins\kubernetes.io\csi\pv\azurefile-60-file.csi.azure.com-preprovsioned-pv-xlpkt\globalmount) fstype() volumeID(capz-fkqvhq#fb9cc2513d8d64827970da6#pre-provisioned-readonly##pre-provisioned-readonly#azurefile-60) context(map[]) mountflags([]) mountOptions([AZURE\fb9cc2513d8d64827970da6]) volumeMountGroup() I0104 10:52:56.046125 9416 safe_mounter_windows.go:163] IsLikelyNotMountPoint: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\azurefile-60-file.csi.azure.com-preprovsioned-pv-xlpkt\globalmount I0104 10:52:56.046125 9416 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\azurefile-60-file.csi.azure.com-preprovsioned-pv-xlpkt\globalmount I0104 10:52:56.047139 9416 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\azurefile-60-file.csi.azure.com-preprovsioned-pv-xlpkt\globalmount I0104 10:52:56.047636 9416 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\azurefile-60-file.csi.azure.com-preprovsioned-pv-xlpkt\globalmount ... skipping 359 lines ... I0104 10:55:23.866971 9416 nodeserver.go:393] NodeUnstageVolume: CleanupMountPoint volume capz-fkqvhq#fb9cc2513d8d64827970da6#pre-provisioned-provided-credentials##pre-provisioned-provided-credentials#azurefile-6443 on \var\lib\kubelet\plugins\kubernetes.io\csi\pv\azurefile-6443-file.csi.azure.com-preprovsioned-pv-drv4f\proxy-mount I0104 10:55:23.866971 9416 safe_mounter_windows.go:133] Remove directory: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\azurefile-6443-file.csi.azure.com-preprovsioned-pv-drv4f\proxy-mount I0104 10:55:23.867476 9416 nodeserver.go:397] NodeUnstageVolume: unmount volume capz-fkqvhq#fb9cc2513d8d64827970da6#pre-provisioned-provided-credentials##pre-provisioned-provided-credentials#azurefile-6443 on \var\lib\kubelet\plugins\kubernetes.io\csi\pv\azurefile-6443-file.csi.azure.com-preprovsioned-pv-drv4f\globalmount successfully I0104 10:55:23.867476 9416 utils.go:83] GRPC response: {} I0104 10:55:28.071537 9416 utils.go:76] GRPC call: /csi.v1.Node/NodeStageVolume I0104 10:55:28.071537 9416 utils.go:77] GRPC request: {"staging_target_path":"\\var\\lib\\kubelet\\plugins\\kubernetes.io\\csi\\pv\\pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca\\globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["dir_mode=0777","file_mode=0777","mfsymlinks","cache=strict","nosharesock","actimeo=30"]}},"access_mode":{"mode":5}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca","csi.storage.k8s.io/pvc/name":"pvc-azurefile","csi.storage.k8s.io/pvc/namespace":"default","secretnamespace":"default","skuName":"Premium_LRS","storage.kubernetes.io/csiProvisionerIdentity":"1672827869886-8081-file.csi.azure.com"},"volume_id":"capz-fkqvhq#f7546d8fb366744099846f9#pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca###default"} W0104 10:55:28.071537 9416 azurefile.go:668] GetStorageAccountFromSecret(azure-storage-account-f7546d8fb366744099846f9-secret, default) failed with error: could not get account key from secret(azure-storage-account-f7546d8fb366744099846f9-secret): KubeClient is nil I0104 10:55:28.071537 9416 azurefile.go:670] use cluster identity to get account key from (0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e, capz-fkqvhq, f7546d8fb366744099846f9) I0104 10:55:28.453635 9416 nodeserver.go:302] cifsMountPath(\var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca\globalmount) fstype() volumeID(capz-fkqvhq#f7546d8fb366744099846f9#pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca###default) context(map[csi.storage.k8s.io/pv/name:pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca csi.storage.k8s.io/pvc/name:pvc-azurefile csi.storage.k8s.io/pvc/namespace:default secretnamespace:default skuName:Premium_LRS storage.kubernetes.io/csiProvisionerIdentity:1672827869886-8081-file.csi.azure.com]) mountflags([dir_mode=0777 file_mode=0777 mfsymlinks cache=strict nosharesock actimeo=30]) mountOptions([AZURE\f7546d8fb366744099846f9]) volumeMountGroup() I0104 10:55:28.453635 9416 safe_mounter_windows.go:163] IsLikelyNotMountPoint: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca\globalmount I0104 10:55:28.453635 9416 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca\globalmount I0104 10:55:28.454510 9416 safe_mounter_windows.go:220] Exists path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca\globalmount I0104 10:55:28.455021 9416 azure_common_windows.go:73] Removing path: \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-903e0341-26d5-4c0c-a217-c4d56c8273ca\globalmount ... skipping 52 lines ... Git Commit: b97b1825130f9837731ff25fd878281b0d2288a3 Go Version: go1.18.3 Platform: windows/amd64 Streaming logs below: I0104 10:52:43.054534 7248 azurefile.go:299] driver userAgent: file.csi.azure.com/v1.24.0 W0104 10:52:43.055879 7248 azure.go:73] get kubeconfig(C:\\k\\config) failed with error: CreateFile C:\\k\\config: The system cannot find the file specified. I0104 10:52:43.056753 7248 azure.go:92] could not read cloud config from secret kube-system/azure-cloud-provider I0104 10:52:43.056753 7248 azure.go:102] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json I0104 10:52:43.056753 7248 azure.go:110] read cloud config from file: C:\k\azure.json successfully I0104 10:52:43.062593 7248 azure_auth.go:245] Using AzurePublicCloud environment I0104 10:52:43.063818 7248 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token I0104 10:52:43.066661 7248 azure_diskclient.go:68] Azure DisksClient using API version: 2022-03-02 ... skipping 448 lines ... # HELP go_gc_heap_objects_objects Number of objects, live or unswept, occupying heap memory. # TYPE go_gc_heap_objects_objects gauge go_gc_heap_objects_objects 52005 # HELP go_gc_heap_tiny_allocs_objects_total Count of small allocations that are packed together into blocks. These allocations are counted separately from other allocations because each individual allocation is not tracked by the runtime, only their block. Each block is already accounted for in allocs-by-size and frees-by-size. # TYPE go_gc_heap_tiny_allocs_objects_total counter go_gc_heap_tiny_allocs_objects_total 19416 # HELP go_gc_limiter_last_enabled_gc_cycle GC cycle the last time the GC CPU limiter was enabled. This metric is useful for diagnosing the root cause of an out-of-memory error, because the limiter trades memory for CPU time when the GC's CPU time gets too high. This is most likely to occur with use of SetMemoryLimit. The first GC cycle is cycle 1, so a value of 0 indicates that it was never enabled. # TYPE go_gc_limiter_last_enabled_gc_cycle gauge go_gc_limiter_last_enabled_gc_cycle 0 # HELP go_gc_pauses_seconds Distribution individual GC-related stop-the-world pause latencies. # TYPE go_gc_pauses_seconds histogram go_gc_pauses_seconds_bucket{le="9.999999999999999e-10"} 0 go_gc_pauses_seconds_bucket{le="9.999999999999999e-09"} 0 ... skipping 252 lines ... [1mSTEP:[0m GetAccountNumByResourceGroup(capz-fkqvhq) returns 7 accounts [38;5;243m01/04/23 10:56:03.122[0m [38;5;243m<< End Captured GinkgoWriter Output[0m [38;5;243m------------------------------[0m [38;5;9m[1mSummarizing 1 Failure:[0m [38;5;9m[FAIL][0m [0mDynamic Provisioning [38;5;243m[38;5;9m[1m[It] should create multiple PV objects, bind to PVCs and attach all to different pods on the same node [kubernetes.io/azure-file] [file.csi.azure.com] [Windows][0m[0m [38;5;243m/home/prow/go/src/sigs.k8s.io/azurefile-csi-driver/test/e2e/testsuites/testsuites.go:292[0m [38;5;9m[1mRan 22 of 38 Specs in 1936.149 seconds[0m [38;5;9m[1mFAIL![0m -- [38;5;10m[1m21 Passed[0m | [38;5;9m[1m1 Failed[0m | [38;5;11m[1m0 Pending[0m | [38;5;14m[1m16 Skipped[0m [38;5;228mYou're using deprecated Ginkgo functionality:[0m [38;5;228m=============================================[0m [38;5;11mSupport for custom reporters has been removed in V2. Please read the documentation linked to below for Ginkgo's new behavior and for a migration path:[0m [1mLearn more at:[0m [38;5;14m[4mhttps://onsi.github.io/ginkgo/MIGRATING_TO_V2#removed-custom-reporters[0m [38;5;243mTo silence deprecations that can be silenced set the following environment variable:[0m [38;5;243mACK_GINKGO_DEPRECATIONS=2.4.0[0m --- FAIL: TestE2E (1936.15s) FAIL FAIL sigs.k8s.io/azurefile-csi-driver/test/e2e 1936.219s FAIL make: *** [Makefile:85: e2e-test] Error 1 NAME STATUS ROLES AGE VERSION INTERNAL-IP EXTERNAL-IP OS-IMAGE KERNEL-VERSION CONTAINER-RUNTIME capz-fkqv-cgjvz Ready <none> 35m v1.23.16-rc.0.37+548d5d2298c4a5 10.1.0.4 <none> Windows Server 2019 Datacenter 10.0.17763.3770 containerd://1.6.2 capz-fkqv-wljrl Ready <none> 34m v1.23.16-rc.0.37+548d5d2298c4a5 10.1.0.5 <none> Windows Server 2019 Datacenter 10.0.17763.3770 containerd://1.6.2 capz-fkqvhq-control-plane-pv9wj Ready control-plane,master 46m v1.23.16-rc.0.37+548d5d2298c4a5 10.0.0.4 <none> Ubuntu 18.04.6 LTS 5.4.0-1098-azure containerd://1.6.2 NAMESPACE NAME READY STATUS RESTARTS AGE IP NODE NOMINATED NODE READINESS GATES azurefile-5466 azurefile-volume-tester-qfcjj 0/1 Terminating 0 21m <none> capz-fkqv-cgjvz <none> <none> ... skipping 32 lines ... Jan 4 10:57:55.425: INFO: Collecting logs for Windows node capz-fkqv-cgjvz in cluster capz-fkqvhq in namespace default Jan 4 10:59:46.204: INFO: Attempting to copy file /c:/crashdumps.tar on node capz-fkqv-cgjvz to /logs/artifacts/clusters/capz-fkqvhq/machines/capz-fkqvhq-md-win-86879667d4-7nfmq/crashdumps.tar Jan 4 10:59:48.495: INFO: Collecting boot logs for AzureMachine capz-fkqvhq-md-win-cgjvz Failed to get logs for machine capz-fkqvhq-md-win-86879667d4-7nfmq, cluster default/capz-fkqvhq: running command "$p = 'c:\localdumps' ; if (Test-Path $p) { tar.exe -cvzf c:\crashdumps.tar $p *>&1 | %{ Write-Output "$_"} } else { Write-Host "No crash dumps found at $p" }": Process exited with status 1 Jan 4 10:59:49.758: INFO: Collecting logs for Windows node capz-fkqv-wljrl in cluster capz-fkqvhq in namespace default Jan 4 11:01:33.241: INFO: Attempting to copy file /c:/crashdumps.tar on node capz-fkqv-wljrl to /logs/artifacts/clusters/capz-fkqvhq/machines/capz-fkqvhq-md-win-86879667d4-xt5cw/crashdumps.tar Jan 4 11:01:35.441: INFO: Collecting boot logs for AzureMachine capz-fkqvhq-md-win-wljrl Failed to get logs for machine capz-fkqvhq-md-win-86879667d4-xt5cw, cluster default/capz-fkqvhq: running command "$p = 'c:\localdumps' ; if (Test-Path $p) { tar.exe -cvzf c:\crashdumps.tar $p *>&1 | %{ Write-Output "$_"} } else { Write-Host "No crash dumps found at $p" }": Process exited with status 1 [1mSTEP[0m: Dumping workload cluster default/capz-fkqvhq kube-system pod logs [1mSTEP[0m: Collecting events for Pod kube-system/calico-kube-controllers-85f479877b-mgw6v [1mSTEP[0m: Fetching kube-system pod logs took 675.63175ms [1mSTEP[0m: Dumping workload cluster default/capz-fkqvhq Azure activity log [1mSTEP[0m: Collecting events for Pod kube-system/csi-proxy-c6cb7 [1mSTEP[0m: Creating log watcher for controller kube-system/calico-kube-controllers-85f479877b-mgw6v, container calico-kube-controllers ... skipping 4 lines ... [1mSTEP[0m: Creating log watcher for controller kube-system/csi-proxy-wvq78, container csi-proxy [1mSTEP[0m: Collecting events for Pod kube-system/calico-node-mxnxh [1mSTEP[0m: Collecting events for Pod kube-system/containerd-logger-6xkmn [1mSTEP[0m: Creating log watcher for controller kube-system/calico-node-windows-qr2lt, container calico-node-startup [1mSTEP[0m: Creating log watcher for controller kube-system/calico-node-windows-qr2lt, container calico-node-felix [1mSTEP[0m: Collecting events for Pod kube-system/kube-scheduler-capz-fkqvhq-control-plane-pv9wj [1mSTEP[0m: failed to find events of Pod "kube-scheduler-capz-fkqvhq-control-plane-pv9wj" [1mSTEP[0m: Collecting events for Pod kube-system/kube-proxy-windows-b9trg [1mSTEP[0m: Creating log watcher for controller kube-system/kube-proxy-windows-hjgvg, container kube-proxy [1mSTEP[0m: Collecting events for Pod kube-system/calico-node-windows-qr2lt [1mSTEP[0m: Creating log watcher for controller kube-system/calico-node-windows-r7h6k, container calico-node-startup [1mSTEP[0m: Collecting events for Pod kube-system/kube-proxy-windows-hjgvg [1mSTEP[0m: Creating log watcher for controller kube-system/kube-scheduler-capz-fkqvhq-control-plane-pv9wj, container kube-scheduler ... skipping 13 lines ... [1mSTEP[0m: Collecting events for Pod kube-system/coredns-bd6b6df9f-ccs7h [1mSTEP[0m: Creating log watcher for controller kube-system/etcd-capz-fkqvhq-control-plane-pv9wj, container etcd [1mSTEP[0m: Collecting events for Pod kube-system/csi-proxy-wvq78 [1mSTEP[0m: Collecting events for Pod kube-system/kube-controller-manager-capz-fkqvhq-control-plane-pv9wj [1mSTEP[0m: Collecting events for Pod kube-system/etcd-capz-fkqvhq-control-plane-pv9wj [1mSTEP[0m: Creating log watcher for controller kube-system/csi-proxy-c6cb7, container csi-proxy [1mSTEP[0m: failed to find events of Pod "etcd-capz-fkqvhq-control-plane-pv9wj" [1mSTEP[0m: failed to find events of Pod "kube-apiserver-capz-fkqvhq-control-plane-pv9wj" [1mSTEP[0m: failed to find events of Pod "kube-controller-manager-capz-fkqvhq-control-plane-pv9wj" [1mSTEP[0m: Fetching activity logs took 8.353370221s ================ REDACTING LOGS ================ All sensitive variables are redacted cluster.cluster.x-k8s.io "capz-fkqvhq" deleted /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kind-v0.14.0 delete cluster --name=capz || true Deleting cluster "capz" ... ... skipping 12 lines ...