kubernetes-sigs/azuredisk-csi-driver PR #1359 pull-azuredisk-csi-driver-e2e-capz-windows-2022 #1532808586315436032
Recent runs || View in Spyglass
Recent runs || View in Spyglass
| PR | jackfrancis: do-not-merge func main comment |
| Result | FAILURE |
| Tests | 0 failed / 0 succeeded |
| Started | |
| Elapsed | 2h15m |
| Revision | fa06ff44036ca43a3c6f75ad053eec797aaeaab9 |
| Refs |
1359 |
... skipping 676 lines ... certificate.cert-manager.io "selfsigned-cert" deleted # Create secret for AzureClusterIdentity ./hack/create-identity-secret.sh make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure' make[2]: Nothing to be done for 'kubectl'. make[2]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure' Error from server (NotFound): secrets "cluster-identity-secret" not found secret/cluster-identity-secret created secret/cluster-identity-secret labeled # Deploy CAPI curl --retry 3 -sSL https://github.com/kubernetes-sigs/cluster-api/releases/download/v1.1.2/cluster-api-components.yaml | /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/envsubst-v2.0.0-20210730161058-179042472c46 | kubectl apply -f - namespace/capi-system created customresourcedefinition.apiextensions.k8s.io/clusterclasses.cluster.x-k8s.io created ... skipping 1032 lines ... image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.4.0" args: - "-csi-address=$(ADDRESS)" - "-v=2" - "-leader-election" - "--leader-election-namespace=kube-system" - '-handle-volume-inuse-error=false' - '-feature-gates=RecoverVolumeExpansionFailure=true' - "-timeout=240s" env: - name: ADDRESS value: /csi/csi.sock volumeMounts: ... skipping 154 lines ... Jun 3 19:55:59.721: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-n4gll] to have phase Bound Jun 3 19:55:59.776: INFO: PersistentVolumeClaim pvc-n4gll found and phase=Bound (54.328586ms) [1mSTEP[0m: checking the PVC [1mSTEP[0m: validating provisioned PV [1mSTEP[0m: checking the PV [1mSTEP[0m: deploying the pod [1mSTEP[0m: checking that the pod's command exits with an error Jun 3 19:55:59.951: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-k4t6t" in namespace "azuredisk-8081" to be "Error status code" Jun 3 19:56:00.006: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 54.827643ms Jun 3 19:56:02.060: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 2.10959701s Jun 3 19:56:04.116: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164779863s Jun 3 19:56:06.172: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 6.221513875s Jun 3 19:56:08.228: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 8.277402103s Jun 3 19:56:10.284: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 10.333558534s ... skipping 427 lines ... Jun 3 20:10:50.668: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.716757953s Jun 3 20:10:52.724: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.773527997s Jun 3 20:10:54.779: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.828518125s Jun 3 20:10:56.835: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.884019815s Jun 3 20:10:58.890: INFO: Pod "azuredisk-volume-tester-k4t6t": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.939357152s Jun 3 20:11:00.891: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-k4t6t" Jun 3 20:11:00.971: INFO: Error getting logs for pod azuredisk-volume-tester-k4t6t: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-k4t6t) [1mSTEP[0m: Deleting pod azuredisk-volume-tester-k4t6t in namespace azuredisk-8081 Jun 3 20:11:01.028: INFO: deleting PVC "azuredisk-8081"/"pvc-n4gll" Jun 3 20:11:01.028: INFO: Deleting PersistentVolumeClaim "pvc-n4gll" Jun 3 20:11:01.086: INFO: Waiting up to 5m0s for PersistentVolumeClaim azuredisk-8081 to be removed Jun 3 20:11:01.140: INFO: Claim "azuredisk-8081" in namespace "pvc-n4gll" doesn't exist in the system [1mSTEP[0m: deleting PV "azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-dv264" ... skipping 7 lines ... Jun 3 20:11:21.480: INFO: PersistentVolume azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-dv264 was removed [1mSTEP[0m: Collecting events from namespace "azuredisk-8081". [1mSTEP[0m: Found 5 events. Jun 3 20:11:21.536: INFO: At 2022-06-03 19:55:59 +0000 UTC - event for azuredisk-volume-tester-k4t6t: {default-scheduler } Scheduled: Successfully assigned azuredisk-8081/azuredisk-volume-tester-k4t6t to capz-52wf-65w45 Jun 3 20:11:21.536: INFO: At 2022-06-03 19:56:11 +0000 UTC - event for azuredisk-volume-tester-k4t6t: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-dv264" Jun 3 20:11:21.536: INFO: At 2022-06-03 19:56:47 +0000 UTC - event for azuredisk-volume-tester-k4t6t: {kubelet capz-52wf-65w45} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 20:11:21.536: INFO: At 2022-06-03 19:56:47 +0000 UTC - event for azuredisk-volume-tester-k4t6t: {kubelet capz-52wf-65w45} Failed: Error: ErrImagePull Jun 3 20:11:21.536: INFO: At 2022-06-03 19:56:48 +0000 UTC - event for azuredisk-volume-tester-k4t6t: {kubelet capz-52wf-65w45} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 20:11:21.590: INFO: POD NODE PHASE GRACE CONDITIONS Jun 3 20:11:21.590: INFO: Jun 3 20:11:21.697: INFO: Logging node info for node capz-52wf-65w45 Jun 3 20:11:21.751: INFO: Node Info: &Node{ObjectMeta:{capz-52wf-65w45 5d8749d6-e04e-4513-a6b0-3c548b20c4fe 3649 0 2022-06-03 19:52:05 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:westus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-52wf-65w45 kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.17763 topology.disk.csi.azure.com/zone: topology.kubernetes.io/region:westus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-52wfkn cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-52wfkn-md-win-5f9c49f686-g7dj2 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-52wfkn-md-win-5f9c49f686 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-52wf-65w45"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.4/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.39.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:1a:63:c4 volumes.kubernetes.io/controller-managed-attach-detach:true] [] [] [{kubelet.exe Update v1 2022-06-03 19:52:05 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-03 19:52:06 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kube-controller-manager Update v1 2022-06-03 19:52:16 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-06-03 19:53:26 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:cluster.x-k8s.io/cluster-name":{},"f:cluster.x-k8s.io/cluster-namespace":{},"f:cluster.x-k8s.io/machine":{},"f:cluster.x-k8s.io/owner-kind":{},"f:cluster.x-k8s.io/owner-name":{}}}} } {Go-http-client Update v1 2022-06-03 19:53:49 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {kubelet.exe Update v1 2022-06-03 20:11:09 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{}},"f:labels":{"f:topology.disk.csi.azure.com/zone":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"DiskPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"MemoryPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"PIDPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"Ready\"}":{"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{}}},"f:images":{}}} status}]},Spec:NodeSpec{PodCIDR:,DoNotUseExternalID:,ProviderID:azure:///subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/virtualMachines/capz-52wf-65w45,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{136912564224 0} {<nil>} 133703676Ki BinarySI},memory: {{17179398144 0} {<nil>} 16776756Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{123221307598 0} {<nil>} 123221307598 DecimalSI},memory: {{17074540544 0} {<nil>} 16674356Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-06-03 20:11:09 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-03 20:11:09 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-03 20:11:09 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-03 20:11:09 +0000 UTC,LastTransitionTime:2022-06-03 19:53:17 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-52wf-65w45,},NodeAddress{Type:InternalIP,Address:10.1.0.4,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-52wf-65w45,SystemUUID:C2889A5E-6D91-43FC-A74C-95084D6382D3,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},} ... skipping 88 lines ... [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:37[0m [single-az] [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:69[0m [91m[1mshould use a pre-provisioned volume and mount it as readOnly in a pod [disk.csi.azure.com][windows] [It][0m [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:70[0m [91mUnexpected error: <*errors.errorString | 0xc000c911b0>: { s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-k4t6t\" to be \"Error status code\"", } Gave up after waiting 15m0s for pod "azuredisk-volume-tester-k4t6t" to be "Error status code" occurred[0m /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:844 [90m------------------------------[0m [0mPre-Provisioned[0m [90m[single-az][0m [1mshould use a pre-provisioned volume and retain PV with reclaimPolicy "Retain" [disk.csi.azure.com][windows][0m ... skipping 51 lines ... Jun 3 20:11:33.597: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready [1mSTEP[0m: Destroying namespace "azuredisk-4728" for this suite. [32m•[0m [90m------------------------------[0m [0mPre-Provisioned[0m [90m[single-az][0m [1mshould fail when maxShares is invalid [disk.csi.azure.com][windows][0m [37m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:163[0m [1mSTEP[0m: Creating a kubernetes client Jun 3 20:11:34.584: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig [1mSTEP[0m: Building a namespace api object, basename azuredisk [1mSTEP[0m: Waiting for a default service account to be provisioned in namespace [1mSTEP[0m: Waiting for kube-root-ca.crt to be provisioned in namespace ... skipping 46 lines ... Jun 3 20:11:45.072: INFO: PersistentVolumeClaim pvc-qfnvc found and phase=Bound (53.952121ms) [1mSTEP[0m: checking the PVC [1mSTEP[0m: validating provisioned PV [1mSTEP[0m: checking the PV [1mSTEP[0m: attaching disk to node#0 [1mSTEP[0m: deploying the pod [1mSTEP[0m: checking that the pod's command exits with no error Jun 3 20:11:57.982: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-9c96b" in namespace "azuredisk-5356" to be "Succeeded or Failed" Jun 3 20:11:58.036: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 54.106727ms Jun 3 20:12:00.108: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 2.125994996s Jun 3 20:12:02.164: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 4.181780469s Jun 3 20:12:04.219: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 6.237299922s Jun 3 20:12:06.274: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 8.292293073s Jun 3 20:12:08.330: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 10.348519402s ... skipping 427 lines ... Jun 3 20:26:49.189: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 14m51.207235627s Jun 3 20:26:51.244: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 14m53.26194867s Jun 3 20:26:53.299: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 14m55.317031359s Jun 3 20:26:55.354: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 14m57.371604111s Jun 3 20:26:57.409: INFO: Pod "azuredisk-volume-tester-9c96b": Phase="Pending", Reason="", readiness=false. Elapsed: 14m59.426789005s Jun 3 20:26:59.410: INFO: deleting Pod "azuredisk-5356"/"azuredisk-volume-tester-9c96b" Jun 3 20:26:59.490: INFO: Error getting logs for pod azuredisk-volume-tester-9c96b: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-9c96b) [1mSTEP[0m: Deleting pod azuredisk-volume-tester-9c96b in namespace azuredisk-5356 Jun 3 20:26:59.660: INFO: deleting PVC "azuredisk-5356"/"pvc-qfnvc" Jun 3 20:26:59.660: INFO: Deleting PersistentVolumeClaim "pvc-qfnvc" Jun 3 20:26:59.714: INFO: Waiting up to 5m0s for PersistentVolumeClaim azuredisk-5356 to be removed Jun 3 20:26:59.769: INFO: Claim "azuredisk-5356" in namespace "pvc-qfnvc" doesn't exist in the system [1mSTEP[0m: deleting PV "azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-gtbd9" ... skipping 6 lines ... Jun 3 20:27:15.046: INFO: PersistentVolume azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-gtbd9 found and phase=Released (15.221606108s) Jun 3 20:27:20.106: INFO: PersistentVolume azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-gtbd9 found and phase=Released (20.281613126s) Jun 3 20:27:25.160: INFO: PersistentVolume azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-gtbd9 was removed [1mSTEP[0m: Collecting events from namespace "azuredisk-5356". [1mSTEP[0m: Found 6 events. Jun 3 20:27:25.214: INFO: At 2022-06-03 20:11:57 +0000 UTC - event for azuredisk-volume-tester-9c96b: {default-scheduler } Scheduled: Successfully assigned azuredisk-5356/azuredisk-volume-tester-9c96b to capz-52wf-q78cs Jun 3 20:27:25.214: INFO: At 2022-06-03 20:12:14 +0000 UTC - event for azuredisk-volume-tester-9c96b: {attachdetach-controller } FailedAttachVolume: AttachVolume.Attach failed for volume "azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-gtbd9" : rpc error: code = Unknown desc = Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/disks/reattach-disk-multiple-nodes to instance capz-52wf-q78cs failed with disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/disks/reattach-disk-multiple-nodes) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/virtualMachines/capz-52wf-65w45), could not be attached to node(capz-52wf-q78cs) Jun 3 20:27:25.214: INFO: At 2022-06-03 20:12:32 +0000 UTC - event for azuredisk-volume-tester-9c96b: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-gtbd9" Jun 3 20:27:25.214: INFO: At 2022-06-03 20:13:09 +0000 UTC - event for azuredisk-volume-tester-9c96b: {kubelet capz-52wf-q78cs} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 20:27:25.214: INFO: At 2022-06-03 20:13:09 +0000 UTC - event for azuredisk-volume-tester-9c96b: {kubelet capz-52wf-q78cs} Failed: Error: ErrImagePull Jun 3 20:27:25.214: INFO: At 2022-06-03 20:13:09 +0000 UTC - event for azuredisk-volume-tester-9c96b: {kubelet capz-52wf-q78cs} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 20:27:25.268: INFO: POD NODE PHASE GRACE CONDITIONS Jun 3 20:27:25.268: INFO: Jun 3 20:27:25.373: INFO: Logging node info for node capz-52wf-65w45 Jun 3 20:27:25.426: INFO: Node Info: &Node{ObjectMeta:{capz-52wf-65w45 5d8749d6-e04e-4513-a6b0-3c548b20c4fe 5886 0 2022-06-03 19:52:05 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:westus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-52wf-65w45 kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.17763 topology.disk.csi.azure.com/zone: topology.kubernetes.io/region:westus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-52wfkn cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-52wfkn-md-win-5f9c49f686-g7dj2 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-52wfkn-md-win-5f9c49f686 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-52wf-65w45"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.4/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.39.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:1a:63:c4 volumes.kubernetes.io/controller-managed-attach-detach:true] [] [] [{kubelet.exe Update v1 2022-06-03 19:52:05 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-03 19:52:06 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {manager Update v1 2022-06-03 19:53:26 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:cluster.x-k8s.io/cluster-name":{},"f:cluster.x-k8s.io/cluster-namespace":{},"f:cluster.x-k8s.io/machine":{},"f:cluster.x-k8s.io/owner-kind":{},"f:cluster.x-k8s.io/owner-name":{}}}} } {Go-http-client Update v1 2022-06-03 19:53:49 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {kubelet.exe Update v1 2022-06-03 20:11:09 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{}},"f:labels":{"f:topology.disk.csi.azure.com/zone":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"DiskPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"MemoryPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"PIDPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"Ready\"}":{"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{}}},"f:images":{}}} status} {kube-controller-manager Update v1 2022-06-03 20:11:57 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} }]},Spec:NodeSpec{PodCIDR:,DoNotUseExternalID:,ProviderID:azure:///subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/virtualMachines/capz-52wf-65w45,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{136912564224 0} {<nil>} 133703676Ki BinarySI},memory: {{17179398144 0} {<nil>} 16776756Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{123221307598 0} {<nil>} 123221307598 DecimalSI},memory: {{17074540544 0} {<nil>} 16674356Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-06-03 20:26:30 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-03 20:26:30 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-03 20:26:30 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-03 20:26:30 +0000 UTC,LastTransitionTime:2022-06-03 19:53:17 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-52wf-65w45,},NodeAddress{Type:InternalIP,Address:10.1.0.4,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-52wf-65w45,SystemUUID:C2889A5E-6D91-43FC-A74C-95084D6382D3,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},} ... skipping 88 lines ... [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:37[0m [single-az] [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:69[0m [91m[1mshould succeed when reattaching a disk to a new node on DanglingAttachError [disk.csi.azure.com] [It][0m [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:249[0m [91mUnexpected error: <*errors.errorString | 0xc0000fdf00>: { s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-9c96b\" to be \"Succeeded or Failed\"", } Gave up after waiting 15m0s for pod "azuredisk-volume-tester-9c96b" to be "Succeeded or Failed" occurred[0m /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:805 [90m------------------------------[0m [0mPre-Provisioned[0m [90m[single-az][0m [1mshould create an inline volume by in-tree driver [kubernetes.io/azure-disk][0m ... skipping 44 lines ... Jun 3 20:27:33.417: INFO: PersistentVolumeClaim pvc-gmcpm found and phase=Bound (4.163702298s) [1mSTEP[0m: checking the PVC [1mSTEP[0m: validating provisioned PV [1mSTEP[0m: checking the PV [1mSTEP[0m: setting up the pod [1mSTEP[0m: deploying the pod [1mSTEP[0m: checking that the pod's command exits with no error Jun 3 20:27:33.580: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-7vczn" in namespace "azuredisk-1353" to be "Succeeded or Failed" Jun 3 20:27:33.638: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 57.372706ms Jun 3 20:27:35.692: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.112049068s Jun 3 20:27:37.747: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.16684527s Jun 3 20:27:39.801: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.220927005s Jun 3 20:27:41.855: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.27490103s Jun 3 20:27:43.911: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.330473905s ... skipping 427 lines ... Jun 3 20:42:23.667: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.087202035s Jun 3 20:42:25.722: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.142106883s Jun 3 20:42:27.778: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.1981882s Jun 3 20:42:29.835: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.254808639s Jun 3 20:42:31.891: INFO: Pod "azuredisk-volume-tester-7vczn": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.310746447s Jun 3 20:42:33.893: INFO: deleting Pod "azuredisk-1353"/"azuredisk-volume-tester-7vczn" Jun 3 20:42:33.967: INFO: Error getting logs for pod azuredisk-volume-tester-7vczn: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-7vczn) [1mSTEP[0m: Deleting pod azuredisk-volume-tester-7vczn in namespace azuredisk-1353 Jun 3 20:42:34.027: INFO: deleting PVC "azuredisk-1353"/"pvc-gmcpm" Jun 3 20:42:34.027: INFO: Deleting PersistentVolumeClaim "pvc-gmcpm" [1mSTEP[0m: waiting for claim's PV "pvc-dadbc5d9-846d-48ad-b143-08fd75d1d9c1" to be deleted Jun 3 20:42:34.083: INFO: Waiting up to 10m0s for PersistentVolume pvc-dadbc5d9-846d-48ad-b143-08fd75d1d9c1 to get deleted Jun 3 20:42:34.138: INFO: PersistentVolume pvc-dadbc5d9-846d-48ad-b143-08fd75d1d9c1 found and phase=Bound (54.856689ms) ... skipping 13 lines ... [1mSTEP[0m: Found 9 events. Jun 3 20:43:19.814: INFO: At 2022-06-03 20:27:29 +0000 UTC - event for pvc-gmcpm: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator Jun 3 20:43:19.814: INFO: At 2022-06-03 20:27:29 +0000 UTC - event for pvc-gmcpm: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } Provisioning: External provisioner is provisioning volume for claim "azuredisk-1353/pvc-gmcpm" Jun 3 20:43:19.814: INFO: At 2022-06-03 20:27:31 +0000 UTC - event for pvc-gmcpm: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } ProvisioningSucceeded: Successfully provisioned volume pvc-dadbc5d9-846d-48ad-b143-08fd75d1d9c1 Jun 3 20:43:19.814: INFO: At 2022-06-03 20:27:33 +0000 UTC - event for azuredisk-volume-tester-7vczn: {default-scheduler } Scheduled: Successfully assigned azuredisk-1353/azuredisk-volume-tester-7vczn to capz-52wf-q78cs Jun 3 20:43:19.814: INFO: At 2022-06-03 20:27:44 +0000 UTC - event for azuredisk-volume-tester-7vczn: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-dadbc5d9-846d-48ad-b143-08fd75d1d9c1" Jun 3 20:43:19.814: INFO: At 2022-06-03 20:28:16 +0000 UTC - event for azuredisk-volume-tester-7vczn: {kubelet capz-52wf-q78cs} Failed: Error: ErrImagePull Jun 3 20:43:19.814: INFO: At 2022-06-03 20:28:16 +0000 UTC - event for azuredisk-volume-tester-7vczn: {kubelet capz-52wf-q78cs} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 20:43:19.814: INFO: At 2022-06-03 20:28:17 +0000 UTC - event for azuredisk-volume-tester-7vczn: {kubelet capz-52wf-q78cs} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 20:43:19.814: INFO: At 2022-06-03 20:28:17 +0000 UTC - event for azuredisk-volume-tester-7vczn: {kubelet capz-52wf-q78cs} Failed: Error: ImagePullBackOff Jun 3 20:43:19.869: INFO: POD NODE PHASE GRACE CONDITIONS Jun 3 20:43:19.869: INFO: Jun 3 20:43:19.924: INFO: Logging node info for node capz-52wf-65w45 Jun 3 20:43:19.978: INFO: Node Info: &Node{ObjectMeta:{capz-52wf-65w45 5d8749d6-e04e-4513-a6b0-3c548b20c4fe 7954 0 2022-06-03 19:52:05 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:westus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-52wf-65w45 kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.17763 topology.disk.csi.azure.com/zone: topology.kubernetes.io/region:westus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-52wfkn cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-52wfkn-md-win-5f9c49f686-g7dj2 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-52wfkn-md-win-5f9c49f686 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-52wf-65w45"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.4/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.39.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:1a:63:c4 volumes.kubernetes.io/controller-managed-attach-detach:true] [] [] [{kubelet.exe Update v1 2022-06-03 19:52:05 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-03 19:52:06 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {manager Update v1 2022-06-03 19:53:26 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:cluster.x-k8s.io/cluster-name":{},"f:cluster.x-k8s.io/cluster-namespace":{},"f:cluster.x-k8s.io/machine":{},"f:cluster.x-k8s.io/owner-kind":{},"f:cluster.x-k8s.io/owner-name":{}}}} } {Go-http-client Update v1 2022-06-03 19:53:49 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {kubelet.exe Update v1 2022-06-03 20:11:09 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{}},"f:labels":{"f:topology.disk.csi.azure.com/zone":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"DiskPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"MemoryPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"PIDPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"Ready\"}":{"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{}}},"f:images":{}}} status} {kube-controller-manager Update v1 2022-06-03 20:11:57 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} }]},Spec:NodeSpec{PodCIDR:,DoNotUseExternalID:,ProviderID:azure:///subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/virtualMachines/capz-52wf-65w45,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{136912564224 0} {<nil>} 133703676Ki BinarySI},memory: {{17179398144 0} {<nil>} 16776756Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{123221307598 0} {<nil>} 123221307598 DecimalSI},memory: {{17074540544 0} {<nil>} 16674356Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-06-03 20:41:49 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-03 20:41:49 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-03 20:41:49 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-03 20:41:49 +0000 UTC,LastTransitionTime:2022-06-03 19:53:17 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-52wf-65w45,},NodeAddress{Type:InternalIP,Address:10.1.0.4,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-52wf-65w45,SystemUUID:C2889A5E-6D91-43FC-A74C-95084D6382D3,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},} Jun 3 20:43:19.978: INFO: ... skipping 87 lines ... [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40[0m [single-az] [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43[0m [91m[1mshould create a volume on demand with mount options [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] [It][0m [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:101[0m [91mUnexpected error: <*errors.errorString | 0xc0006885e0>: { s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-7vczn\" to be \"Succeeded or Failed\"", } Gave up after waiting 15m0s for pod "azuredisk-volume-tester-7vczn" to be "Succeeded or Failed" occurred[0m /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:805 [90m------------------------------[0m [0mDynamic Provisioning[0m [90m[single-az][0m [1mshould create a pod with volume mount subpath [disk.csi.azure.com] [Windows][0m ... skipping 19 lines ... Jun 3 20:43:24.389: INFO: PersistentVolumeClaim pvc-bb7n2 found but phase is Pending instead of Bound. Jun 3 20:43:26.445: INFO: PersistentVolumeClaim pvc-bb7n2 found and phase=Bound (4.169378512s) [1mSTEP[0m: checking the PVC [1mSTEP[0m: validating provisioned PV [1mSTEP[0m: checking the PV [1mSTEP[0m: deploying the pod [1mSTEP[0m: checking that the pods command exits with no error Jun 3 20:43:26.620: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-dzmf7" in namespace "azuredisk-2888" to be "Succeeded or Failed" Jun 3 20:43:26.677: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 56.813421ms Jun 3 20:43:28.731: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.111605975s Jun 3 20:43:30.793: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.173621711s Jun 3 20:43:32.850: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.229776456s Jun 3 20:43:34.904: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.284511019s Jun 3 20:43:36.960: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 10.340091378s ... skipping 427 lines ... Jun 3 20:58:16.860: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.24014284s Jun 3 20:58:18.915: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.295407411s Jun 3 20:58:20.970: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.350147323s Jun 3 20:58:23.024: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.404561956s Jun 3 20:58:25.079: INFO: Pod "azuredisk-volume-tester-dzmf7": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.459330678s Jun 3 20:58:27.081: INFO: deleting Pod "azuredisk-2888"/"azuredisk-volume-tester-dzmf7" Jun 3 20:58:27.154: INFO: Error getting logs for pod azuredisk-volume-tester-dzmf7: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-dzmf7) [1mSTEP[0m: Deleting pod azuredisk-volume-tester-dzmf7 in namespace azuredisk-2888 Jun 3 20:58:27.212: INFO: deleting PVC "azuredisk-2888"/"pvc-bb7n2" Jun 3 20:58:27.212: INFO: Deleting PersistentVolumeClaim "pvc-bb7n2" [1mSTEP[0m: waiting for claim's PV "pvc-82411a75-c820-4c23-8df9-e563bc7af043" to be deleted Jun 3 20:58:27.268: INFO: Waiting up to 10m0s for PersistentVolume pvc-82411a75-c820-4c23-8df9-e563bc7af043 to get deleted Jun 3 20:58:27.322: INFO: PersistentVolume pvc-82411a75-c820-4c23-8df9-e563bc7af043 found and phase=Bound (53.855686ms) ... skipping 13 lines ... [1mSTEP[0m: Found 9 events. Jun 3 20:59:13.001: INFO: At 2022-06-03 20:43:22 +0000 UTC - event for pvc-bb7n2: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } Provisioning: External provisioner is provisioning volume for claim "azuredisk-2888/pvc-bb7n2" Jun 3 20:59:13.001: INFO: At 2022-06-03 20:43:22 +0000 UTC - event for pvc-bb7n2: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator Jun 3 20:59:13.001: INFO: At 2022-06-03 20:43:24 +0000 UTC - event for pvc-bb7n2: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } ProvisioningSucceeded: Successfully provisioned volume pvc-82411a75-c820-4c23-8df9-e563bc7af043 Jun 3 20:59:13.001: INFO: At 2022-06-03 20:43:26 +0000 UTC - event for azuredisk-volume-tester-dzmf7: {default-scheduler } Scheduled: Successfully assigned azuredisk-2888/azuredisk-volume-tester-dzmf7 to capz-52wf-q78cs Jun 3 20:59:13.001: INFO: At 2022-06-03 20:43:37 +0000 UTC - event for azuredisk-volume-tester-dzmf7: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-82411a75-c820-4c23-8df9-e563bc7af043" Jun 3 20:59:13.001: INFO: At 2022-06-03 20:44:09 +0000 UTC - event for azuredisk-volume-tester-dzmf7: {kubelet capz-52wf-q78cs} Failed: Failed to pull image "mcr.microsoft.com/windows/servercore:ltsc2022": rpc error: code = NotFound desc = failed to pull and unpack image "mcr.microsoft.com/windows/servercore:ltsc2022": no match for platform in manifest: not found Jun 3 20:59:13.001: INFO: At 2022-06-03 20:44:09 +0000 UTC - event for azuredisk-volume-tester-dzmf7: {kubelet capz-52wf-q78cs} Failed: Error: ErrImagePull Jun 3 20:59:13.001: INFO: At 2022-06-03 20:44:09 +0000 UTC - event for azuredisk-volume-tester-dzmf7: {kubelet capz-52wf-q78cs} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 20:59:13.001: INFO: At 2022-06-03 20:44:09 +0000 UTC - event for azuredisk-volume-tester-dzmf7: {kubelet capz-52wf-q78cs} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 20:59:13.055: INFO: POD NODE PHASE GRACE CONDITIONS Jun 3 20:59:13.055: INFO: Jun 3 20:59:13.161: INFO: Logging node info for node capz-52wf-65w45 ... skipping 89 lines ... [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40[0m [single-az] [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43[0m [91m[1mshould create a pod with volume mount subpath [disk.csi.azure.com] [Windows] [It][0m [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:159[0m [91mUnexpected error: <*errors.errorString | 0xc000861020>: { s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-dzmf7\" to be \"Succeeded or Failed\"", } Gave up after waiting 15m0s for pod "azuredisk-volume-tester-dzmf7" to be "Succeeded or Failed" occurred[0m /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:805 [90m------------------------------[0m [0mDynamic Provisioning[0m [90m[single-az][0m [1mShould create and attach a volume with basic perfProfile [enableBursting][disk.csi.azure.com] [Windows][0m ... skipping 20 lines ... Jun 3 20:59:19.644: INFO: PersistentVolumeClaim pvc-szlp9 found and phase=Bound (4.167363379s) [1mSTEP[0m: checking the PVC [1mSTEP[0m: validating provisioned PV [1mSTEP[0m: checking the PV [1mSTEP[0m: setting up the pod [1mSTEP[0m: deploying the pod [1mSTEP[0m: checking that the pod's command exits with no error Jun 3 20:59:19.806: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-fpsxt" in namespace "azuredisk-156" to be "Succeeded or Failed" Jun 3 20:59:19.859: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 53.485461ms Jun 3 20:59:21.915: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108652465s Jun 3 20:59:23.970: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164133848s Jun 3 20:59:26.026: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.220390264s Jun 3 20:59:28.082: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.276405249s Jun 3 20:59:30.138: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.33212642s ... skipping 427 lines ... Jun 3 21:14:09.812: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.006196492s Jun 3 21:14:11.866: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.060459355s Jun 3 21:14:13.925: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.119454929s Jun 3 21:14:15.980: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.173605273s Jun 3 21:14:18.034: INFO: Pod "azuredisk-volume-tester-fpsxt": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.227858218s Jun 3 21:14:20.036: INFO: deleting Pod "azuredisk-156"/"azuredisk-volume-tester-fpsxt" Jun 3 21:14:20.105: INFO: Error getting logs for pod azuredisk-volume-tester-fpsxt: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-fpsxt) [1mSTEP[0m: Deleting pod azuredisk-volume-tester-fpsxt in namespace azuredisk-156 Jun 3 21:14:20.162: INFO: deleting PVC "azuredisk-156"/"pvc-szlp9" Jun 3 21:14:20.162: INFO: Deleting PersistentVolumeClaim "pvc-szlp9" [1mSTEP[0m: waiting for claim's PV "pvc-47d55ce8-e723-499e-b779-eee31c27afd2" to be deleted Jun 3 21:14:20.217: INFO: Waiting up to 10m0s for PersistentVolume pvc-47d55ce8-e723-499e-b779-eee31c27afd2 to get deleted Jun 3 21:14:20.271: INFO: PersistentVolume pvc-47d55ce8-e723-499e-b779-eee31c27afd2 found and phase=Bound (53.522274ms) ... skipping 14 lines ... Jun 3 21:15:05.949: INFO: At 2022-06-03 20:59:15 +0000 UTC - event for pvc-szlp9: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } Provisioning: External provisioner is provisioning volume for claim "azuredisk-156/pvc-szlp9" Jun 3 21:15:05.949: INFO: At 2022-06-03 20:59:15 +0000 UTC - event for pvc-szlp9: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator Jun 3 21:15:05.949: INFO: At 2022-06-03 20:59:17 +0000 UTC - event for pvc-szlp9: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } ProvisioningSucceeded: Successfully provisioned volume pvc-47d55ce8-e723-499e-b779-eee31c27afd2 Jun 3 21:15:05.949: INFO: At 2022-06-03 20:59:19 +0000 UTC - event for azuredisk-volume-tester-fpsxt: {default-scheduler } Scheduled: Successfully assigned azuredisk-156/azuredisk-volume-tester-fpsxt to capz-52wf-65w45 Jun 3 21:15:05.949: INFO: At 2022-06-03 20:59:31 +0000 UTC - event for azuredisk-volume-tester-fpsxt: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-47d55ce8-e723-499e-b779-eee31c27afd2" Jun 3 21:15:05.949: INFO: At 2022-06-03 21:00:02 +0000 UTC - event for azuredisk-volume-tester-fpsxt: {kubelet capz-52wf-65w45} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 21:15:05.949: INFO: At 2022-06-03 21:00:03 +0000 UTC - event for azuredisk-volume-tester-fpsxt: {kubelet capz-52wf-65w45} Failed: Error: ErrImagePull Jun 3 21:15:05.949: INFO: At 2022-06-03 21:00:03 +0000 UTC - event for azuredisk-volume-tester-fpsxt: {kubelet capz-52wf-65w45} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 21:15:06.002: INFO: POD NODE PHASE GRACE CONDITIONS Jun 3 21:15:06.002: INFO: Jun 3 21:15:06.107: INFO: Logging node info for node capz-52wf-65w45 Jun 3 21:15:06.162: INFO: Node Info: &Node{ObjectMeta:{capz-52wf-65w45 5d8749d6-e04e-4513-a6b0-3c548b20c4fe 12519 0 2022-06-03 19:52:05 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:westus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-52wf-65w45 kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.17763 topology.disk.csi.azure.com/zone: topology.kubernetes.io/region:westus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-52wfkn cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-52wfkn-md-win-5f9c49f686-g7dj2 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-52wfkn-md-win-5f9c49f686 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-52wf-65w45"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.4/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.39.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:1a:63:c4 volumes.kubernetes.io/controller-managed-attach-detach:true] [] [] [{kubelet.exe Update v1 2022-06-03 19:52:05 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-03 19:52:06 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {manager Update v1 2022-06-03 19:53:26 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:cluster.x-k8s.io/cluster-name":{},"f:cluster.x-k8s.io/cluster-namespace":{},"f:cluster.x-k8s.io/machine":{},"f:cluster.x-k8s.io/owner-kind":{},"f:cluster.x-k8s.io/owner-name":{}}}} } {Go-http-client Update v1 2022-06-03 19:53:49 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {kube-controller-manager Update v1 2022-06-03 20:11:57 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-03 21:14:34 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{}},"f:labels":{"f:topology.disk.csi.azure.com/zone":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"DiskPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"MemoryPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"PIDPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"Ready\"}":{"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{}}},"f:images":{}}} status}]},Spec:NodeSpec{PodCIDR:,DoNotUseExternalID:,ProviderID:azure:///subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/virtualMachines/capz-52wf-65w45,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{136912564224 0} {<nil>} 133703676Ki BinarySI},memory: {{17179398144 0} {<nil>} 16776756Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{123221307598 0} {<nil>} 123221307598 DecimalSI},memory: {{17074540544 0} {<nil>} 16674356Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-06-03 21:14:34 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-03 21:14:34 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-03 21:14:34 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-03 21:14:34 +0000 UTC,LastTransitionTime:2022-06-03 19:53:17 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-52wf-65w45,},NodeAddress{Type:InternalIP,Address:10.1.0.4,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-52wf-65w45,SystemUUID:C2889A5E-6D91-43FC-A74C-95084D6382D3,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},} ... skipping 88 lines ... [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40[0m [single-az] [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43[0m [91m[1mShould create and attach a volume with basic perfProfile [enableBursting][disk.csi.azure.com] [Windows] [It][0m [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:194[0m [91mUnexpected error: <*errors.errorString | 0xc000bb6a90>: { s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-fpsxt\" to be \"Succeeded or Failed\"", } Gave up after waiting 15m0s for pod "azuredisk-volume-tester-fpsxt" to be "Succeeded or Failed" occurred[0m /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:805 [90m------------------------------[0m [0mDynamic Provisioning[0m [90m[single-az][0m [1mshould receive FailedMount event with invalid mount options [kubernetes.io/azure-disk] [disk.csi.azure.com][0m ... skipping 78 lines ... Jun 3 21:15:14.413: INFO: PersistentVolumeClaim pvc-g5ttx found and phase=Bound (4.161737818s) [1mSTEP[0m: checking the PVC [1mSTEP[0m: validating provisioned PV [1mSTEP[0m: checking the PV [1mSTEP[0m: setting up the pod [1mSTEP[0m: deploying the pod [1mSTEP[0m: checking that the pod's command exits with an error Jun 3 21:15:14.586: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-gk7qw" in namespace "azuredisk-9241" to be "Error status code" Jun 3 21:15:14.640: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 54.323105ms Jun 3 21:15:16.694: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108382001s Jun 3 21:15:18.749: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.162946419s Jun 3 21:15:20.803: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.216516165s Jun 3 21:15:22.856: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.270067445s Jun 3 21:15:24.911: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 10.324689546s ... skipping 427 lines ... Jun 3 21:30:04.577: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 14m49.991116336s Jun 3 21:30:06.631: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.045270203s Jun 3 21:30:08.685: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.098862606s Jun 3 21:30:10.739: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.152923843s Jun 3 21:30:12.792: INFO: Pod "azuredisk-volume-tester-gk7qw": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.206230246s Jun 3 21:30:14.793: INFO: deleting Pod "azuredisk-9241"/"azuredisk-volume-tester-gk7qw" Jun 3 21:30:14.861: INFO: Error getting logs for pod azuredisk-volume-tester-gk7qw: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-gk7qw) [1mSTEP[0m: Deleting pod azuredisk-volume-tester-gk7qw in namespace azuredisk-9241 Jun 3 21:30:14.918: INFO: deleting PVC "azuredisk-9241"/"pvc-g5ttx" Jun 3 21:30:14.918: INFO: Deleting PersistentVolumeClaim "pvc-g5ttx" [1mSTEP[0m: waiting for claim's PV "pvc-8eacbf97-b0f5-4e0b-97fa-4dabc1f73075" to be deleted Jun 3 21:30:14.975: INFO: Waiting up to 10m0s for PersistentVolume pvc-8eacbf97-b0f5-4e0b-97fa-4dabc1f73075 to get deleted Jun 3 21:30:15.029: INFO: PersistentVolume pvc-8eacbf97-b0f5-4e0b-97fa-4dabc1f73075 found and phase=Bound (54.063291ms) ... skipping 14 lines ... Jun 3 21:31:00.707: INFO: At 2022-06-03 21:15:10 +0000 UTC - event for pvc-g5ttx: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator Jun 3 21:31:00.707: INFO: At 2022-06-03 21:15:10 +0000 UTC - event for pvc-g5ttx: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } Provisioning: External provisioner is provisioning volume for claim "azuredisk-9241/pvc-g5ttx" Jun 3 21:31:00.707: INFO: At 2022-06-03 21:15:12 +0000 UTC - event for pvc-g5ttx: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } ProvisioningSucceeded: Successfully provisioned volume pvc-8eacbf97-b0f5-4e0b-97fa-4dabc1f73075 Jun 3 21:31:00.707: INFO: At 2022-06-03 21:15:14 +0000 UTC - event for azuredisk-volume-tester-gk7qw: {default-scheduler } Scheduled: Successfully assigned azuredisk-9241/azuredisk-volume-tester-gk7qw to capz-52wf-q78cs Jun 3 21:31:00.707: INFO: At 2022-06-03 21:15:51 +0000 UTC - event for azuredisk-volume-tester-gk7qw: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-8eacbf97-b0f5-4e0b-97fa-4dabc1f73075" Jun 3 21:31:00.707: INFO: At 2022-06-03 21:16:22 +0000 UTC - event for azuredisk-volume-tester-gk7qw: {kubelet capz-52wf-q78cs} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 21:31:00.707: INFO: At 2022-06-03 21:16:23 +0000 UTC - event for azuredisk-volume-tester-gk7qw: {kubelet capz-52wf-q78cs} Failed: Failed to pull image "mcr.microsoft.com/windows/servercore:ltsc2022": rpc error: code = NotFound desc = failed to pull and unpack image "mcr.microsoft.com/windows/servercore:ltsc2022": no match for platform in manifest: not found Jun 3 21:31:00.707: INFO: At 2022-06-03 21:16:23 +0000 UTC - event for azuredisk-volume-tester-gk7qw: {kubelet capz-52wf-q78cs} Failed: Error: ErrImagePull Jun 3 21:31:00.707: INFO: At 2022-06-03 21:16:24 +0000 UTC - event for azuredisk-volume-tester-gk7qw: {kubelet capz-52wf-q78cs} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 21:31:00.761: INFO: POD NODE PHASE GRACE CONDITIONS Jun 3 21:31:00.761: INFO: Jun 3 21:31:00.816: INFO: Logging node info for node capz-52wf-65w45 Jun 3 21:31:00.869: INFO: Node Info: &Node{ObjectMeta:{capz-52wf-65w45 5d8749d6-e04e-4513-a6b0-3c548b20c4fe 14657 0 2022-06-03 19:52:05 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:westus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-52wf-65w45 kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.17763 topology.disk.csi.azure.com/zone: topology.kubernetes.io/region:westus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-52wfkn cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-52wfkn-md-win-5f9c49f686-g7dj2 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-52wfkn-md-win-5f9c49f686 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-52wf-65w45"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.4/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.39.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:1a:63:c4 volumes.kubernetes.io/controller-managed-attach-detach:true] [] [] [{kubelet.exe Update v1 2022-06-03 19:52:05 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-03 19:52:06 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {manager Update v1 2022-06-03 19:53:26 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:cluster.x-k8s.io/cluster-name":{},"f:cluster.x-k8s.io/cluster-namespace":{},"f:cluster.x-k8s.io/machine":{},"f:cluster.x-k8s.io/owner-kind":{},"f:cluster.x-k8s.io/owner-name":{}}}} } {Go-http-client Update v1 2022-06-03 19:53:49 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {kube-controller-manager Update v1 2022-06-03 20:11:57 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-03 21:14:34 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{}},"f:labels":{"f:topology.disk.csi.azure.com/zone":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"DiskPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"MemoryPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"PIDPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"Ready\"}":{"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{}}},"f:images":{}}} status}]},Spec:NodeSpec{PodCIDR:,DoNotUseExternalID:,ProviderID:azure:///subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/virtualMachines/capz-52wf-65w45,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{136912564224 0} {<nil>} 133703676Ki BinarySI},memory: {{17179398144 0} {<nil>} 16776756Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{123221307598 0} {<nil>} 123221307598 DecimalSI},memory: {{17074540544 0} {<nil>} 16674356Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-06-03 21:29:54 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-03 21:29:54 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-03 21:29:54 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-03 21:29:54 +0000 UTC,LastTransitionTime:2022-06-03 19:53:17 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-52wf-65w45,},NodeAddress{Type:InternalIP,Address:10.1.0.4,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-52wf-65w45,SystemUUID:C2889A5E-6D91-43FC-A74C-95084D6382D3,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},} ... skipping 88 lines ... [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40[0m [single-az] [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43[0m [91m[1mshould create a volume on demand and mount it as readOnly in a pod [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] [It][0m [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:299[0m [91mUnexpected error: <*errors.errorString | 0xc000860750>: { s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-gk7qw\" to be \"Error status code\"", } Gave up after waiting 15m0s for pod "azuredisk-volume-tester-gk7qw" to be "Error status code" occurred[0m /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:844 [90m------------------------------[0m [0mDynamic Provisioning[0m [90m[single-az][0m [1mshould create multiple PV objects, bind to PVCs and attach all to different pods on the same node [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows][0m ... skipping 22 lines ... [1mSTEP[0m: validating provisioned PV [1mSTEP[0m: checking the PV [1mSTEP[0m: setting up the pod [1mSTEP[0m: deploying the pod [1mSTEP[0m: checking that the pod is running Jun 3 21:36:07.617: INFO: deleting Pod "azuredisk-9336"/"azuredisk-volume-tester-77wdn" Jun 3 21:36:07.690: INFO: Error getting logs for pod azuredisk-volume-tester-77wdn: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-77wdn) [1mSTEP[0m: Deleting pod azuredisk-volume-tester-77wdn in namespace azuredisk-9336 Jun 3 21:36:07.745: INFO: deleting PVC "azuredisk-9336"/"pvc-vdgn4" Jun 3 21:36:07.745: INFO: Deleting PersistentVolumeClaim "pvc-vdgn4" [1mSTEP[0m: waiting for claim's PV "pvc-35a8e0dc-d116-4c82-8c70-b902be9c7c43" to be deleted Jun 3 21:36:07.801: INFO: Waiting up to 10m0s for PersistentVolume pvc-35a8e0dc-d116-4c82-8c70-b902be9c7c43 to get deleted Jun 3 21:36:07.854: INFO: PersistentVolume pvc-35a8e0dc-d116-4c82-8c70-b902be9c7c43 found and phase=Bound (53.063883ms) ... skipping 14 lines ... Jun 3 21:36:53.513: INFO: At 2022-06-03 21:31:03 +0000 UTC - event for pvc-vdgn4: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } Provisioning: External provisioner is provisioning volume for claim "azuredisk-9336/pvc-vdgn4" Jun 3 21:36:53.513: INFO: At 2022-06-03 21:31:03 +0000 UTC - event for pvc-vdgn4: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator Jun 3 21:36:53.513: INFO: At 2022-06-03 21:31:05 +0000 UTC - event for pvc-vdgn4: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } ProvisioningSucceeded: Successfully provisioned volume pvc-35a8e0dc-d116-4c82-8c70-b902be9c7c43 Jun 3 21:36:53.513: INFO: At 2022-06-03 21:31:07 +0000 UTC - event for azuredisk-volume-tester-77wdn: {default-scheduler } Scheduled: Successfully assigned azuredisk-9336/azuredisk-volume-tester-77wdn to capz-52wf-q78cs Jun 3 21:36:53.513: INFO: At 2022-06-03 21:31:18 +0000 UTC - event for azuredisk-volume-tester-77wdn: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-35a8e0dc-d116-4c82-8c70-b902be9c7c43" Jun 3 21:36:53.513: INFO: At 2022-06-03 21:31:49 +0000 UTC - event for azuredisk-volume-tester-77wdn: {kubelet capz-52wf-q78cs} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 21:36:53.513: INFO: At 2022-06-03 21:31:49 +0000 UTC - event for azuredisk-volume-tester-77wdn: {kubelet capz-52wf-q78cs} Failed: Error: ErrImagePull Jun 3 21:36:53.513: INFO: At 2022-06-03 21:31:49 +0000 UTC - event for azuredisk-volume-tester-77wdn: {kubelet capz-52wf-q78cs} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 21:36:53.567: INFO: POD NODE PHASE GRACE CONDITIONS Jun 3 21:36:53.567: INFO: Jun 3 21:36:53.672: INFO: Logging node info for node capz-52wf-65w45 Jun 3 21:36:53.725: INFO: Node Info: &Node{ObjectMeta:{capz-52wf-65w45 5d8749d6-e04e-4513-a6b0-3c548b20c4fe 15429 0 2022-06-03 19:52:05 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:westus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-52wf-65w45 kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.17763 topology.disk.csi.azure.com/zone: topology.kubernetes.io/region:westus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-52wfkn cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-52wfkn-md-win-5f9c49f686-g7dj2 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-52wfkn-md-win-5f9c49f686 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-52wf-65w45"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.4/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.39.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:1a:63:c4 volumes.kubernetes.io/controller-managed-attach-detach:true] [] [] [{kubelet.exe Update v1 2022-06-03 19:52:05 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-03 19:52:06 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {manager Update v1 2022-06-03 19:53:26 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:cluster.x-k8s.io/cluster-name":{},"f:cluster.x-k8s.io/cluster-namespace":{},"f:cluster.x-k8s.io/machine":{},"f:cluster.x-k8s.io/owner-kind":{},"f:cluster.x-k8s.io/owner-name":{}}}} } {Go-http-client Update v1 2022-06-03 19:53:49 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {kube-controller-manager Update v1 2022-06-03 20:11:57 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-03 21:14:34 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{}},"f:labels":{"f:topology.disk.csi.azure.com/zone":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"DiskPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"MemoryPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"PIDPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"Ready\"}":{"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{}}},"f:images":{}}} status}]},Spec:NodeSpec{PodCIDR:,DoNotUseExternalID:,ProviderID:azure:///subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/virtualMachines/capz-52wf-65w45,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{136912564224 0} {<nil>} 133703676Ki BinarySI},memory: {{17179398144 0} {<nil>} 16776756Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{123221307598 0} {<nil>} 123221307598 DecimalSI},memory: {{17074540544 0} {<nil>} 16674356Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-06-03 21:35:00 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-03 21:35:00 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-03 21:35:00 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-03 21:35:00 +0000 UTC,LastTransitionTime:2022-06-03 19:53:17 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-52wf-65w45,},NodeAddress{Type:InternalIP,Address:10.1.0.4,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-52wf-65w45,SystemUUID:C2889A5E-6D91-43FC-A74C-95084D6382D3,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},} ... skipping 88 lines ... [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40[0m [single-az] [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43[0m [91m[1mshould create multiple PV objects, bind to PVCs and attach all to different pods on the same node [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] [It][0m [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:333[0m [91mUnexpected error: <*errors.errorString | 0xc0001de470>: { s: "timed out waiting for the condition", } timed out waiting for the condition occurred[0m ... skipping 33 lines ... Jun 3 21:37:06.439: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} Jun 3 21:37:08.439: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} Jun 3 21:37:10.439: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} Jun 3 21:37:12.436: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} Jun 3 21:37:14.438: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} Jun 3 21:37:16.437: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} {"component":"entrypoint","file":"k8s.io/test-infra/prow/entrypoint/run.go:165","func":"k8s.io/test-infra/prow/entrypoint.Options.ExecuteProcess","level":"error","msg":"Process did not finish before 2h0m0s timeout","severity":"error","time":"2022-06-03T21:37:17Z"} ++ early_exit_handler ++ '[' -n 157 ']' ++ kill -TERM 157 ++ cleanup_dind ++ [[ true == \t\r\u\e ]] ++ echo 'Cleaning up after docker' ... skipping 3 lines ... make: Nothing to be done for 'kubectl'. ================ DUMPING LOGS FOR MANAGEMENT CLUSTER ================ Jun 3 21:37:18.438: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} ef798259206c 35465243a34e ++ service docker stop Stopping Docker: dockerERROR: failed to get cluster internal kubeconfig: command "docker exec --privileged capz-control-plane cat /etc/kubernetes/admin.conf" failed with error: exit status 1 Command Output: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running? Error from server (NotFound): error when deleting "./scripts/../hack/log/../../hack/log/log-dump-daemonset.yaml": daemonsets.apps "log-dump-node" not found Error from server (NotFound): error when deleting "./scripts/../hack/log/../../hack/log/log-dump-daemonset-windows.yaml": daemonsets.apps "log-dump-node-windows" not found ================ REDACTING LOGS ================ All sensitive variables are redacted The connection to the server 127.0.0.1:33905 was refused - did you specify the right host or port? kind delete cluster --name=capz || true Deleting cluster "capz" ... ERROR: failed to delete cluster "capz": error listing nodes: failed to list clusters: command "docker ps -a --filter label=io.x-k8s.kind.cluster=capz --format '{{.Names}}'" failed with error: exit status 1 Command Output: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running? kind delete cluster --name=capz-e2e || true Deleting cluster "capz-e2e" ... ERROR: failed to delete cluster "capz-e2e": error listing nodes: failed to list clusters: command "docker ps -a --filter label=io.x-k8s.kind.cluster=capz-e2e --format '{{.Names}}'" failed with error: exit status 1 Command Output: Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running? Jun 3 21:37:20.438: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} Jun 3 21:37:22.438: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} Jun 3 21:37:24.437: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} Jun 3 21:37:26.438: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} ... skipping 170 lines ... Jun 3 21:42:46.328: INFO: At 2022-06-03 21:36:55 +0000 UTC - event for pvc-hlvhd: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } Provisioning: External provisioner is provisioning volume for claim "azuredisk-2205/pvc-hlvhd" Jun 3 21:42:46.328: INFO: At 2022-06-03 21:36:58 +0000 UTC - event for pvc-hlvhd: {disk.csi.azure.com_capz-52wfkn-control-plane-tfl4x_9daf94f1-06e6-4231-a750-3537d940acdb } ProvisioningSucceeded: Successfully provisioned volume pvc-ae5e24fb-d03a-433e-a99d-d84085bf2ef7 Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:00 +0000 UTC - event for azuredisk-volume-tester-t8tqz: {deployment-controller } ScalingReplicaSet: Scaled up replica set azuredisk-volume-tester-t8tqz-7bbdb49579 to 1 Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:00 +0000 UTC - event for azuredisk-volume-tester-t8tqz-7bbdb49579: {replicaset-controller } SuccessfulCreate: Created pod: azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:00 +0000 UTC - event for azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs: {default-scheduler } Scheduled: Successfully assigned azuredisk-2205/azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs to capz-52wf-q78cs Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:11 +0000 UTC - event for azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-ae5e24fb-d03a-433e-a99d-d84085bf2ef7" Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:41 +0000 UTC - event for azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs: {kubelet capz-52wf-q78cs} Failed: Error: ImagePullBackOff Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:41 +0000 UTC - event for azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs: {kubelet capz-52wf-q78cs} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:41 +0000 UTC - event for azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs: {kubelet capz-52wf-q78cs} Failed: Failed to pull image "mcr.microsoft.com/windows/servercore:ltsc2022": rpc error: code = NotFound desc = failed to pull and unpack image "mcr.microsoft.com/windows/servercore:ltsc2022": no match for platform in manifest: not found Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:41 +0000 UTC - event for azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs: {kubelet capz-52wf-q78cs} Failed: Error: ErrImagePull Jun 3 21:42:46.328: INFO: At 2022-06-03 21:37:41 +0000 UTC - event for azuredisk-volume-tester-t8tqz-7bbdb49579-7dtcs: {kubelet capz-52wf-q78cs} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022" Jun 3 21:42:46.381: INFO: POD NODE PHASE GRACE CONDITIONS Jun 3 21:42:46.381: INFO: Jun 3 21:42:46.435: INFO: Logging node info for node capz-52wf-65w45 Jun 3 21:42:46.490: INFO: Node Info: &Node{ObjectMeta:{capz-52wf-65w45 5d8749d6-e04e-4513-a6b0-3c548b20c4fe 16216 0 2022-06-03 19:52:05 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:Standard_D4s_v3 beta.kubernetes.io/os:windows failure-domain.beta.kubernetes.io/region:westus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-52wf-65w45 kubernetes.io/os:windows node.kubernetes.io/instance-type:Standard_D4s_v3 node.kubernetes.io/windows-build:10.0.17763 topology.disk.csi.azure.com/zone: topology.kubernetes.io/region:westus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-52wfkn cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-52wfkn-md-win-5f9c49f686-g7dj2 cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-52wfkn-md-win-5f9c49f686 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-52wf-65w45"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.4/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.39.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:1a:63:c4 volumes.kubernetes.io/controller-managed-attach-detach:true] [] [] [{kubelet.exe Update v1 2022-06-03 19:52:05 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-03 19:52:06 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {manager Update v1 2022-06-03 19:53:26 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:cluster.x-k8s.io/cluster-name":{},"f:cluster.x-k8s.io/cluster-namespace":{},"f:cluster.x-k8s.io/machine":{},"f:cluster.x-k8s.io/owner-kind":{},"f:cluster.x-k8s.io/owner-name":{}}}} } {Go-http-client Update v1 2022-06-03 19:53:49 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {kube-controller-manager Update v1 2022-06-03 20:11:57 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-03 21:14:34 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:csi.volume.kubernetes.io/nodeid":{}},"f:labels":{"f:topology.disk.csi.azure.com/zone":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"DiskPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"MemoryPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"PIDPressure\"}":{"f:lastHeartbeatTime":{}},"k:{\"type\":\"Ready\"}":{"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{}}},"f:images":{}}} status}]},Spec:NodeSpec{PodCIDR:,DoNotUseExternalID:,ProviderID:azure:///subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-52wfkn/providers/Microsoft.Compute/virtualMachines/capz-52wf-65w45,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{136912564224 0} {<nil>} 133703676Ki BinarySI},memory: {{17179398144 0} {<nil>} 16776756Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-azure-disk: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{123221307598 0} {<nil>} 123221307598 DecimalSI},memory: {{17074540544 0} {<nil>} 16674356Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-06-03 21:40:07 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-03 21:40:07 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-03 21:40:07 +0000 UTC,LastTransitionTime:2022-06-03 19:52:05 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-03 21:40:07 +0000 UTC,LastTransitionTime:2022-06-03 19:53:17 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-52wf-65w45,},NodeAddress{Type:InternalIP,Address:10.1.0.4,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-52wf-65w45,SystemUUID:C2889A5E-6D91-43FC-A74C-95084D6382D3,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},} ... skipping 88 lines ... [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40[0m [single-az] [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43[0m [91m[1mshould create a deployment object, write and read to it, delete the pod and write and read to it again [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] [It][0m [90m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:397[0m [91mUnexpected error: <*errors.errorString | 0xc000d7a340>: { s: "error waiting for deployment \"azuredisk-volume-tester-t8tqz\" status to match expectation: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:\"MinimumReplicasUnavailable\", Message:\"Deployment does not have minimum availability.\"}, v1.DeploymentCondition{Type:\"Progressing\", Status:\"True\", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:\"ReplicaSetUpdated\", Message:\"ReplicaSet \\\"azuredisk-volume-tester-t8tqz-7bbdb49579\\\" is progressing.\"}}, CollisionCount:(*int32)(nil)}", } error waiting for deployment "azuredisk-volume-tester-t8tqz" status to match expectation: 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(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 3, 21, 37, 0, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-t8tqz-7bbdb49579\" is progressing."}}, CollisionCount:(*int32)(nil)} occurred[0m /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:503 [90m------------------------------[0m [0mDynamic Provisioning[0m [90m[single-az][0m [1mshould delete PV with reclaimPolicy "Delete" [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows][0m ... skipping 199 lines ... Jun 3 21:43:26.194: INFO: PersistentVolumeClaim pvc-qnh57 found and phase=Bound (4.173384473s) [1mSTEP[0m: checking the PVC [1mSTEP[0m: validating provisioned PV [1mSTEP[0m: checking the PV [1mSTEP[0m: setting up the pod [1mSTEP[0m: deploying the pod [1mSTEP[0m: checking that the pod's command exits with no error Jun 3 21:43:26.356: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-6bvrn" in namespace "azuredisk-1387" to be "Succeeded or Failed" Jun 3 21:43:26.410: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 53.314434ms Jun 3 21:43:28.463: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.10714756s Jun 3 21:43:30.519: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.162343783s Jun 3 21:43:32.574: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.218168943s Jun 3 21:43:34.630: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.274024392s Jun 3 21:43:36.686: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.329534737s ... skipping 247 lines ... Jun 3 21:52:06.409: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 8m40.052705701s Jun 3 21:52:08.464: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 8m42.107452217s Jun 3 21:52:10.530: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 8m44.173887489s Jun 3 21:52:12.584: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 8m46.227872366s Jun 3 21:52:14.638: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 8m48.281592562s Jun 3 21:52:16.691: INFO: Pod "azuredisk-volume-tester-6bvrn": Phase="Pending", Reason="", readiness=false. Elapsed: 8m50.334664796s {"component":"entrypoint","file":"k8s.io/test-infra/prow/entrypoint/run.go:255","func":"k8s.io/test-infra/prow/entrypoint.gracefullyTerminate","level":"error","msg":"Process did not exit before 15m0s grace period","severity":"error","time":"2022-06-03T21:52:17Z"} {"component":"entrypoint","error":"os: process already finished","file":"k8s.io/test-infra/prow/entrypoint/run.go:257","func":"k8s.io/test-infra/prow/entrypoint.gracefullyTerminate","level":"error","msg":"Could not kill process after grace period","severity":"error","time":"2022-06-03T21:52:17Z"}