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-02 16:13
Elapsed2h15m
Revisionfa06ff44036ca43a3c6f75ad053eec797aaeaab9
Refs 1359

No Test Failures!


Error lines from build-log.txt

... skipping 674 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 182 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11156  100 11156    0     0   187k      0 --:--:-- --:--:-- --:--:--  191k
Downloading https://get.helm.sh/helm-v3.9.0-linux-amd64.tar.gz
Verifying checksum... Done.
Preparing to install helm into /usr/local/bin
helm installed into /usr/local/bin/helm
docker pull capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7 || make container-all push-manifest
Error response from daemon: manifest for capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7 not found: manifest unknown: manifest tagged by "v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7" is not found
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver'
CGO_ENABLED=0 GOOS=windows go build -a -ldflags "-X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.driverVersion=v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=8f268ea61f83c9f055a1208a57642439601de5e7 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2022-06-02T16:33:26Z -extldflags "-static""  -mod vendor -o _output/amd64/azurediskplugin.exe ./pkg/azurediskplugin
docker buildx rm container-builder || true
error: no builder "container-builder" found
docker buildx create --use --name=container-builder
container-builder
# enable qemu for arm64 build
# https://github.com/docker/buildx/issues/464#issuecomment-741507760
docker run --privileged --rm tonistiigi/binfmt --uninstall qemu-aarch64
Unable to find image 'tonistiigi/binfmt:latest' locally
... skipping 2075 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 159 lines ...
Jun  2 16:43:13.825: INFO: PersistentVolumeClaim pvc-plvtk found and phase=Bound (4.099504562s)
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  2 16:43:13.923: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-g579z" in namespace "azuredisk-8081" to be "Succeeded or Failed"
Jun  2 16:43:13.970: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 47.039705ms
Jun  2 16:43:16.002: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 2.07964062s
Jun  2 16:43:18.036: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 4.112825684s
Jun  2 16:43:20.069: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 6.146051114s
Jun  2 16:43:22.101: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 8.17848126s
Jun  2 16:43:24.134: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 10.210912729s
... skipping 432 lines ...
Jun  2 16:58:04.538: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.614942385s
Jun  2 16:58:06.571: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.648354265s
Jun  2 16:58:08.604: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.681061475s
Jun  2 16:58:10.638: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.715162196s
Jun  2 16:58:12.673: INFO: Pod "azuredisk-volume-tester-g579z": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.749778298s
Jun  2 16:58:14.674: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-g579z"
Jun  2 16:58:14.741: INFO: Error getting logs for pod azuredisk-volume-tester-g579z: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-g579z)
STEP: Deleting pod azuredisk-volume-tester-g579z in namespace azuredisk-8081
Jun  2 16:58:14.774: INFO: deleting PVC "azuredisk-8081"/"pvc-plvtk"
Jun  2 16:58:14.774: INFO: Deleting PersistentVolumeClaim "pvc-plvtk"
STEP: waiting for claim's PV "pvc-d7d9a167-2454-4a2c-8b19-d2a8772aa5c6" to be deleted
Jun  2 16:58:14.807: INFO: Waiting up to 10m0s for PersistentVolume pvc-d7d9a167-2454-4a2c-8b19-d2a8772aa5c6 to get deleted
Jun  2 16:58:14.839: INFO: PersistentVolume pvc-d7d9a167-2454-4a2c-8b19-d2a8772aa5c6 found and phase=Bound (31.648845ms)
... skipping 13 lines ...
Jun  2 16:58:55.212: INFO: At 2022-06-02 16:43:09 +0000 UTC - event for pvc-plvtk: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-8081/pvc-plvtk"
Jun  2 16:58:55.212: INFO: At 2022-06-02 16:43:09 +0000 UTC - event for pvc-plvtk: {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  2 16:58:55.212: INFO: At 2022-06-02 16:43:12 +0000 UTC - event for pvc-plvtk: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } ProvisioningSucceeded: Successfully provisioned volume pvc-d7d9a167-2454-4a2c-8b19-d2a8772aa5c6
Jun  2 16:58:55.212: INFO: At 2022-06-02 16:43:13 +0000 UTC - event for azuredisk-volume-tester-g579z: {default-scheduler } Scheduled: Successfully assigned azuredisk-8081/azuredisk-volume-tester-g579z to capz-e0m0-hmftv
Jun  2 16:58:55.212: INFO: At 2022-06-02 16:43:25 +0000 UTC - event for azuredisk-volume-tester-g579z: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-d7d9a167-2454-4a2c-8b19-d2a8772aa5c6" 
Jun  2 16:58:55.212: INFO: At 2022-06-02 16:43:57 +0000 UTC - event for azuredisk-volume-tester-g579z: {kubelet capz-e0m0-hmftv} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 16:58:55.212: INFO: At 2022-06-02 16:43:57 +0000 UTC - event for azuredisk-volume-tester-g579z: {kubelet capz-e0m0-hmftv} Failed: Error: ErrImagePull
Jun  2 16:58:55.212: INFO: At 2022-06-02 16:43:57 +0000 UTC - event for azuredisk-volume-tester-g579z: {kubelet capz-e0m0-hmftv} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 16:58:55.244: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  2 16:58:55.244: INFO: 
Jun  2 16:58:55.305: INFO: 
Logging node info for node capz-e0m0-hmftv
Jun  2 16:58:55.337: INFO: Node Info: &Node{ObjectMeta:{capz-e0m0-hmftv    6ec87d31-e181-4193-8961-a1deae617993 4673 0 2022-06-02 16:26:40 +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:eastus failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-e0m0-hmftv 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:eastus topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-e0m0ge cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-e0m0ge-md-win-b6967bc77-4tfsp cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-e0m0ge-md-win-b6967bc77 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-e0m0-hmftv"} 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.25.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c5:ee:60 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubelet.exe Update v1 2022-06-02 16:26:40 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-02 16:26:41 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kube-controller-manager Update v1 2022-06-02 16:26:43 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-06-02 16:28:04 +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-02 16:28:10 +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-02 16:58:24 +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-e0m0ge/providers/Microsoft.Compute/virtualMachines/capz-e0m0-hmftv,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-02 16:58:24 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-02 16:58:24 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-02 16:58:24 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-02 16:58:24 +0000 UTC,LastTransitionTime:2022-06-02 16:27:41 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-e0m0-hmftv,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-e0m0-hmftv,SystemUUID:8149DAA4-037D-4074-A46D-29F9204CD28B,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 88 lines ...
/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 | 0xc000654360>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-g579z\" to be \"Succeeded or Failed\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-g579z" 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  2 16:58:58.939: INFO: PersistentVolumeClaim pvc-25plc found but phase is Pending instead of Bound.
Jun  2 16:59:00.972: INFO: PersistentVolumeClaim pvc-25plc found and phase=Bound (4.098558375s)
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  2 16:59:01.070: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-42fgf" in namespace "azuredisk-2540" to be "Succeeded or Failed"
Jun  2 16:59:01.102: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 31.911472ms
Jun  2 16:59:03.135: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.065571257s
Jun  2 16:59:05.168: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.098246179s
Jun  2 16:59:07.202: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.132139854s
Jun  2 16:59:09.237: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.167341316s
Jun  2 16:59:11.271: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.201127137s
... skipping 431 lines ...
Jun  2 17:13:50.966: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m49.895824684s
Jun  2 17:13:53.000: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m51.930194406s
Jun  2 17:13:55.032: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m53.962446189s
Jun  2 17:13:57.065: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m55.995432006s
Jun  2 17:13:59.099: INFO: Pod "azuredisk-volume-tester-42fgf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.028733559s
Jun  2 17:14:01.099: INFO: deleting Pod "azuredisk-2540"/"azuredisk-volume-tester-42fgf"
Jun  2 17:14:01.163: INFO: Error getting logs for pod azuredisk-volume-tester-42fgf: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-42fgf)
STEP: Deleting pod azuredisk-volume-tester-42fgf in namespace azuredisk-2540
Jun  2 17:14:01.196: INFO: deleting PVC "azuredisk-2540"/"pvc-25plc"
Jun  2 17:14:01.197: INFO: Deleting PersistentVolumeClaim "pvc-25plc"
STEP: waiting for claim's PV "pvc-ae1b0913-0587-442c-94b5-1f0532da1d4c" to be deleted
Jun  2 17:14:01.229: INFO: Waiting up to 10m0s for PersistentVolume pvc-ae1b0913-0587-442c-94b5-1f0532da1d4c to get deleted
Jun  2 17:14:01.266: INFO: PersistentVolume pvc-ae1b0913-0587-442c-94b5-1f0532da1d4c found and phase=Bound (36.907018ms)
... skipping 12 lines ...
STEP: Found 9 events.
Jun  2 17:14:41.639: INFO: At 2022-06-02 16:58:56 +0000 UTC - event for pvc-25plc: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-2540/pvc-25plc"
Jun  2 17:14:41.639: INFO: At 2022-06-02 16:58:56 +0000 UTC - event for pvc-25plc: {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  2 17:14:41.639: INFO: At 2022-06-02 16:58:59 +0000 UTC - event for pvc-25plc: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } ProvisioningSucceeded: Successfully provisioned volume pvc-ae1b0913-0587-442c-94b5-1f0532da1d4c
Jun  2 17:14:41.639: INFO: At 2022-06-02 16:59:01 +0000 UTC - event for azuredisk-volume-tester-42fgf: {default-scheduler } Scheduled: Successfully assigned azuredisk-2540/azuredisk-volume-tester-42fgf to capz-e0m0-k428f
Jun  2 17:14:41.639: INFO: At 2022-06-02 16:59:12 +0000 UTC - event for azuredisk-volume-tester-42fgf: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-ae1b0913-0587-442c-94b5-1f0532da1d4c" 
Jun  2 17:14:41.639: INFO: At 2022-06-02 16:59:43 +0000 UTC - event for azuredisk-volume-tester-42fgf: {kubelet capz-e0m0-k428f} Failed: Failed to pull image "mcr.microsoft.com/windows/servercore:ltsc2022": rpc error: code = NotFound desc = failed to pull and unpack image "mcr.microsoft.com/windows/servercore:ltsc2022": no match for platform in manifest: not found
Jun  2 17:14:41.639: INFO: At 2022-06-02 16:59:43 +0000 UTC - event for azuredisk-volume-tester-42fgf: {kubelet capz-e0m0-k428f} Failed: Error: ErrImagePull
Jun  2 17:14:41.639: INFO: At 2022-06-02 16:59:43 +0000 UTC - event for azuredisk-volume-tester-42fgf: {kubelet capz-e0m0-k428f} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:14:41.639: INFO: At 2022-06-02 16:59:43 +0000 UTC - event for azuredisk-volume-tester-42fgf: {kubelet capz-e0m0-k428f} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:14:41.670: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  2 17:14:41.670: INFO: 
Jun  2 17:14:41.710: INFO: 
Logging node info for node capz-e0m0-hmftv
... skipping 89 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 | 0xc0007bcdb0>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-42fgf\" to be \"Succeeded or Failed\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-42fgf" 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  2 17:14:47.360: INFO: PersistentVolumeClaim pvc-ws5qf found and phase=Bound (4.096677962s)
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  2 17:14:47.457: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-c6hvb" in namespace "azuredisk-4728" to be "Succeeded or Failed"
Jun  2 17:14:47.495: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 37.81886ms
Jun  2 17:14:49.529: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.072295471s
Jun  2 17:14:51.563: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.105833998s
Jun  2 17:14:53.596: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.13885377s
Jun  2 17:14:55.629: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.172470302s
Jun  2 17:14:57.661: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.204391033s
... skipping 432 lines ...
Jun  2 17:29:38.153: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.695567125s
Jun  2 17:29:40.186: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.728627652s
Jun  2 17:29:42.219: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.762171547s
Jun  2 17:29:44.251: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.793905045s
Jun  2 17:29:46.291: INFO: Pod "azuredisk-volume-tester-c6hvb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.833830203s
Jun  2 17:29:48.292: INFO: deleting Pod "azuredisk-4728"/"azuredisk-volume-tester-c6hvb"
Jun  2 17:29:48.344: INFO: Error getting logs for pod azuredisk-volume-tester-c6hvb: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-c6hvb)
STEP: Deleting pod azuredisk-volume-tester-c6hvb in namespace azuredisk-4728
Jun  2 17:29:48.382: INFO: deleting PVC "azuredisk-4728"/"pvc-ws5qf"
Jun  2 17:29:48.382: INFO: Deleting PersistentVolumeClaim "pvc-ws5qf"
STEP: waiting for claim's PV "pvc-e5bed105-80cb-4a90-8823-0b630f12eb06" to be deleted
Jun  2 17:29:48.418: INFO: Waiting up to 10m0s for PersistentVolume pvc-e5bed105-80cb-4a90-8823-0b630f12eb06 to get deleted
Jun  2 17:29:48.450: INFO: PersistentVolume pvc-e5bed105-80cb-4a90-8823-0b630f12eb06 found and phase=Bound (31.392175ms)
... skipping 13 lines ...
Jun  2 17:30:28.834: INFO: At 2022-06-02 17:14:43 +0000 UTC - event for pvc-ws5qf: {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  2 17:30:28.834: INFO: At 2022-06-02 17:14:43 +0000 UTC - event for pvc-ws5qf: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-4728/pvc-ws5qf"
Jun  2 17:30:28.834: INFO: At 2022-06-02 17:14:46 +0000 UTC - event for pvc-ws5qf: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } ProvisioningSucceeded: Successfully provisioned volume pvc-e5bed105-80cb-4a90-8823-0b630f12eb06
Jun  2 17:30:28.834: INFO: At 2022-06-02 17:14:47 +0000 UTC - event for azuredisk-volume-tester-c6hvb: {default-scheduler } Scheduled: Successfully assigned azuredisk-4728/azuredisk-volume-tester-c6hvb to capz-e0m0-hmftv
Jun  2 17:30:28.834: INFO: At 2022-06-02 17:14:54 +0000 UTC - event for azuredisk-volume-tester-c6hvb: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-e5bed105-80cb-4a90-8823-0b630f12eb06" 
Jun  2 17:30:28.834: INFO: At 2022-06-02 17:15:24 +0000 UTC - event for azuredisk-volume-tester-c6hvb: {kubelet capz-e0m0-hmftv} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:30:28.834: INFO: At 2022-06-02 17:15:24 +0000 UTC - event for azuredisk-volume-tester-c6hvb: {kubelet capz-e0m0-hmftv} Failed: Error: ErrImagePull
Jun  2 17:30:28.834: INFO: At 2022-06-02 17:15:24 +0000 UTC - event for azuredisk-volume-tester-c6hvb: {kubelet capz-e0m0-hmftv} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:30:28.899: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  2 17:30:28.899: INFO: 
Jun  2 17:30:28.978: INFO: 
Logging node info for node capz-e0m0-hmftv
Jun  2 17:30:29.018: INFO: Node Info: &Node{ObjectMeta:{capz-e0m0-hmftv    6ec87d31-e181-4193-8961-a1deae617993 9056 0 2022-06-02 16:26:40 +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:eastus failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-e0m0-hmftv 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:eastus topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-e0m0ge cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-e0m0ge-md-win-b6967bc77-4tfsp cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-e0m0ge-md-win-b6967bc77 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-e0m0-hmftv"} 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.25.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c5:ee:60 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubelet.exe Update v1 2022-06-02 16:26:40 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-02 16:26:41 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kube-controller-manager Update v1 2022-06-02 16:26:43 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-06-02 16:28:04 +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-02 16:28:10 +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-02 17:29:55 +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-e0m0ge/providers/Microsoft.Compute/virtualMachines/capz-e0m0-hmftv,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-02 17:29:55 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-02 17:29:55 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-02 17:29:55 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-02 17:29:55 +0000 UTC,LastTransitionTime:2022-06-02 16:27:41 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-e0m0-hmftv,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-e0m0-hmftv,SystemUUID:8149DAA4-037D-4074-A46D-29F9204CD28B,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 88 lines ...
/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 | 0xc00045cf30>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-c6hvb\" to be \"Succeeded or Failed\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-c6hvb" 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  2 17:30:35.799: INFO: PersistentVolumeClaim pvc-xj5k7 found and phase=Bound (4.10316085s)
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  2 17:30:35.909: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-q7dxx" in namespace "azuredisk-5356" to be "Error status code"
Jun  2 17:30:35.941: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 31.989367ms
Jun  2 17:30:37.973: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.064467395s
Jun  2 17:30:40.006: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.097822039s
Jun  2 17:30:42.039: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.130863303s
Jun  2 17:30:44.072: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.163372721s
Jun  2 17:30:46.104: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.195652789s
... skipping 432 lines ...
Jun  2 17:45:26.617: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.708500723s
Jun  2 17:45:28.650: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.741051302s
Jun  2 17:45:30.683: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.774505238s
Jun  2 17:45:32.717: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.808674683s
Jun  2 17:45:34.884: INFO: Pod "azuredisk-volume-tester-q7dxx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.975382304s
Jun  2 17:45:36.885: INFO: deleting Pod "azuredisk-5356"/"azuredisk-volume-tester-q7dxx"
Jun  2 17:45:36.932: INFO: Error getting logs for pod azuredisk-volume-tester-q7dxx: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-q7dxx)
STEP: Deleting pod azuredisk-volume-tester-q7dxx in namespace azuredisk-5356
Jun  2 17:45:36.966: INFO: deleting PVC "azuredisk-5356"/"pvc-xj5k7"
Jun  2 17:45:36.966: INFO: Deleting PersistentVolumeClaim "pvc-xj5k7"
STEP: waiting for claim's PV "pvc-95c58a64-4d62-4312-bb06-18da6d4a28a9" to be deleted
Jun  2 17:45:36.999: INFO: Waiting up to 10m0s for PersistentVolume pvc-95c58a64-4d62-4312-bb06-18da6d4a28a9 to get deleted
Jun  2 17:45:37.031: INFO: PersistentVolume pvc-95c58a64-4d62-4312-bb06-18da6d4a28a9 found and phase=Bound (31.642875ms)
... skipping 12 lines ...
Jun  2 17:46:12.377: INFO: At 2022-06-02 17:30:31 +0000 UTC - event for pvc-xj5k7: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-5356/pvc-xj5k7"
Jun  2 17:46:12.377: INFO: At 2022-06-02 17:30:31 +0000 UTC - event for pvc-xj5k7: {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  2 17:46:12.377: INFO: At 2022-06-02 17:30:34 +0000 UTC - event for pvc-xj5k7: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } ProvisioningSucceeded: Successfully provisioned volume pvc-95c58a64-4d62-4312-bb06-18da6d4a28a9
Jun  2 17:46:12.377: INFO: At 2022-06-02 17:30:35 +0000 UTC - event for azuredisk-volume-tester-q7dxx: {default-scheduler } Scheduled: Successfully assigned azuredisk-5356/azuredisk-volume-tester-q7dxx to capz-e0m0-hmftv
Jun  2 17:46:12.377: INFO: At 2022-06-02 17:30:42 +0000 UTC - event for azuredisk-volume-tester-q7dxx: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-95c58a64-4d62-4312-bb06-18da6d4a28a9" 
Jun  2 17:46:12.377: INFO: At 2022-06-02 17:31:12 +0000 UTC - event for azuredisk-volume-tester-q7dxx: {kubelet capz-e0m0-hmftv} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:46:12.377: INFO: At 2022-06-02 17:31:12 +0000 UTC - event for azuredisk-volume-tester-q7dxx: {kubelet capz-e0m0-hmftv} Failed: Error: ErrImagePull
Jun  2 17:46:12.377: INFO: At 2022-06-02 17:31:13 +0000 UTC - event for azuredisk-volume-tester-q7dxx: {kubelet capz-e0m0-hmftv} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:46:12.409: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  2 17:46:12.409: INFO: 
Jun  2 17:46:12.472: INFO: 
Logging node info for node capz-e0m0-hmftv
Jun  2 17:46:12.504: INFO: Node Info: &Node{ObjectMeta:{capz-e0m0-hmftv    6ec87d31-e181-4193-8961-a1deae617993 11276 0 2022-06-02 16:26:40 +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:eastus failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-e0m0-hmftv 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:eastus topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-e0m0ge cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-e0m0ge-md-win-b6967bc77-4tfsp cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-e0m0ge-md-win-b6967bc77 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-e0m0-hmftv"} 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.25.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c5:ee:60 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubelet.exe Update v1 2022-06-02 16:26:40 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-02 16:26:41 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kube-controller-manager Update v1 2022-06-02 16:26:43 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-06-02 16:28:04 +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-02 16:28:10 +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-02 17:45:46 +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-e0m0ge/providers/Microsoft.Compute/virtualMachines/capz-e0m0-hmftv,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-02 17:45:46 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-02 17:45:46 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-02 17:45:46 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-02 17:45:46 +0000 UTC,LastTransitionTime:2022-06-02 16:27:41 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-e0m0-hmftv,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-e0m0-hmftv,SystemUUID:8149DAA4-037D-4074-A46D-29F9204CD28B,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 88 lines ...
/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 | 0xc000ab4d70>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-q7dxx\" to be \"Error status code\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-q7dxx" 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  2 17:51:18.316: INFO: deleting Pod "azuredisk-5194"/"azuredisk-volume-tester-mg9gc"
Jun  2 17:51:18.389: INFO: Error getting logs for pod azuredisk-volume-tester-mg9gc: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-mg9gc)
STEP: Deleting pod azuredisk-volume-tester-mg9gc in namespace azuredisk-5194
Jun  2 17:51:18.423: INFO: deleting PVC "azuredisk-5194"/"pvc-qf22j"
Jun  2 17:51:18.423: INFO: Deleting PersistentVolumeClaim "pvc-qf22j"
STEP: waiting for claim's PV "pvc-6c742fe3-61de-46d1-9a5b-e401152c8030" to be deleted
Jun  2 17:51:18.457: INFO: Waiting up to 10m0s for PersistentVolume pvc-6c742fe3-61de-46d1-9a5b-e401152c8030 to get deleted
Jun  2 17:51:18.489: INFO: PersistentVolume pvc-6c742fe3-61de-46d1-9a5b-e401152c8030 found and phase=Bound (32.056931ms)
... skipping 13 lines ...
STEP: Found 9 events.
Jun  2 17:52:03.906: INFO: At 2022-06-02 17:46:13 +0000 UTC - event for pvc-qf22j: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-5194/pvc-qf22j"
Jun  2 17:52:03.906: INFO: At 2022-06-02 17:46:13 +0000 UTC - event for pvc-qf22j: {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  2 17:52:03.906: INFO: At 2022-06-02 17:46:16 +0000 UTC - event for pvc-qf22j: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } ProvisioningSucceeded: Successfully provisioned volume pvc-6c742fe3-61de-46d1-9a5b-e401152c8030
Jun  2 17:52:03.906: INFO: At 2022-06-02 17:46:18 +0000 UTC - event for azuredisk-volume-tester-mg9gc: {default-scheduler } Scheduled: Successfully assigned azuredisk-5194/azuredisk-volume-tester-mg9gc to capz-e0m0-k428f
Jun  2 17:52:03.906: INFO: At 2022-06-02 17:46:24 +0000 UTC - event for azuredisk-volume-tester-mg9gc: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-6c742fe3-61de-46d1-9a5b-e401152c8030" 
Jun  2 17:52:03.906: INFO: At 2022-06-02 17:46:52 +0000 UTC - event for azuredisk-volume-tester-mg9gc: {kubelet capz-e0m0-k428f} Failed: Failed to pull image "mcr.microsoft.com/windows/servercore:ltsc2022": rpc error: code = NotFound desc = failed to pull and unpack image "mcr.microsoft.com/windows/servercore:ltsc2022": no match for platform in manifest: not found
Jun  2 17:52:03.906: INFO: At 2022-06-02 17:46:52 +0000 UTC - event for azuredisk-volume-tester-mg9gc: {kubelet capz-e0m0-k428f} Failed: Error: ErrImagePull
Jun  2 17:52:03.906: INFO: At 2022-06-02 17:46:52 +0000 UTC - event for azuredisk-volume-tester-mg9gc: {kubelet capz-e0m0-k428f} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:52:03.906: INFO: At 2022-06-02 17:46:53 +0000 UTC - event for azuredisk-volume-tester-mg9gc: {kubelet capz-e0m0-k428f} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:52:03.939: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  2 17:52:03.939: INFO: 
Jun  2 17:52:03.974: INFO: 
Logging node info for node capz-e0m0-hmftv
... skipping 89 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 | 0xc0001e2490>: {
            s: "timed out waiting for the condition",
        }
        timed out waiting for the condition
    occurred

... skipping 203 lines ...
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:08 +0000 UTC - event for pvc-2q4b9: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } ProvisioningSucceeded: Successfully provisioned volume pvc-41026346-9d48-47f0-8cae-8477ba95c588
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:09 +0000 UTC - event for azuredisk-volume-tester-m4spl: {deployment-controller } ScalingReplicaSet: Scaled up replica set azuredisk-volume-tester-m4spl-749ffc6678 to 1
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:09 +0000 UTC - event for azuredisk-volume-tester-m4spl-749ffc6678: {replicaset-controller } SuccessfulCreate: Created pod: azuredisk-volume-tester-m4spl-749ffc6678-fc5mj
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:09 +0000 UTC - event for azuredisk-volume-tester-m4spl-749ffc6678-fc5mj: {default-scheduler } Scheduled: Successfully assigned azuredisk-1353/azuredisk-volume-tester-m4spl-749ffc6678-fc5mj to capz-e0m0-k428f
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:21 +0000 UTC - event for azuredisk-volume-tester-m4spl-749ffc6678-fc5mj: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-41026346-9d48-47f0-8cae-8477ba95c588" 
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:47 +0000 UTC - event for azuredisk-volume-tester-m4spl-749ffc6678-fc5mj: {kubelet capz-e0m0-k428f} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:47 +0000 UTC - event for azuredisk-volume-tester-m4spl-749ffc6678-fc5mj: {kubelet capz-e0m0-k428f} Failed: Failed to pull image "mcr.microsoft.com/windows/servercore:ltsc2022": rpc error: code = NotFound desc = failed to pull and unpack image "mcr.microsoft.com/windows/servercore:ltsc2022": no match for platform in manifest: not found
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:47 +0000 UTC - event for azuredisk-volume-tester-m4spl-749ffc6678-fc5mj: {kubelet capz-e0m0-k428f} Failed: Error: ErrImagePull
Jun  2 17:57:55.278: INFO: At 2022-06-02 17:52:48 +0000 UTC - event for azuredisk-volume-tester-m4spl-749ffc6678-fc5mj: {kubelet capz-e0m0-k428f} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 17:57:55.318: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  2 17:57:55.318: INFO: 
Jun  2 17:57:55.379: INFO: 
Logging node info for node capz-e0m0-hmftv
Jun  2 17:57:55.410: INFO: Node Info: &Node{ObjectMeta:{capz-e0m0-hmftv    6ec87d31-e181-4193-8961-a1deae617993 12832 0 2022-06-02 16:26:40 +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:eastus failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-e0m0-hmftv 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:eastus topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-e0m0ge cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-e0m0ge-md-win-b6967bc77-4tfsp cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-e0m0ge-md-win-b6967bc77 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-e0m0-hmftv"} 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.25.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c5:ee:60 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubelet.exe Update v1 2022-06-02 16:26:40 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-02 16:26:41 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kube-controller-manager Update v1 2022-06-02 16:26:43 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-06-02 16:28:04 +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-02 16:28:10 +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-02 17:45:46 +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-e0m0ge/providers/Microsoft.Compute/virtualMachines/capz-e0m0-hmftv,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-02 17:56:00 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-02 17:56:00 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-02 17:56:00 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-02 17:56:00 +0000 UTC,LastTransitionTime:2022-06-02 16:27:41 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-e0m0-hmftv,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-e0m0-hmftv,SystemUUID:8149DAA4-037D-4074-A46D-29F9204CD28B,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 88 lines ...
/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 | 0xc000923440>: {
            s: "error waiting for deployment \"azuredisk-volume-tester-m4spl\" 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, 2, 17, 52, 9, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 2, 17, 52, 9, 0, time.Local), Reason:\"MinimumReplicasUnavailable\", Message:\"Deployment does not have minimum availability.\"}, v1.DeploymentCondition{Type:\"Progressing\", Status:\"True\", LastUpdateTime:time.Date(2022, time.June, 2, 17, 52, 9, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 2, 17, 52, 9, 0, time.Local), Reason:\"ReplicaSetUpdated\", Message:\"ReplicaSet \\\"azuredisk-volume-tester-m4spl-749ffc6678\\\" is progressing.\"}}, CollisionCount:(*int32)(nil)}",
        }
        error waiting for deployment "azuredisk-volume-tester-m4spl" 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, 2, 17, 52, 9, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 2, 17, 52, 9, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.June, 2, 17, 52, 9, 0, time.Local), LastTransitionTime:time.Date(2022, time.June, 2, 17, 52, 9, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-m4spl-749ffc6678\" 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  2 17:58:31.751: INFO: PersistentVolumeClaim pvc-7hpq5 found and phase=Bound (4.099045275s)
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  2 17:58:31.851: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-4xwqs" in namespace "azuredisk-59" to be "Succeeded or Failed"
Jun  2 17:58:31.883: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 31.994366ms
Jun  2 17:58:33.915: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 2.064003364s
Jun  2 17:58:35.953: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 4.101749363s
Jun  2 17:58:37.986: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 6.135407944s
Jun  2 17:58:40.022: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 8.170780079s
Jun  2 17:58:42.055: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 10.203928177s
... skipping 431 lines ...
Jun  2 18:13:20.571: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 14m48.720411516s
Jun  2 18:13:22.605: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.753540999s
Jun  2 18:13:24.638: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.786584559s
Jun  2 18:13:26.672: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.820536944s
Jun  2 18:13:28.705: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.854166249s
Jun  2 18:13:30.738: INFO: Pod "azuredisk-volume-tester-4xwqs": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.887396029s
{"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-02T18:13:32Z"}
++ early_exit_handler
++ '[' -n 159 ']'
++ kill -TERM 159
++ cleanup_dind
++ [[ true == \t\r\u\e ]]
++ echo 'Cleaning up after docker'
Cleaning up after docker
++ docker ps -aq
++ xargs -r docker rm -f
make: Nothing to be done for 'kubectl'.
================ DUMPING LOGS FOR MANAGEMENT CLUSTER ================
Jun  2 18:13:32.740: INFO: deleting Pod "azuredisk-59"/"azuredisk-volume-tester-4xwqs"
Jun  2 18:13:32.788: INFO: Error getting logs for pod azuredisk-volume-tester-4xwqs: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-4xwqs)
STEP: Deleting pod azuredisk-volume-tester-4xwqs in namespace azuredisk-59
Jun  2 18:13:32.824: INFO: deleting PVC "azuredisk-59"/"pvc-7hpq5"
Jun  2 18:13:32.824: INFO: Deleting PersistentVolumeClaim "pvc-7hpq5"
STEP: waiting for claim's PV "pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849" to be deleted
Jun  2 18:13:32.858: INFO: Waiting up to 10m0s for PersistentVolume pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849 to get deleted
Jun  2 18:13:32.890: INFO: PersistentVolume pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849 found and phase=Bound (31.889556ms)
ERROR: failed to get cluster internal kubeconfig: command "docker exec --privileged capz-control-plane cat /etc/kubernetes/admin.conf" failed with error: exit status 126

Command Output: OCI runtime exec failed: exec failed: container_linux.go:380: starting container process caused: process_linux.go:130: executing setns process caused: exit status 1: unknown

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
7c7ac65573a7
281fc1e90368
66b5e7e3645d
The connection to the server 127.0.0.1:38805 was refused - did you specify the right host or port?
++ service docker stop
Stopping Docker: dockerkind 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  2 18:13:37.924: INFO: PersistentVolume pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849 found and phase=Released (5.065186186s)
Jun  2 18:13:42.960: INFO: PersistentVolume pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849 found and phase=Released (10.101466024s)
Jun  2 18:13:47.996: INFO: PersistentVolume pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849 found and phase=Released (15.138106217s)
Jun  2 18:13:53.031: INFO: PersistentVolume pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849 found and phase=Released (20.172520738s)
... skipping 55 lines ...
Jun  2 18:15:08.954: INFO: At 2022-06-02 17:58:30 +0000 UTC - event for pvc-7hpq5: {disk.csi.azure.com_capz-e0m0ge-control-plane-c7d4z_f96b06f4-4cf8-4f92-95a5-9a6684f68c2c } ProvisioningSucceeded: Successfully provisioned volume pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849
Jun  2 18:15:08.954: INFO: At 2022-06-02 17:58:31 +0000 UTC - event for azuredisk-volume-tester-4xwqs: {default-scheduler } Scheduled: Successfully assigned azuredisk-59/azuredisk-volume-tester-4xwqs to capz-e0m0-hmftv
Jun  2 18:15:08.954: INFO: At 2022-06-02 17:58:44 +0000 UTC - event for azuredisk-volume-tester-4xwqs: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-e9bb9672-4ab7-4a49-9ce8-c05a18baac6a" 
Jun  2 18:15:08.954: INFO: At 2022-06-02 17:58:55 +0000 UTC - event for azuredisk-volume-tester-4xwqs: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-dd0c21da-ddfd-41f1-b88f-4cb1bf8b7849" 
Jun  2 18:15:08.954: INFO: At 2022-06-02 17:58:55 +0000 UTC - event for azuredisk-volume-tester-4xwqs: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-8d6d1773-3a1d-472d-bf52-183f7a6d9914" 
Jun  2 18:15:08.954: INFO: At 2022-06-02 17:59:27 +0000 UTC - event for azuredisk-volume-tester-4xwqs: {kubelet capz-e0m0-hmftv} Pulling: Pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 18:15:08.954: INFO: At 2022-06-02 17:59:28 +0000 UTC - event for azuredisk-volume-tester-4xwqs: {kubelet capz-e0m0-hmftv} Failed: Error: ErrImagePull
Jun  2 18:15:08.954: INFO: At 2022-06-02 17:59:28 +0000 UTC - event for azuredisk-volume-tester-4xwqs: {kubelet capz-e0m0-hmftv} BackOff: Back-off pulling image "mcr.microsoft.com/windows/servercore:ltsc2022"
Jun  2 18:15:08.987: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Jun  2 18:15:08.987: INFO: 
Jun  2 18:15:09.020: INFO: 
Logging node info for node capz-e0m0-hmftv
Jun  2 18:15:09.052: INFO: Node Info: &Node{ObjectMeta:{capz-e0m0-hmftv    6ec87d31-e181-4193-8961-a1deae617993 15417 0 2022-06-02 16:26:40 +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:eastus failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-e0m0-hmftv 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:eastus topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-e0m0ge cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-e0m0ge-md-win-b6967bc77-4tfsp cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-e0m0ge-md-win-b6967bc77 csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-e0m0-hmftv"} 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.25.193 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:c5:ee:60 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubelet.exe Update v1 2022-06-02 16:26:40 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:node.kubernetes.io/windows-build":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}}} } {kubeadm Update v1 2022-06-02 16:26:41 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kube-controller-manager Update v1 2022-06-02 16:26:43 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {manager Update v1 2022-06-02 16:28:04 +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-02 16:28:10 +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-02 18:13:43 +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-e0m0ge/providers/Microsoft.Compute/virtualMachines/capz-e0m0-hmftv,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-02 18:13:43 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-06-02 18:13:43 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-06-02 18:13:43 +0000 UTC,LastTransitionTime:2022-06-02 16:26:40 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-06-02 18:13:43 +0000 UTC,LastTransitionTime:2022-06-02 16:27:41 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-e0m0-hmftv,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-e0m0-hmftv,SystemUUID:8149DAA4-037D-4074-A46D-29F9204CD28B,BootID:,KernelVersion:10.0.17763.2366,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.0-rc.1,KubeletVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,KubeProxyVersion:v1.23.8-rc.0.3+9c77bfb6f557b7,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:3d99006d5b90465d5dea4ae3f04f27cb5ee4c2797e46b1beddf1a65304996496 docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:150371754,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger@sha256:63bf2aa9db909d0d90fb5205abf7fb2a6d9a494b89cbd2508a42457dfc875505 ghcr.io/kubernetes-sigs/sig-windows/eventflow-logger:v0.1.0],SizeBytes:133732668,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:99c77a7b5d82e77436ad6029a1657549b03aaac181dad1aaa71a7efffcc06d2a docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:130119050,},ContainerImage{Names:[capzci.azurecr.io/azuredisk-csi@sha256:40a72c72c870ae49aade94d3d1deb2d0855b04f37ef23af94923b3519516c04d capzci.azurecr.io/azuredisk-csi:v1.19.0-8f268ea61f83c9f055a1208a57642439601de5e7],SizeBytes:127767658,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.8-rc.0.3_9c77bfb6f557b7-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:348b2d4eebc8da38687755a69b6c21035be232325a6bcde54e5ec4e04689fd93 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.0],SizeBytes:111507186,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:e01f5dae19d7e1be536606fe5deb893417429486b628b816d80ffa0e441eeae8 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.6.0],SizeBytes:110604262,},ContainerImage{Names:[ghcr.io/kubernetes-sigs/sig-windows/csi-proxy@sha256:96b4144986319a747ba599892454be2737aae6005d96b8e13ed481321ac3afba ghcr.io/kubernetes-sigs/sig-windows/csi-proxy:v1.0.2],SizeBytes:109639330,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:3d380ca8864549e74af4b29c10f9cb0956236dfb01c40ca076fb6c37253234db k8s.gcr.io/pause:3.6],SizeBytes:104158827,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 88 lines ...
/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 a single 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:549

    Unexpected error:
        <*errors.errorString | 0xc0007f74c0>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-4xwqs\" to be \"Succeeded or Failed\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-4xwqs" 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 raw block volume and a filesystem volume on demand and bind to the same pod [kubernetes.io/azure-disk] [disk.csi.azure.com]
... skipping 126 lines ...
Jun  2 18:15:22.984: INFO: PersistentVolumeClaim pvc-4gt4c found but phase is Pending instead of Bound.
Jun  2 18:15:25.020: INFO: PersistentVolumeClaim pvc-4gt4c found and phase=Bound (4.100558699s)
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 no error
Jun  2 18:15:25.121: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-nzpkx" in namespace "azuredisk-8582" to be "Succeeded or Failed"
Jun  2 18:15:25.185: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 63.678414ms
Jun  2 18:15:27.219: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.097544552s
Jun  2 18:15:29.251: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.129886859s
Jun  2 18:15:31.285: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.163492039s
Jun  2 18:15:33.317: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.195813262s
Jun  2 18:15:35.350: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.228653038s
... skipping 375 lines ...
Jun  2 18:28:20.921: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 12m55.800198678s
Jun  2 18:28:22.956: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 12m57.834293971s
Jun  2 18:28:24.989: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 12m59.867801377s
Jun  2 18:28:27.022: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 13m1.900595626s
Jun  2 18:28:29.055: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 13m3.933487411s
Jun  2 18:28:31.089: INFO: Pod "azuredisk-volume-tester-nzpkx": Phase="Pending", Reason="", readiness=false. Elapsed: 13m5.967658464s
{"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-02T18:28:32Z"}
{"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-02T18:28:32Z"}