This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-06-09 02:39
Elapsed4m25s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I0609 02:40:41.382305    8424 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0609 02:40:41.382560    8424 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0609 02:40:41.383719    8424 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0609 02:40:41.383903    8424 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=36739
I0609 02:40:41.384150    8424 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0609 02:40:42.313652    8424 kubeadmconfig_controller.go:223]  "msg"="Cluster infrastructure is not ready, waiting" "kind"="Machine" "kubeadmconfig"={"Namespace":"default","Name":"my-machine-config"} "name"="my-machine" "version"="109" 
•E0609 02:40:42.325268    8424 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 02:40:42.325296    8424 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-691141679/tls.crt: no such file or directory"  
E0609 02:40:42.325309    8424 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 02:40:42.325321    8424 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-691141679/tls.crt: no such file or directory"  
I0609 02:40:42.325576    8424 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 14.763 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.76s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	47.260s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.01s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0609 02:40:26.537678   10419 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0609 02:40:26.537739   10419 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0609 02:40:26.537788   10419 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0609 02:40:26.537821   10419 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0609 02:40:26.537853   10419 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0609 02:40:26.538485   10419 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2022/06/09 02:40:26 http: TLS handshake error from 127.0.0.1:54484: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0609 02:40:26.936350   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
I0609 02:40:26.939414   10419 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0609 02:40:26.992002   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed
I0609 02:40:26.993501   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0609 02:40:26.993756   10419 machine_controller_phases.go:246]  "msg"="Machine infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-test\" in namespace \"default\", requeuing: requeue in 1s"  
=== RUN   TestReconcileInfrastructure/infrastructure_ref_is_paused
I0609 02:40:26.994122   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0609 02:40:27.237677   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0609 02:40:27.239685   10419 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0609 02:40:27.261378   10419 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-44fmg" "namespace"="test-machine-watches-4v24v" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0609 02:40:27.261745   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0609 02:40:27.375812   10419 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-44fmg" "namespace"="test-machine-watches-4v24v" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0609 02:40:27.375898   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0609 02:40:27.480717   10419 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-44fmg" "namespace"="test-machine-watches-4v24v" "noderef"="node-1"
E0609 02:40:27.493894   10419 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0609 02:40:27.493956   10419 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0609 02:40:27.576004   10419 machine_controller_phases.go:246] controllers/Machine "msg"="Machine infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-created-44fmg\" in namespace \"test-machine-watches-4v24v\", requeuing: requeue in 1s"  
E0609 02:40:27.723428   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-created-44fmg\" in namespace \"test-machine-watches-4v24v\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-44fmg\" in namespace \"test-machine-watches-4v24v\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-44fmg" "namespace"="test-machine-watches-4v24v"
--- PASS: TestWatches (0.76s)
=== RUN   TestIndexMachineByNodeName
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef
--- PASS: TestIndexMachineByNodeName (0.00s)
    --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s)
... skipping 2 lines ...
=== RUN   TestMachine_Reconcile/reconcile_create
I0609 02:40:27.847407   10419 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-bc6kh" "namespace"="test-machine-watches-4v24v" "count"=1
I0609 02:40:27.847476   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-bc6kh" "namespace"="test-machine-watches-4v24v" "descendants"="Worker machines: machine-created-44fmg" "indirect descendants count"=0
I0609 02:40:27.862491   10419 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-bc6kh" "namespace"="test-machine-watches-4v24v" "count"=1
I0609 02:40:27.862585   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-bc6kh" "namespace"="test-machine-watches-4v24v" "descendants"="Worker machines: machine-created-44fmg" "indirect descendants count"=0
I0609 02:40:28.723970   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-bc6kh" "machine"="machine-created-44fmg" "namespace"="test-machine-watches-4v24v" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"ca2d36f4-41cf-4530-b7c1-a7152b3062c9","apiVersion":"v1"}
E0609 02:40:28.769768   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-44fmg\" not found" "controller"="machine" "name"="machine-created-44fmg" "namespace"="test-machine-watches-4v24v"
E0609 02:40:29.821441   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-ww2tg\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-xdcmb\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-xdcmb: secrets \"machine-reconcile-xdcmb-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-ww2tg" "namespace"="default"
I0609 02:40:30.821988   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xdcmb" "machine"="machine-created-ww2tg" "namespace"="default" "cause"="noderef is nil" "node"=null
I0609 02:40:30.946884   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xdcmb" "machine"="machine-created-ww2tg" "namespace"="default" "cause"="noderef is nil" "node"=null
I0609 02:40:31.110352   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xdcmb" "machine"="machine-created-ww2tg" "namespace"="default" "cause"="noderef is nil" "node"=null
E0609 02:40:31.139858   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-ww2tg\" not found" "controller"="machine" "name"="machine-created-ww2tg" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.39s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.39s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 6 lines ...
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0609 02:40:31.157956   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0609 02:40:31.158142   10419 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0609 02:40:31.161764   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0609 02:40:31.161957   10419 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
E0609 02:40:31.162713   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-xdcmb\" not found" "controller"="cluster" "name"="machine-reconcile-xdcmb" "namespace"="default"
--- PASS: TestMachineOwnerReference (0.01s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
... skipping 119 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0609 02:40:31.458077   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6m92" "namespace"="test-mhc-9qgqc" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0609 02:40:31.489907   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0609 02:40:31.490052   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-pdxzq\" not found"  "cluster"="test-mhc-9qgqc/test-cluster-pdxzq"
E0609 02:40:31.495111   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-x6m92\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-x6m92\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-x6m92" "namespace"="test-mhc-9qgqc"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0609 02:40:32.495417   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6m92" "namespace"="test-mhc-9qgqc" 
I0609 02:40:32.495522   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jlkmn" "namespace"="test-mhc-7jjm9" 
I0609 02:40:32.495556   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r26sm" "namespace"="test-mhc-xbslp" 
I0609 02:40:32.495590   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7pbmw" "namespace"="test-mhc-nn6pj" 
I0609 02:40:32.508816   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 02:40:32.555644   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7pbmw" "namespace"="test-mhc-nn6pj" 
I0609 02:40:32.602727   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7pbmw" "namespace"="test-mhc-nn6pj" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0609 02:40:32.631546   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9g9kp" "namespace"="test-mhc-rq82r" 
E0609 02:40:32.651190   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-49rsc\" not found" "controller"="cluster" "name"="test-cluster-49rsc" "namespace"="test-mhc-nn6pj"
I0609 02:40:32.659676   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0609 02:40:32.760188   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-nn6pj/test-cluster-49rsc"
I0609 02:40:32.798330   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9g9kp" "namespace"="test-mhc-rq82r" 
E0609 02:40:32.836929   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rq82r/test-cluster-zhfcl"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0609 02:40:32.841646   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9g9kp" "namespace"="test-mhc-rq82r" 
I0609 02:40:32.959316   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
inframachine created: test-mhc-machine-infra-fz4cw
I0609 02:40:32.986072   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-h9dr8
I0609 02:40:33.014128   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.026654   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.026970   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-h9dr8/"
I0609 02:40:33.048776   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.049190   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-h9dr8/"
node created: test-mhc-node-2xwgf
E0609 02:40:33.106738   10419 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-2xwgf"
E0609 02:40:33.106738   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2xwgf, got []"  "node"="test-mhc-node-2xwgf"
I0609 02:40:33.113631   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
inframachine created: test-mhc-machine-infra-wmtq9
machine created: test-mhc-machine-gzqlt
I0609 02:40:33.132628   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.137815   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.142882   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
... skipping 25 lines ...
I0609 02:40:33.192295   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.194549   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.195827   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.196956   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.199570   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.201126   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.201539   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-gzqlt/"
I0609 02:40:33.225207   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.225628   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-gzqlt/"
I0609 02:40:33.231934   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.232356   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-gzqlt/"
E0609 02:40:33.236808   10419 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-mpx8m"
node created: test-mhc-node-mpx8m
E0609 02:40:33.237942   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mpx8m, got []"  "node"="test-mhc-node-mpx8m"
I0609 02:40:33.239368   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.240051   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-gzqlt/"
I0609 02:40:33.249212   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.249696   10419 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf" "noderef"="test-mhc-node-mpx8m"
I0609 02:40:33.273372   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
Cleaning up nodes, machines and infra machines.
I0609 02:40:33.282506   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.283026   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-h9dr8/"
I0609 02:40:33.306681   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.307209   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-h9dr8/"
I0609 02:40:33.307683   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-gzqlt/"
I0609 02:40:33.327150   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.327691   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-h9dr8/"
I0609 02:40:33.328142   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qzrxf/test-mhc-27hsh/test-mhc-machine-gzqlt/"
E0609 02:40:33.330579   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qzrxf/test-cluster-b4mpf"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
I0609 02:40:33.335543   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-27hsh" "namespace"="test-mhc-qzrxf" 
I0609 02:40:33.462891   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
inframachine created: test-mhc-machine-infra-frslw
E0609 02:40:33.504602   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:40:33.508017   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-d9jwb
I0609 02:40:33.533109   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.541723   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.542800   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.543426   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 54 lines ...
I0609 02:40:33.653945   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.662316   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.664534   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.666437   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.668321   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.670084   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
E0609 02:40:33.671121   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-4v24v/machine-reconcile-bc6kh"
I0609 02:40:33.671710   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.673472   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.676455   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.683390   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.685318   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:33.687168   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 362 lines ...
I0609 02:40:34.491452   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.493834   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.496030   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.498287   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.500664   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.503068   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
E0609 02:40:34.504980   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:34.505148   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.506826   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.509227   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.511366   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.521346   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:34.523628   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 459 lines ...
I0609 02:40:35.478921   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.480948   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.487484   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.490777   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.492776   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.501269   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
E0609 02:40:35.506206   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:40:35.506297   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.508211   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.512865   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.515610   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.518395   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:35.521220   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 454 lines ...
I0609 02:40:36.510409   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.512260   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.513824   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.514535   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.515395   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.517046   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
E0609 02:40:36.518313   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:36.518357   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.518619   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-d9jwb/"
I0609 02:40:36.528089   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.528384   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-d9jwb/"
node created: test-mhc-node-t4crg
E0609 02:40:36.544517   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-t4crg, got []"  "node"="test-mhc-node-t4crg"
I0609 02:40:36.552339   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
inframachine created: test-mhc-machine-infra-qlsml
machine created: test-mhc-machine-2kgbj
I0609 02:40:36.575254   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.580893   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:36.581891   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 349 lines ...
I0609 02:40:37.505763   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.507805   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.509788   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.511809   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.513760   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.519311   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
E0609 02:40:37.519461   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:40:37.521278   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.523277   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.525225   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.527191   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.529139   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:37.531089   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 385 lines ...
I0609 02:40:38.565096   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.567615   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.569817   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.574091   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.576459   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.578539   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
E0609 02:40:38.581384   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:38.583594   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.590340   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.595713   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.600184   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.604946   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:38.607411   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 320 lines ...
I0609 02:40:39.582457   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:39.596780   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:39.598354   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:39.599426   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:39.601559   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:39.602673   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:39.603039   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-2kgbj/"
E0609 02:40:39.603193   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:40:39.614661   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:39.615088   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-2kgbj/"
E0609 02:40:39.686402   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7wmm2, got []"  "node"="test-mhc-node-7wmm2"
node created: test-mhc-node-7wmm2
I0609 02:40:39.694373   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
inframachine created: test-mhc-machine-infra-c287k
machine created: test-mhc-machine-pmztm
I0609 02:40:39.732977   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:39.743099   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 226 lines ...
I0609 02:40:40.580862   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.583403   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.585814   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.588392   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.605673   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.614373   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
E0609 02:40:40.618424   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:40.620630   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.626704   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.640866   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.642223   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.643995   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:40.645406   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 321 lines ...
I0609 02:40:41.651989   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.654812   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.657139   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.658911   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.670022   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.695200   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
E0609 02:40:41.696254   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:40:41.716524   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.719139   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.728714   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.736188   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.737710   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:41.739158   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
... skipping 326 lines ...
I0609 02:40:42.720574   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.722184   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.723806   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.725418   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.727023   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.729856   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.732265   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-pmztm/"
E0609 02:40:42.733074   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:42.742092   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.742640   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-pmztm/"
E0609 02:40:42.751558   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bqsgx, got []"  "node"="test-mhc-node-bqsgx"
node created: test-mhc-node-bqsgx
Cleaning up nodes, machines and infra machines.
I0609 02:40:42.759739   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.760671   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-pmztm/test-mhc-node-bqsgx"
I0609 02:40:42.772609   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.773133   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-pmztm/"
Cleaning up nodes, machines and infra machines.
I0609 02:40:42.788308   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.788918   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-d9jwb/"
I0609 02:40:42.813460   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-pmztm/"
I0609 02:40:42.818523   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:42.819124   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-2kgbj/"
I0609 02:40:42.826190   10419 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-b52wx" "namespace"="test-mhc-qpqm2" "count"=2
I0609 02:40:42.826270   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-b52wx" "namespace"="test-mhc-qpqm2" "descendants"="Worker machines: test-mhc-machine-2kgbj,test-mhc-machine-pmztm,test-mhc-machine-d9jwb" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0609 02:40:42.832286   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-pmztm/"
I0609 02:40:42.832677   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qpqm2/test-mhc-ktlpt/test-mhc-machine-d9jwb/"
I0609 02:40:42.833521   10419 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-b52wx" "namespace"="test-mhc-qpqm2" "count"=2
I0609 02:40:42.833571   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-b52wx" "namespace"="test-mhc-qpqm2" "descendants"="Worker machines: test-mhc-machine-d9jwb,test-mhc-machine-2kgbj,test-mhc-machine-pmztm" "indirect descendants count"=1
E0609 02:40:42.835216   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-ktlpt\" not found" "controller"="machinehealthcheck" "name"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2"
inframachine created: test-mhc-machine-infra-ck6v9
machine created: test-mhc-machine-jzmpg
I0609 02:40:43.733623   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-b52wx" "machine"="test-mhc-machine-2kgbj" "namespace"="test-mhc-qpqm2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-7wmm2"}
E0609 02:40:43.794304   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2kgbj\" not found" "controller"="machine" "name"="test-mhc-machine-2kgbj" "namespace"="test-mhc-qpqm2"
I0609 02:40:43.837088   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ktlpt" "namespace"="test-mhc-qpqm2" 
I0609 02:40:43.837182   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:43.853139   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 02:40:43.885219   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:43.890089   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:43.911003   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:43.952031   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:44.037424   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:44.203440   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:44.524510   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
E0609 02:40:44.794701   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:40:45.165629   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:45.795293   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-b52wx" "machine"="test-mhc-machine-pmztm" "namespace"="test-mhc-qpqm2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-bqsgx"}
E0609 02:40:45.851597   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-pmztm\" not found" "controller"="machine" "name"="test-mhc-machine-pmztm" "namespace"="test-mhc-qpqm2"
I0609 02:40:46.446735   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:46.852124   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-b52wx" "machine"="test-mhc-machine-d9jwb" "namespace"="test-mhc-qpqm2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-t4crg"}
E0609 02:40:46.896848   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-d9jwb\" not found" "controller"="machine" "name"="test-mhc-machine-d9jwb" "namespace"="test-mhc-qpqm2"
E0609 02:40:47.846385   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qpqm2/test-cluster-b52wx"
E0609 02:40:47.897169   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:48.905032   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:48.909743   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
E0609 02:40:48.910172   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:40:48.937016   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
E0609 02:40:49.001507   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ppk2x, got []"  "node"="test-mhc-node-ppk2x"
node created: test-mhc-node-ppk2x
I0609 02:40:49.009444   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
inframachine created: test-mhc-machine-infra-qtmxc
I0609 02:40:49.036082   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:49.037064   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
machine created: test-mhc-machine-nqkxp
I0609 02:40:49.047089   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:49.052197   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:49.073355   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:49.114571   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:49.195667   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:49.357059   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:49.681312   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
E0609 02:40:49.910619   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:50.322680   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:50.923531   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:50.929558   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:50.953965   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:50.959752   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:50.982903   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
E0609 02:40:50.989147   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:40:50.989523   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:51.008872   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
node created: test-mhc-node-zz55s
E0609 02:40:51.044489   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zz55s, got []"  "node"="test-mhc-node-zz55s"
I0609 02:40:51.051766   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
inframachine created: test-mhc-machine-infra-2bb46
I0609 02:40:51.069238   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
machine created: test-mhc-machine-52jnx
I0609 02:40:51.071087   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:51.083773   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:51.603963   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
E0609 02:40:51.989541   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:53.002478   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:53.018322   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:53.030166   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:53.038607   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:53.047489   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:53.059349   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:53.066584   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
E0609 02:40:53.068986   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
node created: test-mhc-node-jdk6c
E0609 02:40:53.091063   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jdk6c, got []"  "node"="test-mhc-node-jdk6c"
Cleaning up nodes, machines and infra machines.
I0609 02:40:53.120249   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:53.136772   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
Cleaning up nodes, machines and infra machines.
I0609 02:40:53.186502   10419 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rjzsc" "namespace"="test-mhc-spgpb" "count"=2
I0609 02:40:53.186593   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rjzsc" "namespace"="test-mhc-spgpb" "descendants"="Worker machines: test-mhc-machine-jzmpg,test-mhc-machine-nqkxp,test-mhc-machine-52jnx" "indirect descendants count"=1
... skipping 3 lines ...
inframachine created: test-mhc-machine-infra-86nvz
machine created: test-mhc-machine-67bfb
I0609 02:40:53.370418   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:40:53.387405   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 02:40:53.414373   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9s8sc" "namespace"="test-mhc-spgpb" 
I0609 02:40:53.414454   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
E0609 02:40:54.069382   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:40:55.072804   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rjzsc" "machine"="test-mhc-machine-jzmpg" "namespace"="test-mhc-spgpb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ppk2x"}
E0609 02:40:55.131167   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jzmpg\" not found" "controller"="machine" "name"="test-mhc-machine-jzmpg" "namespace"="test-mhc-spgpb"
I0609 02:40:56.131674   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rjzsc" "machine"="test-mhc-machine-nqkxp" "namespace"="test-mhc-spgpb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zz55s"}
E0609 02:40:56.200647   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nqkxp\" not found" "controller"="machine" "name"="test-mhc-machine-nqkxp" "namespace"="test-mhc-spgpb"
I0609 02:40:57.201167   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rjzsc" "machine"="test-mhc-machine-52jnx" "namespace"="test-mhc-spgpb" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jdk6c"}
E0609 02:40:57.244358   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-52jnx\" not found" "controller"="machine" "name"="test-mhc-machine-52jnx" "namespace"="test-mhc-spgpb"
E0609 02:40:58.205212   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-spgpb/test-cluster-rjzsc"
I0609 02:40:58.253361   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:40:58.258579   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
E0609 02:40:58.258768   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
node created: test-mhc-node-rwd5t
E0609 02:40:58.356137   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rwd5t, got []"  "node"="test-mhc-node-rwd5t"
I0609 02:40:58.363638   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
inframachine created: test-mhc-machine-infra-m4wlz
I0609 02:40:58.378880   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
machine created: test-mhc-machine-cjrzw
I0609 02:40:58.384009   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:40:58.397310   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
E0609 02:40:59.263038   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:41:00.275600   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.285875   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.307718   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.314170   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.327837   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.332110   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.342600   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.357277   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.367992   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.381836   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.397150   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
E0609 02:41:00.410985   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jgdwz, got []"  "node"="test-mhc-node-jgdwz"
node created: test-mhc-node-jgdwz
I0609 02:41:00.417052   10419 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-cjrzw" "namespace"="test-mhc-xdhtm" "noderef"="test-mhc-node-jgdwz"
I0609 02:41:00.422152   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
inframachine created: test-mhc-machine-infra-zz2cf
machine created: test-mhc-machine-drbts
I0609 02:41:00.625771   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.633021   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
Cleaning up nodes, machines and infra machines.
I0609 02:41:00.645989   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.649295   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8s88r" "machine"="test-mhc-machine-drbts" "namespace"="test-mhc-xdhtm" "cause"="noderef is nil" "node"=null
Cleaning up nodes, machines and infra machines.
I0609 02:41:00.660788   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.661628   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xdhtm/test-mhc-qkndp/test-mhc-machine-67bfb/"
I0609 02:41:00.709621   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:00.710624   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xdhtm/test-mhc-qkndp/test-mhc-machine-67bfb/"
I0609 02:41:00.711549   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xdhtm/test-mhc-qkndp/test-mhc-machine-cjrzw/"
I0609 02:41:00.735768   10419 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-8s88r" "namespace"="test-mhc-xdhtm" "count"=3
I0609 02:41:00.735887   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-8s88r" "namespace"="test-mhc-xdhtm" "descendants"="Worker machines: test-mhc-machine-cjrzw,test-mhc-machine-drbts,test-mhc-machine-67bfb" "indirect descendants count"=0
E0609 02:41:00.739938   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-drbts\" not found" "controller"="machine" "name"="test-mhc-machine-drbts" "namespace"="test-mhc-xdhtm"
I0609 02:41:00.742320   10419 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-8s88r" "namespace"="test-mhc-xdhtm" "count"=2
I0609 02:41:00.742372   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-8s88r" "namespace"="test-mhc-xdhtm" "descendants"="Worker machines: test-mhc-machine-67bfb,test-mhc-machine-cjrzw" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-4mtkz
machine created: test-mhc-machine-fz5cr
E0609 02:41:00.868779   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-qkndp\" not found" "controller"="machinehealthcheck" "name"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm"
I0609 02:41:01.740456   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8s88r" "machine"="test-mhc-machine-67bfb" "namespace"="test-mhc-xdhtm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-rwd5t"}
E0609 02:41:01.782813   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-67bfb\" not found" "controller"="machine" "name"="test-mhc-machine-67bfb" "namespace"="test-mhc-xdhtm"
I0609 02:41:01.871479   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:01.885517   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 02:41:01.905089   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qkndp" "namespace"="test-mhc-xdhtm" 
I0609 02:41:01.905164   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:01.906197   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:01.908046   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
... skipping 433 lines ...
I0609 02:41:02.823763   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.825550   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.827418   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.829887   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.831840   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.834036   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
E0609 02:41:02.835353   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cjrzw\" not found" "controller"="machine" "name"="test-mhc-machine-cjrzw" "namespace"="test-mhc-xdhtm"
I0609 02:41:02.836051   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.837875   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.839677   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.841456   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.843342   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:02.845016   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
... skipping 505 lines ...
I0609 02:41:03.838765   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.840518   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.843752   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.844347   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.851528   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.852343   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.852642   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-plff2/test-mhc-49t44/test-mhc-machine-fz5cr/"
E0609 02:41:03.852346   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:41:03.862697   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.863048   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "target"="test-mhc-plff2/test-mhc-49t44/test-mhc-machine-fz5cr/"
E0609 02:41:03.895411   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-s8tkv, got []"  "node"="test-mhc-node-s8tkv"
node created: test-mhc-node-s8tkv
E0609 02:41:03.895590   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-s8tkv, got []"  "node"="test-mhc-node-s8tkv"
I0609 02:41:03.908679   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.923785   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.936395   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.936778   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-plff2/test-mhc-49t44/test-mhc-machine-fz5cr/test-mhc-node-s8tkv"
I0609 02:41:03.951461   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.951842   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "target"="test-mhc-plff2/test-mhc-49t44/test-mhc-machine-fz5cr/test-mhc-node-s8tkv"
Cleaning up nodes, machines and infra machines.
I0609 02:41:03.963853   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:03.964266   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-plff2/test-mhc-49t44/test-mhc-machine-fz5cr/"
I0609 02:41:03.978384   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6rrh5" "namespace"="test-mhc-plff2" "descendants"="Worker machines: test-mhc-machine-fz5cr" "indirect descendants count"=1
I0609 02:41:03.982564   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6rrh5" "namespace"="test-mhc-plff2" "descendants"="Worker machines: test-mhc-machine-fz5cr" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0609 02:41:04.111675   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-d6r2n" "namespace"="test-mhc-shjv2" "creating"=1 "need"=1
I0609 02:41:04.111726   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-d6r2n" "namespace"="test-mhc-shjv2" 
I0609 02:41:04.117503   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-49t44" "namespace"="test-mhc-plff2" 
I0609 02:41:04.128718   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-d6r2n-hmwd6\"" "machineset"="mhc-ms-d6r2n" "namespace"="test-mhc-shjv2" 
I0609 02:41:04.195684   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ndjlq" "namespace"="test-mhc-shjv2" 
I0609 02:41:04.219497   10419 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0609 02:41:04.237469   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ndjlq" "namespace"="test-mhc-shjv2" 
I0609 02:41:04.238219   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ndjlq" "namespace"="test-mhc-shjv2" 
E0609 02:41:04.853154   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:41:05.237776   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ndjlq" "namespace"="test-mhc-shjv2" 
E0609 02:41:05.756099   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xdhtm/test-cluster-8s88r"
I0609 02:41:05.853680   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6rrh5" "machine"="test-mhc-machine-fz5cr" "namespace"="test-mhc-plff2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-s8tkv"}
E0609 02:41:05.896807   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fz5cr\" not found" "controller"="machine" "name"="test-mhc-machine-fz5cr" "namespace"="test-mhc-plff2"
I0609 02:41:06.238786   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ndjlq" "namespace"="test-mhc-shjv2" 
I0609 02:41:06.931583   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ndjlq" "namespace"="test-mhc-shjv2" 
I0609 02:41:06.939793   10419 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-d6r2n" "namespace"="test-mhc-shjv2" 
I0609 02:41:06.976055   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ndjlq" "namespace"="test-mhc-shjv2" 
I0609 02:41:06.976089   10419 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-d6r2n" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.024422   10419 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-d6r2n-hmwd6" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.024462   10419 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-d6r2n-hmwd6" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.030759   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ndjlq" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.031120   10419 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="Node failed to report startup in 1s" "reason"="NodeStartupTimeout" "target"="test-mhc-shjv2/test-mhc-ndjlq/mhc-ms-d6r2n-hmwd6/"
I0609 02:41:07.031571   10419 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-d6r2n" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.037825   10419 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-d6r2n" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.041852   10419 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-d6r2n-hmwd6" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.041889   10419 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-d6r2n-hmwd6" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.061890   10419 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-d6r2n-hmwd6" "namespace"="test-mhc-shjv2" 
I0609 02:41:07.061934   10419 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-d6r2n-hmwd6" "namespace"="test-mhc-shjv2" 
... skipping 63 lines ...
I0609 02:41:07.432526   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.433088   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.434221   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.436005   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.437184   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.437185   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-m9bjs" "machine"="mhc-ms-d6r2n-hmwd6" "namespace"="test-mhc-shjv2" "cause"="cluster is being deleted" "node"=null
E0609 02:41:07.467874   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-d6r2n-hmwd6\" not found" "controller"="machine" "name"="mhc-ms-d6r2n-hmwd6" "namespace"="test-mhc-shjv2"
I0609 02:41:07.481247   10419 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "remediation request name"="test-mhc-machine-hcm2m" "target"="test-mhc-xzwd6/test-mhc-9v7cr/test-mhc-machine-hcm2m/"
I0609 02:41:07.494830   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
node created: test-mhc-node-m2k42
E0609 02:41:07.531617   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-m2k42, got []"  "node"="test-mhc-node-m2k42"
E0609 02:41:07.531864   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-m2k42, got []"  "node"="test-mhc-node-m2k42"
E0609 02:41:07.532209   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-m2k42, got []"  "node"="test-mhc-node-m2k42"
I0609 02:41:07.539364   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.563616   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.573246   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.588555   10419 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "remediation request name"="test-mhc-machine-hcm2m" "target"="test-mhc-xzwd6/test-mhc-9v7cr/test-mhc-machine-hcm2m/test-mhc-node-m2k42"
I0609 02:41:07.624039   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
Cleaning up nodes, machines and infra machines.
I0609 02:41:07.630444   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.632884   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.636544   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9v7cr" "namespace"="test-mhc-xzwd6" 
I0609 02:41:07.647606   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mbp8d" "namespace"="test-mhc-xzwd6" "descendants"="Worker machines: test-mhc-machine-hcm2m" "indirect descendants count"=1
... skipping 321 lines ...
I0609 02:41:08.495299   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.497044   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.498802   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.500585   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.502425   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.504539   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
E0609 02:41:08.505694   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-hcm2m\" not found" "controller"="machine" "name"="test-mhc-machine-hcm2m" "namespace"="test-mhc-xzwd6"
I0609 02:41:08.506271   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.507977   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.509618   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.511370   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.513260   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.515137   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
... skipping 253 lines ...
I0609 02:41:08.985358   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.986961   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.989290   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.990929   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.992710   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.994665   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
E0609 02:41:08.995612   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-plff2/test-cluster-6rrh5"
I0609 02:41:08.996628   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:08.998612   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.000467   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.002239   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.004203   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.005960   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
... skipping 279 lines ...
I0609 02:41:09.507128   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.509036   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.510629   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.512182   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.514588   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.515762   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
E0609 02:41:09.516116   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
I0609 02:41:09.520097   10419 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="Node failed to report startup in 1ms" "reason"="NodeStartupTimeout" "remediation request name"="test-mhc-machine-f6fbj" "target"="test-mhc-m2b5w/test-mhc-prnrl/test-mhc-machine-f6fbj/"
I0609 02:41:09.530794   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
node created: test-mhc-node-jvdvk
E0609 02:41:09.602957   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jvdvk, got []"  "node"="test-mhc-node-jvdvk"
E0609 02:41:09.602973   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jvdvk, got []"  "node"="test-mhc-node-jvdvk"
E0609 02:41:09.602985   10419 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jvdvk, got []"  "node"="test-mhc-node-jvdvk"
I0609 02:41:09.609357   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.630678   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.647688   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.650561   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.654349   10419 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="Condition Ready on node is reporting status Unknown for more than 5m0s" "reason"="UnhealthyNode" "remediation request name"="test-mhc-machine-f6fbj" "target"="test-mhc-m2b5w/test-mhc-prnrl/test-mhc-machine-f6fbj/test-mhc-node-jvdvk"
I0609 02:41:09.669398   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.681072   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.700018   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
Cleaning up nodes, machines and infra machines.
I0609 02:41:09.709691   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
I0609 02:41:09.715137   10419 machinehealthcheck_controller.go:379] controllers/MachineHealthCheck "msg"="Target has failed health check, creating an external remediation request"  "message"="" "reason"="NodeNotFound" "remediation request name"="test-mhc-machine-f6fbj" "target"="test-mhc-m2b5w/test-mhc-prnrl/test-mhc-machine-f6fbj/"
I0609 02:41:09.722757   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-slk2f" "namespace"="test-mhc-m2b5w" "descendants"="Worker machines: test-mhc-machine-f6fbj" "indirect descendants count"=1
I0609 02:41:09.726672   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-slk2f" "namespace"="test-mhc-m2b5w" "descendants"="Worker machines: test-mhc-machine-f6fbj" "indirect descendants count"=1
--- PASS: TestMachineHealthCheck_Reconcile (38.39s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.14s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.02s)
... skipping 12 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.40s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.08s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0609 02:41:09.733444   10419 machinehealthcheck_controller.go:416]  "msg"="expected a Cluster" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace
--- PASS: TestClusterToMachineHealthCheck (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace (0.00s)
=== RUN   TestMachineToMachineHealthCheck
=== RUN   TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine
E0609 02:41:09.735286   10419 machinehealthcheck_controller.go:445]  "msg"="expected a Machine" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace
E0609 02:41:09.736487   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-prnrl\" not found" "controller"="machinehealthcheck" "name"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w"
--- PASS: TestMachineToMachineHealthCheck (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace (0.00s)
=== RUN   TestNodeToMachineHealthCheck
=== RUN   TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node
E0609 02:41:09.737372   10419 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0609 02:41:09.737670   10419 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got []"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_two_Machines_exist_for_the_Node
E0609 02:41:09.738212   10419 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0609 02:41:09.741952   10419 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0609 02:41:09.742603   10419 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0609 02:41:09.744460   10419 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0609 02:41:09.757299   10419 machineset_controller.go:151]  "msg"="Failed to reconcile MachineSet" "error"="failed to calculate MachineSet's Status: failed to calculate status for MachineSet default/machineset1: invalid label key \"--$-invalid\": name part must consist of alphanumeric characters, '-', '_' or '.', and must start and end with an alphanumeric character (e.g. 'MyName',  or 'my.name',  or '123-abc', regex used for validation is '([A-Za-z0-9][-A-Za-z0-9_.]*)?[A-Za-z0-9]')" "machineset"="machineset1" "namespace"="default" 
--- PASS: TestMachineSetReconcile (0.00s)
    --- PASS: TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion (0.00s)
    --- PASS: TestMachineSetReconcile/records_event_if_reconcile_fails (0.00s)
=== RUN   TestMachineSetToMachines
=== RUN   TestMachineSetToMachines/should_return_empty_request_when_controller_is_set
=== RUN   TestMachineSetToMachines/should_return_nil_if_machine_has_no_owner_reference
... skipping 8 lines ...
--- PASS: TestAdoptOrphan (0.00s)
=== RUN   TestHasMatchingLabels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_has_empty_selector
=== RUN   TestHasMatchingLabels/machine_set_has_bad_selector
E0609 02:41:09.758947   10419 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 57 lines ...
=== RUN   TestGinkgoSuite
Running Suite: Controllers Suite
================================
Random Seed: 1654742414
Will run 16 of 16 specs

•E0609 02:41:09.882693   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-bb992\" not found" "controller"="cluster" "name"="test1-bb992" "namespace"="default"
I0609 02:41:10.516622   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-slk2f" "machine"="test-mhc-machine-f6fbj" "namespace"="test-mhc-m2b5w" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jvdvk"}
E0609 02:41:10.548227   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f6fbj\" not found" "controller"="machine" "name"="test-mhc-machine-f6fbj" "namespace"="test-mhc-m2b5w"
I0609 02:41:10.736729   10419 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-prnrl" "namespace"="test-mhc-m2b5w" 
•I0609 02:41:11.000820   10419 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-qqkch" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0609 02:41:11.115757   10419 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-qqkch" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0609 02:41:11.119305   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\"" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"
E0609 02:41:11.548574   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
E0609 02:41:12.132358   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-qqkch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"
•E0609 02:41:13.144063   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-cn859\" not found" "controller"="cluster" "name"="test3-cn859" "namespace"="default"
E0609 02:41:14.144706   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-qqkch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"
E0609 02:41:15.163374   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-shjv2/test-cluster-m9bjs"
E0609 02:41:15.173243   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xzwd6/test-cluster-mbp8d"
E0609 02:41:15.173722   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-qqkch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"
•E0609 02:41:16.183840   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-m2b5w/test-cluster-slk2f"
E0609 02:41:16.186699   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-5qj8r: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-5qj8r" "namespace"="default"
E0609 02:41:17.187420   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-qqkch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"
E0609 02:41:18.196358   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-5qj8r: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-5qj8r" "namespace"="default"
•E0609 02:41:19.197088   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-qqkch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"
E0609 02:41:19.756504   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-h9dr8\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-h9dr8" "namespace"="test-mhc-qzrxf"
E0609 02:41:20.197826   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-5qj8r: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-5qj8r" "namespace"="default"
E0609 02:41:21.206431   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-qqkch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"
I0609 02:41:21.306559   10419 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-492fh" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0609 02:41:21.316602   10419 machine_controller_noderef.go:73] controllers/Machine "msg"="Failed to retrieve Node by ProviderID" "error"="the cache is not started, can not read objects" "machine"="test6-492fh" "namespace"="default" 
E0609 02:41:21.332890   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\", the cache is not started, can not read objects]" "controller"="machine" "name"="test6-492fh" "namespace"="default"
E0609 02:41:22.207129   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-5qj8r: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-5qj8r" "namespace"="default"
I0609 02:41:22.347633   10419 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-492fh" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0609 02:41:22.347899   10419 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-492fh" "namespace"="default" "noderef"="id-node-1"
E0609 02:41:22.363165   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to find a CustomResourceDefinition for /, Kind= with contract \"cluster.x-k8s.io/v1alpha3\"" "controller"="machine" "name"="test6-492fh" "namespace"="default"
E0609 02:41:23.211513   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-qqkch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"

------------------------------
• [SLOW TEST:5.034 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
  /home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:248
------------------------------
I0609 02:41:23.355618   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-ccrdn" "namespace"="ms-test" "creating"=2 "need"=2
I0609 02:41:23.355654   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-ccrdn" "namespace"="ms-test" 
E0609 02:41:23.363500   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-b4mpf\" for machine \"test-mhc-machine-gzqlt\" in namespace \"test-mhc-qzrxf\": Cluster.cluster.x-k8s.io \"test-cluster-b4mpf\" not found" "controller"="machine" "name"="test-mhc-machine-gzqlt" "namespace"="test-mhc-qzrxf"
I0609 02:41:23.365925   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-ccrdn-mjzrh\"" "machineset"="ms-ccrdn" "namespace"="ms-test" 
I0609 02:41:23.365963   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-ccrdn" "namespace"="ms-test" 
I0609 02:41:23.382339   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-ccrdn-2v6f7\"" "machineset"="ms-ccrdn" "namespace"="ms-test" 
I0609 02:41:23.492694   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-ccrdn" "namespace"="ms-test" "creating"=1 "need"=2
I0609 02:41:23.492745   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-ccrdn" "namespace"="ms-test" 
I0609 02:41:23.505465   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-ccrdn-8qf2d\"" "machineset"="ms-ccrdn" "namespace"="ms-test" 
E0609 02:41:23.718805   10419 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-ccrdn-8qf2d-445sx for machine ms-test/ms-ccrdn-8qf2d: the cache is not started, can not read objects" "machineset"="ms-ccrdn" "namespace"="ms-test" 
E0609 02:41:23.945387   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0609 02:41:23.947588   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0609 02:41:23.948392   10419 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0609 02:41:23.948439   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0609 02:41:23.949020   10419 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0609 02:41:23.949044   10419 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0609 02:41:23.949486   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
... skipping 13 lines ...
I0609 02:41:23.960190   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
•I0609 02:41:23.961561   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0609 02:41:23.962203   10419 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0609 02:41:23.962916   10419 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0609 02:41:23.962945   10419 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0609 02:41:23.963435   10419 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0609 02:41:23.964677   10419 machine_controller.go:494]  "msg"="Error creating a remote client while deleting Machine, won't retry" "error"="failed to create REST configuration for Cluster default/test-cluster: invalid configuration: no configuration has been provided" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node" 
•I0609 02:41:24.009338   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0609 02:41:24.009400   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.019107   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-fcd65-6657c7fddb-vgtm4\"" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.019340   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.027167   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-fcd65-6657c7fddb-p8hq8\"" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.106305   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0609 02:41:24.106352   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.114584   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-fcd65-6657c7fddb-978fw\"" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.114643   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.123139   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-fcd65-6657c7fddb-hd5qk\"" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
E0609 02:41:24.212113   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-5qj8r: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-5qj8r" "namespace"="default"
I0609 02:41:24.215597   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0609 02:41:24.215655   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.225120   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-fcd65-6657c7fddb-9m6n2\"" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" 
I0609 02:41:24.321991   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0609 02:41:24.322036   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" 
I0609 02:41:24.330552   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-fcd65-cdfc6fd6c-vrp2v\"" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" 
I0609 02:41:24.363995   10419 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-2lfl7" "machine"="test6-492fh" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"1409e057-1534-4920-a566-1d5b0642f473","apiVersion":"v1"}
E0609 02:41:24.381622   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-492fh\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-492fh" "namespace"="default"
E0609 02:41:24.543376   10419 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-fcd65-cdfc6fd6c-vrp2v-jd242 for machine md-test/md-fcd65-cdfc6fd6c-vrp2v: the cache is not started, can not read objects" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" 
I0609 02:41:24.565565   10419 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0609 02:41:24.565619   10419 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0609 02:41:24.569164   10419 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "machine"="md-fcd65-6657c7fddb-978fw"
I0609 02:41:24.680870   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0609 02:41:24.680926   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" 
I0609 02:41:24.691086   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-fcd65-cdfc6fd6c-j565t\"" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" 
... skipping 5 lines ...
I0609 02:41:24.946410   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-fcd65-cdfc6fd6c-jg8xx\"" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" 
I0609 02:41:25.082223   10419 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0609 02:41:25.082314   10419 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0609 02:41:25.087569   10419 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-fcd65-6657c7fddb" "namespace"="md-test" "machine"="md-fcd65-6657c7fddb-9m6n2"
I0609 02:41:25.212558   10419 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-2lfl7" "namespace"="default" "count"=1
I0609 02:41:25.212619   10419 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-2lfl7" "namespace"="default" "descendants"="Control plane machines: test6-492fh" "indirect descendants count"=0
E0609 02:41:25.216516   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-qqkch: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-qqkch" "namespace"="default"
I0609 02:41:25.289010   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0609 02:41:25.289059   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" 
I0609 02:41:25.297386   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-fcd65-74d45c49c5-hgp46\"" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" 
E0609 02:41:25.382041   10419 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-ccrdn-2v6f7\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-ccrdn-2v6f7" "namespace"="ms-test"
I0609 02:41:25.426413   10419 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0609 02:41:25.426461   10419 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0609 02:41:25.433473   10419 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" "machine"="md-fcd65-cdfc6fd6c-vrp2v"
I0609 02:41:25.545270   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0609 02:41:25.545327   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" 
I0609 02:41:25.555371   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-fcd65-74d45c49c5-njpb6\"" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" 
... skipping 3 lines ...
I0609 02:41:25.780467   10419 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0609 02:41:25.780507   10419 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" 
I0609 02:41:25.788334   10419 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-fcd65-74d45c49c5-n85nb\"" "machineset"="md-fcd65-74d45c49c5" "namespace"="md-test" 
I0609 02:41:25.920593   10419 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0609 02:41:25.920656   10419 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0609 02:41:25.928466   10419 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-fcd65-cdfc6fd6c" "namespace"="md-test" "machine"="md-fcd65-cdfc6fd6c-jg8xx"
E0609 02:41:26.004877   10419 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="md-test/test-cluster"
•

Ran 16 of 16 Specs in 16.247 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.25s)
PASS
Tearing down test suite
I0609 02:41:26.007828   10419 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0609 02:41:26.007880   10419 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0609 02:41:26.007903   10419 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0609 02:41:26.007925   10419 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0609 02:41:26.007954   10419 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0609 02:41:26.007981   10419 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0609 02:41:26.008077   10419 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0609 02:41:26.008101   10419 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 02:41:26.008162   10419 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-649125418/tls.crt: no such file or directory"  
E0609 02:41:26.041657   10419 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1.Node: Get http://127.0.0.1:40213/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1226&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:40213: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	71.500s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0609 02:40:29.103127   10995 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0609 02:40:29.118130   10995 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0609 02:40:29.418480   10995 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0609 02:40:29.418538   10995 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0609 02:40:29.418607   10995 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0609 02:40:29.941617   10995 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0609 02:40:31.966392   10995 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-92bv4/test-cluster"
•E0609 02:40:32.433869   10995 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-h9qlf/test-cluster"
•E0609 02:40:32.976124   10995 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:41829/?timeout=50ms: dial tcp 127.0.0.1:41829: connect: connection refused"  "cluster"="cluster-cache-test-ls9z9/test-cluster"
•E0609 02:40:33.187522   10995 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 02:40:33.187580   10995 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-827850923/tls.crt: no such file or directory"  
I0609 02:40:33.187598   10995 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0609 02:40:33.282071   10995 reflector.go:309] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Failed to watch *v1alpha3.Cluster: Get http://127.0.0.1:33557/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:33557: connect: connection refused


Ran 5 of 5 Specs in 16.110 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.11s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	16.249s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 208 lines ...
=== RUN   TestReconcileNoClusterOwnerRef
I0609 02:40:40.404455   11569 controller.go:130]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0609 02:40:40.405685   11569 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoCluster (0.00s)
=== RUN   TestReconcilePaused
I0609 02:40:40.406276   11569 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0609 02:40:40.406423   11569 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0609 02:40:55.499313   11569 scale.go:173]  "msg"="Waiting for machines to be deleted" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "Machines"=""
=== RUN   TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue
I0609 02:40:55.499509   11569 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "failures"="machine  reports APIServerPodHealthy condition is false (Error, )"
=== RUN   TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass
--- PASS: TestPreflightChecks (0.00s)
    --- PASS: TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass (0.00s)
... skipping 18 lines ...
=== RUN   TestAPIs
Running Suite: Controller Suite
===============================
Random Seed: 1654742427
Will run 1 of 1 specs

E0609 02:40:55.521435   11569 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-h6dt75\" not found" "kubeadmControlPlane"="kcp-foo-h6dt75" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.018 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0609 02:40:55.523117   11569 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-ila6lc" "kubeadmControlPlane"="kcp-foo-ila6lc" "namespace"="test" 
I0609 02:40:56.535447   11569 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-ila6lc" "kubeadmControlPlane"="kcp-foo-ila6lc" "namespace"="test" "needRollout"=["kcp-foo-ila6lc-2lszl"]
I0609 02:40:56.535605   11569 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-ila6lc" "kubeadmControlPlane"="kcp-foo-ila6lc" "namespace"="test" "failures"="[machine kcp-foo-ila6lc-mk98t does not have APIServerPodHealthy condition, machine kcp-foo-ila6lc-mk98t does not have ControllerManagerPodHealthy condition, machine kcp-foo-ila6lc-mk98t does not have SchedulerPodHealthy condition, machine kcp-foo-ila6lc-mk98t does not have EtcdPodHealthy condition, machine kcp-foo-ila6lc-mk98t does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.01s)
... skipping 60 lines ...
==================================
Random Seed: 1654742426
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1654742426
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0609 02:40:40.563165   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:40:48.886253   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:40:57.872236   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:41:09.002481   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:41:25.475648   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:41:38.484265   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:41:56.131711   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:42:17.055112   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:42:48.071641   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0609 02:43:33.228907   11524 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 84 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
I0609 02:43:33.238738   11524 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0609 02:43:33.238931   11524 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0609 02:43:33.239007   11524 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-006283906/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	187.313s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
PASS
... skipping 287 lines ...
I0609 02:40:48.131418   11870 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0609 02:40:48.131541   11870 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0609 02:40:48.231974   11870 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0609 02:40:48.332378   11870 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0609 02:40:48.332447   11870 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0609 02:40:48.410349   11870 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-lyofge"} 
E0609 02:40:48.435377   11870 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•I0609 02:40:49.488961   11870 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-3mb8ws"} 
E0609 02:40:49.532248   11870 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0609 02:40:50.609757   11870 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0609 02:40:51.638035   11870 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0609 02:40:52.756391   11870 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0609 02:40:53.782433   11870 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset2\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset2" "namespace"="default"
E0609 02:40:54.796805   11870 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0609 02:40:54.804626   11870 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 02:40:54.804678   11870 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-676070691/tls.crt: no such file or directory"  
I0609 02:40:54.804832   11870 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0609 02:40:54.804859   11870 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0609 02:40:54.804372   11870 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 


Ran 5 of 5 Specs in 20.060 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.06s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	20.144s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0609 02:40:41.175988   12094 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 96 lines ...
•I0609 02:40:51.726335   12094 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0609 02:40:51.728830   12094 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0609 02:40:51.770670   12094 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


Ran 9 of 9 Specs in 10.516 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (10.52s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	10.756s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 210 lines ...
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39
  Should patch a clusterv1.Cluster
  /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:411
    updating both spec, status, and adding a condition [It]
    /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:550

    Expected success, but got an error:
        <errors.aggregate | len:1, cap:1>: [
            {
                ErrStatus: {
                    TypeMeta: {Kind: "", APIVersion: ""},
                    ListMeta: {
                        SelfLink: "",
... skipping 23 lines ...
STEP: Creating the object
STEP: Creating a new patch helper
STEP: Updating the object spec
STEP: Updating the object status
STEP: Setting Ready condition
STEP: Patching the object
•E0609 02:41:15.148968   15049 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0609 02:41:15.149020   15049 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-411823168/tls.crt: no such file or directory"  
I0609 02:41:15.148969   15049 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



Summarizing 1 Failure:

[Fail] Patch Helper Should patch a clusterv1.Cluster [It] updating both spec, status, and adding a condition 
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:580

Ran 14 of 14 Specs in 7.225 seconds
FAIL! -- 13 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestPatch (7.23s)
=== RUN   TestToUnstructured
=== RUN   TestToUnstructured/with_a_typed_object
=== RUN   TestToUnstructured/with_an_unstructured_object
--- PASS: TestToUnstructured (0.00s)
    --- PASS: TestToUnstructured/with_a_typed_object (0.00s)
    --- PASS: TestToUnstructured/with_an_unstructured_object (0.00s)
... skipping 2 lines ...
=== RUN   TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields
=== RUN   TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields
--- PASS: TestUnsafeFocusedUnstructured (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=spec,_should_only_return_spec_and_common_fields (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields (0.00s)
FAIL
FAIL	sigs.k8s.io/cluster-api/util/patch	7.282s
?   	sigs.k8s.io/cluster-api/util/predicates	[no test files]
?   	sigs.k8s.io/cluster-api/util/record	[no test files]
=== RUN   TestSortForCreate
--- PASS: TestSortForCreate (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/resource	0.008s
... skipping 88 lines ...
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#01 (0.00s)
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#02 (0.00s)
=== RUN   TestFromUnstructured
--- PASS: TestFromUnstructured (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/yaml	0.040s
FAIL
make: *** [Makefile:116: test] Error 1