This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: [WIP]fix: set informers for CSI driver
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-11-22 13:15
Elapsed2h15m
Revision6c2dfeabd9a19b99f96910059776b03edfed8f62
Refs 1614

No Test Failures!


Error lines from build-log.txt

... skipping 767 lines ...
certificate.cert-manager.io "selfsigned-cert" deleted
# Create secret for AzureClusterIdentity
./hack/create-identity-secret.sh
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
make[2]: Nothing to be done for 'kubectl'.
make[2]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
Error from server (NotFound): secrets "cluster-identity-secret" not found
secret/cluster-identity-secret created
secret/cluster-identity-secret labeled
# Create customized cloud provider configs
./hack/create-custom-cloud-provider-config.sh
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
make[2]: Nothing to be done for 'kubectl'.
... skipping 186 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11156  100 11156    0     0   194k      0 --:--:-- --:--:-- --:--:--  198k
Downloading https://get.helm.sh/helm-v3.10.2-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.25.0-dc9b210e79c74e4451faaa841d84e21ebc47b6c4 || make container-all push-manifest
Error response from daemon: manifest for capzci.azurecr.io/azuredisk-csi:v1.25.0-dc9b210e79c74e4451faaa841d84e21ebc47b6c4 not found: manifest unknown: manifest tagged by "v1.25.0-dc9b210e79c74e4451faaa841d84e21ebc47b6c4" 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.25.0-dc9b210e79c74e4451faaa841d84e21ebc47b6c4 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=dc9b210e79c74e4451faaa841d84e21ebc47b6c4 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2022-11-22T13:35:59Z -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 1790 lines ...
                    type: string
                type: object
                oneOf:
                - required: ["persistentVolumeClaimName"]
                - required: ["volumeSnapshotContentName"]
              volumeSnapshotClassName:
                description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.'
                type: string
            required:
            - source
            type: object
          status:
            description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.
... skipping 2 lines ...
                description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.'
                type: string
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown.
                format: date-time
                type: string
              error:
                description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                type: string
                description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$
                x-kubernetes-int-or-string: true
            type: object
        required:
        - spec
        type: object
... skipping 60 lines ...
                    type: string
                  volumeSnapshotContentName:
                    description: volumeSnapshotContentName specifies the name of a pre-existing VolumeSnapshotContent object representing an existing volume snapshot. This field should be set if the snapshot already exists and only needs a representation in Kubernetes. This field is immutable.
                    type: string
                type: object
              volumeSnapshotClassName:
                description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.'
                type: string
            required:
            - source
            type: object
          status:
            description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.
... skipping 2 lines ...
                description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.'
                type: string
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown.
                format: date-time
                type: string
              error:
                description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                type: string
                description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$
                x-kubernetes-int-or-string: true
            type: object
        required:
        - spec
        type: object
... skipping 254 lines ...
            description: status represents the current information of a snapshot.
            properties:
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC.
                format: int64
                type: integer
              error:
                description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                format: int64
                minimum: 0
                type: integer
              snapshotHandle:
                description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress.
                type: string
            type: object
        required:
        - spec
        type: object
    served: true
... skipping 108 lines ...
            description: status represents the current information of a snapshot.
            properties:
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC.
                format: int64
                type: integer
              error:
                description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                format: int64
                minimum: 0
                type: integer
              snapshotHandle:
                description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress.
                type: string
            type: object
        required:
        - spec
        type: object
    served: true
... skipping 613 lines ...
          image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.5.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 211 lines ...
Nov 22 13:47:36.260: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-wjbdz] to have phase Bound
Nov 22 13:47:36.370: INFO: PersistentVolumeClaim pvc-wjbdz found and phase=Bound (109.653828ms)
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
Nov 22 13:47:36.703: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-vj9z8" in namespace "azuredisk-8081" to be "Error status code"
Nov 22 13:47:36.816: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 112.309937ms
Nov 22 13:47:38.927: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.223309214s
Nov 22 13:47:41.036: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.332776693s
Nov 22 13:47:43.146: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.442621456s
Nov 22 13:47:45.256: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.553022885s
Nov 22 13:47:47.366: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.663067601s
... skipping 416 lines ...
Nov 22 14:02:27.413: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.710005268s
Nov 22 14:02:29.523: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.819576934s
Nov 22 14:02:31.633: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.92948508s
Nov 22 14:02:33.742: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 14m57.038196353s
Nov 22 14:02:35.852: INFO: Pod "azuredisk-volume-tester-vj9z8": Phase="Pending", Reason="", readiness=false. Elapsed: 14m59.148771828s
Nov 22 14:02:37.854: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-vj9z8"
Nov 22 14:02:37.996: INFO: Error getting logs for pod azuredisk-volume-tester-vj9z8: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-vj9z8)
STEP: Deleting pod azuredisk-volume-tester-vj9z8 in namespace azuredisk-8081
Nov 22 14:02:38.131: INFO: deleting PVC "azuredisk-8081"/"pvc-wjbdz"
Nov 22 14:02:38.131: INFO: Deleting PersistentVolumeClaim "pvc-wjbdz"
Nov 22 14:02:38.246: INFO: Waiting up to 5m0s for PersistentVolumeClaim azuredisk-8081 to be removed
Nov 22 14:02:38.355: INFO: Claim "azuredisk-8081" in namespace "pvc-wjbdz" doesn't exist in the system
STEP: deleting PV "azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-mlqf8"
... skipping 118 lines ...
Nov 22 14:12:26.456: INFO: PersistentVolume azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-mlqf8 found and phase=Released (9m47.989084205s)
Nov 22 14:12:31.567: INFO: PersistentVolume azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-mlqf8 found and phase=Released (9m53.100212769s)
Nov 22 14:12:36.678: INFO: PersistentVolume azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-mlqf8 found and phase=Released (9m58.210359522s)
STEP: Collecting events from namespace "azuredisk-8081".
STEP: Found 3 events.
Nov 22 14:12:41.793: INFO: At 2022-11-22 13:47:36 +0000 UTC - event for azuredisk-volume-tester-vj9z8: {default-scheduler } Scheduled: Successfully assigned azuredisk-8081/azuredisk-volume-tester-vj9z8 to capz-cm5c-gcf6w
Nov 22 14:12:41.793: INFO: At 2022-11-22 13:47:37 +0000 UTC - event for azuredisk-volume-tester-vj9z8: {attachdetach-controller } FailedAttachVolume: AttachVolume.Attach failed for volume "azuredisk-8081-disk.csi.azure.com-preprovisioned-pv-mlqf8" : rpc error: code = Internal desc = Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-cm5c4u/providers/Microsoft.Compute/disks/pre-provisioned-readOnly to instance capz-cm5c-gcf6w failed with getNodeVMSet: failed to check the node capz-cm5c-gcf6w management type: node informer is not synced when trying to GetResourceGroups
Nov 22 14:12:41.793: INFO: At 2022-11-22 13:49:39 +0000 UTC - event for azuredisk-volume-tester-vj9z8: {kubelet capz-cm5c-gcf6w} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume-1], unattached volumes=[test-volume-1]: timed out waiting for the condition
Nov 22 14:12:41.902: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Nov 22 14:12:41.902: INFO: 
Nov 22 14:12:42.065: INFO: 
Logging node info for node capz-cm5c-fmf9f
Nov 22 14:12:42.188: INFO: Node Info: &Node{ObjectMeta:{capz-cm5c-fmf9f    a8c78fc5-9149-4271-9093-4b1e9426ff2c 5737 0 2022-11-22 13:32:23 +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:westeurope failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-cm5c-fmf9f 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:westeurope topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-cm5c4u cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-cm5c4u-md-win-fc867f-5z8jk cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-cm5c4u-md-win-fc867f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-cm5c-fmf9f"} 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.138.65 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:3b:da:34 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-11-22 13:32:23 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-11-22 13:32:23 +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-11-22 13:32:27 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {Go-http-client Update v1 2022-11-22 13:33:48 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {manager Update v1 2022-11-22 13:33:50 +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":{}}}} } {kubelet.exe Update v1 2022-11-22 13:47:30 +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-cm5c4u/providers/Microsoft.Compute/virtualMachines/capz-cm5c-fmf9f,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-11-22 14:08:28 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-11-22 14:08:28 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-11-22 14:08:28 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-11-22 14:08:28 +0000 UTC,LastTransitionTime:2022-11-22 13:33:14 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-cm5c-fmf9f,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-cm5c-fmf9f,SystemUUID:688A27A1-A35E-4D82-8941-69E992A839CB,BootID:,KernelVersion:10.0.17763.3406,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.2,KubeletVersion:v1.23.15-rc.0.11+2b8076aad0e0b8,KubeProxyVersion:v1.23.15-rc.0.11+2b8076aad0e0b8,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{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:[capzci.azurecr.io/azuredisk-csi@sha256:7a3c030407bc9a3cdea7b1f15a66e787765eafb186308d88055cd08fc32bbd06 capzci.azurecr.io/azuredisk-csi:v1.25.0-dc9b210e79c74e4451faaa841d84e21ebc47b6c4],SizeBytes:129624120,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.15-rc.0.11_2b8076aad0e0b8-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:2fbd1e1a0538a06f2061afd45975df70c942654aa7f86e920720169ee439c2d6 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.1],SizeBytes:112027297,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:31547791294872570393470991481c2477a311031d3a03e0ae54eb164347dc34 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.7.0],SizeBytes:111112278,},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,},ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:1dac2d6534d9017f8967cc6238d6b448bdc1c978b5e8fea91bf39dc59d29881f docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:47258351,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:6ea7a987c109fdc059a36bf4abc5267c6f3de99d02ef6e84f0826da2aa435ea5 docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:27005594,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 92 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 | 0xc000668210>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-vj9z8\" to be \"Error status code\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-vj9z8" to be "Error status code"
    occurred

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:864
------------------------------
Pre-Provisioned [single-az] 
  should use a pre-provisioned volume and retain PV with reclaimPolicy "Retain" [disk.csi.azure.com][windows]
... skipping 58 lines ...
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:69
    should succeed when creating a shared disk [disk.csi.azure.com][windows]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:143
------------------------------
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:164
STEP: Creating a kubernetes client
Nov 22 14:13:02.506: 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 67 lines ...
Nov 22 14:14:02.125: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-xwjjt] to have phase Bound
Nov 22 14:14:02.234: INFO: PersistentVolumeClaim pvc-xwjjt found and phase=Bound (109.740082ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: attaching disk to node#0
E1122 14:14:03.170290   37337 azure_controller_common.go:451] error of getting data disks for node capz-cm5c-fmf9f: getNodeVMSet: failed to check the node capz-cm5c-fmf9f management type: node informer is not synced when trying to GetResourceGroups
E1122 14:14:03.170342   37337 azure_controller_common.go:476] error of getting data disks for node capz-cm5c-fmf9f: getNodeVMSet: failed to check the node capz-cm5c-fmf9f management type: node informer is not synced when trying to GetResourceGroups
E1122 14:14:03.170356   37337 controllerserver.go:429] Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-cm5c4u/providers/Microsoft.Compute/disks/reattach-disk-multiple-nodes to instance capz-cm5c-fmf9f failed with getNodeVMSet: failed to check the node capz-cm5c-fmf9f management type: node informer is not synced when trying to GetResourceGroups
Nov 22 14:14:03.170: INFO: deleting PVC "azuredisk-5194"/"pvc-xwjjt"
Nov 22 14:14:03.170: INFO: Deleting PersistentVolumeClaim "pvc-xwjjt"
Nov 22 14:14:03.286: INFO: Waiting up to 5m0s for PersistentVolumeClaim azuredisk-5194 to be removed
Nov 22 14:14:03.397: INFO: Claim "azuredisk-5194" in namespace "pvc-xwjjt" doesn't exist in the system
STEP: deleting PV "azuredisk-5194-disk.csi.azure.com-preprovisioned-pv-wr2rl"
Nov 22 14:14:03.397: INFO: Deleting PersistentVolume "azuredisk-5194-disk.csi.azure.com-preprovisioned-pv-wr2rl"
... skipping 102 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:271

    Unexpected error:
        <*status.Error | 0xc000390598>: {
            s: {
                s: {
                    state: {
                        NoUnkeyedLiterals: {},
                        DoNotCompare: [],
                        DoNotCopy: [],
                        atomicMessageInfo: nil,
                    },
                    sizeCache: 0,
                    unknownFields: nil,
                    Code: 13,
                    Message: "Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-cm5c4u/providers/Microsoft.Compute/disks/reattach-disk-multiple-nodes to instance capz-cm5c-fmf9f failed with getNodeVMSet: failed to check the node capz-cm5c-fmf9f management type: node informer is not synced when trying to GetResourceGroups",
                    Details: nil,
                },
            },
        }
        rpc error: code = Internal desc = Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-cm5c4u/providers/Microsoft.Compute/disks/reattach-disk-multiple-nodes to instance capz-cm5c-fmf9f failed with getNodeVMSet: failed to check the node capz-cm5c-fmf9f management type: node informer is not synced when trying to GetResourceGroups
    occurred

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/pre_provisioned_dangling_attach_volume_tester.go:80
------------------------------
Pre-Provisioned [single-az] 
  should create an inline volume by in-tree driver [kubernetes.io/azure-disk]
... skipping 43 lines ...
Nov 22 14:14:16.485: INFO: PersistentVolumeClaim pvc-vskgd found and phase=Bound (4.329033161s)
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
Nov 22 14:14:16.826: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-dtmq5" in namespace "azuredisk-2888" to be "Succeeded or Failed"
Nov 22 14:14:16.942: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 116.477123ms
Nov 22 14:14:19.053: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.227094362s
Nov 22 14:14:21.163: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.337048379s
Nov 22 14:14:23.274: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.448344758s
Nov 22 14:14:25.385: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.558652921s
Nov 22 14:14:27.495: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.669375207s
... skipping 416 lines ...
Nov 22 14:29:07.721: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.894897673s
Nov 22 14:29:09.832: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 14m53.005706114s
Nov 22 14:29:11.941: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 14m55.115436233s
Nov 22 14:29:14.051: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 14m57.225094359s
Nov 22 14:29:16.160: INFO: Pod "azuredisk-volume-tester-dtmq5": Phase="Pending", Reason="", readiness=false. Elapsed: 14m59.333941165s
Nov 22 14:29:18.160: INFO: deleting Pod "azuredisk-2888"/"azuredisk-volume-tester-dtmq5"
Nov 22 14:29:18.292: INFO: Error getting logs for pod azuredisk-volume-tester-dtmq5: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-dtmq5)
STEP: Deleting pod azuredisk-volume-tester-dtmq5 in namespace azuredisk-2888
Nov 22 14:29:18.408: INFO: deleting PVC "azuredisk-2888"/"pvc-vskgd"
Nov 22 14:29:18.408: INFO: Deleting PersistentVolumeClaim "pvc-vskgd"
STEP: waiting for claim's PV "pvc-229c4766-4d1b-439a-bd58-d28939de520c" to be deleted
Nov 22 14:29:18.522: INFO: Waiting up to 10m0s for PersistentVolume pvc-229c4766-4d1b-439a-bd58-d28939de520c to get deleted
Nov 22 14:29:18.630: INFO: PersistentVolume pvc-229c4766-4d1b-439a-bd58-d28939de520c found and phase=Bound (107.890715ms)
... skipping 118 lines ...
STEP: Collecting events from namespace "azuredisk-2888".
STEP: Found 6 events.
Nov 22 14:39:21.918: INFO: At 2022-11-22 14:14:12 +0000 UTC - event for pvc-vskgd: {disk.csi.azure.com_capz-cm5c4u-control-plane-xtz8f_87e1d712-b829-4980-9b37-68aa5021fc1a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-2888/pvc-vskgd"
Nov 22 14:39:21.918: INFO: At 2022-11-22 14:14:12 +0000 UTC - event for pvc-vskgd: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator
Nov 22 14:39:21.918: INFO: At 2022-11-22 14:14:14 +0000 UTC - event for pvc-vskgd: {disk.csi.azure.com_capz-cm5c4u-control-plane-xtz8f_87e1d712-b829-4980-9b37-68aa5021fc1a } ProvisioningSucceeded: Successfully provisioned volume pvc-229c4766-4d1b-439a-bd58-d28939de520c
Nov 22 14:39:21.918: INFO: At 2022-11-22 14:14:16 +0000 UTC - event for azuredisk-volume-tester-dtmq5: {default-scheduler } Scheduled: Successfully assigned azuredisk-2888/azuredisk-volume-tester-dtmq5 to capz-cm5c-gcf6w
Nov 22 14:39:21.918: INFO: At 2022-11-22 14:14:17 +0000 UTC - event for azuredisk-volume-tester-dtmq5: {attachdetach-controller } FailedAttachVolume: AttachVolume.Attach failed for volume "pvc-229c4766-4d1b-439a-bd58-d28939de520c" : rpc error: code = Internal desc = Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-cm5c4u/providers/Microsoft.Compute/disks/pvc-229c4766-4d1b-439a-bd58-d28939de520c to instance capz-cm5c-gcf6w failed with getNodeVMSet: failed to check the node capz-cm5c-gcf6w management type: node informer is not synced when trying to GetResourceGroups
Nov 22 14:39:21.918: INFO: At 2022-11-22 14:16:19 +0000 UTC - event for azuredisk-volume-tester-dtmq5: {kubelet capz-cm5c-gcf6w} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume-1], unattached volumes=[test-volume-1]: timed out waiting for the condition
Nov 22 14:39:22.026: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Nov 22 14:39:22.026: INFO: 
Nov 22 14:39:22.144: INFO: 
Logging node info for node capz-cm5c-fmf9f
Nov 22 14:39:22.254: INFO: Node Info: &Node{ObjectMeta:{capz-cm5c-fmf9f    a8c78fc5-9149-4271-9093-4b1e9426ff2c 10403 0 2022-11-22 13:32:23 +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:westeurope failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-cm5c-fmf9f 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:westeurope topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-cm5c4u cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-cm5c4u-md-win-fc867f-5z8jk cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-cm5c4u-md-win-fc867f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-cm5c-fmf9f"} 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.138.65 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:3b:da:34 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-11-22 13:32:23 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-11-22 13:32:23 +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-11-22 13:32:27 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {Go-http-client Update v1 2022-11-22 13:33:48 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {manager Update v1 2022-11-22 13:33:50 +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":{}}}} } {kubelet.exe Update v1 2022-11-22 13:47:30 +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-cm5c4u/providers/Microsoft.Compute/virtualMachines/capz-cm5c-fmf9f,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-11-22 14:39:07 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-11-22 14:39:07 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-11-22 14:39:07 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-11-22 14:39:07 +0000 UTC,LastTransitionTime:2022-11-22 13:33:14 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-cm5c-fmf9f,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-cm5c-fmf9f,SystemUUID:688A27A1-A35E-4D82-8941-69E992A839CB,BootID:,KernelVersion:10.0.17763.3406,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.2,KubeletVersion:v1.23.15-rc.0.11+2b8076aad0e0b8,KubeProxyVersion:v1.23.15-rc.0.11+2b8076aad0e0b8,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{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:[capzci.azurecr.io/azuredisk-csi@sha256:7a3c030407bc9a3cdea7b1f15a66e787765eafb186308d88055cd08fc32bbd06 capzci.azurecr.io/azuredisk-csi:v1.25.0-dc9b210e79c74e4451faaa841d84e21ebc47b6c4],SizeBytes:129624120,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.15-rc.0.11_2b8076aad0e0b8-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:2fbd1e1a0538a06f2061afd45975df70c942654aa7f86e920720169ee439c2d6 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.1],SizeBytes:112027297,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:31547791294872570393470991481c2477a311031d3a03e0ae54eb164347dc34 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.7.0],SizeBytes:111112278,},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,},ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:1dac2d6534d9017f8967cc6238d6b448bdc1c978b5e8fea91bf39dc59d29881f docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:47258351,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:6ea7a987c109fdc059a36bf4abc5267c6f3de99d02ef6e84f0826da2aa435ea5 docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:27005594,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 92 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 | 0xc0000273e0>: {
            s: "Gave up after waiting 15m0s for pod \"azuredisk-volume-tester-dtmq5\" to be \"Succeeded or Failed\"",
        }
        Gave up after waiting 15m0s for pod "azuredisk-volume-tester-dtmq5" to be "Succeeded or Failed"
    occurred

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:825
------------------------------
Dynamic Provisioning [single-az] 
  should create a pod with volume mount subpath [disk.csi.azure.com] [Windows]
... skipping 18 lines ...
Nov 22 14:39:28.720: INFO: PersistentVolumeClaim pvc-vr6th found but phase is Pending instead of Bound.
Nov 22 14:39:30.831: INFO: PersistentVolumeClaim pvc-vr6th found and phase=Bound (4.328566299s)
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
Nov 22 14:39:31.159: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-nstmx" in namespace "azuredisk-156" to be "Succeeded or Failed"
Nov 22 14:39:31.269: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 110.598543ms
Nov 22 14:39:33.379: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.220784729s
Nov 22 14:39:35.489: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.330769327s
Nov 22 14:39:37.598: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.439578018s
Nov 22 14:39:39.708: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.548931918s
Nov 22 14:39:41.817: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.658632882s
... skipping 416 lines ...
Nov 22 14:54:21.767: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.608098843s
Nov 22 14:54:23.876: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.717410864s
Nov 22 14:54:25.985: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.826727659s
Nov 22 14:54:28.095: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.936820958s
Nov 22 14:54:30.206: INFO: Pod "azuredisk-volume-tester-nstmx": Phase="Pending", Reason="", readiness=false. Elapsed: 14m59.047855669s
Nov 22 14:54:32.208: INFO: deleting Pod "azuredisk-156"/"azuredisk-volume-tester-nstmx"
Nov 22 14:54:32.341: INFO: Error getting logs for pod azuredisk-volume-tester-nstmx: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-nstmx)
STEP: Deleting pod azuredisk-volume-tester-nstmx in namespace azuredisk-156
Nov 22 14:54:32.459: INFO: deleting PVC "azuredisk-156"/"pvc-vr6th"
Nov 22 14:54:32.459: INFO: Deleting PersistentVolumeClaim "pvc-vr6th"
STEP: waiting for claim's PV "pvc-9151113f-dd7a-49d8-be7c-4a3ea3390f7c" to be deleted
Nov 22 14:54:32.578: INFO: Waiting up to 10m0s for PersistentVolume pvc-9151113f-dd7a-49d8-be7c-4a3ea3390f7c to get deleted
Nov 22 14:54:32.687: INFO: PersistentVolume pvc-9151113f-dd7a-49d8-be7c-4a3ea3390f7c found and phase=Bound (109.343358ms)
... skipping 118 lines ...
STEP: Collecting events from namespace "azuredisk-156".
STEP: Found 6 events.
Nov 22 15:04:35.980: INFO: At 2022-11-22 14:39:26 +0000 UTC - event for pvc-vr6th: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator
Nov 22 15:04:35.980: INFO: At 2022-11-22 14:39:26 +0000 UTC - event for pvc-vr6th: {disk.csi.azure.com_capz-cm5c4u-control-plane-xtz8f_87e1d712-b829-4980-9b37-68aa5021fc1a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-156/pvc-vr6th"
Nov 22 15:04:35.980: INFO: At 2022-11-22 14:39:29 +0000 UTC - event for pvc-vr6th: {disk.csi.azure.com_capz-cm5c4u-control-plane-xtz8f_87e1d712-b829-4980-9b37-68aa5021fc1a } ProvisioningSucceeded: Successfully provisioned volume pvc-9151113f-dd7a-49d8-be7c-4a3ea3390f7c
Nov 22 15:04:35.980: INFO: At 2022-11-22 14:39:31 +0000 UTC - event for azuredisk-volume-tester-nstmx: {default-scheduler } Scheduled: Successfully assigned azuredisk-156/azuredisk-volume-tester-nstmx to capz-cm5c-gcf6w
Nov 22 15:04:35.980: INFO: At 2022-11-22 14:39:31 +0000 UTC - event for azuredisk-volume-tester-nstmx: {attachdetach-controller } FailedAttachVolume: AttachVolume.Attach failed for volume "pvc-9151113f-dd7a-49d8-be7c-4a3ea3390f7c" : rpc error: code = Internal desc = Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-cm5c4u/providers/Microsoft.Compute/disks/pvc-9151113f-dd7a-49d8-be7c-4a3ea3390f7c to instance capz-cm5c-gcf6w failed with getNodeVMSet: failed to check the node capz-cm5c-gcf6w management type: node informer is not synced when trying to GetResourceGroups
Nov 22 15:04:35.980: INFO: At 2022-11-22 14:41:34 +0000 UTC - event for azuredisk-volume-tester-nstmx: {kubelet capz-cm5c-gcf6w} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume-1], unattached volumes=[test-volume-1]: timed out waiting for the condition
Nov 22 15:04:36.088: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Nov 22 15:04:36.088: INFO: 
Nov 22 15:04:36.206: INFO: 
Logging node info for node capz-cm5c-fmf9f
Nov 22 15:04:36.317: INFO: Node Info: &Node{ObjectMeta:{capz-cm5c-fmf9f    a8c78fc5-9149-4271-9093-4b1e9426ff2c 13502 0 2022-11-22 13:32:23 +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:westeurope failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-cm5c-fmf9f 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:westeurope topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-cm5c4u cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-cm5c4u-md-win-fc867f-5z8jk cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-cm5c4u-md-win-fc867f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-cm5c-fmf9f"} 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.138.65 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:3b:da:34 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-11-22 13:32:23 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-11-22 13:32:23 +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-11-22 13:32:27 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {Go-http-client Update v1 2022-11-22 13:33:48 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {manager Update v1 2022-11-22 13:33:50 +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":{}}}} } {kubelet.exe Update v1 2022-11-22 13:47:30 +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-cm5c4u/providers/Microsoft.Compute/virtualMachines/capz-cm5c-fmf9f,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-11-22 14:59:33 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-11-22 14:59:33 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-11-22 14:59:33 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-11-22 14:59:33 +0000 UTC,LastTransitionTime:2022-11-22 13:33:14 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-cm5c-fmf9f,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-cm5c-fmf9f,SystemUUID:688A27A1-A35E-4D82-8941-69E992A839CB,BootID:,KernelVersion:10.0.17763.3406,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.2,KubeletVersion:v1.23.15-rc.0.11+2b8076aad0e0b8,KubeProxyVersion:v1.23.15-rc.0.11+2b8076aad0e0b8,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{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:[capzci.azurecr.io/azuredisk-csi@sha256:7a3c030407bc9a3cdea7b1f15a66e787765eafb186308d88055cd08fc32bbd06 capzci.azurecr.io/azuredisk-csi:v1.25.0-dc9b210e79c74e4451faaa841d84e21ebc47b6c4],SizeBytes:129624120,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.15-rc.0.11_2b8076aad0e0b8-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:2fbd1e1a0538a06f2061afd45975df70c942654aa7f86e920720169ee439c2d6 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.1],SizeBytes:112027297,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:31547791294872570393470991481c2477a311031d3a03e0ae54eb164347dc34 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.7.0],SizeBytes:111112278,},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,},ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:1dac2d6534d9017f8967cc6238d6b448bdc1c978b5e8fea91bf39dc59d29881f docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:47258351,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:6ea7a987c109fdc059a36bf4abc5267c6f3de99d02ef6e84f0826da2aa435ea5 docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:27005594,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 92 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:150

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

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:825
------------------------------
Dynamic Provisioning [single-az] 
  Should create and attach a volume with basic perfProfile [enableBursting][disk.csi.azure.com] [Windows]
... skipping 19 lines ...
Nov 22 15:04:44.938: INFO: PersistentVolumeClaim pvc-qd52w found and phase=Bound (4.325700795s)
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
Nov 22 15:04:45.282: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-nzbsg" in namespace "azuredisk-1563" to be "Succeeded or Failed"
Nov 22 15:04:45.395: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 113.785294ms
Nov 22 15:04:47.504: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.22279529s
Nov 22 15:04:49.614: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.332465414s
Nov 22 15:04:51.724: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.442649089s
Nov 22 15:04:53.834: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.552019094s
Nov 22 15:04:55.951: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.669054163s
... skipping 287 lines ...
Nov 22 15:15:03.963: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 10m18.681677606s
Nov 22 15:15:06.073: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 10m20.791769866s
Nov 22 15:15:08.185: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 10m22.903710648s
Nov 22 15:15:10.295: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 10m25.01373428s
Nov 22 15:15:12.405: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 10m27.123457935s
Nov 22 15:15:14.515: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 10m29.233135734s
{"component":"entrypoint","file":"k8s.io/test-infra/prow/entrypoint/run.go:164","func":"k8s.io/test-infra/prow/entrypoint.Options.ExecuteProcess","level":"error","msg":"Process did not finish before 2h0m0s timeout","severity":"error","time":"2022-11-22T15:15:15Z"}
++ early_exit_handler
++ '[' -n 163 ']'
++ kill -TERM 163
++ cleanup_dind
++ [[ true == \t\r\u\e ]]
++ echo 'Cleaning up after docker'
... skipping 114 lines ...
Nov 22 15:17:35.981: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 12m50.699890589s
Nov 22 15:17:38.092: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 12m52.810269961s
Nov 22 15:17:40.203: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 12m54.920986822s
Nov 22 15:17:42.313: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 12m57.031775523s
Nov 22 15:17:44.424: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 12m59.142473585s
Nov 22 15:17:46.535: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 13m1.253235034s
panic: Failed to get controller-runtime client
Unexpected error:
    <*url.Error | 0xc00071dc20>: {
        Op: "Get",
        URL: "https://127.0.0.1:44921/api?timeout=32s",
        Err: <*net.OpError | 0xc0004fd6d0>{
            Op: "dial",
            Net: "tcp",
            Source: nil,
... skipping 9 lines ...
        },
    }
    Get "https://127.0.0.1:44921/api?timeout=32s": dial tcp 127.0.0.1:44921: connect: connection refused
occurred

goroutine 1 [running]:
main.Fail({0xc000576600?, 0xc00067ecf0?}, {0xc00071dc20?, 0xc000576300?, 0x1c8aefa?})
	/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/test/logger.go:36 +0x2d
github.com/onsi/gomega/internal.(*Assertion).match(0xc0006088c0, {0x3126dd8, 0x44399d0}, 0x0, {0xc000414400, 0x1, 0x1})
	/home/prow/go/pkg/mod/github.com/onsi/gomega@v1.18.1/internal/assertion.go:100 +0x1f0
github.com/onsi/gomega/internal.(*Assertion).ToNot(0xc0006088c0, {0x3126dd8, 0x44399d0}, {0xc000414400, 0x1, 0x1})
	/home/prow/go/pkg/mod/github.com/onsi/gomega@v1.18.1/internal/assertion.go:63 +0x91
sigs.k8s.io/cluster-api/test/framework.(*clusterProxy).GetClient(0xc0007954c0)
... skipping 5 lines ...
exit status 2
================ REDACTING LOGS ================
All sensitive variables are redacted
The connection to the server 127.0.0.1:44921 was refused - did you specify the right host or port?
/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kind-v0.14.0 delete cluster --name=capz || true
Deleting cluster "capz" ...
ERROR: failed to delete cluster "capz": error listing nodes: failed to list nodes: 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?
/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kind-v0.14.0 delete cluster --name=capz-e2e || true
Deleting cluster "capz-e2e" ...
ERROR: failed to delete cluster "capz-e2e": error listing nodes: failed to list nodes: 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?
Nov 22 15:17:48.648: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 13m3.366696656s
Nov 22 15:17:50.758: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 13m5.47625169s
Nov 22 15:17:52.868: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 13m7.586935342s
Nov 22 15:17:54.979: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 13m9.69730651s
... skipping 47 lines ...
Nov 22 15:19:36.289: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 14m51.0073491s
Nov 22 15:19:38.399: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 14m53.117059609s
Nov 22 15:19:40.509: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 14m55.22776655s
Nov 22 15:19:42.619: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 14m57.3376093s
Nov 22 15:19:44.729: INFO: Pod "azuredisk-volume-tester-nzbsg": Phase="Pending", Reason="", readiness=false. Elapsed: 14m59.447204824s
Nov 22 15:19:46.729: INFO: deleting Pod "azuredisk-1563"/"azuredisk-volume-tester-nzbsg"
Nov 22 15:19:46.874: INFO: Error getting logs for pod azuredisk-volume-tester-nzbsg: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-nzbsg)
STEP: Deleting pod azuredisk-volume-tester-nzbsg in namespace azuredisk-1563
Nov 22 15:19:46.997: INFO: deleting PVC "azuredisk-1563"/"pvc-qd52w"
Nov 22 15:19:46.997: INFO: Deleting PersistentVolumeClaim "pvc-qd52w"
STEP: waiting for claim's PV "pvc-d1a68cdd-ea47-4cf5-bb36-b463ee516322" to be deleted
Nov 22 15:19:47.116: INFO: Waiting up to 10m0s for PersistentVolume pvc-d1a68cdd-ea47-4cf5-bb36-b463ee516322 to get deleted
Nov 22 15:19:47.225: INFO: PersistentVolume pvc-d1a68cdd-ea47-4cf5-bb36-b463ee516322 found and phase=Bound (108.796799ms)
... skipping 118 lines ...
STEP: Collecting events from namespace "azuredisk-1563".
STEP: Found 6 events.
Nov 22 15:29:50.584: INFO: At 2022-11-22 15:04:40 +0000 UTC - event for pvc-qd52w: {disk.csi.azure.com_capz-cm5c4u-control-plane-xtz8f_87e1d712-b829-4980-9b37-68aa5021fc1a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-1563/pvc-qd52w"
Nov 22 15:29:50.584: INFO: At 2022-11-22 15:04:40 +0000 UTC - event for pvc-qd52w: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator
Nov 22 15:29:50.584: INFO: At 2022-11-22 15:04:43 +0000 UTC - event for pvc-qd52w: {disk.csi.azure.com_capz-cm5c4u-control-plane-xtz8f_87e1d712-b829-4980-9b37-68aa5021fc1a } ProvisioningSucceeded: Successfully provisioned volume pvc-d1a68cdd-ea47-4cf5-bb36-b463ee516322
Nov 22 15:29:50.584: INFO: At 2022-11-22 15:04:45 +0000 UTC - event for azuredisk-volume-tester-nzbsg: {default-scheduler } Scheduled: Successfully assigned azuredisk-1563/azuredisk-volume-tester-nzbsg to capz-cm5c-gcf6w
Nov 22 15:29:50.584: INFO: At 2022-11-22 15:04:45 +0000 UTC - event for azuredisk-volume-tester-nzbsg: {attachdetach-controller } FailedAttachVolume: AttachVolume.Attach failed for volume "pvc-d1a68cdd-ea47-4cf5-bb36-b463ee516322" : rpc error: code = Internal desc = Attach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/capz-cm5c4u/providers/Microsoft.Compute/disks/pvc-d1a68cdd-ea47-4cf5-bb36-b463ee516322 to instance capz-cm5c-gcf6w failed with getNodeVMSet: failed to check the node capz-cm5c-gcf6w management type: node informer is not synced when trying to GetResourceGroups
Nov 22 15:29:50.584: INFO: At 2022-11-22 15:06:48 +0000 UTC - event for azuredisk-volume-tester-nzbsg: {kubelet capz-cm5c-gcf6w} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume-1], unattached volumes=[test-volume-1]: timed out waiting for the condition
Nov 22 15:29:50.693: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
Nov 22 15:29:50.693: INFO: 
Nov 22 15:29:50.812: INFO: 
Logging node info for node capz-cm5c-fmf9f
Nov 22 15:29:50.924: INFO: Node Info: &Node{ObjectMeta:{capz-cm5c-fmf9f    a8c78fc5-9149-4271-9093-4b1e9426ff2c 17388 0 2022-11-22 13:32:23 +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:westeurope failure-domain.beta.kubernetes.io/zone:0 kubernetes.io/arch:amd64 kubernetes.io/hostname:capz-cm5c-fmf9f 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:westeurope topology.kubernetes.io/zone:0] map[cluster.x-k8s.io/cluster-name:capz-cm5c4u cluster.x-k8s.io/cluster-namespace:default cluster.x-k8s.io/machine:capz-cm5c4u-md-win-fc867f-5z8jk cluster.x-k8s.io/owner-kind:MachineSet cluster.x-k8s.io/owner-name:capz-cm5c4u-md-win-fc867f csi.volume.kubernetes.io/nodeid:{"disk.csi.azure.com":"capz-cm5c-fmf9f"} 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.138.65 projectcalico.org/VXLANTunnelMACAddr:00:15:5d:3b:da:34 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kubeadm Update v1 2022-11-22 13:32:23 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:kubeadm.alpha.kubernetes.io/cri-socket":{}}}} } {kubelet.exe Update v1 2022-11-22 13:32:23 +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-11-22 13:32:27 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}}} } {Go-http-client Update v1 2022-11-22 13:33:48 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:projectcalico.org/IPv4Address":{},"f:projectcalico.org/IPv4VXLANTunnelAddr":{},"f:projectcalico.org/VXLANTunnelMACAddr":{}}}} status} {manager Update v1 2022-11-22 13:33:50 +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":{}}}} } {kubelet.exe Update v1 2022-11-22 13:47:30 +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-cm5c4u/providers/Microsoft.Compute/virtualMachines/capz-cm5c-fmf9f,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-11-22 15:25:06 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-11-22 15:25:06 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-11-22 15:25:06 +0000 UTC,LastTransitionTime:2022-11-22 13:32:23 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-11-22 15:25:06 +0000 UTC,LastTransitionTime:2022-11-22 13:33:14 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status,},},Addresses:[]NodeAddress{NodeAddress{Type:Hostname,Address:capz-cm5c-fmf9f,},NodeAddress{Type:InternalIP,Address:10.1.0.5,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:capz-cm5c-fmf9f,SystemUUID:688A27A1-A35E-4D82-8941-69E992A839CB,BootID:,KernelVersion:10.0.17763.3406,OSImage:Windows Server 2019 Datacenter,ContainerRuntimeVersion:containerd://1.6.2,KubeletVersion:v1.23.15-rc.0.11+2b8076aad0e0b8,KubeProxyVersion:v1.23.15-rc.0.11+2b8076aad0e0b8,OperatingSystem:windows,Architecture:amd64,},Images:[]ContainerImage{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:[capzci.azurecr.io/azuredisk-csi@sha256:7a3c030407bc9a3cdea7b1f15a66e787765eafb186308d88055cd08fc32bbd06 capzci.azurecr.io/azuredisk-csi:v1.25.0-dc9b210e79c74e4451faaa841d84e21ebc47b6c4],SizeBytes:129624120,},ContainerImage{Names:[docker.io/sigwindowstools/kube-proxy:v1.23.1-calico-hostprocess docker.io/sigwindowstools/kube-proxy:v1.23.15-rc.0.11_2b8076aad0e0b8-calico-hostprocess],SizeBytes:116182072,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar@sha256:2fbd1e1a0538a06f2061afd45975df70c942654aa7f86e920720169ee439c2d6 mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.5.1],SizeBytes:112027297,},ContainerImage{Names:[mcr.microsoft.com/oss/kubernetes-csi/livenessprobe@sha256:31547791294872570393470991481c2477a311031d3a03e0ae54eb164347dc34 mcr.microsoft.com/oss/kubernetes-csi/livenessprobe:v2.7.0],SizeBytes:111112278,},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,},ContainerImage{Names:[docker.io/sigwindowstools/calico-install@sha256:1dac2d6534d9017f8967cc6238d6b448bdc1c978b5e8fea91bf39dc59d29881f docker.io/sigwindowstools/calico-install:v3.23.0-hostprocess],SizeBytes:47258351,},ContainerImage{Names:[docker.io/sigwindowstools/calico-node@sha256:6ea7a987c109fdc059a36bf4abc5267c6f3de99d02ef6e84f0826da2aa435ea5 docker.io/sigwindowstools/calico-node:v3.23.0-hostprocess],SizeBytes:27005594,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 92 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:185

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

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:825
------------------------------
Dynamic Provisioning [single-az] 
  should receive FailedMount event with invalid mount options [kubernetes.io/azure-disk] [disk.csi.azure.com]
... skipping 75 lines ...
Nov 22 15:30:03.208: INFO: PersistentVolumeClaim pvc-chrnd found and phase=Bound (4.328991236s)
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
Nov 22 15:30:03.540: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-9wggc" in namespace "azuredisk-9336" to be "Error status code"
Nov 22 15:30:03.649: INFO: Pod "azuredisk-volume-tester-9wggc": Phase="Pending", Reason="", readiness=false. Elapsed: 108.899729ms
Nov 22 15:30:05.760: INFO: Pod "azuredisk-volume-tester-9wggc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.219425459s
Nov 22 15:30:07.871: INFO: Pod "azuredisk-volume-tester-9wggc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.330749544s
Nov 22 15:30:09.983: INFO: Pod "azuredisk-volume-tester-9wggc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.442833716s
Nov 22 15:30:12.095: INFO: Pod "azuredisk-volume-tester-9wggc": Phase="Pending", Reason="", readiness=false. Elapsed: 8.555179529s
Nov 22 15:30:14.206: INFO: Pod "azuredisk-volume-tester-9wggc": Phase="Pending", Reason="", readiness=false. Elapsed: 10.665896883s
{"component":"entrypoint","file":"k8s.io/test-infra/prow/entrypoint/run.go:254","func":"k8s.io/test-infra/prow/entrypoint.gracefullyTerminate","level":"error","msg":"Process did not exit before 15m0s grace period","severity":"error","time":"2022-11-22T15:30:15Z"}
{"component":"entrypoint","error":"os: process already finished","file":"k8s.io/test-infra/prow/entrypoint/run.go:256","func":"k8s.io/test-infra/prow/entrypoint.gracefullyTerminate","level":"error","msg":"Could not kill process after grace period","severity":"error","time":"2022-11-22T15:30:15Z"}