This job view page is being replaced by Spyglass soon. Check out the new job view.
PRjackfrancis: do-not-merge func main comment
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-06-01 21:54
Elapsed2h15m
Revisionfa06ff44036ca43a3c6f75ad053eec797aaeaab9
Refs 1359

No Test Failures!


Error lines from build-log.txt

... skipping 672 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 1033 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  1 22:11:09.107: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-6926j] to have phase Bound
Jun  1 22:11:09.142: INFO: PersistentVolumeClaim pvc-6926j found and phase=Bound (34.986958ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with an error
Jun  1 22:11:09.252: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-2d4d4" in namespace "azuredisk-8081" to be "Error status code"
Jun  1 22:11:09.287: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 35.126233ms
Jun  1 22:11:11.329: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.076944721s
Jun  1 22:11:13.365: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.113382715s
Jun  1 22:11:15.403: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.151013107s
Jun  1 22:11:17.441: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.1889709s
Jun  1 22:11:19.484: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.232415528s
... skipping 431 lines ...
Jun  1 22:25:59.632: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.380491227s
Jun  1 22:26:01.669: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.416973542s
Jun  1 22:26:03.706: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.454614452s
Jun  1 22:26:05.743: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.491123882s
Jun  1 22:26:07.783: INFO: Pod "azuredisk-volume-tester-2d4d4": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.531634729s
Jun  1 22:26:09.785: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-2d4d4"
Jun  1 22:26:09.834: INFO: Error getting logs for pod azuredisk-volume-tester-2d4d4: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-2d4d4)
STEP: Deleting pod azuredisk-volume-tester-2d4d4 in namespace azuredisk-8081
Jun  1 22:26:09.876: INFO: deleting PVC "azuredisk-8081"/"pvc-6926j"
Jun  1 22:26:09.876: INFO: Deleting PersistentVolumeClaim "pvc-6926j"
Jun  1 22:26:09.913: INFO: Waiting up to 5m0s for PersistentVolumeClaim azuredisk-8081 to be removed
Jun  1 22:26:09.948: INFO: Claim "azuredisk-8081" in namespace "pvc-6926j" doesn't exist in the system
STEP: deleting PV "azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-hvjb7"
... skipping 10 lines ...
Jun  1 22:26:45.287: INFO: PersistentVolume azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-hvjb7 was removed
STEP: Collecting events from namespace "azuredisk-8081".
STEP: Found 5 events.
Jun  1 22:26:45.324: INFO: At 2022-06-01 22:11:09 +0000 UTC - event for azuredisk-volume-tester-2d4d4: {default-scheduler } Scheduled: Successfully assigned azuredisk-8081/azuredisk-volume-tester-2d4d4 to capz-t0o8-rmk8l
Jun  1 22:26:45.324: INFO: At 2022-06-01 22:11:15 +0000 UTC - event for azuredisk-volume-tester-2d4d4: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-hvjb7" 
Jun  1 22:26:45.324: INFO: At 2022-06-01 22:11:47 +0000 UTC - event for azuredisk-volume-tester-2d4d4: {kubelet capz-t0o8-rmk8l} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 22:26:45.324: INFO: At 2022-06-01 22:11:48 +0000 UTC - event for azuredisk-volume-tester-2d4d4: {kubelet capz-t0o8-rmk8l} Failed: Error: ErrImagePull
Jun  1 22:26:45.324: INFO: At 2022-06-01 22:11:48 +0000 UTC - event for azuredisk-volume-tester-2d4d4: {kubelet capz-t0o8-rmk8l} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 22:26:45.359: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  1 22:26:45.359: INFO: 
Jun  1 22:26:45.430: INFO: 
Logging node info for node capz-t0o8-45hdr
Jun  1 22:26:45.465: INFO: Node Info: &Node{ObjectMeta:{capz-t0o8-45hdr    30337305-834f-40af-a3d0-c3f1c2be0dc4 2972 0 2022-06-01 22:07:56 +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:eastus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-t0o8-45hdr 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:eastus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-t0o8fk cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-t0o8fk-md-win-7556bc86f-hhdqq cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-t0o8fk-md-win-7556bc86f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-t0o8-45hdr"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.218.129 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c6:a5:0a volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-06-01 22:07:56 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-06-01 22:07:56 +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":{}}} } {kube-controller-manager Update v1 2022-06-01 22:08:06 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-06-01 22:09:05 +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-01 22:09:24 +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-01 22:11:02 +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-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr,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-01 22:21:45 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-01 22:21:45 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-01 22:21:45 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-01 22:21:45 +0000 UTC,LastTransitionTime:2022-06-01 22:08:57 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-t0o8-45hdr,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-t0o8-45hdr,SystemUUID:D71EFA06-BDCF-4FED-8B99-A18B4DC0512C,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:c36c31a6fd4661f9bfe7f496a346b4c3308d8b5239db568c12d39fdada044526 capzci.azurecr.io/azuredisk-csi:v1.19.0-382e5c4473e73d1e23efbc30c74a84820fdf2d98],SizeBytes:127767703,},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 ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:37
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:69
    should use a pre-provisioned volume and mount it as readOnly in a pod [disk.csi.azure.com][windows] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:70

    Unexpected error:
        <*errors.errorString | 0xc00063f560>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-2d4d4\" to be \"Error status code\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-2d4d4" to be "Error status code"
    occurred

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:844
------------------------------
Pre-Provisioned [single-az] 
  should use a pre-provisioned volume and retain PV with reclaimPolicy "Retain" [disk.csi.azure.com][windows]
... skipping 51 lines ...

Jun  1 22:26:55.762: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "azuredisk-4728" for this suite.
•
------------------------------
Pre-Provisioned [single-az] 
  should fail when maxShares is invalid [disk.csi.azure.com][windows]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:163
STEP: Creating a kubernetes client
Jun  1 22:26:56.548: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
STEP: Building a namespace api object, basename azuredisk
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
... skipping 46 lines ...
Jun  1 22:27:00.994: INFO: PersistentVolumeClaim pvc-4nwlh found and phase=Bound (35.034392ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: attaching disk to node#0
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Jun  1 22:27:08.236: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-lkqt2" in namespace "azuredisk-5356" to be "Succeeded or Failed"
Jun  1 22:27:08.271: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 34.864157ms
Jun  1 22:27:10.307: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071387851s
Jun  1 22:27:12.345: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.109059486s
Jun  1 22:27:14.383: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.146732487s
Jun  1 22:27:16.420: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.184252478s
Jun  1 22:27:18.458: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.221582077s
... skipping 431 lines ...
Jun  1 22:41:58.628: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.392118779s
Jun  1 22:42:00.664: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.428121637s
Jun  1 22:42:02.702: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.465480461s
Jun  1 22:42:04.738: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.502098576s
Jun  1 22:42:06.777: INFO: Pod "azuredisk-volume-tester-lkqt2": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.540579393s
Jun  1 22:42:08.778: INFO: deleting Pod "azuredisk-5356"/"azuredisk-volume-tester-lkqt2"
Jun  1 22:42:08.834: INFO: Error getting logs for pod azuredisk-volume-tester-lkqt2: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-lkqt2)
STEP: Deleting pod azuredisk-volume-tester-lkqt2 in namespace azuredisk-5356
Jun  1 22:42:08.947: INFO: deleting PVC "azuredisk-5356"/"pvc-4nwlh"
Jun  1 22:42:08.948: INFO: Deleting PersistentVolumeClaim "pvc-4nwlh"
Jun  1 22:42:08.983: INFO: Waiting up to 5m0s for PersistentVolumeClaim azuredisk-5356 to be removed
Jun  1 22:42:09.021: INFO: Claim "azuredisk-5356" in namespace "pvc-4nwlh" doesn't exist in the system
STEP: deleting PV "azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-svhwg"
... skipping 7 lines ...
Jun  1 22:42:29.250: INFO: PersistentVolume azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-svhwg found and phase=Released (20.189554769s)
Jun  1 22:42:34.286: INFO: PersistentVolume azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-svhwg found and phase=Released (25.225496783s)
Jun  1 22:42:39.326: INFO: PersistentVolume azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-svhwg was removed
STEP: Collecting events from namespace "azuredisk-5356".
STEP: Found 6 events.
Jun  1 22:42:39.362: INFO: At 2022-06-01 22:27:08 +0000 UTC - event for azuredisk-volume-tester-lkqt2: {default-scheduler } Scheduled: Successfully assigned azuredisk-5356/azuredisk-volume-tester-lkqt2 to capz-t0o8-rmk8l
Jun  1 22:42:39.362: INFO: At 2022-06-01 22:27:24 +0000 UTC - event for azuredisk-volume-tester-lkqt2: {attachdetach-controller } FailedAttachVolume: AttachVolume.Attach failed for volume "azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-svhwg" : rpc error: code = Unknown desc = Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-t0o8fk/providers/Microsoft.Compute/disks/reattach-disk-multiple-nodes to instance capz-t0o8-rmk8l failed with disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-t0o8fk/providers/Microsoft.Compute/disks/reattach-disk-multiple-nodes) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr), could not be attached to node(capz-t0o8-rmk8l)
Jun  1 22:42:39.362: INFO: At 2022-06-01 22:27:34 +0000 UTC - event for azuredisk-volume-tester-lkqt2: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "azuredisk-5356-disk.csi.azure.com-preprovisioned-pv-svhwg" 
Jun  1 22:42:39.362: INFO: At 2022-06-01 22:27:59 +0000 UTC - event for azuredisk-volume-tester-lkqt2: {kubelet capz-t0o8-rmk8l} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 22:42:39.362: INFO: At 2022-06-01 22:27:59 +0000 UTC - event for azuredisk-volume-tester-lkqt2: {kubelet capz-t0o8-rmk8l} Failed: Error: ErrImagePull
Jun  1 22:42:39.362: INFO: At 2022-06-01 22:28:00 +0000 UTC - event for azuredisk-volume-tester-lkqt2: {kubelet capz-t0o8-rmk8l} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 22:42:39.397: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  1 22:42:39.397: INFO: 
Jun  1 22:42:39.466: INFO: 
Logging node info for node capz-t0o8-45hdr
Jun  1 22:42:39.502: INFO: Node Info: &Node{ObjectMeta:{capz-t0o8-45hdr    30337305-834f-40af-a3d0-c3f1c2be0dc4 5856 0 2022-06-01 22:07:56 +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:eastus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-t0o8-45hdr 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:eastus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-t0o8fk cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-t0o8fk-md-win-7556bc86f-hhdqq cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-t0o8fk-md-win-7556bc86f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-t0o8-45hdr"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.218.129 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c6:a5:0a volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-06-01 22:07:56 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-06-01 22:07:56 +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":{}}} } {manager Update v1 2022-06-01 22:09:05 +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-01 22:09:24 +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-01 22:11:02 +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-01 22:27:08 +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-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr,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-01 22:42:13 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-01 22:42:13 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-01 22:42:13 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-01 22:42:13 +0000 UTC,LastTransitionTime:2022-06-01 22:08:57 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-t0o8-45hdr,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-t0o8-45hdr,SystemUUID:D71EFA06-BDCF-4FED-8B99-A18B4DC0512C,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:c36c31a6fd4661f9bfe7f496a346b4c3308d8b5239db568c12d39fdada044526 capzci.azurecr.io/azuredisk-csi:v1.19.0-382e5c4473e73d1e23efbc30c74a84820fdf2d98],SizeBytes:127767703,},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 ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:37
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:69
    should succeed when reattaching a disk to a new node on DanglingAttachError [disk.csi.azure.com] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:249

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

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:805
------------------------------
Pre-Provisioned [single-az] 
  should create an inline volume by in-tree driver [kubernetes.io/azure-disk]
... skipping 43 lines ...
Jun  1 22:42:51.633: INFO: PersistentVolumeClaim pvc-bhzv9 found and phase=Bound (4.109915058s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Jun  1 22:42:51.744: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-gtknm" in namespace "azuredisk-1353" to be "Succeeded or Failed"
Jun  1 22:42:51.784: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 40.443012ms
Jun  1 22:42:53.822: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.077480969s
Jun  1 22:42:55.859: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.114763913s
Jun  1 22:42:57.896: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.15176318s
Jun  1 22:42:59.933: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.189115671s
Jun  1 22:43:01.970: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.225505339s
... skipping 431 lines ...
Jun  1 22:57:41.987: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.242630502s
Jun  1 22:57:44.108: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.364126556s
Jun  1 22:57:46.145: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.401149284s
Jun  1 22:57:48.183: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.438517792s
Jun  1 22:57:50.219: INFO: Pod "azuredisk-volume-tester-gtknm": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.474551856s
Jun  1 22:57:52.219: INFO: deleting Pod "azuredisk-1353"/"azuredisk-volume-tester-gtknm"
Jun  1 22:57:52.267: INFO: Error getting logs for pod azuredisk-volume-tester-gtknm: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-gtknm)
STEP: Deleting pod azuredisk-volume-tester-gtknm in namespace azuredisk-1353
Jun  1 22:57:52.305: INFO: deleting PVC "azuredisk-1353"/"pvc-bhzv9"
Jun  1 22:57:52.305: INFO: Deleting PersistentVolumeClaim "pvc-bhzv9"
STEP: waiting for claim's PV "pvc-1b709ac5-8c47-4bb1-adf6-ea10c54ac4e3" to be deleted
Jun  1 22:57:52.341: INFO: Waiting up to 10m0s for PersistentVolume pvc-1b709ac5-8c47-4bb1-adf6-ea10c54ac4e3 to get deleted
Jun  1 22:57:52.376: INFO: PersistentVolume pvc-1b709ac5-8c47-4bb1-adf6-ea10c54ac4e3 found and phase=Bound (34.913663ms)
... skipping 13 lines ...
Jun  1 22:58:32.803: INFO: At 2022-06-01 22:42:47 +0000 UTC - event for pvc-bhzv9: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } Provisioning: External provisioner is provisioning volume for claim "azuredisk-1353/pvc-bhzv9"
Jun  1 22:58:32.803: INFO: At 2022-06-01 22:42:47 +0000 UTC - event for pvc-bhzv9: {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  1 22:58:32.803: INFO: At 2022-06-01 22:42:49 +0000 UTC - event for pvc-bhzv9: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } ProvisioningSucceeded: Successfully provisioned volume pvc-1b709ac5-8c47-4bb1-adf6-ea10c54ac4e3
Jun  1 22:58:32.803: INFO: At 2022-06-01 22:42:51 +0000 UTC - event for azuredisk-volume-tester-gtknm: {default-scheduler } Scheduled: Successfully assigned azuredisk-1353/azuredisk-volume-tester-gtknm to capz-t0o8-rmk8l
Jun  1 22:58:32.803: INFO: At 2022-06-01 22:42:57 +0000 UTC - event for azuredisk-volume-tester-gtknm: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-1b709ac5-8c47-4bb1-adf6-ea10c54ac4e3" 
Jun  1 22:58:32.803: INFO: At 2022-06-01 22:43:23 +0000 UTC - event for azuredisk-volume-tester-gtknm: {kubelet capz-t0o8-rmk8l} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 22:58:32.803: INFO: At 2022-06-01 22:43:23 +0000 UTC - event for azuredisk-volume-tester-gtknm: {kubelet capz-t0o8-rmk8l} Failed: Error: ErrImagePull
Jun  1 22:58:32.803: INFO: At 2022-06-01 22:43:24 +0000 UTC - event for azuredisk-volume-tester-gtknm: {kubelet capz-t0o8-rmk8l} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 22:58:32.839: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  1 22:58:32.839: INFO: 
Jun  1 22:58:32.909: INFO: 
Logging node info for node capz-t0o8-45hdr
Jun  1 22:58:32.945: INFO: Node Info: &Node{ObjectMeta:{capz-t0o8-45hdr    30337305-834f-40af-a3d0-c3f1c2be0dc4 7972 0 2022-06-01 22:07:56 +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:eastus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-t0o8-45hdr 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:eastus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-t0o8fk cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-t0o8fk-md-win-7556bc86f-hhdqq cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-t0o8fk-md-win-7556bc86f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-t0o8-45hdr"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.218.129 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c6:a5:0a volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-06-01 22:07:56 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-06-01 22:07:56 +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":{}}} } {manager Update v1 2022-06-01 22:09:05 +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-01 22:09:24 +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-01 22:11:02 +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-01 22:27:08 +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-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr,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-01 22:57:32 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-01 22:57:32 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-01 22:57:32 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-01 22:57:32 +0000 UTC,LastTransitionTime:2022-06-01 22:08:57 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-t0o8-45hdr,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-t0o8-45hdr,SystemUUID:D71EFA06-BDCF-4FED-8B99-A18B4DC0512C,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:c36c31a6fd4661f9bfe7f496a346b4c3308d8b5239db568c12d39fdada044526 capzci.azurecr.io/azuredisk-csi:v1.19.0-382e5c4473e73d1e23efbc30c74a84820fdf2d98],SizeBytes:127767703,},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 ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43
    should create a volume on demand with mount options [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:101

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

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:805
------------------------------
Dynamic Provisioning [single-az] 
  should create a pod with volume mount subpath [disk.csi.azure.com] [Windows]
... skipping 18 lines ...
Jun  1 22:58:36.841: INFO: PersistentVolumeClaim pvc-llx6b found but phase is Pending instead of Bound.
Jun  1 22:58:38.877: INFO: PersistentVolumeClaim pvc-llx6b found and phase=Bound (4.107836422s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Jun  1 22:58:38.986: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-p6d6p" in namespace "azuredisk-2888" to be "Succeeded or Failed"
Jun  1 22:58:39.021: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 35.009041ms
Jun  1 22:58:41.058: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 2.072476404s
Jun  1 22:58:43.095: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 4.109317143s
Jun  1 22:58:45.132: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 6.145913999s
Jun  1 22:58:47.169: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 8.182886729s
Jun  1 22:58:49.205: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 10.219513372s
... skipping 431 lines ...
Jun  1 23:13:29.774: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.787690679s
Jun  1 23:13:31.811: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.824783771s
Jun  1 23:13:33.848: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.86168849s
Jun  1 23:13:35.888: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.90186353s
Jun  1 23:13:37.925: INFO: Pod "azuredisk-volume-tester-p6d6p": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.939067323s
Jun  1 23:13:39.926: INFO: deleting Pod "azuredisk-2888"/"azuredisk-volume-tester-p6d6p"
Jun  1 23:13:39.977: INFO: Error getting logs for pod azuredisk-volume-tester-p6d6p: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-p6d6p)
STEP: Deleting pod azuredisk-volume-tester-p6d6p in namespace azuredisk-2888
Jun  1 23:13:40.014: INFO: deleting PVC "azuredisk-2888"/"pvc-llx6b"
Jun  1 23:13:40.014: INFO: Deleting PersistentVolumeClaim "pvc-llx6b"
STEP: waiting for claim's PV "pvc-8e02b521-7a0a-43c3-a217-62eb4513c4d1" to be deleted
Jun  1 23:13:40.054: INFO: Waiting up to 10m0s for PersistentVolume pvc-8e02b521-7a0a-43c3-a217-62eb4513c4d1 to get deleted
Jun  1 23:13:40.089: INFO: PersistentVolume pvc-8e02b521-7a0a-43c3-a217-62eb4513c4d1 found and phase=Bound (35.197058ms)
... skipping 13 lines ...
Jun  1 23:14:20.519: INFO: At 2022-06-01 22:58:34 +0000 UTC - event for pvc-llx6b: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } Provisioning: External provisioner is provisioning volume for claim "azuredisk-2888/pvc-llx6b"
Jun  1 23:14:20.519: INFO: At 2022-06-01 22:58:34 +0000 UTC - event for pvc-llx6b: {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  1 23:14:20.519: INFO: At 2022-06-01 22:58:37 +0000 UTC - event for pvc-llx6b: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } ProvisioningSucceeded: Successfully provisioned volume pvc-8e02b521-7a0a-43c3-a217-62eb4513c4d1
Jun  1 23:14:20.519: INFO: At 2022-06-01 22:58:38 +0000 UTC - event for azuredisk-volume-tester-p6d6p: {default-scheduler } Scheduled: Successfully assigned azuredisk-2888/azuredisk-volume-tester-p6d6p to capz-t0o8-45hdr
Jun  1 23:14:20.519: INFO: At 2022-06-01 22:58:44 +0000 UTC - event for azuredisk-volume-tester-p6d6p: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-8e02b521-7a0a-43c3-a217-62eb4513c4d1" 
Jun  1 23:14:20.519: INFO: At 2022-06-01 22:59:15 +0000 UTC - event for azuredisk-volume-tester-p6d6p: {kubelet capz-t0o8-45hdr} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:14:20.519: INFO: At 2022-06-01 22:59:15 +0000 UTC - event for azuredisk-volume-tester-p6d6p: {kubelet capz-t0o8-45hdr} Failed: Error: ErrImagePull
Jun  1 23:14:20.519: INFO: At 2022-06-01 22:59:16 +0000 UTC - event for azuredisk-volume-tester-p6d6p: {kubelet capz-t0o8-45hdr} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:14:20.557: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  1 23:14:20.557: INFO: 
Jun  1 23:14:20.625: INFO: 
Logging node info for node capz-t0o8-45hdr
Jun  1 23:14:20.661: INFO: Node Info: &Node{ObjectMeta:{capz-t0o8-45hdr    30337305-834f-40af-a3d0-c3f1c2be0dc4 10263 0 2022-06-01 22:07:56 +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:eastus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-t0o8-45hdr 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:eastus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-t0o8fk cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-t0o8fk-md-win-7556bc86f-hhdqq cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-t0o8fk-md-win-7556bc86f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-t0o8-45hdr"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.218.129 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c6:a5:0a volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-06-01 22:07:56 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-06-01 22:07:56 +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":{}}} } {manager Update v1 2022-06-01 22:09:05 +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-01 22:09:24 +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-01 22:27:08 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-01 23:13:52 +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-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr,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-01 23:13:52 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-01 23:13:52 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-01 23:13:52 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-01 23:13:52 +0000 UTC,LastTransitionTime:2022-06-01 22:08:57 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-t0o8-45hdr,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-t0o8-45hdr,SystemUUID:D71EFA06-BDCF-4FED-8B99-A18B4DC0512C,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:c36c31a6fd4661f9bfe7f496a346b4c3308d8b5239db568c12d39fdada044526 capzci.azurecr.io/azuredisk-csi:v1.19.0-382e5c4473e73d1e23efbc30c74a84820fdf2d98],SizeBytes:127767703,},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 ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43
    should create a pod with volume mount subpath [disk.csi.azure.com] [Windows] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:159

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

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:805
------------------------------
Dynamic Provisioning [single-az] 
  Should create and attach a volume with basic perfProfile [enableBursting][disk.csi.azure.com] [Windows]
... skipping 19 lines ...
Jun  1 23:14:26.535: INFO: PersistentVolumeClaim pvc-t4kfz found and phase=Bound (4.110421316s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Jun  1 23:14:26.647: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-gltkb" in namespace "azuredisk-156" to be "Succeeded or Failed"
Jun  1 23:14:26.682: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 34.973084ms
Jun  1 23:14:28.719: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.07231237s
Jun  1 23:14:30.757: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.109649182s
Jun  1 23:14:32.796: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.148682153s
Jun  1 23:14:34.833: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.185625532s
Jun  1 23:14:36.871: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.223752866s
... skipping 431 lines ...
Jun  1 23:29:16.985: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.338058876s
Jun  1 23:29:19.021: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.374349061s
Jun  1 23:29:21.058: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.410619668s
Jun  1 23:29:23.094: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.446955628s
Jun  1 23:29:25.130: INFO: Pod "azuredisk-volume-tester-gltkb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.483134848s
Jun  1 23:29:27.131: INFO: deleting Pod "azuredisk-156"/"azuredisk-volume-tester-gltkb"
Jun  1 23:29:27.190: INFO: Error getting logs for pod azuredisk-volume-tester-gltkb: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-gltkb)
STEP: Deleting pod azuredisk-volume-tester-gltkb in namespace azuredisk-156
Jun  1 23:29:27.228: INFO: deleting PVC "azuredisk-156"/"pvc-t4kfz"
Jun  1 23:29:27.228: INFO: Deleting PersistentVolumeClaim "pvc-t4kfz"
STEP: waiting for claim's PV "pvc-b36da503-1a34-44a9-bfb3-948bdbdb4aa8" to be deleted
Jun  1 23:29:27.269: INFO: Waiting up to 10m0s for PersistentVolume pvc-b36da503-1a34-44a9-bfb3-948bdbdb4aa8 to get deleted
Jun  1 23:29:27.304: INFO: PersistentVolume pvc-b36da503-1a34-44a9-bfb3-948bdbdb4aa8 found and phase=Bound (35.533929ms)
... skipping 13 lines ...
Jun  1 23:30:07.716: INFO: At 2022-06-01 23:14:22 +0000 UTC - event for pvc-t4kfz: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } Provisioning: External provisioner is provisioning volume for claim "azuredisk-156/pvc-t4kfz"
Jun  1 23:30:07.716: INFO: At 2022-06-01 23:14:22 +0000 UTC - event for pvc-t4kfz: {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  1 23:30:07.716: INFO: At 2022-06-01 23:14:24 +0000 UTC - event for pvc-t4kfz: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } ProvisioningSucceeded: Successfully provisioned volume pvc-b36da503-1a34-44a9-bfb3-948bdbdb4aa8
Jun  1 23:30:07.716: INFO: At 2022-06-01 23:14:26 +0000 UTC - event for azuredisk-volume-tester-gltkb: {default-scheduler } Scheduled: Successfully assigned azuredisk-156/azuredisk-volume-tester-gltkb to capz-t0o8-45hdr
Jun  1 23:30:07.716: INFO: At 2022-06-01 23:14:38 +0000 UTC - event for azuredisk-volume-tester-gltkb: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-b36da503-1a34-44a9-bfb3-948bdbdb4aa8" 
Jun  1 23:30:07.716: INFO: At 2022-06-01 23:15:06 +0000 UTC - event for azuredisk-volume-tester-gltkb: {kubelet capz-t0o8-45hdr} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:30:07.716: INFO: At 2022-06-01 23:15:06 +0000 UTC - event for azuredisk-volume-tester-gltkb: {kubelet capz-t0o8-45hdr} Failed: Error: ErrImagePull
Jun  1 23:30:07.716: INFO: At 2022-06-01 23:15:06 +0000 UTC - event for azuredisk-volume-tester-gltkb: {kubelet capz-t0o8-45hdr} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:30:07.751: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  1 23:30:07.751: INFO: 
Jun  1 23:30:07.820: INFO: 
Logging node info for node capz-t0o8-45hdr
Jun  1 23:30:07.859: INFO: Node Info: &Node{ObjectMeta:{capz-t0o8-45hdr    30337305-834f-40af-a3d0-c3f1c2be0dc4 12442 0 2022-06-01 22:07:56 +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:eastus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-t0o8-45hdr 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:eastus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-t0o8fk cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-t0o8fk-md-win-7556bc86f-hhdqq cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-t0o8fk-md-win-7556bc86f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-t0o8-45hdr"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.218.129 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c6:a5:0a volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-06-01 22:07:56 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-06-01 22:07:56 +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":{}}} } {manager Update v1 2022-06-01 22:09:05 +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-01 22:09:24 +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-01 22:27:08 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-01 23:29:35 +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-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr,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-01 23:29:35 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-01 23:29:35 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-01 23:29:35 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-01 23:29:35 +0000 UTC,LastTransitionTime:2022-06-01 22:08:57 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-t0o8-45hdr,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-t0o8-45hdr,SystemUUID:D71EFA06-BDCF-4FED-8B99-A18B4DC0512C,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:c36c31a6fd4661f9bfe7f496a346b4c3308d8b5239db568c12d39fdada044526 capzci.azurecr.io/azuredisk-csi:v1.19.0-382e5c4473e73d1e23efbc30c74a84820fdf2d98],SizeBytes:127767703,},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 ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43
    Should create and attach a volume with basic perfProfile [enableBursting][disk.csi.azure.com] [Windows] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:194

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

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:805
------------------------------
Dynamic Provisioning [single-az] 
  should receive FailedMount event with invalid mount options [kubernetes.io/azure-disk] [disk.csi.azure.com]
... skipping 75 lines ...
Jun  1 23:30:14.927: INFO: PersistentVolumeClaim pvc-rwdsl found and phase=Bound (4.140065111s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with an error
Jun  1 23:30:15.033: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-jb54r" in namespace "azuredisk-9241" to be "Error status code"
Jun  1 23:30:15.068: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 34.631265ms
Jun  1 23:30:17.105: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071097073s
Jun  1 23:30:19.142: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 4.108092353s
Jun  1 23:30:21.179: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 6.145259175s
Jun  1 23:30:23.216: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 8.182468867s
Jun  1 23:30:25.254: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 10.220021883s
... skipping 431 lines ...
Jun  1 23:45:05.423: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.389700803s
Jun  1 23:45:07.460: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.426300065s
Jun  1 23:45:09.498: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.4640066s
Jun  1 23:45:11.538: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.504100203s
Jun  1 23:45:13.574: INFO: Pod "azuredisk-volume-tester-jb54r": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.540897463s
Jun  1 23:45:15.576: INFO: deleting Pod "azuredisk-9241"/"azuredisk-volume-tester-jb54r"
Jun  1 23:45:15.627: INFO: Error getting logs for pod azuredisk-volume-tester-jb54r: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-jb54r)
STEP: Deleting pod azuredisk-volume-tester-jb54r in namespace azuredisk-9241
Jun  1 23:45:15.666: INFO: deleting PVC "azuredisk-9241"/"pvc-rwdsl"
Jun  1 23:45:15.666: INFO: Deleting PersistentVolumeClaim "pvc-rwdsl"
STEP: waiting for claim's PV "pvc-e6fe8573-6113-4801-ab00-77dbcea5ec5a" to be deleted
Jun  1 23:45:15.708: INFO: Waiting up to 10m0s for PersistentVolume pvc-e6fe8573-6113-4801-ab00-77dbcea5ec5a to get deleted
Jun  1 23:45:15.768: INFO: PersistentVolume pvc-e6fe8573-6113-4801-ab00-77dbcea5ec5a found and phase=Bound (59.439161ms)
... skipping 13 lines ...
Jun  1 23:45:56.195: INFO: At 2022-06-01 23:30:10 +0000 UTC - event for pvc-rwdsl: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } Provisioning: External provisioner is provisioning volume for claim "azuredisk-9241/pvc-rwdsl"
Jun  1 23:45:56.195: INFO: At 2022-06-01 23:30:10 +0000 UTC - event for pvc-rwdsl: {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  1 23:45:56.195: INFO: At 2022-06-01 23:30:13 +0000 UTC - event for pvc-rwdsl: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } ProvisioningSucceeded: Successfully provisioned volume pvc-e6fe8573-6113-4801-ab00-77dbcea5ec5a
Jun  1 23:45:56.195: INFO: At 2022-06-01 23:30:15 +0000 UTC - event for azuredisk-volume-tester-jb54r: {default-scheduler } Scheduled: Successfully assigned azuredisk-9241/azuredisk-volume-tester-jb54r to capz-t0o8-rmk8l
Jun  1 23:45:56.195: INFO: At 2022-06-01 23:30:20 +0000 UTC - event for azuredisk-volume-tester-jb54r: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-e6fe8573-6113-4801-ab00-77dbcea5ec5a" 
Jun  1 23:45:56.195: INFO: At 2022-06-01 23:30:48 +0000 UTC - event for azuredisk-volume-tester-jb54r: {kubelet capz-t0o8-rmk8l} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:45:56.195: INFO: At 2022-06-01 23:30:48 +0000 UTC - event for azuredisk-volume-tester-jb54r: {kubelet capz-t0o8-rmk8l} Failed: Error: ErrImagePull
Jun  1 23:45:56.195: INFO: At 2022-06-01 23:30:49 +0000 UTC - event for azuredisk-volume-tester-jb54r: {kubelet capz-t0o8-rmk8l} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:45:56.230: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  1 23:45:56.230: INFO: 
Jun  1 23:45:56.267: INFO: 
Logging node info for node capz-t0o8-45hdr
Jun  1 23:45:56.303: INFO: Node Info: &Node{ObjectMeta:{capz-t0o8-45hdr    30337305-834f-40af-a3d0-c3f1c2be0dc4 14575 0 2022-06-01 22:07:56 +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:eastus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-t0o8-45hdr 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:eastus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-t0o8fk cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-t0o8fk-md-win-7556bc86f-hhdqq cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-t0o8fk-md-win-7556bc86f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-t0o8-45hdr"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.218.129 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c6:a5:0a volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-06-01 22:07:56 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-06-01 22:07:56 +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":{}}} } {manager Update v1 2022-06-01 22:09:05 +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-01 22:09:24 +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-01 22:27:08 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-01 23:29:35 +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-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr,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-01 23:44:53 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-01 23:44:53 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-01 23:44:53 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-01 23:44:53 +0000 UTC,LastTransitionTime:2022-06-01 22:08:57 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-t0o8-45hdr,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-t0o8-45hdr,SystemUUID:D71EFA06-BDCF-4FED-8B99-A18B4DC0512C,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:c36c31a6fd4661f9bfe7f496a346b4c3308d8b5239db568c12d39fdada044526 capzci.azurecr.io/azuredisk-csi:v1.19.0-382e5c4473e73d1e23efbc30c74a84820fdf2d98],SizeBytes:127767703,},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 ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43
    should create a volume on demand and mount it as readOnly in a pod [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:299

    Unexpected error:
        <*errors.errorString | 0xc000f33100>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-jb54r\" to be \"Error status code\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-jb54r" to be "Error status code"
    occurred

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:844
------------------------------
Dynamic Provisioning [single-az] 
  should 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]
... skipping 21 lines ...
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod is running
Jun  1 23:51:02.226: INFO: deleting Pod "azuredisk-9336"/"azuredisk-volume-tester-bwm29"
Jun  1 23:51:02.285: INFO: Error getting logs for pod azuredisk-volume-tester-bwm29: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-bwm29)
STEP: Deleting pod azuredisk-volume-tester-bwm29 in namespace azuredisk-9336
Jun  1 23:51:02.325: INFO: deleting PVC "azuredisk-9336"/"pvc-5w55k"
Jun  1 23:51:02.325: INFO: Deleting PersistentVolumeClaim "pvc-5w55k"
STEP: waiting for claim's PV "pvc-03bbd427-2a99-4c14-8ea0-5d3a0b597513" to be deleted
Jun  1 23:51:02.361: INFO: Waiting up to 10m0s for PersistentVolume pvc-03bbd427-2a99-4c14-8ea0-5d3a0b597513 to get deleted
Jun  1 23:51:02.396: INFO: PersistentVolume pvc-03bbd427-2a99-4c14-8ea0-5d3a0b597513 found and phase=Bound (35.440038ms)
... skipping 13 lines ...
Jun  1 23:51:42.819: INFO: At 2022-06-01 23:45:57 +0000 UTC - event for pvc-5w55k: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } Provisioning: External provisioner is provisioning volume for claim "azuredisk-9336/pvc-5w55k"
Jun  1 23:51:42.819: INFO: At 2022-06-01 23:45:57 +0000 UTC - event for pvc-5w55k: {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  1 23:51:42.819: INFO: At 2022-06-01 23:46:00 +0000 UTC - event for pvc-5w55k: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } ProvisioningSucceeded: Successfully provisioned volume pvc-03bbd427-2a99-4c14-8ea0-5d3a0b597513
Jun  1 23:51:42.819: INFO: At 2022-06-01 23:46:02 +0000 UTC - event for azuredisk-volume-tester-bwm29: {default-scheduler } Scheduled: Successfully assigned azuredisk-9336/azuredisk-volume-tester-bwm29 to capz-t0o8-45hdr
Jun  1 23:51:42.819: INFO: At 2022-06-01 23:46:08 +0000 UTC - event for azuredisk-volume-tester-bwm29: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-03bbd427-2a99-4c14-8ea0-5d3a0b597513" 
Jun  1 23:51:42.819: INFO: At 2022-06-01 23:46:34 +0000 UTC - event for azuredisk-volume-tester-bwm29: {kubelet capz-t0o8-45hdr} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:51:42.819: INFO: At 2022-06-01 23:46:34 +0000 UTC - event for azuredisk-volume-tester-bwm29: {kubelet capz-t0o8-45hdr} Failed: Error: ErrImagePull
Jun  1 23:51:42.819: INFO: At 2022-06-01 23:46:35 +0000 UTC - event for azuredisk-volume-tester-bwm29: {kubelet capz-t0o8-45hdr} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:51:42.855: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  1 23:51:42.855: INFO: 
Jun  1 23:51:42.924: INFO: 
Logging node info for node capz-t0o8-45hdr
Jun  1 23:51:42.960: INFO: Node Info: &Node{ObjectMeta:{capz-t0o8-45hdr    30337305-834f-40af-a3d0-c3f1c2be0dc4 15521 0 2022-06-01 22:07:56 +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:eastus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-t0o8-45hdr 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:eastus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-t0o8fk cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-t0o8fk-md-win-7556bc86f-hhdqq cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-t0o8fk-md-win-7556bc86f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-t0o8-45hdr"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.218.129 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c6:a5:0a volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-06-01 22:07:56 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-06-01 22:07:56 +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":{}}} } {manager Update v1 2022-06-01 22:09:05 +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-01 22:09:24 +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-01 22:27:08 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-01 23:51:12 +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-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr,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-01 23:51:12 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-01 23:51:12 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-01 23:51:12 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-01 23:51:12 +0000 UTC,LastTransitionTime:2022-06-01 22:08:57 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-t0o8-45hdr,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-t0o8-45hdr,SystemUUID:D71EFA06-BDCF-4FED-8B99-A18B4DC0512C,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:c36c31a6fd4661f9bfe7f496a346b4c3308d8b5239db568c12d39fdada044526 capzci.azurecr.io/azuredisk-csi:v1.19.0-382e5c4473e73d1e23efbc30c74a84820fdf2d98],SizeBytes:127767703,},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 ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43
    should 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]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:333

    Unexpected error:
        <*errors.errorString | 0xc0001e0470>: {
            s: "timed out waiting for the condition",
        }
        timed out waiting for the condition
    occurred

... skipping 104 lines ...
Jun  1 23:54:18.880: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
Jun  1 23:54:20.879: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
Jun  1 23:54:22.879: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
Jun  1 23:54:24.880: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
Jun  1 23:54:26.879: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
Jun  1 23:54:28.880: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" 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-01T23:54:29Z"}
++ early_exit_handler
++ '[' -n 150 ']'
++ kill -TERM 150
++ cleanup_dind
++ [[ true == \t\r\u\e ]]
++ echo 'Cleaning up after docker'
... skipping 2 lines ...
++ xargs -r docker rm -f
make: Nothing to be done for 'kubectl'.
================ DUMPING LOGS FOR MANAGEMENT CLUSTER ================
8f38f3fcd159
a9704b47d734
++ 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?
Jun  1 23:54:30.879: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
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:41767 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  1 23:54:32.879: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
Jun  1 23:54:34.879: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
Jun  1 23:54:36.879: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
Jun  1 23:54:38.878: 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
... skipping 98 lines ...
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:51:46 +0000 UTC - event for pvc-tflvq: {disk.csi.azure.com_capz-t0o8fk-control-plane-6k4zw_289a83e7-a5d7-4488-8de8-10a2eb51d267 } ProvisioningSucceeded: Successfully provisioned volume pvc-19fad7c0-e9f5-4de9-9981-1e1f338944d7
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:51:48 +0000 UTC - event for azuredisk-volume-tester-2tzf5: {deployment-controller } ScalingReplicaSet: Scaled up replica set azuredisk-volume-tester-2tzf5-84777bd46 to 1
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:51:48 +0000 UTC - event for azuredisk-volume-tester-2tzf5-84777bd46: {replicaset-controller } SuccessfulCreate: Created pod: azuredisk-volume-tester-2tzf5-84777bd46-jdtbg
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:51:48 +0000 UTC - event for azuredisk-volume-tester-2tzf5-84777bd46-jdtbg: {default-scheduler } Scheduled: Successfully assigned azuredisk-2205/azuredisk-volume-tester-2tzf5-84777bd46-jdtbg to capz-t0o8-45hdr
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:52:00 +0000 UTC - event for azuredisk-volume-tester-2tzf5-84777bd46-jdtbg: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-19fad7c0-e9f5-4de9-9981-1e1f338944d7" 
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:52:25 +0000 UTC - event for azuredisk-volume-tester-2tzf5-84777bd46-jdtbg: {kubelet capz-t0o8-45hdr} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:52:25 +0000 UTC - event for azuredisk-volume-tester-2tzf5-84777bd46-jdtbg: {kubelet capz-t0o8-45hdr} Failed: Error: ErrImagePull
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:52:26 +0000 UTC - event for azuredisk-volume-tester-2tzf5-84777bd46-jdtbg: {kubelet capz-t0o8-45hdr} Failed: Error: ImagePullBackOff
Jun  1 23:57:29.445: INFO: At 2022-06-01 23:52:26 +0000 UTC - event for azuredisk-volume-tester-2tzf5-84777bd46-jdtbg: {kubelet capz-t0o8-45hdr} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  1 23:57:29.480: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  1 23:57:29.481: INFO: 
Jun  1 23:57:29.549: INFO: 
Logging node info for node capz-t0o8-45hdr
Jun  1 23:57:29.585: INFO: Node Info: &Node{ObjectMeta:{capz-t0o8-45hdr    30337305-834f-40af-a3d0-c3f1c2be0dc4 16402 0 2022-06-01 22:07:56 +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:eastus2 failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-t0o8-45hdr 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:eastus2 topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-t0o8fk cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-t0o8fk-md-win-7556bc86f-hhdqq cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-t0o8fk-md-win-7556bc86f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-t0o8-45hdr"} kubeadm.alpha.kubernetes.io/cri-socket:npipe:////./pipe/containerd-containerd node.alpha.kubernetes.io/ttl:0 projectcalico.org/IPv4Address:10.1.0.5/16 projectcalico.org/IPv4VXLANTunnelAddr:192.168.218.129 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c6:a5:0a volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-06-01 22:07:56 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-06-01 22:07:56 +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":{}}} } {manager Update v1 2022-06-01 22:09:05 +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-01 22:09:24 +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-01 22:27:08 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {kubelet.exe Update v1 2022-06-01 23:56:58 +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-t0o8fk/providers/Microsoft.Compute/virtualMachines/capz-t0o8-45hdr,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-01 23:56:58 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-01 23:56:58 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-01 23:56:58 +0000 UTC,LastTransitionTime:2022-06-01 22:07:56 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-01 23:56:58 +0000 UTC,LastTransitionTime:2022-06-01 22:08:57 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-t0o8-45hdr,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-t0o8-45hdr,SystemUUID:D71EFA06-BDCF-4FED-8B99-A18B4DC0512C,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:c36c31a6fd4661f9bfe7f496a346b4c3308d8b5239db568c12d39fdada044526 capzci.azurecr.io/azuredisk-csi:v1.19.0-382e5c4473e73d1e23efbc30c74a84820fdf2d98],SizeBytes:127767703,},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 ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:40
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:43
    should 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]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:397

    Unexpected error:
        <*errors.errorString | 0xc00060cd20>: {
            s: "error waiting for deployment \"azuredisk-volume-tester-2tzf5\" 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:\"MinimumReplicasUnavailable\", Message:\"Deployment does not have minimum availability.\"}, v1.DeploymentCondition{Type:\"Progressing\", Status:\"True\", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:\"ReplicaSetUpdated\", Message:\"ReplicaSet \\\"azuredisk-volume-tester-2tzf5-84777bd46\\\" is progressing.\"}}, CollisionCount:(*int32)(nil)}",
        }
        error waiting for deployment "azuredisk-volume-tester-2tzf5" 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, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 1, 23, 51, 48, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-2tzf5-84777bd46\" is progressing."}}, CollisionCount:(*int32)(nil)}
    occurred

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:503
------------------------------
Dynamic Provisioning [single-az] 
  should delete PV with reclaimPolicy "Delete" [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows]
... skipping 194 lines ...
Jun  1 23:58:06.600: INFO: PersistentVolumeClaim pvc-tp6pj found and phase=Bound (4.109509606s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Jun  1 23:58:06.708: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-4kfl6" in namespace "azuredisk-1387" to be "Succeeded or Failed"
Jun  1 23:58:06.743: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 34.906223ms
Jun  1 23:58:08.780: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.072287595s
Jun  1 23:58:10.818: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.109848128s
Jun  1 23:58:12.855: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.146978302s
Jun  1 23:58:14.891: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.183501708s
Jun  1 23:58:16.929: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.220931795s
... skipping 324 lines ...
Jun  2 00:09:19.041: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 11m12.333065074s
Jun  2 00:09:21.077: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 11m14.36922535s
Jun  2 00:09:23.115: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 11m16.406690099s
Jun  2 00:09:25.152: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 11m18.443840323s
Jun  2 00:09:27.188: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 11m20.480162247s
Jun  2 00:09:29.225: INFO: Pod "azuredisk-volume-tester-4kfl6": Phase="Pending", Reason="", readiness=false. Elapsed: 11m22.517639287s
{"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-02T00:09:29Z"}
{"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-02T00:09:29Z"}