This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-06-08 14:38
Elapsed5m29s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I0608 14:41:33.261024    8492 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0608 14:41:33.261237    8492 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0608 14:41:33.262233    8492 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0608 14:41:33.262437    8492 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=35981
I0608 14:41:33.262470    8492 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0608 14:41:34.075576    8492 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" 
•E0608 14:41:34.097799    8492 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0608 14:41:34.097872    8492 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-803378223/tls.crt: no such file or directory"  
E0608 14:41:34.097900    8492 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0608 14:41:34.097926    8492 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-803378223/tls.crt: no such file or directory"  
I0608 14:41:34.098061    8492 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.229 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.23s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	47.805s
=== 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 1403 lines ...
I0608 14:41:19.813987   10530 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0608 14:41:20.009239   10530 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"
2022/06/08 14:41:20 http: TLS handshake error from 127.0.0.1:35752: EOF
I0608 14:41:20.012973   10530 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
I0608 14:41:20.014048   10530 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"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_is_marked_ready_on_cluster
I0608 14:41:20.018476   10530 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"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_infrastructure_has_the_paused_annotation
... skipping 100 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0608 14:41:20.065364   10530 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
I0608 14:41:20.067074   10530 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"
E0608 14:41:20.067431   10530 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
I0608 14:41:20.067941   10530 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
I0608 14:41:20.343344   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0608 14:41:20.444118   10530 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0608 14:41:20.452162   10530 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-cct2v" "namespace"="test-machine-watches-k4trr" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0608 14:41:20.452255   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0608 14:41:20.563896   10530 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-cct2v" "namespace"="test-machine-watches-k4trr" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0608 14:41:20.563974   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0608 14:41:20.664388   10530 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-cct2v" "namespace"="test-machine-watches-k4trr" "noderef"="node-1"
E0608 14:41:20.687080   10530 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0608 14:41:20.687125   10530 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0608 14:41:20.721817   10530 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-cct2v\" in namespace \"test-machine-watches-k4trr\", requeuing: requeue in 1s"  
E0608 14:41:20.741981   10530 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-cct2v\" in namespace \"test-machine-watches-k4trr\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-cct2v\" in namespace \"test-machine-watches-k4trr\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-cct2v" "namespace"="test-machine-watches-k4trr"
--- PASS: TestWatches (0.70s)
=== 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
I0608 14:41:21.064632   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-dpp4f" "namespace"="test-machine-watches-k4trr" "count"=1
I0608 14:41:21.064709   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-dpp4f" "namespace"="test-machine-watches-k4trr" "descendants"="Worker machines: machine-created-cct2v" "indirect descendants count"=0
I0608 14:41:21.079509   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-dpp4f" "namespace"="test-machine-watches-k4trr" "count"=1
I0608 14:41:21.079568   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-dpp4f" "namespace"="test-machine-watches-k4trr" "descendants"="Worker machines: machine-created-cct2v" "indirect descendants count"=0
I0608 14:41:21.742639   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-dpp4f" "machine"="machine-created-cct2v" "namespace"="test-machine-watches-k4trr" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"136a8e84-2e89-43dc-bbca-a4ffaf0f726b","apiVersion":"v1"}
E0608 14:41:21.787997   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-cct2v\" not found" "controller"="machine" "name"="machine-created-cct2v" "namespace"="test-machine-watches-k4trr"
E0608 14:41:22.844733   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-w5c4w\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-xszwz\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-xszwz: secrets \"machine-reconcile-xszwz-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-w5c4w" "namespace"="default"
I0608 14:41:23.845329   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xszwz" "machine"="machine-created-w5c4w" "namespace"="default" "cause"="noderef is nil" "node"=null
I0608 14:41:23.889769   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xszwz" "machine"="machine-created-w5c4w" "namespace"="default" "cause"="noderef is nil" "node"=null
I0608 14:41:23.932128   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xszwz" "machine"="machine-created-w5c4w" "namespace"="default" "cause"="noderef is nil" "node"=null
E0608 14:41:23.980790   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-w5c4w\" not found" "controller"="machine" "name"="machine-created-w5c4w" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.22s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.22s)
=== 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 4 lines ...
I0608 14:41:23.994948   10530 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0608 14:41:23.995052   10530 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
I0608 14:41:23.999933   10530 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"
I0608 14:41:24.000209   10530 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
E0608 14:41:24.006628   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-xszwz\" not found" "controller"="cluster" "name"="machine-reconcile-xszwz" "namespace"="default"
I0608 14:41:24.011517   10530 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"
I0608 14:41:24.011650   10530 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.02s)
    --- 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.01s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
... skipping 121 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0608 14:41:24.157647   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rgvj" "namespace"="test-mhc-qrmrw" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0608 14:41:24.180008   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0608 14:41:24.181093   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-g2f2s\" not found"  "cluster"="test-mhc-qrmrw/test-cluster-g2f2s"
E0608 14:41:24.185756   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-4rgvj\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-4rgvj\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-4rgvj" "namespace"="test-mhc-qrmrw"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0608 14:41:25.186091   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4rgvj" "namespace"="test-mhc-qrmrw" 
I0608 14:41:25.186202   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gf8gz" "namespace"="test-mhc-ztvb7" 
I0608 14:41:25.186230   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j59xf" "namespace"="test-mhc-7zb45" 
I0608 14:41:25.186258   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qrcmf" "namespace"="test-mhc-9twvc" 
I0608 14:41:25.204868   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0608 14:41:25.324081   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qrcmf" "namespace"="test-mhc-9twvc" 
E0608 14:41:25.403054   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9twvc/test-cluster-qmcv8"
E0608 14:41:25.405103   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-qmcv8\" not found" "controller"="cluster" "name"="test-cluster-qmcv8" "namespace"="test-mhc-9twvc"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0608 14:41:25.408337   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qrcmf" "namespace"="test-mhc-9twvc" 
I0608 14:41:25.531232   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dnffs" "namespace"="test-mhc-l9pb2" 
I0608 14:41:25.555046   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0608 14:41:25.692059   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dnffs" "namespace"="test-mhc-l9pb2" 
E0608 14:41:25.739281   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-l9pb2/test-cluster-jvqxd"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0608 14:41:25.744920   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dnffs" "namespace"="test-mhc-l9pb2" 
I0608 14:41:25.862329   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
inframachine created: test-mhc-machine-infra-cc2k4
I0608 14:41:25.875108   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-s9hgf
I0608 14:41:25.900678   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:25.907379   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:25.907684   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:25.926880   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:25.927322   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:25.931439   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:25.931756   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:25.938739   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:25.939161   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:25.962731   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:25.963107   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:25.980187   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:25.980529   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
E0608 14:41:25.992461   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2tdnj, got []"  "node"="test-mhc-node-2tdnj"
node created: test-mhc-node-2tdnj
E0608 14:41:26.000988   10530 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-2tdnj"
I0608 14:41:26.001750   10530 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv" "noderef"="test-mhc-node-2tdnj"
E0608 14:41:26.007273   10530 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-2tdnj"
E0608 14:41:26.007335   10530 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-2tdnj"
E0608 14:41:26.008011   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2tdnj, got []"  "node"="test-mhc-node-2tdnj"
E0608 14:41:26.008059   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2tdnj, got []"  "node"="test-mhc-node-2tdnj"
I0608 14:41:26.018326   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.018711   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:26.019629   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.020080   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:26.025907   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
inframachine created: test-mhc-machine-infra-6z5gk
machine created: test-mhc-machine-nr2ht
I0608 14:41:26.086580   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.094538   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.096018   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
... skipping 2 lines ...
I0608 14:41:26.100788   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.101784   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.102797   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.103836   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.105988   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.108045   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.108396   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-nr2ht/"
I0608 14:41:26.120486   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.120963   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-nr2ht/"
I0608 14:41:26.145743   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.146293   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-nr2ht/"
I0608 14:41:26.166262   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.166744   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-nr2ht/"
I0608 14:41:26.174915   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.175381   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-nr2ht/"
I0608 14:41:26.185597   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.186092   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-nr2ht/"
E0608 14:41:26.187901   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r5qzj, got []"  "node"="test-mhc-node-r5qzj"
node created: test-mhc-node-r5qzj
E0608 14:41:26.188246   10530 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-r5qzj"
I0608 14:41:26.192967   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.193399   10530 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-9hbqv/test-mhc-bx8dr/test-mhc-machine-nr2ht/"
I0608 14:41:26.198630   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.202177   10530 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv" "noderef"="test-mhc-node-r5qzj"
I0608 14:41:26.224449   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
Cleaning up nodes, machines and infra machines.
I0608 14:41:26.233485   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.234026   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:26.267175   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:26.267723   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-9hbqv/test-mhc-bx8dr/test-mhc-machine-s9hgf/"
I0608 14:41:26.268169   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-9hbqv/test-mhc-bx8dr/test-mhc-machine-nr2ht/"
E0608 14:41:26.278494   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-9hbqv/test-cluster-829rh"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0608 14:41:26.283014   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-bx8dr\" not found" "controller"="machinehealthcheck" "name"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv"
inframachine created: test-mhc-machine-infra-d4svj
machine created: test-mhc-machine-lpxnl
E0608 14:41:26.361394   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
E0608 14:41:26.421899   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-k4trr/machine-reconcile-dpp4f"
I0608 14:41:27.283337   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bx8dr" "namespace"="test-mhc-9hbqv" 
I0608 14:41:27.283434   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.319967   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0608 14:41:27.340458   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.345284   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.346403   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
... skipping 17 lines ...
I0608 14:41:27.378276   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.379936   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.381674   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.382737   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.385640   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.387575   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
E0608 14:41:27.389638   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:27.389651   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.389897   10530 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-g572m/test-mhc-bhrwl/test-mhc-machine-lpxnl/"
I0608 14:41:27.401114   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.401463   10530 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-g572m/test-mhc-bhrwl/test-mhc-machine-lpxnl/"
node created: test-mhc-node-dtcm6
E0608 14:41:27.433080   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-dtcm6, got []"  "node"="test-mhc-node-dtcm6"
I0608 14:41:27.441675   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
inframachine created: test-mhc-machine-infra-xv8nd
machine created: test-mhc-machine-kdjfw
I0608 14:41:27.458595   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.464149   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:27.465284   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
... skipping 337 lines ...
I0608 14:41:28.379421   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.381619   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.383799   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.386012   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.389019   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.391035   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
E0608 14:41:28.391563   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:28.393359   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.395740   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.397877   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.400367   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.402689   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:28.405203   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
... skipping 364 lines ...
I0608 14:41:29.434436   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.437255   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.440770   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.442546   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.444998   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.446703   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
E0608 14:41:29.448071   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:29.448281   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.449960   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.452844   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.464783   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.470975   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:29.475884   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
... skipping 353 lines ...
I0608 14:41:30.464149   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:30.466498   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:30.467806   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:30.468929   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:30.470022   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:30.471626   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
E0608 14:41:30.472006   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:30.472024   10530 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-g572m/test-mhc-bhrwl/test-mhc-machine-kdjfw/"
node created: test-mhc-node-x85nn
E0608 14:41:30.481247   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-x85nn, got []"  "node"="test-mhc-node-x85nn"
I0608 14:41:30.483298   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:30.483705   10530 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-g572m/test-mhc-bhrwl/test-mhc-machine-kdjfw/"
I0608 14:41:30.488088   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
inframachine created: test-mhc-machine-infra-m2s9n
I0608 14:41:30.502944   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:30.507024   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
machine created: test-mhc-machine-sdj7z
I0608 14:41:30.513595   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
... skipping 252 lines ...
I0608 14:41:31.433545   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.436577   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.443168   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.447293   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.451418   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.472387   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
E0608 14:41:31.491098   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:31.495493   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.536058   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.540096   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.545114   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.552870   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:31.556707   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
... skipping 264 lines ...
I0608 14:41:32.514403   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.515817   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.523663   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.534147   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.537199   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.540698   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
E0608 14:41:32.544790   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:32.545375   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.547137   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.549222   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.551262   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.556110   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:32.560124   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
... skipping 277 lines ...
I0608 14:41:33.547485   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.550173   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.553274   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.556026   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.557491   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.562151   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.562771   10530 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-g572m/test-mhc-bhrwl/test-mhc-machine-sdj7z/"
E0608 14:41:33.568841   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:33.575479   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.576019   10530 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-g572m/test-mhc-bhrwl/test-mhc-machine-sdj7z/"
E0608 14:41:33.639443   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gxxx2, got []"  "node"="test-mhc-node-gxxx2"
node created: test-mhc-node-gxxx2
Cleaning up nodes, machines and infra machines.
I0608 14:41:33.647145   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.647799   10530 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-g572m/test-mhc-bhrwl/test-mhc-machine-sdj7z/test-mhc-node-gxxx2"
I0608 14:41:33.662979   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.663562   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-g572m/test-mhc-bhrwl/test-mhc-machine-sdj7z/"
Cleaning up nodes, machines and infra machines.
I0608 14:41:33.686690   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:33.687243   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-g572m/test-mhc-bhrwl/test-mhc-machine-kdjfw/"
I0608 14:41:33.698332   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2ll7f" "namespace"="test-mhc-g572m" "count"=2
I0608 14:41:33.698419   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2ll7f" "namespace"="test-mhc-g572m" "descendants"="Worker machines: test-mhc-machine-lpxnl,test-mhc-machine-kdjfw,test-mhc-machine-sdj7z" "indirect descendants count"=1
I0608 14:41:33.702123   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-g572m/test-mhc-bhrwl/test-mhc-machine-sdj7z/"
I0608 14:41:33.702560   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-g572m/test-mhc-bhrwl/test-mhc-machine-lpxnl/"
I0608 14:41:33.707966   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2ll7f" "namespace"="test-mhc-g572m" "count"=2
I0608 14:41:33.708037   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2ll7f" "namespace"="test-mhc-g572m" "descendants"="Worker machines: test-mhc-machine-lpxnl,test-mhc-machine-kdjfw,test-mhc-machine-sdj7z" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
E0608 14:41:33.726011   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-bhrwl\" not found" "controller"="machinehealthcheck" "name"="test-mhc-bhrwl" "namespace"="test-mhc-g572m"
inframachine created: test-mhc-machine-infra-w66t4
machine created: test-mhc-machine-84flk
I0608 14:41:34.569398   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2ll7f" "machine"="test-mhc-machine-kdjfw" "namespace"="test-mhc-g572m" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-x85nn"}
E0608 14:41:34.642064   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kdjfw\" not found" "controller"="machine" "name"="test-mhc-machine-kdjfw" "namespace"="test-mhc-g572m"
I0608 14:41:34.726251   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bhrwl" "namespace"="test-mhc-g572m" 
I0608 14:41:34.726359   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:34.740481   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0608 14:41:34.770658   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:34.786594   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:34.796775   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:34.841368   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:34.922455   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:35.083486   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:35.404584   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:35.642442   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:36.045571   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:36.651167   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2ll7f" "machine"="test-mhc-machine-sdj7z" "namespace"="test-mhc-g572m" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-gxxx2"}
E0608 14:41:36.707565   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-sdj7z\" not found" "controller"="machine" "name"="test-mhc-machine-sdj7z" "namespace"="test-mhc-g572m"
I0608 14:41:37.326582   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:37.707980   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:38.708274   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2ll7f" "namespace"="test-mhc-g572m" "count"=1
I0608 14:41:38.708374   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2ll7f" "namespace"="test-mhc-g572m" "descendants"="Worker machines: test-mhc-machine-lpxnl" "indirect descendants count"=0
I0608 14:41:38.708473   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2ll7f" "machine"="test-mhc-machine-lpxnl" "namespace"="test-mhc-g572m" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-dtcm6"}
E0608 14:41:38.767822   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lpxnl\" not found" "controller"="machine" "name"="test-mhc-machine-lpxnl" "namespace"="test-mhc-g572m"
E0608 14:41:39.781806   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:39.783044   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:39.791351   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mxsdl, got []"  "node"="test-mhc-node-mxsdl"
E0608 14:41:39.791603   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mxsdl, got []"  "node"="test-mhc-node-mxsdl"
node created: test-mhc-node-mxsdl
inframachine created: test-mhc-machine-infra-4b5t5
machine created: test-mhc-machine-qchp7
I0608 14:41:39.942791   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:39.961654   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:40.782212   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:41.799570   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:41.820295   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:41.823524   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:41.830263   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:41.839618   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:41.839648   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:41.894108   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:41.928187   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mbg99, got []"  "node"="test-mhc-node-mbg99"
node created: test-mhc-node-mbg99
E0608 14:41:41.928376   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mbg99, got []"  "node"="test-mhc-node-mbg99"
I0608 14:41:41.935375   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
inframachine created: test-mhc-machine-infra-gth6b
I0608 14:41:41.948202   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
machine created: test-mhc-machine-vbgsr
I0608 14:41:41.952816   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:41.971218   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:42.840016   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
E0608 14:41:43.726482   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-g572m/test-cluster-2ll7f"
I0608 14:41:43.864676   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:43.880500   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:43.891288   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:43.908243   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:43.915075   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:43.924809   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:43.931050   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:43.931581   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:43.959921   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
E0608 14:41:43.965358   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pkkqs, got []"  "node"="test-mhc-node-pkkqs"
node created: test-mhc-node-pkkqs
Cleaning up nodes, machines and infra machines.
I0608 14:41:43.974422   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:43.985753   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
Cleaning up nodes, machines and infra machines.
I0608 14:41:44.026855   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6wc82" "namespace"="test-mhc-tbzsv" "count"=2
... skipping 4 lines ...
inframachine created: test-mhc-machine-infra-q787r
machine created: test-mhc-machine-rsrqf
I0608 14:41:44.133349   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:44.167417   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0608 14:41:44.190984   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:44.191065   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
E0608 14:41:44.931511   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:45.062979   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-759dj" "namespace"="test-mhc-tbzsv" 
I0608 14:41:45.934598   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6wc82" "machine"="test-mhc-machine-84flk" "namespace"="test-mhc-tbzsv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mxsdl"}
E0608 14:41:45.972227   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-84flk\" not found" "controller"="machine" "name"="test-mhc-machine-84flk" "namespace"="test-mhc-tbzsv"
I0608 14:41:46.972784   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6wc82" "machine"="test-mhc-machine-qchp7" "namespace"="test-mhc-tbzsv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mbg99"}
E0608 14:41:47.013890   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qchp7\" not found" "controller"="machine" "name"="test-mhc-machine-qchp7" "namespace"="test-mhc-tbzsv"
I0608 14:41:48.014424   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6wc82" "machine"="test-mhc-machine-vbgsr" "namespace"="test-mhc-tbzsv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-pkkqs"}
E0608 14:41:48.075636   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vbgsr\" not found" "controller"="machine" "name"="test-mhc-machine-vbgsr" "namespace"="test-mhc-tbzsv"
E0608 14:41:49.053944   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-tbzsv/test-cluster-6wc82"
I0608 14:41:49.083550   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
E0608 14:41:49.089733   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:49.090113   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
node created: test-mhc-node-7p52z
E0608 14:41:49.116513   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7p52z, got []"  "node"="test-mhc-node-7p52z"
I0608 14:41:49.125159   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
inframachine created: test-mhc-machine-infra-cc2r4
machine created: test-mhc-machine-dlpqj
I0608 14:41:49.143443   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:49.149062   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
E0608 14:41:50.090196   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:51.114438   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:51.124661   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:51.134886   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:51.148994   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:51.158675   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
E0608 14:41:51.162021   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:51.164240   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
E0608 14:41:51.252061   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6wkgb, got []"  "node"="test-mhc-node-6wkgb"
node created: test-mhc-node-6wkgb
I0608 14:41:51.259517   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
inframachine created: test-mhc-machine-infra-t2rx7
I0608 14:41:51.281043   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
machine created: test-mhc-machine-cwmp9
I0608 14:41:51.285160   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:51.293305   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.174294   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.194141   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.199952   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.210225   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.218395   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.228747   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
E0608 14:41:52.235966   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:52.236357   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
Cleaning up nodes, machines and infra machines.
I0608 14:41:52.317613   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
Cleaning up nodes, machines and infra machines.
I0608 14:41:52.331602   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.332142   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r4d9d/test-mhc-dxs2v/test-mhc-machine-rsrqf/"
I0608 14:41:52.349207   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.349778   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r4d9d/test-mhc-dxs2v/test-mhc-machine-rsrqf/"
I0608 14:41:52.350217   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r4d9d/test-mhc-dxs2v/test-mhc-machine-dlpqj/"
I0608 14:41:52.372144   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:52.372691   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-vzbxq" "namespace"="test-mhc-r4d9d" "count"=2
I0608 14:41:52.372767   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vzbxq" "namespace"="test-mhc-r4d9d" "descendants"="Worker machines: test-mhc-machine-dlpqj,test-mhc-machine-cwmp9,test-mhc-machine-rsrqf" "indirect descendants count"=1
I0608 14:41:52.379961   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r4d9d/test-mhc-dxs2v/test-mhc-machine-dlpqj/"
I0608 14:41:52.380694   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r4d9d/test-mhc-dxs2v/test-mhc-machine-rsrqf/"
I0608 14:41:52.382330   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-vzbxq" "namespace"="test-mhc-r4d9d" "count"=2
I0608 14:41:52.382920   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vzbxq" "namespace"="test-mhc-r4d9d" "descendants"="Worker machines: test-mhc-machine-cwmp9,test-mhc-machine-rsrqf,test-mhc-machine-dlpqj" "indirect descendants count"=1
=== 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
E0608 14:41:52.388937   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-dxs2v\" not found" "controller"="machinehealthcheck" "name"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d"
inframachine created: test-mhc-machine-infra-hrrfc
machine created: test-mhc-machine-2mh5k
I0608 14:41:53.236523   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vzbxq" "machine"="test-mhc-machine-rsrqf" "namespace"="test-mhc-r4d9d" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-7p52z"}
E0608 14:41:53.278777   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rsrqf\" not found" "controller"="machine" "name"="test-mhc-machine-rsrqf" "namespace"="test-mhc-r4d9d"
I0608 14:41:53.389232   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dxs2v" "namespace"="test-mhc-r4d9d" 
I0608 14:41:53.389341   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:53.404719   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0608 14:41:53.524031   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:53.529117   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:53.530242   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
... skipping 371 lines ...
I0608 14:41:54.333164   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.334919   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.336715   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.338439   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.340201   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.342481   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
E0608 14:41:54.342937   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dlpqj\" not found" "controller"="machine" "name"="test-mhc-machine-dlpqj" "namespace"="test-mhc-r4d9d"
I0608 14:41:54.344892   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.346785   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.348829   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.350661   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.352639   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:54.354631   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
... skipping 483 lines ...
I0608 14:41:55.375007   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.376771   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.378445   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.380121   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.381812   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.383503   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
E0608 14:41:55.384256   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cwmp9\" not found" "controller"="machine" "name"="test-mhc-machine-cwmp9" "namespace"="test-mhc-r4d9d"
I0608 14:41:55.385212   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.386948   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.388784   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.390532   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.392227   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:55.393788   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
... skipping 486 lines ...
I0608 14:41:56.388631   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.390418   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.392541   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.393113   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.395361   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.397116   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
E0608 14:41:56.397281   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:41:56.397386   10530 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-xvvxq/test-mhc-lmgmz/test-mhc-machine-2mh5k/"
I0608 14:41:56.407058   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.407421   10530 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-xvvxq/test-mhc-lmgmz/test-mhc-machine-2mh5k/"
node created: test-mhc-node-k8n8w
E0608 14:41:56.477929   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-k8n8w, got []"  "node"="test-mhc-node-k8n8w"
E0608 14:41:56.477934   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-k8n8w, got []"  "node"="test-mhc-node-k8n8w"
I0608 14:41:56.485087   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.568459   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.568875   10530 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-xvvxq/test-mhc-lmgmz/test-mhc-machine-2mh5k/test-mhc-node-k8n8w"
Cleaning up nodes, machines and infra machines.
I0608 14:41:56.586567   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.586919   10530 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-xvvxq/test-mhc-lmgmz/test-mhc-machine-2mh5k/test-mhc-node-k8n8w"
I0608 14:41:56.590309   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.590639   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xvvxq/test-mhc-lmgmz/test-mhc-machine-2mh5k/"
I0608 14:41:56.609719   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
I0608 14:41:56.610105   10530 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xvvxq/test-mhc-lmgmz/test-mhc-machine-2mh5k/"
I0608 14:41:56.622218   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jk5ml" "namespace"="test-mhc-xvvxq" "descendants"="Worker machines: test-mhc-machine-2mh5k" "indirect descendants count"=1
I0608 14:41:56.627032   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jk5ml" "namespace"="test-mhc-xvvxq" "descendants"="Worker machines: test-mhc-machine-2mh5k" "indirect descendants count"=1
I0608 14:41:56.628801   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lmgmz" "namespace"="test-mhc-xvvxq" 
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0608 14:41:56.822796   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" "creating"=1 "need"=1
I0608 14:41:56.822854   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" 
I0608 14:41:56.835557   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-4dr5n-vb2n5\"" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" 
I0608 14:41:56.898728   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:41:56.913416   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0608 14:41:56.930103   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
E0608 14:41:57.394110   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-r4d9d/test-cluster-vzbxq"
E0608 14:41:57.397665   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
I0608 14:41:57.932103   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:41:58.398193   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jk5ml" "machine"="test-mhc-machine-2mh5k" "namespace"="test-mhc-xvvxq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-k8n8w"}
E0608 14:41:58.452686   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2mh5k\" not found" "controller"="machine" "name"="test-mhc-machine-2mh5k" "namespace"="test-mhc-xvvxq"
I0608 14:41:58.933243   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:41:59.462318   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:41:59.468121   10530 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" 
I0608 14:41:59.476360   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:41:59.476543   10530 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" 
I0608 14:41:59.481690   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
... skipping 7 lines ...
I0608 14:41:59.510638   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
I0608 14:41:59.510684   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
I0608 14:41:59.934441   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:42:00.495993   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
I0608 14:42:00.496048   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.000583   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.000948   10530 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-7tcts/test-mhc-cnf7q/mhc-ms-4dr5n-vb2n5/"
I0608 14:42:01.007323   10530 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.011494   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.011538   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.013227   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.013594   10530 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-7tcts/test-mhc-cnf7q/mhc-ms-4dr5n-vb2n5/"
I0608 14:42:01.017354   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.017608   10530 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.017698   10530 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-7tcts/test-mhc-cnf7q/mhc-ms-4dr5n-vb2n5/"
I0608 14:42:01.031940   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.031984   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.034712   10530 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" "machine"="mhc-ms-4dr5n-vb2n5"
I0608 14:42:01.034955   10530 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-495fl" "namespace"="test-mhc-7tcts" "count"=1
I0608 14:42:01.034996   10530 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-495fl" "namespace"="test-mhc-7tcts" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-4dr5n"
I0608 14:42:01.042702   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.043063   10530 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-7tcts/test-mhc-cnf7q/mhc-ms-4dr5n-vb2n5/"
I0608 14:42:01.043520   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-495fl" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" "cause"="cluster is being deleted" "node"=null
I0608 14:42:01.045943   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cnf7q" "namespace"="test-mhc-7tcts" 
I0608 14:42:01.049082   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-495fl" "namespace"="test-mhc-7tcts" "descendants"="Machine sets: mhc-ms-4dr5n;Worker machines: mhc-ms-4dr5n-vb2n5" "indirect descendants count"=1
I0608 14:42:01.054341   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-495fl" "namespace"="test-mhc-7tcts" "descendants"="Worker machines: mhc-ms-4dr5n-vb2n5" "indirect descendants count"=1
E0608 14:42:01.055223   10530 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to retrieve InfrastructureMachineTemplate external object \"test-mhc-7tcts\"/\"mhc-ms-template-86dw8\": infrastructuremachinetemplates.infrastructure.cluster.x-k8s.io \"mhc-ms-template-86dw8\" not found" "machineset"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts" 
E0608 14:42:01.055334   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to retrieve InfrastructureMachineTemplate external object \"test-mhc-7tcts\"/\"mhc-ms-template-86dw8\": infrastructuremachinetemplates.infrastructure.cluster.x-k8s.io \"mhc-ms-template-86dw8\" not found" "controller"="machineset" "name"="mhc-ms-4dr5n" "namespace"="test-mhc-7tcts"
=== 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
I0608 14:42:01.129094   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
inframachine created: test-mhc-machine-infra-8dl94
machine created: test-mhc-machine-qq68t
I0608 14:42:01.147117   10530 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0608 14:42:01.252482   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-495fl" "machine"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts" "cause"="cluster is being deleted" "node"=null
I0608 14:42:01.264708   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
E0608 14:42:01.283933   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-4dr5n-vb2n5\" not found" "controller"="machine" "name"="mhc-ms-4dr5n-vb2n5" "namespace"="test-mhc-7tcts"
I0608 14:42:01.310437   10530 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-qq68t" "target"="test-mhc-6nj5l/test-mhc-j856v/test-mhc-machine-qq68t/"
I0608 14:42:01.322879   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
node created: test-mhc-node-zr5dm
E0608 14:42:01.350328   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zr5dm, got []"  "node"="test-mhc-node-zr5dm"
E0608 14:42:01.350360   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zr5dm, got []"  "node"="test-mhc-node-zr5dm"
E0608 14:42:01.350407   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zr5dm, got []"  "node"="test-mhc-node-zr5dm"
I0608 14:42:01.358444   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
I0608 14:42:01.376093   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
I0608 14:42:01.386269   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
I0608 14:42:01.390324   10530 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-qq68t" "target"="test-mhc-6nj5l/test-mhc-j856v/test-mhc-machine-qq68t/test-mhc-node-zr5dm"
I0608 14:42:01.405016   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
I0608 14:42:01.409237   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
Cleaning up nodes, machines and infra machines.
I0608 14:42:01.422781   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
I0608 14:42:01.425462   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
I0608 14:42:01.428382   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-j856v" "namespace"="test-mhc-6nj5l" 
... skipping 22 lines ...
I0608 14:42:01.629642   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.631678   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.633382   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.635054   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.636955   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.638897   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
E0608 14:42:01.639581   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xvvxq/test-cluster-jk5ml"
I0608 14:42:01.640732   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.642458   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.644206   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.646223   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.648106   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:01.649828   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
... skipping 355 lines ...
I0608 14:42:02.305795   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.307509   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.309427   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.311234   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.313127   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.314906   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
E0608 14:42:02.316587   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qq68t\" not found" "controller"="machine" "name"="test-mhc-machine-qq68t" "namespace"="test-mhc-6nj5l"
I0608 14:42:02.316726   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.319520   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.321379   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.323395   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.325330   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:02.327355   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
... skipping 546 lines ...
I0608 14:42:03.318490   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.320322   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.322079   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.323810   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.324387   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.326229   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
E0608 14:42:03.326544   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
I0608 14:42:03.326901   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.330392   10530 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-znmpc" "target"="test-mhc-5jgsg/test-mhc-hr2rc/test-mhc-machine-znmpc/"
I0608 14:42:03.340025   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
node created: test-mhc-node-r74b2
E0608 14:42:03.397653   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r74b2, got []"  "node"="test-mhc-node-r74b2"
E0608 14:42:03.397656   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r74b2, got []"  "node"="test-mhc-node-r74b2"
E0608 14:42:03.397660   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r74b2, got []"  "node"="test-mhc-node-r74b2"
I0608 14:42:03.403607   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.421841   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.426876   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.430164   10530 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-znmpc" "target"="test-mhc-5jgsg/test-mhc-hr2rc/test-mhc-machine-znmpc/test-mhc-node-r74b2"
I0608 14:42:03.443635   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.447230   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.452175   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.471644   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
Cleaning up nodes, machines and infra machines.
I0608 14:42:03.478450   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
I0608 14:42:03.482732   10530 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-znmpc" "target"="test-mhc-5jgsg/test-mhc-hr2rc/test-mhc-machine-znmpc/"
I0608 14:42:03.489840   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-lc2l7" "namespace"="test-mhc-5jgsg" "descendants"="Worker machines: test-mhc-machine-znmpc" "indirect descendants count"=1
I0608 14:42:03.493522   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-lc2l7" "namespace"="test-mhc-5jgsg" "descendants"="Worker machines: test-mhc-machine-znmpc" "indirect descendants count"=1
E0608 14:42:03.497642   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-hr2rc\" not found" "controller"="machinehealthcheck" "name"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg"
--- PASS: TestMachineHealthCheck_Reconcile (39.37s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.16s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.34s)
... skipping 10 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.39s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.05s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0608 14:42:03.501748   10530 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
E0608 14:42:03.503602   10530 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
E0608 14:42:03.505373   10530 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0608 14:42:03.505621   10530 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
E0608 14:42:03.506054   10530 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
I0608 14:42:03.508973   10530 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0608 14:42:03.509381   10530 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0608 14:42:03.510519   10530 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
E0608 14:42:03.517576   10530 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
E0608 14:42:03.519049   10530 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 73 lines ...
I0608 14:42:03.794514   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0608 14:42:03.794559   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" 
I0608 14:42:03.803888   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-smrcq-6657c7fddb-l6c7b\"" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" 
I0608 14:42:03.913785   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0608 14:42:03.913821   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" 
I0608 14:42:03.922335   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-smrcq-cdfc6fd6c-k5cr4\"" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" 
E0608 14:42:03.995058   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:03.995395   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:03.995399   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:04.099107   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:04.099181   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:04.099385   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:04.099434   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:04.099610   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:04.099672   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-k5cr4-hrb5p, got []"  "node"="md-smrcq-cdfc6fd6c-k5cr4-hrb5p"
E0608 14:42:04.119496   10530 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-smrcq-cdfc6fd6c-k5cr4-hrb5p for machine md-test/md-smrcq-cdfc6fd6c-k5cr4: the cache is not started, can not read objects" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" 
I0608 14:42:04.148872   10530 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0608 14:42:04.148915   10530 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0608 14:42:04.154057   10530 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "machine"="md-smrcq-6657c7fddb-gdjzz"
I0608 14:42:04.262567   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0608 14:42:04.262607   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" 
I0608 14:42:04.272152   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-smrcq-cdfc6fd6c-6ppns\"" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" 
E0608 14:42:04.326941   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
E0608 14:42:04.328262   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
E0608 14:42:04.328286   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
E0608 14:42:04.328312   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
E0608 14:42:04.431928   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
E0608 14:42:04.431959   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
E0608 14:42:04.431993   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
E0608 14:42:04.431928   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
E0608 14:42:04.432004   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
E0608 14:42:04.432031   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-6ppns-sfjqv, got []"  "node"="md-smrcq-cdfc6fd6c-6ppns-sfjqv"
I0608 14:42:04.466685   10530 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0608 14:42:04.466724   10530 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0608 14:42:04.472068   10530 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "machine"="md-smrcq-6657c7fddb-d2gzg"
I0608 14:42:04.481281   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0608 14:42:04.481356   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" 
I0608 14:42:04.491558   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-smrcq-cdfc6fd6c-7k5lh\"" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" 
I0608 14:42:04.497842   10530 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hr2rc" "namespace"="test-mhc-5jgsg" 
E0608 14:42:04.576522   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
E0608 14:42:04.576826   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
E0608 14:42:04.576863   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
E0608 14:42:04.680284   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
E0608 14:42:04.680346   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
E0608 14:42:04.680518   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
E0608 14:42:04.680572   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
E0608 14:42:04.680742   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
E0608 14:42:04.680777   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-cdfc6fd6c-7k5lh-j2bnr, got []"  "node"="md-smrcq-cdfc6fd6c-7k5lh-j2bnr"
I0608 14:42:04.710506   10530 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0608 14:42:04.710556   10530 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0608 14:42:04.718158   10530 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-smrcq-6657c7fddb" "namespace"="md-test" "machine"="md-smrcq-6657c7fddb-l6c7b"
I0608 14:42:04.901556   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0608 14:42:04.901606   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" 
I0608 14:42:04.911073   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-smrcq-74d45c49c5-h52ml\"" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" 
E0608 14:42:04.979141   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
E0608 14:42:04.979230   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
E0608 14:42:04.979307   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
E0608 14:42:05.081900   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
E0608 14:42:05.081899   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
E0608 14:42:05.081958   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
E0608 14:42:05.081963   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
E0608 14:42:05.082003   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
E0608 14:42:05.082047   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-h52ml-2dc52, got []"  "node"="md-smrcq-74d45c49c5-h52ml-2dc52"
I0608 14:42:05.110771   10530 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0608 14:42:05.110811   10530 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0608 14:42:05.115767   10530 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "machine"="md-smrcq-cdfc6fd6c-6ppns"
I0608 14:42:05.134091   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0608 14:42:05.134129   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" 
I0608 14:42:05.144252   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-smrcq-74d45c49c5-mhgwp\"" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" 
E0608 14:42:05.203247   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
E0608 14:42:05.203303   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
E0608 14:42:05.203564   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
E0608 14:42:05.308518   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
E0608 14:42:05.308569   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
E0608 14:42:05.309006   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
E0608 14:42:05.309062   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
E0608 14:42:05.309414   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
E0608 14:42:05.309468   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-mhgwp-7lpzr, got []"  "node"="md-smrcq-74d45c49c5-mhgwp-7lpzr"
I0608 14:42:05.327402   10530 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lc2l7" "machine"="test-mhc-machine-znmpc" "namespace"="test-mhc-5jgsg" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-r74b2"}
I0608 14:42:05.349072   10530 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0608 14:42:05.349115   10530 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0608 14:42:05.352694   10530 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "machine"="md-smrcq-cdfc6fd6c-7k5lh"
E0608 14:42:05.365266   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-znmpc\" not found" "controller"="machine" "name"="test-mhc-machine-znmpc" "namespace"="test-mhc-5jgsg"
I0608 14:42:05.460985   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0608 14:42:05.461092   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" 
I0608 14:42:05.470030   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-smrcq-74d45c49c5-f7vc8\"" "machineset"="md-smrcq-74d45c49c5" "namespace"="md-test" 
E0608 14:42:05.565581   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
E0608 14:42:05.565874   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
E0608 14:42:05.565908   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
E0608 14:42:05.669074   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
E0608 14:42:05.669137   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
E0608 14:42:05.669235   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
E0608 14:42:05.669280   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
E0608 14:42:05.669286   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
E0608 14:42:05.669321   10530 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-smrcq-74d45c49c5-f7vc8-4r9pf, got []"  "node"="md-smrcq-74d45c49c5-f7vc8-4r9pf"
I0608 14:42:05.696558   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-smrcq-74d45c49c5,md-smrcq-cdfc6fd6c;Worker machines: md-smrcq-6657c7fddb-x5xcl,md-smrcq-6657c7fddb-rk899,md-smrcq-74d45c49c5-mhgwp,md-smrcq-74d45c49c5-f7vc8,md-smrcq-74d45c49c5-h52ml,md-smrcq-cdfc6fd6c-k5cr4" "indirect descendants count"=8
•I0608 14:42:05.700158   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-smrcq-74d45c49c5,md-smrcq-cdfc6fd6c;Worker machines: md-smrcq-74d45c49c5-h52ml,md-smrcq-cdfc6fd6c-k5cr4,md-smrcq-6657c7fddb-x5xcl,md-smrcq-6657c7fddb-rk899,md-smrcq-74d45c49c5-mhgwp,md-smrcq-74d45c49c5-f7vc8" "indirect descendants count"=8
E0608 14:42:05.701787   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-smrcq\" not found" "controller"="machinedeployment" "name"="md-smrcq" "namespace"="md-test"
I0608 14:42:05.703728   10530 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0608 14:42:05.703756   10530 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0608 14:42:05.707607   10530 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-smrcq-cdfc6fd6c" "namespace"="md-test" "machine"="md-smrcq-cdfc6fd6c-k5cr4"
•E0608 14:42:05.820515   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-8zpjl\" not found" "controller"="cluster" "name"="test1-8zpjl" "namespace"="default"
I0608 14:42:06.433302   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:06.433412   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:06.451998   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
I0608 14:42:06.452117   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
E0608 14:42:06.493618   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
E0608 14:42:06.841625   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7tcts/test-cluster-495fl"
E0608 14:42:06.856368   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6nj5l/test-cluster-2hr6v"
I0608 14:42:06.958995   10530 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-td652" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
•I0608 14:42:07.083462   10530 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-td652" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0608 14:42:07.087076   10530 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-td652" "namespace"="default"
E0608 14:42:07.517242   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-mhgwp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-mhgwp" "namespace"="md-test"
E0608 14:42:08.098507   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
•I0608 14:42:08.545267   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:08.545306   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:08.549705   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
I0608 14:42:08.549756   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
E0608 14:42:08.555377   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
E0608 14:42:09.110409   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-ssw4t\" not found" "controller"="cluster" "name"="test3-ssw4t" "namespace"="default"
E0608 14:42:09.560672   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-mhgwp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-mhgwp" "namespace"="md-test"
E0608 14:42:10.111241   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
E0608 14:42:10.568861   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
E0608 14:42:11.131050   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5jgsg/test-cluster-lc2l7"
E0608 14:42:11.131805   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
•I0608 14:42:11.573576   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:11.573635   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:11.577526   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
I0608 14:42:11.577568   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
E0608 14:42:11.581716   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-mhgwp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-mhgwp" "namespace"="md-test"
I0608 14:42:12.132568   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-smrcq-74d45c49c5,md-smrcq-cdfc6fd6c;Worker machines: md-smrcq-6657c7fddb-x5xcl,md-smrcq-6657c7fddb-rk899,md-smrcq-74d45c49c5-mhgwp,md-smrcq-74d45c49c5-f7vc8,md-smrcq-74d45c49c5-h52ml" "indirect descendants count"=7
E0608 14:42:12.136961   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"
E0608 14:42:12.586332   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
E0608 14:42:13.137745   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
E0608 14:42:13.591296   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-mhgwp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-mhgwp" "namespace"="md-test"
E0608 14:42:14.147047   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"
•I0608 14:42:14.595999   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:14.596034   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:14.599824   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
I0608 14:42:14.599860   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
E0608 14:42:14.603552   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
E0608 14:42:15.147984   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
E0608 14:42:15.603987   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-s9hgf\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-s9hgf" "namespace"="test-mhc-9hbqv"
E0608 14:42:16.148997   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"
E0608 14:42:16.609078   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-mhgwp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-mhgwp" "namespace"="md-test"
E0608 14:42:17.196341   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
E0608 14:42:17.609536   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-829rh\" for machine \"test-mhc-machine-nr2ht\" in namespace \"test-mhc-9hbqv\": Cluster.cluster.x-k8s.io \"test-cluster-829rh\" not found" "controller"="machine" "name"="test-mhc-machine-nr2ht" "namespace"="test-mhc-9hbqv"
E0608 14:42:18.197274   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"
E0608 14:42:18.614832   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
I0608 14:42:19.197966   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-smrcq-74d45c49c5,md-smrcq-cdfc6fd6c;Worker machines: md-smrcq-74d45c49c5-f7vc8,md-smrcq-74d45c49c5-h52ml,md-smrcq-6657c7fddb-x5xcl,md-smrcq-6657c7fddb-rk899,md-smrcq-74d45c49c5-mhgwp" "indirect descendants count"=7
E0608 14:42:19.198602   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
I0608 14:42:19.619801   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:19.619847   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:19.623869   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
I0608 14:42:19.623907   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
E0608 14:42:19.628088   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-mhgwp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-mhgwp" "namespace"="md-test"
E0608 14:42:20.199638   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"
E0608 14:42:20.642272   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
E0608 14:42:21.200633   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
E0608 14:42:21.646992   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-mhgwp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-mhgwp" "namespace"="md-test"
E0608 14:42:22.201412   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"
I0608 14:42:22.651659   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:22.651705   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:22.655571   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
I0608 14:42:22.655612   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
I0608 14:42:22.670715   10530 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dr5jc" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0608 14:42:22.686167   10530 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-dr5jc" "namespace"="default" 
E0608 14:42:22.701690   10530 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-dr5jc" "namespace"="default"
E0608 14:42:23.202242   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"
E0608 14:42:23.706984   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
E0608 14:42:24.202939   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-td652: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-td652" "namespace"="default"
E0608 14:42:24.711933   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-mhgwp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-mhgwp" "namespace"="md-test"
E0608 14:42:25.203667   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"
I0608 14:42:25.729951   10530 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-dr5jc" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0608 14:42:25.730177   10530 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-dr5jc" "namespace"="default" "noderef"="id-node-1"
E0608 14:42:25.742074   10530 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-dr5jc" "namespace"="default"
I0608 14:42:26.204297   10530 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-smrcq-74d45c49c5,md-smrcq-cdfc6fd6c;Worker machines: md-smrcq-74d45c49c5-h52ml,md-smrcq-6657c7fddb-x5xcl,md-smrcq-6657c7fddb-rk899,md-smrcq-74d45c49c5-mhgwp,md-smrcq-74d45c49c5-f7vc8" "indirect descendants count"=7
E0608 14:42:26.208417   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-dmzz4: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-dmzz4" "namespace"="default"

------------------------------
• [SLOW TEST:11.954 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
... skipping 21 lines ...
I0608 14:42:26.254443   10530 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"
•I0608 14:42:26.255789   10530 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"
I0608 14:42:26.256426   10530 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"
I0608 14:42:26.256972   10530 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0608 14:42:26.257000   10530 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0608 14:42:26.257466   10530 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0608 14:42:26.258750   10530 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" 
•I0608 14:42:26.326600   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-wnn4n" "namespace"="ms-test" "creating"=2 "need"=2
I0608 14:42:26.326653   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-wnn4n" "namespace"="ms-test" 
I0608 14:42:26.342111   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-wnn4n-wqhht\"" "machineset"="ms-wnn4n" "namespace"="ms-test" 
I0608 14:42:26.342172   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-wnn4n" "namespace"="ms-test" 
I0608 14:42:26.356027   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-wnn4n-ttbqs\"" "machineset"="ms-wnn4n" "namespace"="ms-test" 
I0608 14:42:26.466508   10530 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-wnn4n" "namespace"="ms-test" "creating"=1 "need"=2
I0608 14:42:26.466546   10530 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-wnn4n" "namespace"="ms-test" 
I0608 14:42:26.478950   10530 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-wnn4n-dxwlc\"" "machineset"="ms-wnn4n" "namespace"="ms-test" 
E0608 14:42:26.595533   10530 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-wnn4n-dxwlc-r2wjd for machine ms-test/ms-wnn4n-dxwlc: the cache is not started, can not read objects" "machineset"="ms-wnn4n" "namespace"="ms-test" 
I0608 14:42:26.746178   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:26.746235   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-x5xcl" "namespace"="md-test" 
I0608 14:42:26.749745   10530 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
I0608 14:42:26.749795   10530 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-smrcq-6657c7fddb-rk899" "namespace"="md-test" 
E0608 14:42:26.754441   10530 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-smrcq-74d45c49c5-h52ml\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-smrcq-74d45c49c5-h52ml" "namespace"="md-test"
E0608 14:42:26.824058   10530 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•

Ran 16 of 16 Specs in 23.306 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (23.31s)
PASS
Tearing down test suite
I0608 14:42:26.826726   10530 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0608 14:42:26.826784   10530 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0608 14:42:26.826813   10530 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0608 14:42:26.826822   10530 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0608 14:42:26.826837   10530 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0608 14:42:26.826863   10530 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0608 14:42:26.826885   10530 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0608 14:42:26.861485   10530 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:37687/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1230&timeout=10s&timeoutSeconds=393&watch=true: dial tcp 127.0.0.1:37687: connect: connection refused
E0608 14:42:26.861554   10530 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:37687/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1230&timeout=10s&timeoutSeconds=372&watch=true: dial tcp 127.0.0.1:37687: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	80.184s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 261 lines ...
I0608 14:41:20.292720   11020 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0608 14:41:20.297450   11020 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":{}}}
I0608 14:41:20.497988   11020 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0608 14:41:20.498045   11020 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0608 14:41:20.796332   11020 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0608 14:41:21.225070   11020 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0608 14:41:23.253126   11020 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-dgc2c/test-cluster"
•E0608 14:41:23.716375   11020 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-gnht4/test-cluster"
•E0608 14:41:24.273302   11020 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:42873/?timeout=50ms: dial tcp 127.0.0.1:42873: connect: connection refused"  "cluster"="cluster-cache-test-smjf9/test-cluster"
•I0608 14:41:24.498010   11020 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}}}
I0608 14:41:24.598397   11020 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0608 14:41:24.598461   11020 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0608 14:41:24.759938   11020 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0608 14:41:24.760075   11020 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0608 14:41:24.813264   11020 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:38287/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:38287: connect: connection refused


Ran 5 of 5 Specs in 16.198 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.20s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	16.393s
?   	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
I0608 14:41:32.481525   11642 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
E0608 14:41:32.482791   11642 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
I0608 14:41:32.483428   11642 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0608 14:41:32.483570   11642 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 74 lines ...
=== RUN   TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_desired_replicas_<=_1
I0608 14:41:44.237673   11642 remediation.go:85]  "msg"="A control plane machine needs remediation, but the number of current replicas is less or equal to 1. Skipping remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "Replicas"=1 "UnhealthyMachine"="m1-unhealthy-77rq9"
=== RUN   TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_number_of_machines_lower_than_desired
I0608 14:41:44.279039   11642 remediation.go:93]  "msg"="A control plane machine needs remediation, but the current number of replicas is lower that expected. Skipping remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "CurrentReplicas"=2 "Replicas"=3 "UnhealthyMachine"="m1-unhealthy-tw8gn"
=== RUN   TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_a_deleting_machine
I0608 14:41:44.327840   11642 remediation.go:100]  "msg"="A control plane machine needs remediation, but there are other control-plane machines being deleted. Skipping remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-ppt5z"
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x174dbb2]

goroutine 1439 [running]:
testing.tRunner.func1(0xc000c68600)
	/usr/local/go/src/testing/testing.go:874 +0x3a3
panic(0x1930a20, 0x2c7fce0)
... skipping 3 lines ...
sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers.TestReconcileUnhealthyMachines.func5(0xc000c68600)
	/home/prow/go/src/sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers/remediation_test.go:136 +0x695
testing.tRunner(0xc000c68600, 0xc000573470)
	/usr/local/go/src/testing/testing.go:909 +0xc9
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:960 +0x350
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	24.927s
I0608 14:41:30.425112   11614 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0608 14:41:30.425250   11614 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0608 14:41:30.425348   11614 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0608 14:41:30.425379   11614 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0608 14:41:30.425464   11614 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
I0608 14:41:30.425489   11614 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1654699278
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: 1654699278
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
E0608 14:41:32.538283   11614 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"  
E0608 14:41:40.861433   11614 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"  
E0608 14:41:49.847500   11614 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"  
E0608 14:42:00.977818   11614 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"  
E0608 14:42:17.451049   11614 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"  
E0608 14:42:30.459721   11614 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"  
E0608 14:42:48.107240   11614 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"  
E0608 14:43:09.030743   11614 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"  
E0608 14:43:40.047454   11614 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"  
E0608 14:44:25.204630   11614 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 84 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
I0608 14:44:25.214415   11614 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0608 14:44:25.215007   11614 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0608 14:44:25.215096   11614 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-062026632/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	186.748s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
PASS
... skipping 287 lines ...
I0608 14:41:40.912809   11905 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0608 14:41:40.913025   11905 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0608 14:41:41.013430   11905 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0608 14:41:41.113795   11905 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0608 14:41:41.113862   11905 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0608 14:41:41.199447   11905 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-lraf8v"} 
E0608 14:41:41.224300   11905 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"
•I0608 14:41:42.273265   11905 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-ulvzc9"} 
E0608 14:41:42.309098   11905 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"
•E0608 14:41:43.384066   11905 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0608 14:41:44.408569   11905 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"
•E0608 14:41:45.544565   11905 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"
•E0608 14:41:46.570243   11905 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"
E0608 14:41:47.586688   11905 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"
•I0608 14:41:47.592530   11905 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0608 14:41:47.592572   11905 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0608 14:41:47.592805   11905 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 


Ran 5 of 5 Specs in 20.418 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.42s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	20.480s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0608 14:41:31.596460   12111 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 92 lines ...
•I0608 14:41:44.452187   12111 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0608 14:41:44.483078   12111 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0608 14:41:44.486211   12111 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0608 14:41:44.511311   12111 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0608 14:41:44.519588   12111 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0608 14:41:44.542014   12111 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0608 14:41:44.544874   12111 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0608 14:41:44.544926   12111 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-220297236/tls.crt: no such file or directory"  
E0608 14:41:44.544955   12111 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0608 14:41:44.544983   12111 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-220297236/tls.crt: no such file or directory"  
I0608 14:41:44.545255   12111 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 12.851 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (12.85s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	13.259s
?   	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 204 lines ...
I0608 14:42:06.656785   15095 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=45111
I0608 14:42:06.656821   15095 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••I0608 14:42:07.442433   15095 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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