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

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0811 15:05:40.011144    8438 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0811 15:05:40.688255    8438 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" 
•I0811 15:05:40.698794    8438 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 14.608 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.61s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	51.309s
=== 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.01s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0811 15:05:23.297533   10486 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}},"status":{"bootstrapReady":false,"infrastructureReady":false}}}
I0811 15:05:23.297610   10486 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0811 15:05:23.297645   10486 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0811 15:05:23.297688   10486 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0811 15:05:23.298696   10486 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0811 15:05:23.299549   10486 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
2022/08/11 15:05:23 http: TLS handshake error from 127.0.0.1:38332: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0811 15:05:23.394722   10486 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"
I0811 15:05:23.398082   10486 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.01s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0811 15:05:23.450082   10486 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
I0811 15:05:23.451961   10486 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"
E0811 15:05:23.452337   10486 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
I0811 15:05:23.452789   10486 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
I0811 15:05:23.747910   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0811 15:05:23.848765   10486 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0811 15:05:23.896706   10486 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-994rm" "namespace"="test-machine-watches-6g77v" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0811 15:05:23.896813   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0811 15:05:24.015471   10486 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-994rm" "namespace"="test-machine-watches-6g77v" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0811 15:05:24.015568   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0811 15:05:24.116089   10486 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-994rm" "namespace"="test-machine-watches-6g77v" "noderef"="node-1"
E0811 15:05:24.136956   10486 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0811 15:05:24.137017   10486 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0811 15:05:24.194079   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-994rm\" in namespace \"test-machine-watches-6g77v\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-994rm" "namespace"="test-machine-watches-6g77v"
E0811 15:05:25.198338   10486 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-994rm\" in namespace \"test-machine-watches-6g77v\", requeuing: requeue in 1s"  
E0811 15:05:25.209271   10486 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-994rm\" in namespace \"test-machine-watches-6g77v\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-994rm\" in namespace \"test-machine-watches-6g77v\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-994rm" "namespace"="test-machine-watches-6g77v"
--- PASS: TestWatches (1.79s)
=== 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
I0811 15:05:25.430701   10486 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-zghpw" "namespace"="test-machine-watches-6g77v" "count"=1
I0811 15:05:25.430771   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-zghpw" "namespace"="test-machine-watches-6g77v" "descendants"="Worker machines: machine-created-994rm" "indirect descendants count"=0
I0811 15:05:25.449154   10486 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-zghpw" "namespace"="test-machine-watches-6g77v" "count"=1
I0811 15:05:25.449224   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-zghpw" "namespace"="test-machine-watches-6g77v" "descendants"="Worker machines: machine-created-994rm" "indirect descendants count"=0
I0811 15:05:26.209822   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zghpw" "machine"="machine-created-994rm" "namespace"="test-machine-watches-6g77v" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"12264d37-5164-4a41-841d-70c8b904805a","apiVersion":"v1"}
E0811 15:05:26.255119   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-994rm\" not found" "controller"="machine" "name"="machine-created-994rm" "namespace"="test-machine-watches-6g77v"
E0811 15:05:27.296916   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-9h858\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-zbntp\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-zbntp: secrets \"machine-reconcile-zbntp-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-9h858" "namespace"="default"
I0811 15:05:28.297484   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zbntp" "machine"="machine-created-9h858" "namespace"="default" "cause"="noderef is nil" "node"=null
I0811 15:05:28.331712   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zbntp" "machine"="machine-created-9h858" "namespace"="default" "cause"="noderef is nil" "node"=null
I0811 15:05:28.354542   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-zbntp" "machine"="machine-created-9h858" "namespace"="default" "cause"="noderef is nil" "node"=null
E0811 15:05:28.391019   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-9h858\" not found" "controller"="machine" "name"="machine-created-9h858" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.17s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.17s)
=== 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 13 lines ...
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0811 15:05:28.420566   10486 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0811 15:05:28.423130   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-zbntp\" not found" "controller"="cluster" "name"="machine-reconcile-zbntp" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0811 15:05:28.424847   10486 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0811 15:05:28.428868   10486 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
--- PASS: TestReconcileRequest (0.03s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.00s)
... skipping 112 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0811 15:05:28.559665   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wg2h4" "namespace"="test-mhc-crmms" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0811 15:05:28.609455   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0811 15:05:28.609557   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-hhb6j\" not found"  "cluster"="test-mhc-crmms/test-cluster-hhb6j"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
E0811 15:05:28.714463   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-wg2h4\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-wg2h4\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-wg2h4" "namespace"="test-mhc-crmms"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
error cannot retrieve mhc in ctx: MachineHealthCheck.cluster.x-k8s.io "test-mhc-4qr5m" not foundI0811 15:05:29.714810   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nscmx" "namespace"="test-mhc-fl2fw" 
I0811 15:05:29.714924   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wg2h4" "namespace"="test-mhc-crmms" 
I0811 15:05:29.714955   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wcckl" "namespace"="test-mhc-sj8vv" 
I0811 15:05:29.714983   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4qr5m" "namespace"="test-mhc-wlclj" 
I0811 15:05:29.732772   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0811 15:05:29.852260   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4qr5m" "namespace"="test-mhc-wlclj" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0811 15:05:29.937159   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4qr5m" "namespace"="test-mhc-wlclj" 
E0811 15:05:29.948433   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wlclj/test-cluster-qphmw"
E0811 15:05:29.953053   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-qphmw\" not found" "controller"="cluster" "name"="test-cluster-qphmw" "namespace"="test-mhc-wlclj"
I0811 15:05:30.077719   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwzmp" "namespace"="test-mhc-xqppk" 
I0811 15:05:30.100588   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0811 15:05:30.223478   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwzmp" "namespace"="test-mhc-xqppk" 
E0811 15:05:30.282909   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xqppk/test-cluster-5jt6x"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0811 15:05:30.288954   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwzmp" "namespace"="test-mhc-xqppk" 
I0811 15:05:30.307575   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
inframachine created: test-mhc-machine-infra-zsrbc
I0811 15:05:30.321788   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-2jcrt
I0811 15:05:30.422393   10486 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-fnvq7/test-mhc-9294s/test-mhc-machine-2jcrt/"
E0811 15:05:30.432073   10486 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-lb7zf"
E0811 15:05:30.432142   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lb7zf, got []"  "node"="test-mhc-node-lb7zf"
node created: test-mhc-node-lb7zf
inframachine created: test-mhc-machine-infra-sgmfp
machine created: test-mhc-machine-rwm2d
I0811 15:05:30.458231   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.472698   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.473828   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
... skipping 36 lines ...
I0811 15:05:30.633020   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.634140   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.639644   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.645211   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.646530   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.647803   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.648238   10486 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-fnvq7/test-mhc-9294s/test-mhc-machine-rwm2d/"
node created: test-mhc-node-cm8km
E0811 15:05:30.671751   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cm8km, got []"  "node"="test-mhc-node-cm8km"
E0811 15:05:30.672738   10486 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-cm8km"
I0811 15:05:30.676985   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.677679   10486 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-fnvq7/test-mhc-9294s/test-mhc-machine-rwm2d/"
I0811 15:05:30.681743   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.685891   10486 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7" "noderef"="test-mhc-node-cm8km"
I0811 15:05:30.698491   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
Cleaning up nodes, machines and infra machines.
I0811 15:05:30.703350   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.703803   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fnvq7/test-mhc-9294s/test-mhc-machine-2jcrt/"
I0811 15:05:30.728186   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.728704   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fnvq7/test-mhc-9294s/test-mhc-machine-2jcrt/"
I0811 15:05:30.729178   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fnvq7/test-mhc-9294s/test-mhc-machine-rwm2d/"
I0811 15:05:30.755183   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.755732   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fnvq7/test-mhc-9294s/test-mhc-machine-2jcrt/"
I0811 15:05:30.756173   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fnvq7/test-mhc-9294s/test-mhc-machine-rwm2d/"
E0811 15:05:30.764389   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
E0811 15:05:30.768681   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fnvq7/test-cluster-4z4gb"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
I0811 15:05:30.774843   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9294s" "namespace"="test-mhc-fnvq7" 
I0811 15:05:30.797317   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
inframachine created: test-mhc-machine-infra-5q2jt
I0811 15:05:30.813939   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-xpsxb
... skipping 24 lines ...
I0811 15:05:30.999079   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.000826   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.002681   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.004405   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.006279   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.008070   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:31.009490   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-6g77v/machine-reconcile-zghpw"
I0811 15:05:31.009833   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.011599   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.013317   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.015051   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.016933   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.018866   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 324 lines ...
I0811 15:05:31.750277   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.752359   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.754566   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.756553   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.758667   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.761913   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:31.764900   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:31.764697   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.767330   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.769179   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.782911   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.793045   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:31.798814   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 376 lines ...
I0811 15:05:32.750705   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.752526   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.758911   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.760961   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.762713   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.764952   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:32.766243   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
I0811 15:05:32.769007   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.772109   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.776854   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.779220   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.780913   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:32.782710   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 388 lines ...
I0811 15:05:33.768883   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:33.771360   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:33.774254   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:33.775077   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:33.776291   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:33.778917   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:33.779136   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:33.779213   10486 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-psbdf/test-mhc-8t4f9/test-mhc-machine-xpsxb/"
I0811 15:05:33.788636   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:33.788937   10486 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-psbdf/test-mhc-8t4f9/test-mhc-machine-xpsxb/"
E0811 15:05:33.849776   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4x848, got []"  "node"="test-mhc-node-4x848"
node created: test-mhc-node-4x848
I0811 15:05:33.857247   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
inframachine created: test-mhc-machine-infra-p5mgd
machine created: test-mhc-machine-wmfhg
I0811 15:05:33.875912   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:33.881595   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 266 lines ...
I0811 15:05:34.740485   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.742548   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.769508   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.772879   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.775071   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.777215   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:34.779460   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
I0811 15:05:34.779564   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.782814   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.787965   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.794767   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.797032   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:34.799184   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 377 lines ...
I0811 15:05:35.806751   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.808071   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.809086   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.811412   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.813756   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.815090   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:35.815291   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:35.816086   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.817237   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.819539   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.822060   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.824453   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:35.826756   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 364 lines ...
I0811 15:05:36.845610   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:36.847036   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:36.848156   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:36.849217   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:36.851456   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:36.854322   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:36.855904   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
I0811 15:05:36.856667   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:36.857065   10486 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-psbdf/test-mhc-8t4f9/test-mhc-machine-wmfhg/"
I0811 15:05:36.874649   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:36.875065   10486 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-psbdf/test-mhc-8t4f9/test-mhc-machine-wmfhg/"
E0811 15:05:36.905519   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-c22dr, got []"  "node"="test-mhc-node-c22dr"
node created: test-mhc-node-c22dr
I0811 15:05:36.914080   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
inframachine created: test-mhc-machine-infra-nb2bz
machine created: test-mhc-machine-wwtgh
I0811 15:05:36.943809   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:36.956831   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 214 lines ...
I0811 15:05:37.878874   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.886149   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.888818   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.890434   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.891932   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.893627   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:37.895559   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:37.895993   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.897501   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.900018   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.902560   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.906788   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:37.909898   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 282 lines ...
I0811 15:05:38.934560   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.937280   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.940433   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.943930   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.945821   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.948541   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
E0811 15:05:38.950815   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
I0811 15:05:38.951381   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.954967   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.957388   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.962498   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.965107   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:38.968092   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
... skipping 285 lines ...
I0811 15:05:39.935601   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:39.941498   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:39.945146   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:39.949523   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:39.958732   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:39.968591   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:39.969941   10486 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-psbdf/test-mhc-8t4f9/test-mhc-machine-wwtgh/"
E0811 15:05:39.971253   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:39.985691   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:39.986327   10486 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-psbdf/test-mhc-8t4f9/test-mhc-machine-wwtgh/"
E0811 15:05:39.990625   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mgh8r, got []"  "node"="test-mhc-node-mgh8r"
node created: test-mhc-node-mgh8r
I0811 15:05:40.000073   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:40.000681   10486 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-psbdf/test-mhc-8t4f9/test-mhc-machine-wwtgh/test-mhc-node-mgh8r"
Cleaning up nodes, machines and infra machines.
I0811 15:05:40.024834   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
Cleaning up nodes, machines and infra machines.
I0811 15:05:40.025399   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-psbdf/test-mhc-8t4f9/test-mhc-machine-wwtgh/"
I0811 15:05:40.044151   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:40.044737   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-psbdf/test-mhc-8t4f9/test-mhc-machine-xpsxb/"
I0811 15:05:40.063624   10486 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-nm787" "namespace"="test-mhc-psbdf" "count"=2
I0811 15:05:40.063709   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-nm787" "namespace"="test-mhc-psbdf" "descendants"="Worker machines: test-mhc-machine-wmfhg,test-mhc-machine-wwtgh,test-mhc-machine-xpsxb" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0811 15:05:40.068784   10486 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-nm787" "namespace"="test-mhc-psbdf" "count"=2
I0811 15:05:40.068857   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-nm787" "namespace"="test-mhc-psbdf" "descendants"="Worker machines: test-mhc-machine-xpsxb,test-mhc-machine-wmfhg,test-mhc-machine-wwtgh" "indirect descendants count"=1
inframachine created: test-mhc-machine-infra-btdh8
machine created: test-mhc-machine-2m25k
I0811 15:05:40.231988   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-psbdf/test-mhc-8t4f9/test-mhc-machine-wmfhg/"
I0811 15:05:40.243899   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-psbdf/test-mhc-8t4f9/test-mhc-machine-wwtgh/"
E0811 15:05:40.253613   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-8t4f9\" not found" "controller"="machinehealthcheck" "name"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf"
I0811 15:05:40.971780   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-nm787" "machine"="test-mhc-machine-wmfhg" "namespace"="test-mhc-psbdf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-c22dr"}
E0811 15:05:41.028197   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wmfhg\" not found" "controller"="machine" "name"="test-mhc-machine-wmfhg" "namespace"="test-mhc-psbdf"
I0811 15:05:41.258824   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:41.278346   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0811 15:05:41.406549   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8t4f9" "namespace"="test-mhc-psbdf" 
I0811 15:05:41.406668   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:41.412885   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:41.423052   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:41.464079   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:41.545184   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:41.706281   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:42.027251   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
E0811 15:05:42.029628   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
I0811 15:05:42.670117   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:43.030143   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-nm787" "machine"="test-mhc-machine-wwtgh" "namespace"="test-mhc-psbdf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mgh8r"}
E0811 15:05:43.107952   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wwtgh\" not found" "controller"="machine" "name"="test-mhc-machine-wwtgh" "namespace"="test-mhc-psbdf"
I0811 15:05:43.951188   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:44.108518   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-nm787" "machine"="test-mhc-machine-xpsxb" "namespace"="test-mhc-psbdf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4x848"}
E0811 15:05:44.154422   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xpsxb\" not found" "controller"="machine" "name"="test-mhc-machine-xpsxb" "namespace"="test-mhc-psbdf"
E0811 15:05:45.091617   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-psbdf/test-cluster-nm787"
E0811 15:05:45.154857   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:46.163023   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:46.168543   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
E0811 15:05:46.172748   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
E0811 15:05:46.197267   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-k4rms, got []"  "node"="test-mhc-node-k4rms"
node created: test-mhc-node-k4rms
I0811 15:05:46.202591   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:46.206796   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
inframachine created: test-mhc-machine-infra-8t9w2
machine created: test-mhc-machine-kp7dn
I0811 15:05:46.228026   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:46.416967   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:46.423696   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:46.433813   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:46.475186   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:46.556683   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:46.718030   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:47.039487   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
E0811 15:05:47.173254   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:47.684059   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:48.190490   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:48.202762   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:48.205219   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:48.223594   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:48.232867   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:48.238227   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
E0811 15:05:48.240178   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
node created: test-mhc-node-swplg
E0811 15:05:48.250642   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-swplg, got []"  "node"="test-mhc-node-swplg"
I0811 15:05:48.264566   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
inframachine created: test-mhc-machine-infra-fbtkr
I0811 15:05:48.278144   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
machine created: test-mhc-machine-gxqwz
I0811 15:05:48.282190   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:48.295169   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:48.968122   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
E0811 15:05:49.240852   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:50.252146   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:50.271691   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:50.278022   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:50.288342   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:50.292685   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:50.299396   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:50.304233   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
E0811 15:05:50.304858   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
I0811 15:05:50.365363   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
E0811 15:05:50.395735   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2768x, got []"  "node"="test-mhc-node-2768x"
node created: test-mhc-node-2768x
I0811 15:05:50.403295   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
Cleaning up nodes, machines and infra machines.
I0811 15:05:50.416526   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:50.435480   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
Cleaning up nodes, machines and infra machines.
... skipping 5 lines ...
inframachine created: test-mhc-machine-infra-txtvq
machine created: test-mhc-machine-ptzxb
I0811 15:05:50.656853   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:50.675032   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0811 15:05:50.705611   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-r85ml" "namespace"="test-mhc-vlprs" 
I0811 15:05:50.705683   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
E0811 15:05:51.305274   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:52.305844   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-66r4t" "machine"="test-mhc-machine-2m25k" "namespace"="test-mhc-vlprs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-k4rms"}
E0811 15:05:52.350731   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2m25k\" not found" "controller"="machine" "name"="test-mhc-machine-2m25k" "namespace"="test-mhc-vlprs"
I0811 15:05:53.352675   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-66r4t" "machine"="test-mhc-machine-kp7dn" "namespace"="test-mhc-vlprs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-swplg"}
E0811 15:05:53.394229   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kp7dn\" not found" "controller"="machine" "name"="test-mhc-machine-kp7dn" "namespace"="test-mhc-vlprs"
I0811 15:05:54.394810   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-66r4t" "machine"="test-mhc-machine-gxqwz" "namespace"="test-mhc-vlprs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2768x"}
E0811 15:05:54.438458   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-gxqwz\" not found" "controller"="machine" "name"="test-mhc-machine-gxqwz" "namespace"="test-mhc-vlprs"
I0811 15:05:55.449419   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:55.459020   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
E0811 15:05:55.460492   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
node created: test-mhc-node-phpsp
E0811 15:05:55.479041   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-phpsp, got []"  "node"="test-mhc-node-phpsp"
E0811 15:05:55.479263   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-phpsp, got []"  "node"="test-mhc-node-phpsp"
I0811 15:05:55.487266   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
inframachine created: test-mhc-machine-infra-5cc6w
machine created: test-mhc-machine-wgn57
I0811 15:05:55.505666   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:55.511619   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
E0811 15:05:55.513520   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vlprs/test-cluster-66r4t"
I0811 15:05:55.518327   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
E0811 15:05:56.460914   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:05:57.475713   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.484660   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.502045   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.519321   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.539018   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.545472   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.558378   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.580820   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.590449   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.595625   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.611572   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
node created: test-mhc-node-bcccl
E0811 15:05:57.614353   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bcccl, got []"  "node"="test-mhc-node-bcccl"
I0811 15:05:57.617145   10486 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-wgn57" "namespace"="test-mhc-fddx7" "noderef"="test-mhc-node-bcccl"
I0811 15:05:57.622506   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
inframachine created: test-mhc-machine-infra-vmsnv
machine created: test-mhc-machine-4tllm
I0811 15:05:57.653830   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.659628   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
... skipping 5 lines ...
Cleaning up nodes, machines and infra machines.
I0811 15:05:57.854329   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.873573   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
Cleaning up nodes, machines and infra machines.
I0811 15:05:57.877050   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.884617   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.885289   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fddx7/test-mhc-cl6v6/test-mhc-machine-ptzxb/"
I0811 15:05:57.888812   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jp2qf" "machine"="test-mhc-machine-4tllm" "namespace"="test-mhc-fddx7" "cause"="noderef is nil" "node"=null
I0811 15:05:57.913407   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.913927   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fddx7/test-mhc-cl6v6/test-mhc-machine-ptzxb/"
I0811 15:05:57.914259   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fddx7/test-mhc-cl6v6/test-mhc-machine-wgn57/"
I0811 15:05:57.936216   10486 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jp2qf" "namespace"="test-mhc-fddx7" "count"=3
I0811 15:05:57.936313   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jp2qf" "namespace"="test-mhc-fddx7" "descendants"="Worker machines: test-mhc-machine-ptzxb,test-mhc-machine-wgn57,test-mhc-machine-4tllm" "indirect descendants count"=0
I0811 15:05:57.942930   10486 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jp2qf" "namespace"="test-mhc-fddx7" "count"=3
I0811 15:05:57.943000   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jp2qf" "namespace"="test-mhc-fddx7" "descendants"="Worker machines: test-mhc-machine-wgn57,test-mhc-machine-4tllm,test-mhc-machine-ptzxb" "indirect descendants count"=0
I0811 15:05:57.952860   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:57.953653   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fddx7/test-mhc-cl6v6/test-mhc-machine-ptzxb/"
I0811 15:05:57.954088   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fddx7/test-mhc-cl6v6/test-mhc-machine-wgn57/"
=== 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
E0811 15:05:57.960121   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-cl6v6\" not found" "controller"="machinehealthcheck" "name"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7"
E0811 15:05:57.977141   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-4tllm\" not found" "controller"="machine" "name"="test-mhc-machine-4tllm" "namespace"="test-mhc-fddx7"
inframachine created: test-mhc-machine-infra-tpm8l
machine created: test-mhc-machine-sv7b6
I0811 15:05:58.960435   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cl6v6" "namespace"="test-mhc-fddx7" 
I0811 15:05:58.960579   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:05:58.978149   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jp2qf" "machine"="test-mhc-machine-ptzxb" "namespace"="test-mhc-fddx7" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-phpsp"}
I0811 15:05:58.985244   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0811 15:05:59.048953   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:05:59.053476   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:05:59.054767   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
E0811 15:05:59.055570   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ptzxb\" not found" "controller"="machine" "name"="test-mhc-machine-ptzxb" "namespace"="test-mhc-fddx7"
I0811 15:05:59.056896   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:05:59.059010   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:05:59.062884   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:05:59.070510   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:05:59.080855   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:05:59.082180   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
... skipping 500 lines ...
I0811 15:06:00.094495   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.096373   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.098083   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.099794   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.102723   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.105010   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
E0811 15:06:00.105793   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wgn57\" not found" "controller"="machine" "name"="test-mhc-machine-wgn57" "namespace"="test-mhc-fddx7"
I0811 15:06:00.106718   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.108486   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.110166   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.111952   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.113649   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:00.115409   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
... skipping 493 lines ...
I0811 15:06:01.095610   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.097315   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.099818   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.101545   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.103161   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.104775   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
E0811 15:06:01.106151   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
I0811 15:06:01.106325   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.108028   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.109813   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.111520   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.113237   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:01.115463   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
... skipping 468 lines ...
I0811 15:06:02.113516   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.115261   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.115827   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.116927   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.119013   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.121349   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
E0811 15:06:02.121609   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:06:02.122335   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.122662   10486 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-kjr4d/test-mhc-w6b4n/test-mhc-machine-sv7b6/"
node created: test-mhc-node-zwrtv
E0811 15:06:02.132277   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zwrtv, got []"  "node"="test-mhc-node-zwrtv"
E0811 15:06:02.132501   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zwrtv, got []"  "node"="test-mhc-node-zwrtv"
I0811 15:06:02.136420   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.136762   10486 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-kjr4d/test-mhc-w6b4n/test-mhc-machine-sv7b6/"
I0811 15:06:02.138814   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.158045   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.162550   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.162910   10486 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-kjr4d/test-mhc-w6b4n/test-mhc-machine-sv7b6/test-mhc-node-zwrtv"
I0811 15:06:02.177805   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.178181   10486 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-kjr4d/test-mhc-w6b4n/test-mhc-machine-sv7b6/test-mhc-node-zwrtv"
Cleaning up nodes, machines and infra machines.
I0811 15:06:02.190419   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.190804   10486 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-kjr4d/test-mhc-w6b4n/test-mhc-machine-sv7b6/test-mhc-node-zwrtv"
I0811 15:06:02.191855   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.192124   10486 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-kjr4d/test-mhc-w6b4n/test-mhc-machine-sv7b6/"
I0811 15:06:02.247981   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ksqxt" "namespace"="test-mhc-kjr4d" "descendants"="Worker machines: test-mhc-machine-sv7b6" "indirect descendants count"=1
I0811 15:06:02.251896   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ksqxt" "namespace"="test-mhc-kjr4d" "descendants"="Worker machines: test-mhc-machine-sv7b6" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0811 15:06:02.415311   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-w6b4n" "namespace"="test-mhc-kjr4d" 
I0811 15:06:02.415856   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" "creating"=1 "need"=1
I0811 15:06:02.415903   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" 
I0811 15:06:02.455102   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-hqc4j-k58k6\"" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" 
I0811 15:06:02.480205   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:02.500496   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0811 15:06:02.561595   10486 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" 
I0811 15:06:02.619910   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:02.620636   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
E0811 15:06:02.956883   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fddx7/test-cluster-jp2qf"
I0811 15:06:03.122210   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ksqxt" "machine"="test-mhc-machine-sv7b6" "namespace"="test-mhc-kjr4d" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zwrtv"}
E0811 15:06:03.191554   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-sv7b6\" not found" "controller"="machine" "name"="test-mhc-machine-sv7b6" "namespace"="test-mhc-kjr4d"
I0811 15:06:03.620113   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:04.200779   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:04.201603   10486 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" 
I0811 15:06:04.212818   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:04.213088   10486 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" 
I0811 15:06:04.227046   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
... skipping 8 lines ...
I0811 15:06:04.275101   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
I0811 15:06:04.275158   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
I0811 15:06:04.621130   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:05.248516   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
I0811 15:06:05.248565   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.000615   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.001038   10486 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-4x8gs/test-mhc-lnjm5/mhc-ms-hqc4j-k58k6/"
I0811 15:06:06.008194   10486 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.013458   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.013845   10486 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-4x8gs/test-mhc-lnjm5/mhc-ms-hqc4j-k58k6/"
I0811 15:06:06.014556   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.014590   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.020777   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.021123   10486 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-4x8gs/test-mhc-lnjm5/mhc-ms-hqc4j-k58k6/"
I0811 15:06:06.021243   10486 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.035237   10486 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-b5jfq" "namespace"="test-mhc-4x8gs" "count"=1
I0811 15:06:06.035294   10486 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-b5jfq" "namespace"="test-mhc-4x8gs" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-hqc4j"
I0811 15:06:06.037010   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.037053   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.039048   10486 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" "machine"="mhc-ms-hqc4j-k58k6"
I0811 15:06:06.041118   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lnjm5" "namespace"="test-mhc-4x8gs" 
I0811 15:06:06.041605   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-b5jfq" "namespace"="test-mhc-4x8gs" "descendants"="Machine sets: mhc-ms-hqc4j;Worker machines: mhc-ms-hqc4j-k58k6" "indirect descendants count"=1
I0811 15:06:06.044211   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-b5jfq" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" "cause"="cluster is being deleted" "node"=null
I0811 15:06:06.047480   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-b5jfq" "namespace"="test-mhc-4x8gs" "descendants"="Worker machines: mhc-ms-hqc4j-k58k6" "indirect descendants count"=1
E0811 15:06:06.060144   10486 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-hqc4j\" not found" "machineset"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs" 
E0811 15:06:06.060238   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-hqc4j\" not found" "controller"="machineset" "name"="mhc-ms-hqc4j" "namespace"="test-mhc-4x8gs"
=== 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
I0811 15:06:06.114246   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
inframachine created: test-mhc-machine-infra-krnwd
I0811 15:06:06.137028   10486 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-wzmxc
... skipping 2 lines ...
I0811 15:06:06.264350   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.266315   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.268029   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.268849   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.270638   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.272454   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
E0811 15:06:06.272592   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
I0811 15:06:06.307707   10486 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-wzmxc" "target"="test-mhc-htpgx/test-mhc-7p6c2/test-mhc-machine-wzmxc/"
I0811 15:06:06.320307   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
E0811 15:06:06.343543   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2d5c, got []"  "node"="test-mhc-node-g2d5c"
E0811 15:06:06.343543   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2d5c, got []"  "node"="test-mhc-node-g2d5c"
E0811 15:06:06.343803   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2d5c, got []"  "node"="test-mhc-node-g2d5c"
node created: test-mhc-node-g2d5c
I0811 15:06:06.350979   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.369432   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.384940   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.412875   10486 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-wzmxc" "target"="test-mhc-htpgx/test-mhc-7p6c2/test-mhc-machine-wzmxc/test-mhc-node-g2d5c"
I0811 15:06:06.430849   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.437773   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
Cleaning up nodes, machines and infra machines.
I0811 15:06:06.443381   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.446072   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
I0811 15:06:06.454568   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7p6c2" "namespace"="test-mhc-htpgx" 
... skipping 345 lines ...
I0811 15:06:07.255575   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.257269   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.259138   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.261480   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.263152   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.264929   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
E0811 15:06:07.265330   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kjr4d/test-cluster-ksqxt"
I0811 15:06:07.266924   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.268688   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.270753   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.272539   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.273027   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-b5jfq" "machine"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs" "cause"="cluster is being deleted" "node"=null
I0811 15:06:07.274523   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
... skipping 8 lines ...
I0811 15:06:07.291547   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.293545   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.295550   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.297317   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.299030   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.301130   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
E0811 15:06:07.302088   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-hqc4j-k58k6\" not found" "controller"="machine" "name"="mhc-ms-hqc4j-k58k6" "namespace"="test-mhc-4x8gs"
I0811 15:06:07.303027   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.304772   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.306359   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.307999   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.309612   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:07.311447   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
... skipping 576 lines ...
I0811 15:06:08.327789   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.329668   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.331469   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.333401   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.335226   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.337094   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
E0811 15:06:08.338120   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wzmxc\" not found" "controller"="machine" "name"="test-mhc-machine-wzmxc" "namespace"="test-mhc-htpgx"
I0811 15:06:08.338918   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.340848   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.342594   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.344457   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.346170   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:08.347818   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
... skipping 554 lines ...
I0811 15:06:09.344383   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.345018   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.345487   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.346046   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.347764   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.350119   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
E0811 15:06:09.350598   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:06:09.350771   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.354048   10486 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-zjdgn" "target"="test-mhc-k5m74/test-mhc-hv5ss/test-mhc-machine-zjdgn/"
I0811 15:06:09.363664   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
node created: test-mhc-node-5wvmt
E0811 15:06:09.433475   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5wvmt, got []"  "node"="test-mhc-node-5wvmt"
E0811 15:06:09.433505   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5wvmt, got []"  "node"="test-mhc-node-5wvmt"
E0811 15:06:09.433610   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5wvmt, got []"  "node"="test-mhc-node-5wvmt"
I0811 15:06:09.439633   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.458997   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.462443   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.465623   10486 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-zjdgn" "target"="test-mhc-k5m74/test-mhc-hv5ss/test-mhc-machine-zjdgn/test-mhc-node-5wvmt"
I0811 15:06:09.484451   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.486713   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.496243   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.513396   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.518441   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
Cleaning up nodes, machines and infra machines.
I0811 15:06:09.523192   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
I0811 15:06:09.529780   10486 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-zjdgn" "target"="test-mhc-k5m74/test-mhc-hv5ss/test-mhc-machine-zjdgn/"
I0811 15:06:09.535001   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mzf9l" "namespace"="test-mhc-k5m74" "descendants"="Worker machines: test-mhc-machine-zjdgn" "indirect descendants count"=1
E0811 15:06:09.551906   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-hv5ss\" not found" "controller"="machinehealthcheck" "name"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74"
I0811 15:06:09.559963   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mzf9l" "namespace"="test-mhc-k5m74" "descendants"="Worker machines: test-mhc-machine-zjdgn" "indirect descendants count"=1
--- PASS: TestMachineHealthCheck_Reconcile (41.02s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.13s)
    --- 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.19s)
... skipping 11 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.41s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.09s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0811 15:06:09.560651   10486 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
E0811 15:06:09.562224   10486 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
E0811 15:06:09.563797   10486 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0811 15:06:09.563957   10486 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
E0811 15:06:09.564272   10486 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
I0811 15:06:09.566311   10486 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0811 15:06:09.566724   10486 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0811 15:06:09.567871   10486 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
E0811 15:06:09.573909   10486 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
E0811 15:06:09.575439   10486 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 65 lines ...
I0811 15:06:09.663096   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-g95tz-pwcr7\"" "machineset"="ms-g95tz" "namespace"="ms-test" 
I0811 15:06:09.663151   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-g95tz" "namespace"="ms-test" 
I0811 15:06:09.675303   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-g95tz-5vtkl\"" "machineset"="ms-g95tz" "namespace"="ms-test" 
I0811 15:06:09.781861   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-g95tz" "namespace"="ms-test" "creating"=1 "need"=2
I0811 15:06:09.781916   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-g95tz" "namespace"="ms-test" 
I0811 15:06:09.794514   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-g95tz-pqqtx\"" "machineset"="ms-g95tz" "namespace"="ms-test" 
E0811 15:06:09.892671   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:09.892874   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:09.892894   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:09.996622   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:09.996680   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:09.996697   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:09.996749   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:09.996697   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:09.996782   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-pqqtx-x48bj, got []"  "node"="ms-g95tz-pqqtx-x48bj"
E0811 15:06:10.020053   10486 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-g95tz-pqqtx-x48bj for machine ms-test/ms-g95tz-pqqtx: the cache is not started, can not read objects" "machineset"="ms-g95tz" "namespace"="ms-test" 
E0811 15:06:10.026547   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
E0811 15:06:10.026547   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
E0811 15:06:10.026656   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
E0811 15:06:10.029306   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
E0811 15:06:10.029357   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
E0811 15:06:10.029367   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
E0811 15:06:10.029383   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
E0811 15:06:10.029397   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
E0811 15:06:10.029428   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-g95tz-5vtkl-b4l92, got []"  "node"="ms-g95tz-5vtkl-b4l92"
I0811 15:06:10.149133   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-g95tz-pqqtx,ms-g95tz-5vtkl" "indirect descendants count"=2
•I0811 15:06:10.156137   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-g95tz-pqqtx,ms-g95tz-5vtkl" "indirect descendants count"=2
I0811 15:06:10.212540   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0811 15:06:10.212600   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
I0811 15:06:10.221561   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-8pktp-6657c7fddb-nwqfd\"" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
I0811 15:06:10.221632   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
I0811 15:06:10.230587   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-8pktp-6657c7fddb-mllq4\"" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
I0811 15:06:10.339515   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0811 15:06:10.339565   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
I0811 15:06:10.348211   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-8pktp-6657c7fddb-kwbsq\"" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
I0811 15:06:10.348263   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
I0811 15:06:10.351067   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mzf9l" "machine"="test-mhc-machine-zjdgn" "namespace"="test-mhc-k5m74" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5wvmt"}
I0811 15:06:10.358357   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-8pktp-6657c7fddb-xsp87\"" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
E0811 15:06:10.382349   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zjdgn\" not found" "controller"="machine" "name"="test-mhc-machine-zjdgn" "namespace"="test-mhc-k5m74"
I0811 15:06:10.462788   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0811 15:06:10.462834   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
I0811 15:06:10.471704   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8pktp-6657c7fddb-fzj24\"" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" 
E0811 15:06:10.512536   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Operation cannot be fulfilled on machinedeployments.cluster.x-k8s.io \"md-8pktp\": the object has been modified; please apply your changes to the latest version and try again" "controller"="machinedeployment" "name"="md-8pktp" "namespace"="md-test"
I0811 15:06:10.552195   10486 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hv5ss" "namespace"="test-mhc-k5m74" 
E0811 15:06:11.058836   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4x8gs/test-cluster-b5jfq"
E0811 15:06:11.473776   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-htpgx/test-cluster-f4tpg"
I0811 15:06:11.526252   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:11.526291   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:11.527258   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0811 15:06:11.527337   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" 
I0811 15:06:11.539199   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8pktp-cdfc6fd6c-fgc8n\"" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" 
I0811 15:06:11.543920   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:11.543974   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:11.562504   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-kwbsq" "namespace"="md-test" 
I0811 15:06:11.562552   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-kwbsq" "namespace"="md-test" 
I0811 15:06:11.577986   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-xsp87" "namespace"="md-test" 
I0811 15:06:11.578032   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-xsp87" "namespace"="md-test" 
I0811 15:06:11.592845   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-fzj24" "namespace"="md-test" 
I0811 15:06:11.592881   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-fzj24" "namespace"="md-test" 
E0811 15:06:11.644883   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-fgc8n-vmjrw, got []"  "node"="md-8pktp-cdfc6fd6c-fgc8n-vmjrw"
I0811 15:06:11.649847   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:11.649888   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:11.666856   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:11.666894   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:11.670105   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-kwbsq" "namespace"="md-test" 
I0811 15:06:11.670137   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-kwbsq" "namespace"="md-test" 
I0811 15:06:11.673596   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-xsp87" "namespace"="md-test" 
I0811 15:06:11.673675   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-xsp87" "namespace"="md-test" 
I0811 15:06:11.676791   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-fzj24" "namespace"="md-test" 
I0811 15:06:11.676820   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-fzj24" "namespace"="md-test" 
E0811 15:06:11.700442   10486 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"="md-8pktp-cdfc6fd6c-fgc8n" "namespace"="md-test" 
E0811 15:06:11.716842   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="the cache is not started, can not read objects" "controller"="machine" "name"="md-8pktp-cdfc6fd6c-fgc8n" "namespace"="md-test"
E0811 15:06:11.748579   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-fgc8n-vmjrw, got []"  "node"="md-8pktp-cdfc6fd6c-fgc8n-vmjrw"
E0811 15:06:11.748646   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-fgc8n-vmjrw, got []"  "node"="md-8pktp-cdfc6fd6c-fgc8n-vmjrw"
I0811 15:06:11.791135   10486 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0811 15:06:11.791183   10486 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0811 15:06:11.795796   10486 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "machine"="md-8pktp-6657c7fddb-fzj24"
I0811 15:06:11.814102   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0811 15:06:11.814150   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" 
I0811 15:06:11.831972   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8pktp-cdfc6fd6c-85tl8\"" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" 
E0811 15:06:11.878397   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-85tl8-7fz6s, got []"  "node"="md-8pktp-cdfc6fd6c-85tl8-7fz6s"
E0811 15:06:11.881686   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-85tl8-7fz6s, got []"  "node"="md-8pktp-cdfc6fd6c-85tl8-7fz6s"
E0811 15:06:11.881745   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-85tl8-7fz6s, got []"  "node"="md-8pktp-cdfc6fd6c-85tl8-7fz6s"
I0811 15:06:11.973542   10486 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0811 15:06:11.973598   10486 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0811 15:06:11.980654   10486 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "machine"="md-8pktp-6657c7fddb-kwbsq"
I0811 15:06:12.030946   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0811 15:06:12.031051   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" 
I0811 15:06:12.047955   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8pktp-cdfc6fd6c-7w7l9\"" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" 
E0811 15:06:12.170374   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-7w7l9-n9cjb, got []"  "node"="md-8pktp-cdfc6fd6c-7w7l9-n9cjb"
E0811 15:06:12.274782   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-7w7l9-n9cjb, got []"  "node"="md-8pktp-cdfc6fd6c-7w7l9-n9cjb"
E0811 15:06:12.274839   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-cdfc6fd6c-7w7l9-n9cjb, got []"  "node"="md-8pktp-cdfc6fd6c-7w7l9-n9cjb"
I0811 15:06:12.313259   10486 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0811 15:06:12.313307   10486 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0811 15:06:12.317059   10486 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8pktp-6657c7fddb" "namespace"="md-test" "machine"="md-8pktp-6657c7fddb-xsp87"
I0811 15:06:12.584303   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0811 15:06:12.584352   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" 
I0811 15:06:12.603123   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8pktp-74d45c49c5-2tbvn\"" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" 
E0811 15:06:12.677660   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-2tbvn-4q5ds, got []"  "node"="md-8pktp-74d45c49c5-2tbvn-4q5ds"
E0811 15:06:12.742441   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-cdfc6fd6c-fgc8n\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-cdfc6fd6c-fgc8n" "namespace"="md-test"
E0811 15:06:12.781383   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-2tbvn-4q5ds, got []"  "node"="md-8pktp-74d45c49c5-2tbvn-4q5ds"
E0811 15:06:12.781441   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-2tbvn-4q5ds, got []"  "node"="md-8pktp-74d45c49c5-2tbvn-4q5ds"
I0811 15:06:12.849586   10486 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0811 15:06:12.849641   10486 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0811 15:06:12.861232   10486 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "machine"="md-8pktp-cdfc6fd6c-fgc8n"
I0811 15:06:12.969969   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0811 15:06:12.970079   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" 
I0811 15:06:12.980272   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8pktp-74d45c49c5-mlmcd\"" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" 
E0811 15:06:13.035240   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-mlmcd-hx2g7, got []"  "node"="md-8pktp-74d45c49c5-mlmcd-hx2g7"
E0811 15:06:13.038721   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-mlmcd-hx2g7, got []"  "node"="md-8pktp-74d45c49c5-mlmcd-hx2g7"
E0811 15:06:13.040193   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-mlmcd-hx2g7, got []"  "node"="md-8pktp-74d45c49c5-mlmcd-hx2g7"
I0811 15:06:13.080193   10486 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0811 15:06:13.080268   10486 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0811 15:06:13.085997   10486 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8pktp-cdfc6fd6c" "namespace"="md-test" "machine"="md-8pktp-cdfc6fd6c-7w7l9"
I0811 15:06:13.196437   10486 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0811 15:06:13.196482   10486 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" 
I0811 15:06:13.206150   10486 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8pktp-74d45c49c5-x9tn9\"" "machineset"="md-8pktp-74d45c49c5" "namespace"="md-test" 
E0811 15:06:13.313844   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-x9tn9-fp6z9, got []"  "node"="md-8pktp-74d45c49c5-x9tn9-fp6z9"
E0811 15:06:13.417373   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-x9tn9-fp6z9, got []"  "node"="md-8pktp-74d45c49c5-x9tn9-fp6z9"
E0811 15:06:13.417440   10486 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8pktp-74d45c49c5-x9tn9-fp6z9, got []"  "node"="md-8pktp-74d45c49c5-x9tn9-fp6z9"
I0811 15:06:13.449468   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8pktp-74d45c49c5,md-8pktp-cdfc6fd6c;Worker machines: md-8pktp-74d45c49c5-2tbvn,md-8pktp-6657c7fddb-nwqfd,md-8pktp-6657c7fddb-kwbsq,md-8pktp-6657c7fddb-xsp87,md-8pktp-cdfc6fd6c-85tl8,md-8pktp-6657c7fddb-mllq4,md-8pktp-6657c7fddb-fzj24,md-8pktp-cdfc6fd6c-fgc8n,md-8pktp-74d45c49c5-mlmcd,md-8pktp-74d45c49c5-x9tn9" "indirect descendants count"=12
•I0811 15:06:13.452518   10486 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"
I0811 15:06:13.453609   10486 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0811 15:06:13.453666   10486 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"
I0811 15:06:13.454558   10486 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0811 15:06:13.454602   10486 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0811 15:06:13.454921   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8pktp-74d45c49c5,md-8pktp-cdfc6fd6c;Worker machines: md-8pktp-6657c7fddb-mllq4,md-8pktp-6657c7fddb-fzj24,md-8pktp-cdfc6fd6c-fgc8n,md-8pktp-74d45c49c5-mlmcd,md-8pktp-74d45c49c5-x9tn9,md-8pktp-6657c7fddb-nwqfd,md-8pktp-6657c7fddb-kwbsq,md-8pktp-6657c7fddb-xsp87,md-8pktp-cdfc6fd6c-85tl8,md-8pktp-74d45c49c5-2tbvn" "indirect descendants count"=12
I0811 15:06:13.455272   10486 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"
I0811 15:06:13.456047   10486 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0811 15:06:13.456092   10486 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"
E0811 15:06:13.456627   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-8pktp\" not found" "controller"="machinedeployment" "name"="md-8pktp" "namespace"="md-test"
I0811 15:06:13.456789   10486 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0811 15:06:13.456831   10486 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0811 15:06:13.457338   10486 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"
I0811 15:06:13.458482   10486 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"
I0811 15:06:13.459420   10486 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0811 15:06:13.459457   10486 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
... skipping 8 lines ...
I0811 15:06:13.465740   10486 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"
•I0811 15:06:13.467438   10486 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"
I0811 15:06:13.468136   10486 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"
I0811 15:06:13.468823   10486 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0811 15:06:13.468858   10486 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0811 15:06:13.469476   10486 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0811 15:06:13.471304   10486 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" 
••E0811 15:06:13.598692   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-rq2hx\" not found" "controller"="cluster" "name"="test1-rq2hx" "namespace"="default"
I0811 15:06:13.743077   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8pktp-6657c7fddb-fzj24" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0811 15:06:13.766837   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8pktp-6657c7fddb-kwbsq" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0811 15:06:13.792054   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8pktp-6657c7fddb-xsp87" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0811 15:06:13.822896   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:13.822937   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:13.826370   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:13.826418   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:13.838932   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8pktp-cdfc6fd6c-fgc8n" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-8pktp-cdfc6fd6c-fgc8n-vmjrw"}
I0811 15:06:13.882653   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8pktp-6657c7fddb-fzj24" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0811 15:06:13.905408   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-8pktp-6657c7fddb-fzj24\" not found" "controller"="machine" "name"="md-8pktp-6657c7fddb-fzj24" "namespace"="md-test"
E0811 15:06:14.617483   10486 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-k5m74/test-cluster-mzf9l"
•I0811 15:06:14.714472   10486 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-mpd5w" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0811 15:06:14.829135   10486 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-mpd5w" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0811 15:06:14.832851   10486 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-mpd5w" "namespace"="default"
I0811 15:06:14.905933   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8pktp-6657c7fddb-kwbsq" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0811 15:06:14.931901   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-8pktp-6657c7fddb-kwbsq\" not found" "controller"="machine" "name"="md-8pktp-6657c7fddb-kwbsq" "namespace"="md-test"
E0811 15:06:15.845955   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
•I0811 15:06:15.932596   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8pktp-6657c7fddb-xsp87" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0811 15:06:16.060838   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-8pktp-6657c7fddb-xsp87\" not found" "controller"="machine" "name"="md-8pktp-6657c7fddb-xsp87" "namespace"="md-test"
I0811 15:06:16.846594   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-g95tz-pqqtx,ms-g95tz-5vtkl" "indirect descendants count"=2
E0811 15:06:16.858597   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-cgbq5\" not found" "controller"="cluster" "name"="test3-cgbq5" "namespace"="default"
E0811 15:06:17.085142   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-2tbvn\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-2tbvn" "namespace"="md-test"
E0811 15:06:17.859401   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
I0811 15:06:18.085702   10486 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-8pktp-cdfc6fd6c-fgc8n" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-8pktp-cdfc6fd6c-fgc8n-vmjrw"}
E0811 15:06:18.108826   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-8pktp-cdfc6fd6c-fgc8n\" not found" "controller"="machine" "name"="md-8pktp-cdfc6fd6c-fgc8n" "namespace"="md-test"
E0811 15:06:18.869272   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
•E0811 15:06:19.131354   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-mlmcd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-mlmcd" "namespace"="md-test"
I0811 15:06:19.869933   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8pktp-74d45c49c5,md-8pktp-cdfc6fd6c;Worker machines: md-8pktp-6657c7fddb-nwqfd,md-8pktp-74d45c49c5-2tbvn,md-8pktp-6657c7fddb-mllq4,md-8pktp-74d45c49c5-mlmcd,md-8pktp-74d45c49c5-x9tn9" "indirect descendants count"=7
E0811 15:06:19.874229   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"
I0811 15:06:20.157057   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:20.157107   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:20.161036   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:20.161080   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
E0811 15:06:20.161605   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-2jcrt\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-2jcrt" "namespace"="test-mhc-fnvq7"
E0811 15:06:20.875090   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
E0811 15:06:21.166885   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-2tbvn\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-2tbvn" "namespace"="md-test"
E0811 15:06:21.884034   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"
•E0811 15:06:22.172282   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-mlmcd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-mlmcd" "namespace"="md-test"
E0811 15:06:22.884722   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
E0811 15:06:23.172807   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4z4gb\" for machine \"test-mhc-machine-rwm2d\" in namespace \"test-mhc-fnvq7\": Cluster.cluster.x-k8s.io \"test-cluster-4z4gb\" not found" "controller"="machine" "name"="test-mhc-machine-rwm2d" "namespace"="test-mhc-fnvq7"
I0811 15:06:23.885276   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-g95tz-pqqtx,ms-g95tz-5vtkl" "indirect descendants count"=2
E0811 15:06:23.885750   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"
I0811 15:06:24.181213   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:24.181247   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:24.184842   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:24.184880   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
E0811 15:06:24.188646   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-2tbvn\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-2tbvn" "namespace"="md-test"
E0811 15:06:24.895390   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
E0811 15:06:25.193394   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-mlmcd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-mlmcd" "namespace"="md-test"
E0811 15:06:25.896070   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"
E0811 15:06:26.198814   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-2tbvn\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-2tbvn" "namespace"="md-test"
I0811 15:06:26.896797   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8pktp-74d45c49c5,md-8pktp-cdfc6fd6c;Worker machines: md-8pktp-6657c7fddb-nwqfd,md-8pktp-74d45c49c5-2tbvn,md-8pktp-6657c7fddb-mllq4,md-8pktp-74d45c49c5-mlmcd,md-8pktp-74d45c49c5-x9tn9" "indirect descendants count"=7
E0811 15:06:26.897400   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
I0811 15:06:27.215496   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:27.215544   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:27.219016   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:27.219064   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
E0811 15:06:27.223132   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-mlmcd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-mlmcd" "namespace"="md-test"
E0811 15:06:27.898095   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"
E0811 15:06:28.228050   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-2tbvn\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-2tbvn" "namespace"="md-test"
E0811 15:06:28.898789   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
I0811 15:06:29.249325   10486 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-xvtln" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0811 15:06:29.270747   10486 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-xvtln" "namespace"="default" 
E0811 15:06:29.289172   10486 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-xvtln" "namespace"="default"
E0811 15:06:29.899439   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"
E0811 15:06:30.294927   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-mlmcd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-mlmcd" "namespace"="md-test"
I0811 15:06:30.900149   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-g95tz-pqqtx,ms-g95tz-5vtkl" "indirect descendants count"=2
E0811 15:06:30.901087   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"
I0811 15:06:31.303416   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:31.303458   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-nwqfd" "namespace"="md-test" 
I0811 15:06:31.307286   10486 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
I0811 15:06:31.307339   10486 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8pktp-6657c7fddb-mllq4" "namespace"="md-test" 
E0811 15:06:31.313437   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-2tbvn\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-2tbvn" "namespace"="md-test"
E0811 15:06:31.901915   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-mpd5w: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-mpd5w" "namespace"="default"
I0811 15:06:32.330621   10486 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-xvtln" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0811 15:06:32.330865   10486 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-xvtln" "namespace"="default" "noderef"="id-node-1"
E0811 15:06:32.343432   10486 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-xvtln" "namespace"="default"
E0811 15:06:32.902578   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"
E0811 15:06:33.348597   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8pktp-74d45c49c5-mlmcd\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8pktp-74d45c49c5-mlmcd" "namespace"="md-test"
I0811 15:06:33.903198   10486 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8pktp-74d45c49c5,md-8pktp-cdfc6fd6c;Worker machines: md-8pktp-6657c7fddb-mllq4,md-8pktp-74d45c49c5-mlmcd,md-8pktp-74d45c49c5-x9tn9,md-8pktp-6657c7fddb-nwqfd,md-8pktp-74d45c49c5-2tbvn" "indirect descendants count"=7
E0811 15:06:33.907371   10486 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-rx758: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-rx758" "namespace"="default"

------------------------------
• [SLOW TEST:11.952 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
  /home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:248
------------------------------


Ran 16 of 16 Specs in 24.338 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (24.34s)
PASS
Tearing down test suite
I0811 15:06:33.915519   10486 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0811 15:06:33.915570   10486 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0811 15:06:33.915586   10486 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0811 15:06:33.915610   10486 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
E0811 15:06:33.915612   10486 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0811 15:06:33.915644   10486 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0811 15:06:33.915673   10486 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-107892614/tls.crt: no such file or directory"  
I0811 15:06:33.915682   10486 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0811 15:06:33.915693   10486 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0811 15:06:33.915714   10486 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-107892614/tls.crt: no such file or directory"  
I0811 15:06:33.915776   10486 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0811 15:06:33.949877   10486 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:43339/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1327&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:43339: connect: connection refused
E0811 15:06:33.949902   10486 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:43339/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1327&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:43339: connect: connection refused
E0811 15:06:33.949870   10486 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:43339/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1327&timeout=10s&timeoutSeconds=569&watch=true: dial tcp 127.0.0.1:43339: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	83.671s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 256 lines ...
I0811 15:05:23.502992   11005 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0811 15:05:23.503041   11005 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0811 15:05:23.503316   11005 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0811 15:05:23.504296   11005 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0811 15:05:23.504517   11005 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=44465
I0811 15:05:23.505376   11005 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0811 15:05:25.640760   11005 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-jf4rl/test-cluster"
•E0811 15:05:26.086856   11005 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-ldxc6/test-cluster"
•E0811 15:05:26.628413   11005 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:40607/?timeout=50ms: dial tcp 127.0.0.1:40607: connect: connection refused"  "cluster"="cluster-cache-test-vs675/test-cluster"
•I0811 15:05:26.857296   11005 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":{}}}
I0811 15:05:26.957917   11005 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0811 15:05:26.957983   11005 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0811 15:05:26.989278   11005 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0811 15:05:27.520692   11005 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0811 15:05:27.540092   11005 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}}}
I0811 15:05:27.640525   11005 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0811 15:05:27.640596   11005 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0811 15:05:27.789271   11005 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0811 15:05:27.789489   11005 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0811 15:05:27.833590   11005 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:42887/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:42887: connect: connection refused


Ran 5 of 5 Specs in 15.036 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (15.04s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	15.231s
?   	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
I0811 15:05:35.813019   11566 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
E0811 15:05:35.814352   11566 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
I0811 15:05:35.815047   11566 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0811 15:05:35.815212   11566 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 94 lines ...
I0811 15:05:49.152313   11566 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-wgc85" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-np497 (m2-healthy-np497)","node-m3-healthy-cspxl (m3-healthy-cspxl)"] "targetQuorum"=2 "targetTotalMembers"=2 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I0811 15:05:49.156192   11566 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-wgc85"
=== RUN   TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_4_CP_(during_3_CP_rolling_upgrade)
I0811 15:05:49.251988   11566 remediation.go:195]  "msg"="etcd cluster before remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "currentMembers"=["node-m4-healthy-2grqd","node-m1-unhealthy-r66tx","node-m2-healthy-rsbf9","node-m3-healthy-65t65"] "currentTotalMembers"=4
I0811 15:05:49.252072   11566 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-r66tx" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m4-healthy-2grqd (m4-healthy-2grqd)","node-m2-healthy-rsbf9 (m2-healthy-rsbf9)","node-m3-healthy-65t65 (m3-healthy-65t65)"] "targetQuorum"=2 "targetTotalMembers"=3 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I0811 15:05:49.259807   11566 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-r66tx"
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 1652 [running]:
testing.tRunner.func1(0xc000d10000)
	/usr/local/go/src/testing/testing.go:874 +0x3a3
panic(0x1930a20, 0x2c7fce0)
... skipping 3 lines ...
sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers.TestReconcileUnhealthyMachines.func10(0xc000d10000)
	/home/prow/go/src/sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers/remediation_test.go:347 +0xc16
testing.tRunner(0xc000d10000, 0xc000a9a260)
	/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	26.353s
I0811 15:05:35.276568   11541 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"
I0811 15:05:35.276707   11541 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0811 15:05:35.276752   11541 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"
I0811 15:05:35.276777   11541 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0811 15:05:35.276857   11541 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"
I0811 15:05:35.276878   11541 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1660230322
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: 1660230322
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
E0811 15:05:37.893947   11541 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"  
E0811 15:05:46.217054   11541 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"  
E0811 15:05:55.203027   11541 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"  
E0811 15:06:06.333340   11541 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"  
E0811 15:06:22.806577   11541 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"  
E0811 15:06:35.815134   11541 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"  
E0811 15:06:53.462571   11541 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"  
E0811 15:07:14.386000   11541 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"  
E0811 15:07:45.402549   11541 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"  
E0811 15:08:30.559831   11541 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 383 lines ...
I0811 15:05:44.511275   11897 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0811 15:05:44.511313   11897 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0811 15:05:44.515707   11897 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0811 15:05:44.616115   11897 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0811 15:05:44.616194   11897 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0811 15:05:44.687984   11897 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-fpdlx7"} 
E0811 15:05:44.712920   11897 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"
•I0811 15:05:45.755729   11897 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-emfftv"} 
•E0811 15:05:45.819565   11897 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"
E0811 15:05:46.904402   11897 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"
•E0811 15:05:47.925558   11897 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"
E0811 15:05:49.095894   11897 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"
•E0811 15:05:50.123408   11897 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"
E0811 15:05:51.152835   11897 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"
•I0811 15:05:51.158204   11897 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0811 15:05:51.158268   11897 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0811 15:05:51.158313   11897 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-861635462/tls.crt: no such file or directory"  
I0811 15:05:51.158343   11897 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0811 15:05:51.158410   11897 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 


Ran 5 of 5 Specs in 20.464 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.46s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	20.573s
?   	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
E0811 15:05:37.792188   12138 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 ...
•I0811 15:05:50.666128   12138 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0811 15:05:50.710087   12138 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0811 15:05:50.712571   12138 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0811 15:05:50.715538   12138 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}}}
I0811 15:05:50.749518   12138 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0811 15:05:50.797613   12138 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0811 15:05:50.800772   12138 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0811 15:05:50.800851   12138 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-191522612/tls.crt: no such file or directory"  
E0811 15:05:50.800874   12138 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0811 15:05:50.800902   12138 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-191522612/tls.crt: no such file or directory"  
I0811 15:05:50.801106   12138 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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

    Expected success, but got an error:
        <errors.aggregate | len:1, cap:1>: [
            {
                ErrStatus: {
                    TypeMeta: {Kind: "", APIVersion: ""},
                    ListMeta: {
                        SelfLink: "",
... skipping 29 lines ...
•I0811 15:06:13.875597   15046 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



Summarizing 1 Failure:

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

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