This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-08-09 15:03
Elapsed4m28s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I0809 15:05:12.309168    8418 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0809 15:05:12.309705    8418 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0809 15:05:12.310668    8418 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0809 15:05:12.311059    8418 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=34767
I0809 15:05:12.311152    8418 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0809 15:05:13.087048    8418 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" 
•E0809 15:05:13.097815    8418 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0809 15:05:13.097873    8418 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-028140448/tls.crt: no such file or directory"  
E0809 15:05:13.097893    8418 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0809 15:05:13.097912    8418 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-028140448/tls.crt: no such file or directory"  
I0809 15:05:13.098042    8418 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.209 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.21s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	46.392s
=== 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.00s)
    --- 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 1399 lines ...
I0809 15:04:59.342223   10445 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0809 15:04:59.342263   10445 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0809 15:04:59.343034   10445 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0809 15:04:59.343890   10445 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1
I0809 15:04:59.345233   10445 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
=== RUN   TestClusterReconcilePhases
2022/08/09 15:04:59 http: TLS handshake error from 127.0.0.1:36290: EOF
=== 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
I0809 15:04:59.639906   10445 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"
I0809 15:04:59.642083   10445 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"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion
... skipping 104 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.01s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0809 15:04:59.669818   10445 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
I0809 15:04:59.672483   10445 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"
E0809 15:04:59.673032   10445 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
I0809 15:04:59.673570   10445 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
I0809 15:04:59.890456   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0809 15:04:59.893936   10445 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0809 15:04:59.899718   10445 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-642bx" "namespace"="test-machine-watches-4rmtm" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0809 15:04:59.899822   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0809 15:05:00.013074   10445 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-642bx" "namespace"="test-machine-watches-4rmtm" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0809 15:05:00.013194   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0809 15:05:00.113718   10445 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-642bx" "namespace"="test-machine-watches-4rmtm" "noderef"="node-1"
E0809 15:05:00.120986   10445 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0809 15:05:00.121047   10445 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0809 15:05:00.179137   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-642bx\" in namespace \"test-machine-watches-4rmtm\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-642bx" "namespace"="test-machine-watches-4rmtm"
E0809 15:05:01.183810   10445 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-642bx\" in namespace \"test-machine-watches-4rmtm\", requeuing: requeue in 1s"  
E0809 15:05:01.192327   10445 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-642bx\" in namespace \"test-machine-watches-4rmtm\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-642bx\" in namespace \"test-machine-watches-4rmtm\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-642bx" "namespace"="test-machine-watches-4rmtm"
--- PASS: TestWatches (1.54s)
=== 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
I0809 15:05:01.412097   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-cw45f" "namespace"="test-machine-watches-4rmtm" "count"=1
I0809 15:05:01.412177   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-cw45f" "namespace"="test-machine-watches-4rmtm" "descendants"="Worker machines: machine-created-642bx" "indirect descendants count"=0
I0809 15:05:01.441289   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-cw45f" "namespace"="test-machine-watches-4rmtm" "count"=1
I0809 15:05:01.441358   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-cw45f" "namespace"="test-machine-watches-4rmtm" "descendants"="Worker machines: machine-created-642bx" "indirect descendants count"=0
I0809 15:05:02.192796   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cw45f" "machine"="machine-created-642bx" "namespace"="test-machine-watches-4rmtm" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"602c72f1-2345-42a7-af56-1a3624509065","apiVersion":"v1"}
E0809 15:05:02.287213   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-642bx\" not found" "controller"="machine" "name"="machine-created-642bx" "namespace"="test-machine-watches-4rmtm"
E0809 15:05:03.342674   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-wng6f\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-8kk55\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-8kk55: secrets \"machine-reconcile-8kk55-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-wng6f" "namespace"="default"
I0809 15:05:04.343388   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-8kk55" "machine"="machine-created-wng6f" "namespace"="default" "cause"="noderef is nil" "node"=null
I0809 15:05:04.382065   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-8kk55" "machine"="machine-created-wng6f" "namespace"="default" "cause"="noderef is nil" "node"=null
I0809 15:05:04.411454   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-8kk55" "machine"="machine-created-wng6f" "namespace"="default" "cause"="noderef is nil" "node"=null
E0809 15:05:04.451081   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-wng6f\" not found" "controller"="machine" "name"="machine-created-wng6f" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.24s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.24s)
=== 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 5 lines ...
I0809 15:05:04.463347   10445 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0809 15:05:04.467417   10445 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"
I0809 15:05:04.468247   10445 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
I0809 15:05:04.472109   10445 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"
E0809 15:05:04.484349   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-8kk55\" not found" "controller"="cluster" "name"="machine-reconcile-8kk55" "namespace"="default"
I0809 15:05:04.493414   10445 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.03s)
    --- 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.03s)
=== RUN   TestReconcileRequest
... skipping 119 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
    --- 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
I0809 15:05:04.752861   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8skr4" "namespace"="test-mhc-69cbw" 
I0809 15:05:04.780047   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0809 15:05:04.780158   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-bbpjh\" not found"  "cluster"="test-mhc-69cbw/test-cluster-bbpjh"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
E0809 15:05:04.885346   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-8skr4\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-8skr4\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-8skr4" "namespace"="test-mhc-69cbw"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0809 15:05:05.885730   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lskbd" "namespace"="test-mhc-8tbzd" 
I0809 15:05:05.885855   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8skr4" "namespace"="test-mhc-69cbw" 
I0809 15:05:05.885900   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vj5k5" "namespace"="test-mhc-287vv" 
I0809 15:05:05.885935   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-v2m7n" "namespace"="test-mhc-k44kc" 
I0809 15:05:05.904416   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0809 15:05:06.039957   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-v2m7n" "namespace"="test-mhc-k44kc" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0809 15:05:06.124526   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-v2m7n" "namespace"="test-mhc-k44kc" 
E0809 15:05:06.145727   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-k44kc/test-cluster-dhvbb"
I0809 15:05:06.147660   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l8p22" "namespace"="test-mhc-hndpg" 
E0809 15:05:06.148509   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-dhvbb\" not found" "controller"="cluster" "name"="test-cluster-dhvbb" "namespace"="test-mhc-k44kc"
I0809 15:05:06.164402   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0809 15:05:06.283527   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l8p22" "namespace"="test-mhc-hndpg" 
E0809 15:05:06.363226   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hndpg/test-cluster-zv2bc"
I0809 15:05:06.372018   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l8p22" "namespace"="test-mhc-hndpg" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0809 15:05:06.396803   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
inframachine created: test-mhc-machine-infra-vm5n8
machine created: test-mhc-machine-h7djk
I0809 15:05:06.427827   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0809 15:05:06.448906   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
I0809 15:05:06.449221   10445 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-9p5wv/test-mhc-mjbgh/test-mhc-machine-h7djk/"
E0809 15:05:06.516288   10445 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-45sx9"
node created: test-mhc-node-45sx9
E0809 15:05:06.516635   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-45sx9, got []"  "node"="test-mhc-node-45sx9"
inframachine created: test-mhc-machine-infra-7pzxl
machine created: test-mhc-machine-qhq72
I0809 15:05:06.661808   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
I0809 15:05:06.662299   10445 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-9p5wv/test-mhc-mjbgh/test-mhc-machine-qhq72/"
node created: test-mhc-node-r29lh
E0809 15:05:06.667047   10445 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-r29lh"
E0809 15:05:06.667299   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r29lh, got []"  "node"="test-mhc-node-r29lh"
I0809 15:05:06.698875   10445 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv" "noderef"="test-mhc-node-r29lh"
I0809 15:05:06.721415   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
I0809 15:05:06.878066   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
Cleaning up nodes, machines and infra machines.
I0809 15:05:06.879648   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
I0809 15:05:06.882566   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
I0809 15:05:06.883106   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-9p5wv/test-mhc-mjbgh/test-mhc-machine-h7djk/"
I0809 15:05:06.915164   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
I0809 15:05:06.915747   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-9p5wv/test-mhc-mjbgh/test-mhc-machine-h7djk/"
I0809 15:05:06.916243   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-9p5wv/test-mhc-mjbgh/test-mhc-machine-qhq72/"
E0809 15:05:06.924968   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
E0809 15:05:06.945508   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9p5wv/test-cluster-lpsmp"
I0809 15:05:06.949122   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
E0809 15:05:06.949347   10445 machinehealthcheck_controller.go:128] controllers/MachineHealthCheck "msg"="Failed to fetch Cluster for MachineHealthCheck" "error"="Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "cluster"="test-cluster-lpsmp" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
E0809 15:05:06.949437   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machinehealthcheck" "name"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-xcjx9
machine created: test-mhc-machine-28dpk
E0809 15:05:07.163975   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-4rmtm/machine-reconcile-cw45f"
E0809 15:05:07.925356   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:07.949798   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mjbgh" "namespace"="test-mhc-9p5wv" 
I0809 15:05:07.949962   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:07.968898   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0809 15:05:08.035320   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.036847   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.038662   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
... skipping 390 lines ...
I0809 15:05:08.914942   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.916886   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.920222   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.921967   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.923744   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.925598   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
E0809 15:05:08.926068   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:08.927395   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.929115   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.930847   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.932566   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.934245   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:08.936039   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
... skipping 434 lines ...
I0809 15:05:09.926650   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:09.931075   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:09.935217   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:09.935827   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:09.936947   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:09.938795   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
E0809 15:05:09.939059   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:09.939129   10445 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-wflkh/test-mhc-xk8mp/test-mhc-machine-28dpk/"
I0809 15:05:09.951971   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:09.952889   10445 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-wflkh/test-mhc-xk8mp/test-mhc-machine-28dpk/"
node created: test-mhc-node-j4jr4
E0809 15:05:09.959146   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-j4jr4, got []"  "node"="test-mhc-node-j4jr4"
inframachine created: test-mhc-machine-infra-z6dvs
I0809 15:05:09.977871   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
machine created: test-mhc-machine-24mpz
I0809 15:05:10.000003   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.006468   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.007604   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
... skipping 279 lines ...
I0809 15:05:10.919453   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.921553   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.923620   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.933365   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.935873   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.938471   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
E0809 15:05:10.939406   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:10.940671   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.943444   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.945517   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.947935   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.949942   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:10.952149   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
... skipping 386 lines ...
I0809 15:05:11.972915   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.974017   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.976266   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.980626   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.984754   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.990973   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
E0809 15:05:11.992159   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:11.993529   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.995096   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.996807   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.998433   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:11.999926   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:12.001331   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
... skipping 352 lines ...
I0809 15:05:12.999310   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.004996   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.006166   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.007262   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.008236   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.009456   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.009927   10445 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-wflkh/test-mhc-xk8mp/test-mhc-machine-24mpz/"
E0809 15:05:13.012843   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
node created: test-mhc-node-7p9mq
I0809 15:05:13.022034   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.022480   10445 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-wflkh/test-mhc-xk8mp/test-mhc-machine-24mpz/"
E0809 15:05:13.028667   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7p9mq, got []"  "node"="test-mhc-node-7p9mq"
I0809 15:05:13.034714   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
inframachine created: test-mhc-machine-infra-4mkdw
machine created: test-mhc-machine-55tn9
I0809 15:05:13.069899   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.077603   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:13.079205   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
... skipping 249 lines ...
I0809 15:05:14.020625   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.023382   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.026179   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.028859   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.031406   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.032784   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
E0809 15:05:14.034891   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:14.035148   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.037533   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.040137   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.042645   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.045083   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:14.047431   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
... skipping 303 lines ...
I0809 15:05:15.061340   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.066918   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.070969   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.072948   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.074487   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.076514   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
E0809 15:05:15.076901   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:15.078124   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.080383   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.083246   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.085622   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.093307   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:15.095231   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
... skipping 256 lines ...
I0809 15:05:16.077283   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.081690   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.088722   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.091555   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.094152   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.096900   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.097327   10445 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-wflkh/test-mhc-xk8mp/test-mhc-machine-55tn9/"
E0809 15:05:16.104463   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:16.109095   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.109598   10445 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-wflkh/test-mhc-xk8mp/test-mhc-machine-55tn9/"
E0809 15:05:16.179146   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hdjvt, got []"  "node"="test-mhc-node-hdjvt"
node created: test-mhc-node-hdjvt
I0809 15:05:16.189257   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.189858   10445 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-wflkh/test-mhc-xk8mp/test-mhc-machine-55tn9/test-mhc-node-hdjvt"
Cleaning up nodes, machines and infra machines.
I0809 15:05:16.213132   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.213844   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-wflkh/test-mhc-xk8mp/test-mhc-machine-55tn9/"
Cleaning up nodes, machines and infra machines.
I0809 15:05:16.232508   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.233255   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-wflkh/test-mhc-xk8mp/test-mhc-machine-55tn9/"
I0809 15:05:16.236706   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.237285   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-wflkh/test-mhc-xk8mp/test-mhc-machine-28dpk/"
I0809 15:05:16.267651   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-wflkh/test-mhc-xk8mp/test-mhc-machine-55tn9/"
I0809 15:05:16.273485   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:16.274114   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-wflkh/test-mhc-xk8mp/test-mhc-machine-28dpk/"
I0809 15:05:16.274563   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-wflkh/test-mhc-xk8mp/test-mhc-machine-24mpz/"
I0809 15:05:16.283758   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-ktncg" "namespace"="test-mhc-wflkh" "count"=2
I0809 15:05:16.283850   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ktncg" "namespace"="test-mhc-wflkh" "descendants"="Worker machines: test-mhc-machine-28dpk,test-mhc-machine-24mpz,test-mhc-machine-55tn9" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0809 15:05:16.292281   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-ktncg" "namespace"="test-mhc-wflkh" "count"=2
I0809 15:05:16.292354   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ktncg" "namespace"="test-mhc-wflkh" "descendants"="Worker machines: test-mhc-machine-28dpk,test-mhc-machine-24mpz,test-mhc-machine-55tn9" "indirect descendants count"=1
I0809 15:05:16.294195   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-wflkh/test-mhc-xk8mp/test-mhc-machine-55tn9/"
E0809 15:05:16.296738   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-xk8mp\" not found" "controller"="machinehealthcheck" "name"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh"
inframachine created: test-mhc-machine-infra-6z2jf
machine created: test-mhc-machine-f6mnq
I0809 15:05:17.107041   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ktncg" "machine"="test-mhc-machine-24mpz" "namespace"="test-mhc-wflkh" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-7p9mq"}
E0809 15:05:17.164504   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-24mpz\" not found" "controller"="machine" "name"="test-mhc-machine-24mpz" "namespace"="test-mhc-wflkh"
I0809 15:05:17.297258   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xk8mp" "namespace"="test-mhc-wflkh" 
I0809 15:05:17.297406   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:17.342571   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0809 15:05:17.469626   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:17.474870   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:17.495915   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:17.537443   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:17.618528   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:17.779632   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:18.100717   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:18.164942   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:18.743540   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:19.165482   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ktncg" "machine"="test-mhc-machine-55tn9" "namespace"="test-mhc-wflkh" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-hdjvt"}
E0809 15:05:19.221919   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-55tn9\" not found" "controller"="machine" "name"="test-mhc-machine-55tn9" "namespace"="test-mhc-wflkh"
I0809 15:05:20.024574   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:20.222310   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:21.222921   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ktncg" "machine"="test-mhc-machine-28dpk" "namespace"="test-mhc-wflkh" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-j4jr4"}
I0809 15:05:21.292653   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-ktncg" "namespace"="test-mhc-wflkh" "count"=1
I0809 15:05:21.292758   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ktncg" "namespace"="test-mhc-wflkh" "descendants"="Worker machines: test-mhc-machine-28dpk" "indirect descendants count"=0
E0809 15:05:21.309502   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-28dpk\" not found" "controller"="machine" "name"="test-mhc-machine-28dpk" "namespace"="test-mhc-wflkh"
I0809 15:05:22.319917   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:22.325881   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:22.335466   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:22.353547   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
node created: test-mhc-node-fszwn
E0809 15:05:22.380562   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fszwn, got []"  "node"="test-mhc-node-fszwn"
E0809 15:05:22.380791   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fszwn, got []"  "node"="test-mhc-node-fszwn"
I0809 15:05:22.388255   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
inframachine created: test-mhc-machine-infra-2klhs
machine created: test-mhc-machine-f7wvb
I0809 15:05:22.414616   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:22.594873   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:22.595638   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:22.600088   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:22.641323   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:22.722732   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:22.885755   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:23.207259   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:23.335930   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:23.848844   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.351691   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.356144   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.379007   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.402141   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.418021   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.425330   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:24.431635   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:24.431973   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.452469   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:24.528565   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v2fkg, got []"  "node"="test-mhc-node-v2fkg"
node created: test-mhc-node-v2fkg
E0809 15:05:24.529294   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v2fkg, got []"  "node"="test-mhc-node-v2fkg"
I0809 15:05:24.541053   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
inframachine created: test-mhc-machine-infra-gtwkj
I0809 15:05:24.556722   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
machine created: test-mhc-machine-5czbj
I0809 15:05:24.561799   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.571939   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:24.578826   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:25.130257   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:25.432069   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
E0809 15:05:26.312431   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wflkh/test-cluster-ktncg"
I0809 15:05:26.455858   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:26.478145   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:26.488440   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:26.511725   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:26.527628   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:26.538755   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:26.548108   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:26.550429   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:26.576782   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
E0809 15:05:26.581797   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9cnr2, got []"  "node"="test-mhc-node-9cnr2"
node created: test-mhc-node-9cnr2
I0809 15:05:26.589057   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
Cleaning up nodes, machines and infra machines.
I0809 15:05:26.601081   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:26.621926   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
Cleaning up nodes, machines and infra machines.
... skipping 5 lines ...
inframachine created: test-mhc-machine-infra-7247g
machine created: test-mhc-machine-xmgcj
I0809 15:05:26.836549   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:26.867433   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0809 15:05:26.897367   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lpd9c" "namespace"="test-mhc-zf6l7" 
I0809 15:05:26.897466   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
E0809 15:05:27.550981   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:28.551538   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lvh8n" "machine"="test-mhc-machine-f6mnq" "namespace"="test-mhc-zf6l7" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-fszwn"}
E0809 15:05:28.602960   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f6mnq\" not found" "controller"="machine" "name"="test-mhc-machine-f6mnq" "namespace"="test-mhc-zf6l7"
I0809 15:05:29.603611   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lvh8n" "machine"="test-mhc-machine-f7wvb" "namespace"="test-mhc-zf6l7" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-v2fkg"}
E0809 15:05:29.653349   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f7wvb\" not found" "controller"="machine" "name"="test-mhc-machine-f7wvb" "namespace"="test-mhc-zf6l7"
I0809 15:05:30.653872   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lvh8n" "machine"="test-mhc-machine-5czbj" "namespace"="test-mhc-zf6l7" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9cnr2"}
E0809 15:05:30.709009   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5czbj\" not found" "controller"="machine" "name"="test-mhc-machine-5czbj" "namespace"="test-mhc-zf6l7"
E0809 15:05:31.687214   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zf6l7/test-cluster-lvh8n"
I0809 15:05:31.719285   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:31.728800   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
E0809 15:05:31.729942   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
E0809 15:05:31.759798   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2pjff, got []"  "node"="test-mhc-node-2pjff"
node created: test-mhc-node-2pjff
I0809 15:05:31.768213   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
inframachine created: test-mhc-machine-infra-pp5d4
I0809 15:05:31.784215   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:31.787473   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
machine created: test-mhc-machine-vwmgd
I0809 15:05:31.794493   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
E0809 15:05:32.730401   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:33.756218   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.766405   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.777090   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.785140   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.797416   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.827264   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.846190   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.868895   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.891272   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.898021   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
E0809 15:05:33.908187   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-295nr, got []"  "node"="test-mhc-node-295nr"
node created: test-mhc-node-295nr
I0809 15:05:33.911693   10445 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-vwmgd" "namespace"="test-mhc-bfcrm" "noderef"="test-mhc-node-295nr"
E0809 15:05:33.916414   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-295nr, got []"  "node"="test-mhc-node-295nr"
E0809 15:05:33.916468   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-295nr, got []"  "node"="test-mhc-node-295nr"
I0809 15:05:33.921554   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
inframachine created: test-mhc-machine-infra-pq7qz
I0809 15:05:33.941674   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:33.945194   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
machine created: test-mhc-machine-lm2fw
I0809 15:05:33.963004   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
... skipping 2 lines ...
I0809 15:05:34.128893   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:34.134790   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
Cleaning up nodes, machines and infra machines.
I0809 15:05:34.156323   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
Cleaning up nodes, machines and infra machines.
I0809 15:05:34.175506   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:34.176189   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bfcrm/test-mhc-wdvp2/test-mhc-machine-xmgcj/"
I0809 15:05:34.211216   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:34.211875   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bfcrm/test-mhc-wdvp2/test-mhc-machine-xmgcj/"
I0809 15:05:34.212346   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bfcrm/test-mhc-wdvp2/test-mhc-machine-vwmgd/"
I0809 15:05:34.249905   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-8f9wf" "namespace"="test-mhc-bfcrm" "count"=2
I0809 15:05:34.250019   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-8f9wf" "namespace"="test-mhc-bfcrm" "descendants"="Worker machines: test-mhc-machine-vwmgd,test-mhc-machine-lm2fw,test-mhc-machine-xmgcj" "indirect descendants count"=1
I0809 15:05:34.255682   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-8f9wf" "namespace"="test-mhc-bfcrm" "count"=2
I0809 15:05:34.255847   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-8f9wf" "namespace"="test-mhc-bfcrm" "descendants"="Worker machines: test-mhc-machine-xmgcj,test-mhc-machine-vwmgd,test-mhc-machine-lm2fw" "indirect descendants count"=1
I0809 15:05:34.261663   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
I0809 15:05:34.262567   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bfcrm/test-mhc-wdvp2/test-mhc-machine-xmgcj/"
I0809 15:05:34.263087   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-bfcrm/test-mhc-wdvp2/test-mhc-machine-vwmgd/"
=== 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
I0809 15:05:34.269921   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdvp2" "namespace"="test-mhc-bfcrm" 
2022/08/09 15:05:34 http: TLS handshake error from 127.0.0.1:41852: EOF
I0809 15:05:34.331087   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
inframachine created: test-mhc-machine-infra-mwdp6
I0809 15:05:34.338118   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8f9wf" "machine"="test-mhc-machine-xmgcj" "namespace"="test-mhc-bfcrm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2pjff"}
I0809 15:05:34.352103   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-277x7
E0809 15:05:34.412816   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xmgcj\" not found" "controller"="machine" "name"="test-mhc-machine-xmgcj" "namespace"="test-mhc-bfcrm"
I0809 15:05:34.481110   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:34.482245   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:34.483581   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:34.484734   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:34.487388   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:34.489418   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
... skipping 392 lines ...
I0809 15:05:35.478351   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.481280   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.483454   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.485311   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.488564   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.490661   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
E0809 15:05:35.492486   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vwmgd\" not found" "controller"="machine" "name"="test-mhc-machine-vwmgd" "namespace"="test-mhc-bfcrm"
I0809 15:05:35.492684   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.494564   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.497941   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.500675   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.502552   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:35.504444   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
... skipping 459 lines ...
I0809 15:05:36.482393   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.484355   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.486231   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.488064   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.489958   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.491730   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
E0809 15:05:36.492984   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:36.493460   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.495281   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.497042   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.504892   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.506853   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:36.508832   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
... skipping 439 lines ...
I0809 15:05:37.534152   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.535989   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.537849   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.539646   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.541700   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.543643   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
E0809 15:05:37.555289   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lm2fw\" not found" "controller"="machine" "name"="test-mhc-machine-lm2fw" "namespace"="test-mhc-bfcrm"
I0809 15:05:37.559198   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.561228   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.563136   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.565057   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.566754   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:37.568923   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
... skipping 427 lines ...
I0809 15:05:38.563185   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.565100   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.567392   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.568425   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.569137   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.571445   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
E0809 15:05:38.573256   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:38.573812   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.574220   10445 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-8zg5h/test-mhc-bsh28/test-mhc-machine-277x7/"
I0809 15:05:38.587774   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.588128   10445 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-8zg5h/test-mhc-bsh28/test-mhc-machine-277x7/"
node created: test-mhc-node-ngtbq
E0809 15:05:38.626459   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ngtbq, got []"  "node"="test-mhc-node-ngtbq"
E0809 15:05:38.626747   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ngtbq, got []"  "node"="test-mhc-node-ngtbq"
I0809 15:05:38.636351   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.655903   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.659911   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.661211   10445 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-8zg5h/test-mhc-bsh28/test-mhc-machine-277x7/test-mhc-node-ngtbq"
I0809 15:05:38.685306   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.685724   10445 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-8zg5h/test-mhc-bsh28/test-mhc-machine-277x7/test-mhc-node-ngtbq"
Cleaning up nodes, machines and infra machines.
I0809 15:05:38.697222   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.697620   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8zg5h/test-mhc-bsh28/test-mhc-machine-277x7/"
I0809 15:05:38.711997   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.712393   10445 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8zg5h/test-mhc-bsh28/test-mhc-machine-277x7/"
I0809 15:05:38.717791   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tnrxp" "namespace"="test-mhc-8zg5h" "descendants"="Worker machines: test-mhc-machine-277x7" "indirect descendants count"=1
I0809 15:05:38.732810   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tnrxp" "namespace"="test-mhc-8zg5h" "descendants"="Worker machines: test-mhc-machine-277x7" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0809 15:05:38.735835   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bsh28" "namespace"="test-mhc-8zg5h" 
I0809 15:05:38.855207   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" "creating"=1 "need"=1
I0809 15:05:38.855266   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" 
I0809 15:05:38.881545   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-52tcf-4x7wj\"" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" 
I0809 15:05:38.981407   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:39.012991   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0809 15:05:39.132554   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:39.133327   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
E0809 15:05:39.270320   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-bfcrm/test-cluster-8f9wf"
I0809 15:05:39.573879   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tnrxp" "machine"="test-mhc-machine-277x7" "namespace"="test-mhc-8zg5h" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ngtbq"}
E0809 15:05:39.648052   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-277x7\" not found" "controller"="machine" "name"="test-mhc-machine-277x7" "namespace"="test-mhc-8zg5h"
I0809 15:05:40.132763   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.667850   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.668177   10445 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.676078   10445 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.676278   10445 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.676883   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
... skipping 6 lines ...
I0809 15:05:40.730928   10445 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.743671   10445 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.743726   10445 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.755266   10445 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" 
I0809 15:05:40.755426   10445 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.133958   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.134413   10445 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-g6jk7/test-mhc-z56n6/mhc-ms-52tcf-4x7wj/"
I0809 15:05:41.143556   10445 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.149783   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.150165   10445 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-g6jk7/test-mhc-z56n6/mhc-ms-52tcf-4x7wj/"
I0809 15:05:41.155039   10445 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.155090   10445 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.165314   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.165323   10445 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.165638   10445 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-g6jk7/test-mhc-z56n6/mhc-ms-52tcf-4x7wj/"
I0809 15:05:41.182067   10445 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.182121   10445 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.253549   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-zw968" "namespace"="test-mhc-g6jk7" "count"=1
I0809 15:05:41.253611   10445 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-zw968" "namespace"="test-mhc-g6jk7" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-52tcf"
I0809 15:05:41.254593   10445 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-52tcf" "namespace"="test-mhc-g6jk7" "machine"="mhc-ms-52tcf-4x7wj"
I0809 15:05:41.261111   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.261488   10445 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-g6jk7/test-mhc-z56n6/mhc-ms-52tcf-4x7wj/"
I0809 15:05:41.263085   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-zw968" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" "cause"="cluster is being deleted" "node"=null
I0809 15:05:41.270097   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zw968" "namespace"="test-mhc-g6jk7" "descendants"="Machine sets: mhc-ms-52tcf;Worker machines: mhc-ms-52tcf-4x7wj" "indirect descendants count"=1
I0809 15:05:41.271214   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z56n6" "namespace"="test-mhc-g6jk7" 
I0809 15:05:41.275502   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zw968" "namespace"="test-mhc-g6jk7" "descendants"="Worker machines: mhc-ms-52tcf-4x7wj" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0809 15:05:41.353095   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
inframachine created: test-mhc-machine-infra-g4pxp
I0809 15:05:41.376709   10445 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-r46jf
I0809 15:05:41.492166   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-zw968" "machine"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7" "cause"="cluster is being deleted" "node"=null
I0809 15:05:41.499079   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
E0809 15:05:41.533162   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-52tcf-4x7wj\" not found" "controller"="machine" "name"="mhc-ms-52tcf-4x7wj" "namespace"="test-mhc-g6jk7"
I0809 15:05:41.561011   10445 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-r46jf" "target"="test-mhc-dzxbw/test-mhc-vtggv/test-mhc-machine-r46jf/"
I0809 15:05:41.579740   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
E0809 15:05:41.589931   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8sqln, got []"  "node"="test-mhc-node-8sqln"
E0809 15:05:41.590195   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8sqln, got []"  "node"="test-mhc-node-8sqln"
node created: test-mhc-node-8sqln
E0809 15:05:41.591004   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8sqln, got []"  "node"="test-mhc-node-8sqln"
I0809 15:05:41.599430   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
I0809 15:05:41.637300   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
I0809 15:05:41.640632   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
I0809 15:05:41.646232   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
I0809 15:05:41.654093   10445 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-r46jf" "target"="test-mhc-dzxbw/test-mhc-vtggv/test-mhc-machine-r46jf/test-mhc-node-8sqln"
I0809 15:05:41.675343   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
Cleaning up nodes, machines and infra machines.
I0809 15:05:41.696731   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
I0809 15:05:41.700039   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
I0809 15:05:41.705075   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtggv" "namespace"="test-mhc-dzxbw" 
I0809 15:05:41.727895   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hngmq" "namespace"="test-mhc-dzxbw" "descendants"="Worker machines: test-mhc-machine-r46jf" "indirect descendants count"=1
... skipping 313 lines ...
I0809 15:05:42.599299   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.601129   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.602919   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.604667   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.606434   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.608269   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
E0809 15:05:42.608377   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-r46jf\" not found" "controller"="machine" "name"="test-mhc-machine-r46jf" "namespace"="test-mhc-dzxbw"
I0809 15:05:42.609994   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.611733   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.613465   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.615257   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.616987   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:42.618849   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
... skipping 444 lines ...
I0809 15:05:43.598052   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.599756   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.601850   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.603775   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.605678   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.607426   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
E0809 15:05:43.608717   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
I0809 15:05:43.609138   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.610907   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.613098   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.614904   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.616695   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.618548   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
... skipping 60 lines ...
I0809 15:05:43.735801   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.737797   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.739489   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.741159   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.743037   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.744775   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
E0809 15:05:43.745291   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8zg5h/test-cluster-tnrxp"
I0809 15:05:43.746755   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.748470   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.750348   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.752187   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.753985   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:43.755819   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
... skipping 415 lines ...
I0809 15:05:44.613291   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.615083   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.616485   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.617231   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.618376   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.621721   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
E0809 15:05:44.622209   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
I0809 15:05:44.625940   10445 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-z7xkv" "target"="test-mhc-bn9vw/test-mhc-9fsxf/test-mhc-machine-z7xkv/"
I0809 15:05:44.642103   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
E0809 15:05:44.646016   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gqkgv, got []"  "node"="test-mhc-node-gqkgv"
E0809 15:05:44.646028   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gqkgv, got []"  "node"="test-mhc-node-gqkgv"
node created: test-mhc-node-gqkgv
E0809 15:05:44.646279   10445 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gqkgv, got []"  "node"="test-mhc-node-gqkgv"
I0809 15:05:44.653347   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.685086   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.699314   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.702508   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.712485   10445 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-z7xkv" "target"="test-mhc-bn9vw/test-mhc-9fsxf/test-mhc-machine-z7xkv/test-mhc-node-gqkgv"
I0809 15:05:44.730453   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.733589   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.754980   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
Cleaning up nodes, machines and infra machines.
I0809 15:05:44.776823   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.780827   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.785560   10445 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-z7xkv" "target"="test-mhc-bn9vw/test-mhc-9fsxf/test-mhc-machine-z7xkv/"
I0809 15:05:44.798103   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-smkb5" "namespace"="test-mhc-bn9vw" "descendants"="Worker machines: test-mhc-machine-z7xkv" "indirect descendants count"=1
I0809 15:05:44.802763   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-smkb5" "namespace"="test-mhc-bn9vw" "descendants"="Worker machines: test-mhc-machine-z7xkv" "indirect descendants count"=1
I0809 15:05:44.804240   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
I0809 15:05:44.808798   10445 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9fsxf" "namespace"="test-mhc-bn9vw" 
--- PASS: TestMachineHealthCheck_Reconcile (40.10s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.06s)
... skipping 14 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.46s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.07s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0809 15:05:44.817248   10445 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
E0809 15:05:44.819096   10445 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
--- 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
E0809 15:05:44.820986   10445 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0809 15:05:44.821232   10445 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
E0809 15:05:44.821648   10445 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
I0809 15:05:44.824616   10445 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0809 15:05:44.825222   10445 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0809 15:05:44.826979   10445 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
E0809 15:05:44.838428   10445 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
E0809 15:05:44.840456   10445 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 82 lines ...
I0809 15:05:44.863496   10445 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"
•I0809 15:05:44.864954   10445 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"
I0809 15:05:44.865605   10445 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"
I0809 15:05:44.866195   10445 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0809 15:05:44.866225   10445 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0809 15:05:44.867184   10445 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0809 15:05:44.868505   10445 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" 
••E0809 15:05:45.010348   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-mvbjq\" not found" "controller"="cluster" "name"="test1-mvbjq" "namespace"="default"
I0809 15:05:45.622779   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-smkb5" "machine"="test-mhc-machine-z7xkv" "namespace"="test-mhc-bn9vw" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-gqkgv"}
E0809 15:05:45.664867   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-z7xkv\" not found" "controller"="machine" "name"="test-mhc-machine-z7xkv" "namespace"="test-mhc-bn9vw"
•I0809 15:05:46.134945   10445 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-w42zx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0809 15:05:46.252669   10445 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-w42zx" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0809 15:05:46.257704   10445 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-w42zx" "namespace"="default"
E0809 15:05:47.273612   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-w42zx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-w42zx" "namespace"="default"
•E0809 15:05:48.286814   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-g6jk7/test-cluster-zw968"
E0809 15:05:48.298709   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-dzxbw/test-cluster-hngmq"
E0809 15:05:48.311604   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-bk5hg\" not found" "controller"="cluster" "name"="test3-bk5hg" "namespace"="default"
E0809 15:05:49.312327   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-w42zx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-w42zx" "namespace"="default"
E0809 15:05:50.323660   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-w42zx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-w42zx" "namespace"="default"
•E0809 15:05:51.335588   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-bn9vw/test-cluster-smkb5"
E0809 15:05:51.339123   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-7m7v6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-7m7v6" "namespace"="default"
E0809 15:05:52.339955   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-w42zx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-w42zx" "namespace"="default"
E0809 15:05:53.350855   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-7m7v6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-7m7v6" "namespace"="default"
•E0809 15:05:53.849121   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-h7djk\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-h7djk" "namespace"="test-mhc-9p5wv"
E0809 15:05:54.351821   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-w42zx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-w42zx" "namespace"="default"
E0809 15:05:54.862553   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-lpsmp\" for machine \"test-mhc-machine-qhq72\" in namespace \"test-mhc-9p5wv\": Cluster.cluster.x-k8s.io \"test-cluster-lpsmp\" not found" "controller"="machine" "name"="test-mhc-machine-qhq72" "namespace"="test-mhc-9p5wv"
E0809 15:05:55.352825   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-7m7v6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-7m7v6" "namespace"="default"
E0809 15:05:56.364780   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-w42zx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-w42zx" "namespace"="default"
I0809 15:05:56.447599   10445 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-hgz6z" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0809 15:05:56.458482   10445 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-hgz6z" "namespace"="default" 
E0809 15:05:56.473503   10445 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-hgz6z" "namespace"="default"
E0809 15:05:57.365561   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-7m7v6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-7m7v6" "namespace"="default"
I0809 15:05:57.488665   10445 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-hgz6z" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0809 15:05:57.488867   10445 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-hgz6z" "namespace"="default" "noderef"="id-node-1"
E0809 15:05:57.501692   10445 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-hgz6z" "namespace"="default"
E0809 15:05:58.370364   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-w42zx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-w42zx" "namespace"="default"

------------------------------
• [SLOW TEST:5.045 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
------------------------------
I0809 15:05:58.502457   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-zxn8m" "machine"="test6-hgz6z" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"7387e360-fc3f-4758-bc80-60fa1c06ee49","apiVersion":"v1"}
I0809 15:05:58.502948   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-l75g9" "namespace"="ms-test" "creating"=2 "need"=2
I0809 15:05:58.502992   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-l75g9" "namespace"="ms-test" 
I0809 15:05:58.519389   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-l75g9-cl497\"" "machineset"="ms-l75g9" "namespace"="ms-test" 
I0809 15:05:58.519458   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-l75g9" "namespace"="ms-test" 
E0809 15:05:58.521959   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-hgz6z\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-hgz6z" "namespace"="default"
I0809 15:05:58.539587   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-l75g9-fgb6t\"" "machineset"="ms-l75g9" "namespace"="ms-test" 
I0809 15:05:58.637600   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-l75g9" "namespace"="ms-test" "creating"=1 "need"=2
I0809 15:05:58.637647   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-l75g9" "namespace"="ms-test" 
I0809 15:05:58.651739   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-l75g9-cxfx4\"" "machineset"="ms-l75g9" "namespace"="ms-test" 
E0809 15:05:58.978714   10445 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-l75g9-cxfx4-7pt2w for machine ms-test/ms-l75g9-cxfx4: the cache is not started, can not read objects" "machineset"="ms-l75g9" "namespace"="ms-test" 
E0809 15:05:59.207285   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0809 15:05:59.261859   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0809 15:05:59.261898   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.272971   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-6dgq5-6657c7fddb-pklbf\"" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.273025   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.295262   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-6dgq5-6657c7fddb-k8xt9\"" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
E0809 15:05:59.371276   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-7m7v6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-7m7v6" "namespace"="default"
I0809 15:05:59.403140   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0809 15:05:59.403189   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.410839   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-6dgq5-6657c7fddb-bwtjl\"" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.410916   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.420714   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-6dgq5-6657c7fddb-g8b5n\"" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.473814   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0809 15:05:59.473936   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.481855   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6dgq5-6657c7fddb-fmbvb\"" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" 
I0809 15:05:59.522516   10445 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-zxn8m" "machine"="test6-hgz6z" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"7387e360-fc3f-4758-bc80-60fa1c06ee49","apiVersion":"v1"}
E0809 15:05:59.523183   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-hgz6z\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-hgz6z" "namespace"="default"
I0809 15:05:59.574610   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0809 15:05:59.574671   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" 
I0809 15:05:59.584543   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6dgq5-cdfc6fd6c-tv4sk\"" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" 
E0809 15:05:59.793023   10445 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-6dgq5-cdfc6fd6c-tv4sk-tsfg2 for machine md-test/md-6dgq5-cdfc6fd6c-tv4sk: the cache is not started, can not read objects" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" 
I0809 15:05:59.819555   10445 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0809 15:05:59.819591   10445 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0809 15:05:59.824814   10445 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "machine"="md-6dgq5-6657c7fddb-bwtjl"
I0809 15:05:59.933518   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0809 15:05:59.933641   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" 
I0809 15:05:59.942086   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6dgq5-cdfc6fd6c-ft27c\"" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" 
... skipping 5 lines ...
I0809 15:06:00.205853   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6dgq5-cdfc6fd6c-5vcc5\"" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" 
I0809 15:06:00.342877   10445 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0809 15:06:00.342923   10445 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0809 15:06:00.346141   10445 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6dgq5-6657c7fddb" "namespace"="md-test" "machine"="md-6dgq5-6657c7fddb-fmbvb"
I0809 15:06:00.371885   10445 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-zxn8m" "namespace"="default" "count"=1
I0809 15:06:00.371962   10445 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-zxn8m" "namespace"="default" "descendants"="Control plane machines: test6-hgz6z" "indirect descendants count"=0
E0809 15:06:00.375988   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-w42zx: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-w42zx" "namespace"="default"
E0809 15:06:00.523495   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-l75g9-fgb6t\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-l75g9-fgb6t" "namespace"="ms-test"
I0809 15:06:00.544386   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6dgq5-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0809 15:06:00.544427   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-6dgq5-74d45c49c5" "namespace"="md-test" 
I0809 15:06:00.556541   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6dgq5-74d45c49c5-sbvnv\"" "machineset"="md-6dgq5-74d45c49c5" "namespace"="md-test" 
I0809 15:06:00.679401   10445 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0809 15:06:00.679476   10445 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0809 15:06:00.684352   10445 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "machine"="md-6dgq5-cdfc6fd6c-5vcc5"
... skipping 5 lines ...
I0809 15:06:00.912751   10445 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "machine"="md-6dgq5-cdfc6fd6c-ft27c"
I0809 15:06:01.022584   10445 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6dgq5-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0809 15:06:01.022630   10445 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6dgq5-74d45c49c5" "namespace"="md-test" 
I0809 15:06:01.035337   10445 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6dgq5-74d45c49c5-p7bnn\"" "machineset"="md-6dgq5-74d45c49c5" "namespace"="md-test" 
I0809 15:06:01.258388   10445 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0809 15:06:01.258438   10445 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
E0809 15:06:01.262585   10445 machinedeployment_controller.go:149] controllers/MachineDeployment "msg"="Failed to reconcile MachineDeployment" "error"="MachineDeployment.cluster.x-k8s.io \"md-6dgq5\" not found" "machinedeployment"="md-6dgq5" "namespace"="md-test" 
E0809 15:06:01.263129   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="MachineDeployment.cluster.x-k8s.io \"md-6dgq5\" not found" "controller"="machinedeployment" "name"="md-6dgq5" "namespace"="md-test"
E0809 15:06:01.267865   10445 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="md-test/test-cluster"
I0809 15:06:01.269242   10445 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" "machine"="md-6dgq5-cdfc6fd6c-tv4sk"
•

Ran 16 of 16 Specs in 16.428 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.43s)
PASS
Tearing down test suite
I0809 15:06:01.271379   10445 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0809 15:06:01.271421   10445 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0809 15:06:01.271438   10445 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0809 15:06:01.271457   10445 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0809 15:06:01.271479   10445 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0809 15:06:01.271498   10445 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0809 15:06:01.271559   10445 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0809 15:06:01.273885   10445 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error creating client and cache for remote cluster: error creating dynamic rest mapper for remote cluster \"md-test/test-cluster\": Get http://127.0.0.1:38811/api?timeout=10s: dial tcp 127.0.0.1:38811: connect: connection refused" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" 
E0809 15:06:01.274518   10445 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: Patch http://127.0.0.1:38811/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machinesets/md-6dgq5-cdfc6fd6c/status: dial tcp 127.0.0.1:38811: connect: connection refused" "machineset"="md-6dgq5-cdfc6fd6c" "namespace"="md-test" 
E0809 15:06:01.274588   10445 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: Patch http://127.0.0.1:38811/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machinesets/md-6dgq5-cdfc6fd6c/status: dial tcp 127.0.0.1:38811: connect: connection refused" "controller"="machineset" "name"="md-6dgq5-cdfc6fd6c" "namespace"="md-test"
E0809 15:06:01.274898   10445 event.go:272] Unable to write event: 'Post http://127.0.0.1:38811/api/v1/namespaces/md-test/events: dial tcp 127.0.0.1:38811: connect: connection refused' (may retry after sleeping)
E0809 15:06:01.307768   10445 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:38811/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1196&timeout=10s&timeoutSeconds=522&watch=true: dial tcp 127.0.0.1:38811: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	74.216s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 256 lines ...
I0809 15:05:02.112983   10965 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0809 15:05:02.112998   10965 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0809 15:05:02.113598   10965 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0809 15:05:02.114696   10965 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0809 15:05:02.114952   10965 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=35595
I0809 15:05:02.115144   10965 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0809 15:05:04.312395   10965 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-7xtmn/test-cluster"
•E0809 15:05:04.757755   10965 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-hzdz7/test-cluster"
•E0809 15:05:05.367292   10965 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:39563/?timeout=50ms: dial tcp 127.0.0.1:39563: connect: connection refused"  "cluster"="cluster-cache-test-pj8rn/test-cluster"
•I0809 15:05:05.605547   10965 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0809 15:05:05.707685   10965 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0809 15:05:05.707742   10965 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0809 15:05:05.868319   10965 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0809 15:05:05.878460   10965 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":{}}}
I0809 15:05:06.178903   10965 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0809 15:05:06.178973   10965 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0809 15:05:06.179061   10965 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0809 15:05:06.704634   10965 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0809 15:05:06.704773   10965 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0809 15:05:06.774630   10965 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:36053/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:36053: connect: connection refused


Ran 5 of 5 Specs in 17.265 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (17.27s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	17.458s
?   	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
I0809 15:05:14.042457   11568 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
E0809 15:05:14.043699   11568 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
I0809 15:05:14.044272   11568 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0809 15:05:14.044432   11568 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
I0809 15:05:29.437252   11568 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
I0809 15:05:29.437428   11568 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: 1660057500
Will run 1 of 1 specs

E0809 15:05:29.462817   11568 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-xe605a\" not found" "kubeadmControlPlane"="kcp-foo-xe605a" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.022 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0809 15:05:29.464151   11568 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-gie2ys" "kubeadmControlPlane"="kcp-foo-gie2ys" "namespace"="test" 
I0809 15:05:30.935039   11568 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-gie2ys" "kubeadmControlPlane"="kcp-foo-gie2ys" "namespace"="test" "needRollout"=["kcp-foo-gie2ys-gqgbw"]
I0809 15:05:30.935197   11568 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-gie2ys" "kubeadmControlPlane"="kcp-foo-gie2ys" "namespace"="test" "failures"="[machine kcp-foo-gie2ys-v22x4 does not have APIServerPodHealthy condition, machine kcp-foo-gie2ys-v22x4 does not have ControllerManagerPodHealthy condition, machine kcp-foo-gie2ys-v22x4 does not have SchedulerPodHealthy condition, machine kcp-foo-gie2ys-v22x4 does not have EtcdPodHealthy condition, machine kcp-foo-gie2ys-v22x4 does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.47s)
... skipping 60 lines ...
==================================
Random Seed: 1660057498
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: 1660057498
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: 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
E0809 15:05:13.038856   11504 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"  
E0809 15:05:21.362014   11504 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"  
E0809 15:05:30.348044   11504 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"  
E0809 15:05:41.478352   11504 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"  
E0809 15:05:57.951478   11504 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"  
E0809 15:06:10.960201   11504 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"  
E0809 15:06:28.607596   11504 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"  
E0809 15:06:49.531075   11504 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"  
E0809 15:07:20.547734   11504 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"  
E0809 15:08:05.705006   11504 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 83 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s)
    --- 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
E0809 15:08:05.715468   11504 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0809 15:08:05.715510   11504 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-643787839/tls.crt: no such file or directory"  
E0809 15:08:05.715530   11504 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0809 15:08:05.715556   11504 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-643787839/tls.crt: no such file or directory"  
I0809 15:08:05.715593   11504 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	187.049s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0809 15:05:21.868052   11859 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0809 15:05:21.868101   11859 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0809 15:05:21.966014   11859 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0809 15:05:22.066431   11859 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0809 15:05:22.066512   11859 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0809 15:05:22.157922   11859 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-rdpcju"} 
E0809 15:05:22.196887   11859 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"
•I0809 15:05:23.260257   11859 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-ymer3a"} 
E0809 15:05:23.311158   11859 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"
•
------------------------------
• Failure [11.094 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E0809 15:05:34.411849   11859 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"
E0809 15:05:35.594853   11859 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"
•E0809 15:05:36.626715   11859 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"
E0809 15:05:37.641683   11859 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"
•I0809 15:05:37.649188   11859 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0809 15:05:37.649254   11859 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0809 15:05:37.649311   11859 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 



Summarizing 1 Failure:

[Fail] ClusterResourceSet Reconciler [It] Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources 
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:307

Ran 5 of 5 Specs in 29.196 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (29.20s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	29.258s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-create
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-update
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-delete
... skipping 58 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
E0809 15:05:15.229540   12124 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 91 lines ...
•I0809 15:05:27.073873   12124 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0809 15:05:27.110919   12124 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0809 15:05:27.152533   12124 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0809 15:05:27.155064   12124 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0809 15:05:27.199543   12124 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0809 15:05:27.237264   12124 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0809 15:05:27.240106   12124 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0809 15:05:27.240167   12124 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-893345464/tls.crt: no such file or directory"  
E0809 15:05:27.240187   12124 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0809 15:05:27.240205   12124 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-893345464/tls.crt: no such file or directory"  
I0809 15:05:27.240222   12124 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 12.040 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (12.04s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	12.302s
?   	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 200 lines ...
I0809 15:05:50.752046   15085 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0809 15:05:50.752062   15085 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0809 15:05:50.752323   15085 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0809 15:05:50.753642   15085 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0809 15:05:50.753842   15085 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=37577
I0809 15:05:50.754010   15085 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••E0809 15:05:51.892268   15085 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0809 15:05:51.892315   15085 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-796544337/tls.crt: no such file or directory"  
E0809 15:05:51.892336   15085 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0809 15:05:51.892355   15085 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-796544337/tls.crt: no such file or directory"  
I0809 15:05:51.892359   15085 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 14 of 14 Specs in 8.008 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (8.01s)
=== 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)
... skipping 105 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.032s
FAIL
make: *** [Makefile:116: test] Error 1