This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-11-19 03:35
Elapsed4m25s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 773 lines ...
I1119 03:37:10.922800    8550 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I1119 03:37:10.923603    8550 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I1119 03:37:10.924891    8550 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I1119 03:37:10.925250    8550 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I1119 03:37:10.925625    8550 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=34563
I1119 03:37:11.501611    8550 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" 
•E1119 03:37:11.531925    8550 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1119 03:37:11.531984    8550 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-783188048/tls.crt: no such file or directory"  
I1119 03:37:11.531993    8550 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E1119 03:37:11.532006    8550 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1119 03:37:11.532028    8550 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-783188048/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 14.217 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.22s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	48.264s
=== 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 ...
I1119 03:36:55.701231   10555 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I1119 03:36:55.701479   10555 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":{}}}
I1119 03:36:55.701530   10555 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I1119 03:36:55.701558   10555 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I1119 03:36:55.701590   10555 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I1119 03:36:55.702512   10555 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2022/11/19 03:36:55 http: TLS handshake error from 127.0.0.1:42604: 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
I1119 03:36:55.802311   10555 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"
I1119 03:36:55.805328   10555 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I1119 03:36:55.857089   10555 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
I1119 03:36:55.858771   10555 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"
E1119 03:36:55.859105   10555 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
I1119 03:36:55.859598   10555 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
I1119 03:36:56.285393   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E1119 03:36:56.287788   10555 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I1119 03:36:56.298375   10555 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-mzv95" "namespace"="test-machine-watches-mxm5w" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I1119 03:36:56.298462   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I1119 03:36:56.408028   10555 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-mzv95" "namespace"="test-machine-watches-mxm5w" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I1119 03:36:56.408125   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I1119 03:36:56.508597   10555 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-mzv95" "namespace"="test-machine-watches-mxm5w" "noderef"="node-1"
E1119 03:36:56.543950   10555 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E1119 03:36:56.544004   10555 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E1119 03:36:56.582362   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-mzv95\" in namespace \"test-machine-watches-mxm5w\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-mzv95" "namespace"="test-machine-watches-mxm5w"
E1119 03:36:57.586828   10555 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-mzv95\" in namespace \"test-machine-watches-mxm5w\", requeuing: requeue in 1s"  
E1119 03:36:57.592973   10555 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-mzv95\" in namespace \"test-machine-watches-mxm5w\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-mzv95\" in namespace \"test-machine-watches-mxm5w\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-mzv95" "namespace"="test-machine-watches-mxm5w"
--- PASS: TestWatches (1.76s)
=== RUN   TestIndexMachineByNodeName
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef
--- PASS: TestIndexMachineByNodeName (0.00s)
    --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s)
... skipping 2 lines ...
=== RUN   TestMachine_Reconcile/reconcile_create
I1119 03:36:57.719657   10555 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-bxzg6" "namespace"="test-machine-watches-mxm5w" "count"=1
I1119 03:36:57.719728   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-bxzg6" "namespace"="test-machine-watches-mxm5w" "descendants"="Worker machines: machine-created-mzv95" "indirect descendants count"=0
I1119 03:36:57.755989   10555 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-bxzg6" "namespace"="test-machine-watches-mxm5w" "count"=1
I1119 03:36:57.756054   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-bxzg6" "namespace"="test-machine-watches-mxm5w" "descendants"="Worker machines: machine-created-mzv95" "indirect descendants count"=0
I1119 03:36:58.593509   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-bxzg6" "machine"="machine-created-mzv95" "namespace"="test-machine-watches-mxm5w" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"c8433d05-4f93-469a-89cd-3a139cc2b3b6","apiVersion":"v1"}
E1119 03:36:58.725865   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-mzv95\" not found" "controller"="machine" "name"="machine-created-mzv95" "namespace"="test-machine-watches-mxm5w"
E1119 03:36:59.787931   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-pdzqp\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-ggfjc\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-ggfjc: secrets \"machine-reconcile-ggfjc-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-pdzqp" "namespace"="default"
I1119 03:37:00.788509   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-ggfjc" "machine"="machine-created-pdzqp" "namespace"="default" "cause"="noderef is nil" "node"=null
I1119 03:37:00.822828   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-ggfjc" "machine"="machine-created-pdzqp" "namespace"="default" "cause"="noderef is nil" "node"=null
I1119 03:37:00.853948   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-ggfjc" "machine"="machine-created-pdzqp" "namespace"="default" "cause"="noderef is nil" "node"=null
E1119 03:37:00.895552   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-pdzqp\" not found" "controller"="machine" "name"="machine-created-pdzqp" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.29s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.29s)
=== 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.01s)
    --- 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.01s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I1119 03:37:00.930712   10555 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"
E1119 03:37:00.937021   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-ggfjc\" not found" "controller"="cluster" "name"="machine-reconcile-ggfjc" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I1119 03:37:00.964803   10555 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
I1119 03:37:00.970097   10555 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.04s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.03s)
... 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
I1119 03:37:01.227740   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9r5qw" "namespace"="test-mhc-qbmg8" 
I1119 03:37:01.259224   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E1119 03:37:01.260312   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-8759z\" not found"  "cluster"="test-mhc-qbmg8/test-cluster-8759z"
E1119 03:37:01.275535   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-9r5qw\" not found" "controller"="machinehealthcheck" "name"="test-mhc-9r5qw" "namespace"="test-mhc-qbmg8"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
error cannot retrieve mhc in ctx: MachineHealthCheck.cluster.x-k8s.io "test-mhc-k97kb" not foundI1119 03:37:02.275865   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9r5qw" "namespace"="test-mhc-qbmg8" 
I1119 03:37:02.275985   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kd9p" "namespace"="test-mhc-sprch" 
I1119 03:37:02.276022   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wch6g" "namespace"="test-mhc-h8zm8" 
I1119 03:37:02.276056   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-k97kb" "namespace"="test-mhc-769g7" 
I1119 03:37:02.289993   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1119 03:37:02.416582   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-k97kb" "namespace"="test-mhc-769g7" 
I1119 03:37:02.528592   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-k97kb" "namespace"="test-mhc-769g7" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E1119 03:37:02.587764   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-769g7/test-cluster-jzzfn"
E1119 03:37:02.589474   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-jzzfn\" not found" "controller"="cluster" "name"="test-cluster-jzzfn" "namespace"="test-mhc-769g7"
I1119 03:37:02.700980   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scd5p" "namespace"="test-mhc-5hd49" 
I1119 03:37:02.721264   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1119 03:37:02.740963   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scd5p" "namespace"="test-mhc-5hd49" 
E1119 03:37:02.806420   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5hd49/test-cluster-ffpvw"
I1119 03:37:02.810832   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scd5p" "namespace"="test-mhc-5hd49" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I1119 03:37:02.828650   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
inframachine created: test-mhc-machine-infra-fw759
I1119 03:37:02.854773   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-bz8mv
I1119 03:37:02.882272   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:02.882654   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
I1119 03:37:02.896314   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:02.896648   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
I1119 03:37:02.905333   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:02.905747   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
I1119 03:37:02.922455   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:02.922851   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
I1119 03:37:02.928750   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:02.929083   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
I1119 03:37:02.941250   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:02.942051   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
I1119 03:37:02.947258   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:02.947590   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
E1119 03:37:02.958419   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pjm4p, got []"  "node"="test-mhc-node-pjm4p"
node created: test-mhc-node-pjm4p
E1119 03:37:02.958971   10555 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-pjm4p"
I1119 03:37:02.961032   10555 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm" "noderef"="test-mhc-node-pjm4p"
E1119 03:37:02.965557   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pjm4p, got []"  "node"="test-mhc-node-pjm4p"
E1119 03:37:02.965615   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pjm4p, got []"  "node"="test-mhc-node-pjm4p"
E1119 03:37:02.967272   10555 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-pjm4p"
E1119 03:37:02.967310   10555 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-pjm4p"
I1119 03:37:02.969966   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
inframachine created: test-mhc-machine-infra-zjs6s
machine created: test-mhc-machine-tjpqj
I1119 03:37:02.992592   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:02.999324   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.000605   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
... skipping 46 lines ...
I1119 03:37:03.124393   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.126637   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.128832   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.130429   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.131491   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.133677   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.134100   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-tjpqj/"
I1119 03:37:03.157645   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.158234   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-tjpqj/"
I1119 03:37:03.167885   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.168265   10555 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-pj2cm/test-mhc-wnlkr/test-mhc-machine-tjpqj/"
E1119 03:37:03.191692   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ds8q5, got []"  "node"="test-mhc-node-ds8q5"
node created: test-mhc-node-ds8q5
E1119 03:37:03.192330   10555 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-ds8q5"
I1119 03:37:03.207392   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.241679   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
Cleaning up nodes, machines and infra machines.
I1119 03:37:03.243287   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.249452   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.249909   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
I1119 03:37:03.277814   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:03.278405   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-pj2cm/test-mhc-wnlkr/test-mhc-machine-bz8mv/"
I1119 03:37:03.278849   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-pj2cm/test-mhc-wnlkr/test-mhc-machine-tjpqj/"
E1119 03:37:03.288953   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-pj2cm/test-cluster-2lrdb"
I1119 03:37:03.297174   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
E1119 03:37:03.297277   10555 machinehealthcheck_controller.go:128] controllers/MachineHealthCheck "msg"="Failed to fetch Cluster for MachineHealthCheck" "error"="Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "cluster"="test-cluster-2lrdb" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
E1119 03:37:03.297331   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machinehealthcheck" "name"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E1119 03:37:03.404401   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
inframachine created: test-mhc-machine-infra-9hkvt
machine created: test-mhc-machine-64l7p
E1119 03:37:03.603302   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-mxm5w/machine-reconcile-bxzg6"
I1119 03:37:04.297610   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wnlkr" "namespace"="test-mhc-pj2cm" 
I1119 03:37:04.297712   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:04.314743   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E1119 03:37:04.404828   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:04.456541   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:04.458039   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:04.459133   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:04.461114   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:04.462808   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:04.464470   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
... skipping 467 lines ...
I1119 03:37:05.394008   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.395738   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.397447   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.399123   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.403424   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.406393   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
E1119 03:37:05.406534   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:05.409249   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.411392   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.413315   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.415111   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.416881   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:05.418616   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
... skipping 456 lines ...
I1119 03:37:06.390573   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:06.392879   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:06.406996   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:06.409411   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:06.411735   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:06.414595   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
E1119 03:37:06.425191   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:06.425529   10555 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-r6f4d/test-mhc-f2n5z/test-mhc-machine-64l7p/"
I1119 03:37:06.441654   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:06.442031   10555 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-r6f4d/test-mhc-f2n5z/test-mhc-machine-64l7p/"
node created: test-mhc-node-snlw4
E1119 03:37:06.451437   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-snlw4, got []"  "node"="test-mhc-node-snlw4"
I1119 03:37:06.460937   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
inframachine created: test-mhc-machine-infra-f6zd5
I1119 03:37:06.479611   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
machine created: test-mhc-machine-7cl7x
I1119 03:37:06.485923   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:06.493140   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
... skipping 332 lines ...
I1119 03:37:07.406489   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.414226   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.416565   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.419571   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.421809   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.424084   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
E1119 03:37:07.429563   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:07.431679   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.434391   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.437069   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.439657   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.443033   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:07.445478   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
... skipping 340 lines ...
I1119 03:37:08.461764   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.464006   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.466310   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.468594   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.479650   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.482426   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
E1119 03:37:08.482902   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:08.486594   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.488262   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.489586   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.491318   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.492466   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:08.493664   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
... skipping 317 lines ...
I1119 03:37:09.482842   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:09.492612   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:09.498681   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:09.499882   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:09.502418   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:09.505086   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
E1119 03:37:09.506529   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:09.507214   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:09.507712   10555 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-r6f4d/test-mhc-f2n5z/test-mhc-machine-7cl7x/"
I1119 03:37:09.518102   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:09.518615   10555 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-r6f4d/test-mhc-f2n5z/test-mhc-machine-7cl7x/"
node created: test-mhc-node-8v4z5
E1119 03:37:09.609119   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8v4z5, got []"  "node"="test-mhc-node-8v4z5"
I1119 03:37:09.619135   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
inframachine created: test-mhc-machine-infra-kf9qx
I1119 03:37:09.641945   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
machine created: test-mhc-machine-bjdwq
I1119 03:37:09.644252   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:09.650555   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
... skipping 250 lines ...
I1119 03:37:10.494094   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.496813   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.508369   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.512475   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.515174   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.520294   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
E1119 03:37:10.523703   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:10.524350   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.525786   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.528292   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.530883   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.533586   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:10.536252   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
... skipping 304 lines ...
I1119 03:37:11.564257   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.566917   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.568304   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.569321   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.572402   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.575367   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
E1119 03:37:11.576548   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:11.577042   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.578373   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.579917   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.581450   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.584779   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:11.586948   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
... skipping 241 lines ...
I1119 03:37:12.582257   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.587382   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.590116   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.595090   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.597638   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.600035   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.600583   10555 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-r6f4d/test-mhc-f2n5z/test-mhc-machine-bjdwq/"
E1119 03:37:12.608354   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:12.611204   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.611738   10555 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-r6f4d/test-mhc-f2n5z/test-mhc-machine-bjdwq/"
E1119 03:37:12.660678   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lwwj2, got []"  "node"="test-mhc-node-lwwj2"
node created: test-mhc-node-lwwj2
Cleaning up nodes, machines and infra machines.
I1119 03:37:12.669257   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.669836   10555 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-r6f4d/test-mhc-f2n5z/test-mhc-machine-bjdwq/test-mhc-node-lwwj2"
I1119 03:37:12.686919   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.687483   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-bjdwq/"
Cleaning up nodes, machines and infra machines.
I1119 03:37:12.701440   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.701970   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-64l7p/"
I1119 03:37:12.723725   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-bjdwq/"
I1119 03:37:12.749555   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.750181   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-64l7p/"
I1119 03:37:12.750611   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-7cl7x/"
I1119 03:37:12.765984   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-bjdwq/"
I1119 03:37:12.772036   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
I1119 03:37:12.772617   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-64l7p/"
I1119 03:37:12.773077   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-7cl7x/"
I1119 03:37:12.773461   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-r6f4d/test-mhc-f2n5z/test-mhc-machine-bjdwq/"
I1119 03:37:12.791318   10555 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-v5svs" "namespace"="test-mhc-r6f4d" "count"=2
I1119 03:37:12.791407   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-v5svs" "namespace"="test-mhc-r6f4d" "descendants"="Worker machines: test-mhc-machine-64l7p,test-mhc-machine-7cl7x,test-mhc-machine-bjdwq" "indirect descendants count"=1
I1119 03:37:12.800027   10555 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-v5svs" "namespace"="test-mhc-r6f4d" "count"=2
I1119 03:37:12.800088   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-v5svs" "namespace"="test-mhc-r6f4d" "descendants"="Worker machines: test-mhc-machine-64l7p,test-mhc-machine-7cl7x,test-mhc-machine-bjdwq" "indirect descendants count"=1
I1119 03:37:12.807513   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-f2n5z" "namespace"="test-mhc-r6f4d" 
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
... skipping 6 lines ...
I1119 03:37:12.923658   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:12.964999   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:13.046110   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:13.207210   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:13.528376   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:13.608974   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-v5svs" "machine"="test-mhc-machine-7cl7x" "namespace"="test-mhc-r6f4d" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8v4z5"}
E1119 03:37:13.658713   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7cl7x\" not found" "controller"="machine" "name"="test-mhc-machine-7cl7x" "namespace"="test-mhc-r6f4d"
I1119 03:37:14.169428   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
E1119 03:37:14.659510   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:15.450560   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:15.660057   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-v5svs" "machine"="test-mhc-machine-bjdwq" "namespace"="test-mhc-r6f4d" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-lwwj2"}
E1119 03:37:15.716275   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-bjdwq\" not found" "controller"="machine" "name"="test-mhc-machine-bjdwq" "namespace"="test-mhc-r6f4d"
I1119 03:37:16.717125   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-v5svs" "machine"="test-mhc-machine-64l7p" "namespace"="test-mhc-r6f4d" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-snlw4"}
E1119 03:37:16.767237   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-64l7p\" not found" "controller"="machine" "name"="test-mhc-machine-64l7p" "namespace"="test-mhc-r6f4d"
E1119 03:37:17.767693   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
E1119 03:37:17.813472   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-r6f4d/test-cluster-v5svs"
I1119 03:37:18.011664   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:18.775536   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
E1119 03:37:18.789295   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:18.790112   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
E1119 03:37:18.802772   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q9n7p, got []"  "node"="test-mhc-node-q9n7p"
node created: test-mhc-node-q9n7p
I1119 03:37:18.809071   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:18.810797   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
inframachine created: test-mhc-machine-infra-8s8bz
machine created: test-mhc-machine-f95hk
I1119 03:37:18.835587   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:18.847627   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:18.853161   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:18.854355   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:18.895607   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:18.976953   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:19.138321   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:19.460904   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
E1119 03:37:19.789746   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:20.102238   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:20.804058   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:20.811358   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:20.821267   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:20.840475   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:20.872574   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:20.881050   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
E1119 03:37:20.883227   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:20.911995   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
node created: test-mhc-node-v5x9b
E1119 03:37:20.948368   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v5x9b, got []"  "node"="test-mhc-node-v5x9b"
I1119 03:37:20.955854   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
inframachine created: test-mhc-machine-infra-f5gg8
I1119 03:37:20.969868   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
machine created: test-mhc-machine-c5mqq
I1119 03:37:20.979280   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:20.993923   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:21.001229   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:21.383684   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
E1119 03:37:21.883567   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:22.894548   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:22.912824   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:22.929404   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:22.952354   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:22.962188   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:22.978350   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:22.982764   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
E1119 03:37:22.985282   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
E1119 03:37:23.004077   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-scwx4, got []"  "node"="test-mhc-node-scwx4"
node created: test-mhc-node-scwx4
Cleaning up nodes, machines and infra machines.
I1119 03:37:23.019043   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:23.052103   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
I1119 03:37:23.062822   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-chhjr" "namespace"="test-mhc-qbmlm" 
Cleaning up nodes, machines and infra machines.
... skipping 10 lines ...
inframachine created: test-mhc-machine-infra-682dn
I1119 03:37:23.166064   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-tp89c
I1119 03:37:23.184978   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:23.192236   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:23.985865   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-m268w" "machine"="test-mhc-machine-nlwh7" "namespace"="test-mhc-qbmlm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-q9n7p"}
E1119 03:37:24.038338   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nlwh7\" not found" "controller"="machine" "name"="test-mhc-machine-nlwh7" "namespace"="test-mhc-qbmlm"
I1119 03:37:25.038921   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-m268w" "machine"="test-mhc-machine-f95hk" "namespace"="test-mhc-qbmlm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-v5x9b"}
E1119 03:37:25.092416   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f95hk\" not found" "controller"="machine" "name"="test-mhc-machine-f95hk" "namespace"="test-mhc-qbmlm"
I1119 03:37:26.092941   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-m268w" "machine"="test-mhc-machine-c5mqq" "namespace"="test-mhc-qbmlm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-scwx4"}
E1119 03:37:26.139086   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-c5mqq\" not found" "controller"="machine" "name"="test-mhc-machine-c5mqq" "namespace"="test-mhc-qbmlm"
E1119 03:37:27.139488   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
E1119 03:37:28.120209   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qbmlm/test-cluster-m268w"
I1119 03:37:28.148765   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:28.160554   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
E1119 03:37:28.160735   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
E1119 03:37:28.195680   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gpkm4, got []"  "node"="test-mhc-node-gpkm4"
node created: test-mhc-node-gpkm4
I1119 03:37:28.203409   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
inframachine created: test-mhc-machine-infra-zjxgr
machine created: test-mhc-machine-fv9x2
I1119 03:37:28.252173   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:28.259390   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.176742   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.190118   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.203854   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.211492   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.228790   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.236850   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.249394   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
E1119 03:37:29.256164   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bfpxn, got []"  "node"="test-mhc-node-bfpxn"
node created: test-mhc-node-bfpxn
I1119 03:37:29.280202   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.282294   10555 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-fv9x2" "namespace"="test-mhc-vf9m6" "noderef"="test-mhc-node-bfpxn"
inframachine created: test-mhc-machine-infra-trvhs
machine created: test-mhc-machine-q6jwv
I1119 03:37:29.314178   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
... skipping 8 lines ...
I1119 03:37:29.517917   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.530270   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
Cleaning up nodes, machines and infra machines.
I1119 03:37:29.560289   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.573572   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.587884   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.588468   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vf9m6/test-mhc-9c8f9/test-mhc-machine-tp89c/"
I1119 03:37:29.593107   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-nggwq" "machine"="test-mhc-machine-q6jwv" "namespace"="test-mhc-vf9m6" "cause"="noderef is nil" "node"=null
I1119 03:37:29.627930   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:29.628603   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vf9m6/test-mhc-9c8f9/test-mhc-machine-tp89c/"
I1119 03:37:29.629030   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-vf9m6/test-mhc-9c8f9/test-mhc-machine-fv9x2/"
E1119 03:37:29.667992   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-q6jwv\" not found" "controller"="machine" "name"="test-mhc-machine-q6jwv" "namespace"="test-mhc-vf9m6"
I1119 03:37:29.674821   10555 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-nggwq" "namespace"="test-mhc-vf9m6" "count"=2
I1119 03:37:29.674913   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-nggwq" "namespace"="test-mhc-vf9m6" "descendants"="Worker machines: test-mhc-machine-tp89c,test-mhc-machine-fv9x2" "indirect descendants count"=0
I1119 03:37:29.688793   10555 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-nggwq" "namespace"="test-mhc-vf9m6" "count"=2
I1119 03:37:29.688861   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-nggwq" "namespace"="test-mhc-vf9m6" "descendants"="Worker machines: test-mhc-machine-tp89c,test-mhc-machine-fv9x2" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-tvnq4
machine created: test-mhc-machine-x9jfv
E1119 03:37:29.810324   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-9c8f9\" not found" "controller"="machinehealthcheck" "name"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6"
I1119 03:37:30.668479   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-nggwq" "machine"="test-mhc-machine-tp89c" "namespace"="test-mhc-vf9m6" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-gpkm4"}
E1119 03:37:30.719418   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-tp89c\" not found" "controller"="machine" "name"="test-mhc-machine-tp89c" "namespace"="test-mhc-vf9m6"
I1119 03:37:30.810635   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:30.826081   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1119 03:37:30.946455   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9c8f9" "namespace"="test-mhc-vf9m6" 
I1119 03:37:30.946532   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:30.947539   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:30.949320   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
... skipping 390 lines ...
I1119 03:37:31.768310   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.770600   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.785501   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.789575   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.791510   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.793522   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
E1119 03:37:31.793938   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fv9x2\" not found" "controller"="machine" "name"="test-mhc-machine-fv9x2" "namespace"="test-mhc-vf9m6"
I1119 03:37:31.795320   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.797077   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.798810   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.800708   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.802525   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:31.804278   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
... skipping 451 lines ...
I1119 03:37:32.784850   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.786533   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.788242   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.789942   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.791781   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.793797   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
E1119 03:37:32.794347   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:32.795950   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.797722   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.799481   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.801283   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.803031   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:32.804787   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
... skipping 435 lines ...
I1119 03:37:33.793174   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.794981   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.796714   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.798665   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.809347   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.810190   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
E1119 03:37:33.817290   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:33.817813   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.821020   10555 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-8rbrc/test-mhc-zbgwx/test-mhc-machine-x9jfv/"
I1119 03:37:33.833926   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.834404   10555 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-8rbrc/test-mhc-zbgwx/test-mhc-machine-x9jfv/"
E1119 03:37:33.863059   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pcgtv, got []"  "node"="test-mhc-node-pcgtv"
node created: test-mhc-node-pcgtv
E1119 03:37:33.863999   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pcgtv, got []"  "node"="test-mhc-node-pcgtv"
I1119 03:37:33.871318   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.886087   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.895247   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.895645   10555 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-8rbrc/test-mhc-zbgwx/test-mhc-machine-x9jfv/test-mhc-node-pcgtv"
I1119 03:37:33.914102   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.914671   10555 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-8rbrc/test-mhc-zbgwx/test-mhc-machine-x9jfv/test-mhc-node-pcgtv"
Cleaning up nodes, machines and infra machines.
I1119 03:37:33.922585   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.923002   10555 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-8rbrc/test-mhc-zbgwx/test-mhc-machine-x9jfv/test-mhc-node-pcgtv"
I1119 03:37:33.925337   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.925672   10555 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-8rbrc/test-mhc-zbgwx/test-mhc-machine-x9jfv/test-mhc-node-pcgtv"
I1119 03:37:33.928049   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.928544   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8rbrc/test-mhc-zbgwx/test-mhc-machine-x9jfv/"
I1119 03:37:33.945494   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k567n" "namespace"="test-mhc-8rbrc" "descendants"="Worker machines: test-mhc-machine-x9jfv" "indirect descendants count"=1
I1119 03:37:33.947446   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:33.947793   10555 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8rbrc/test-mhc-zbgwx/test-mhc-machine-x9jfv/"
I1119 03:37:33.952254   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k567n" "namespace"="test-mhc-8rbrc" "descendants"="Worker machines: test-mhc-machine-x9jfv" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I1119 03:37:33.957527   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zbgwx" "namespace"="test-mhc-8rbrc" 
I1119 03:37:34.157917   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" "creating"=1 "need"=1
I1119 03:37:34.157968   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" 
I1119 03:37:34.169868   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-pxtst-gtvjg\"" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" 
I1119 03:37:34.246568   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:34.267612   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I1119 03:37:34.287915   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
E1119 03:37:34.702091   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vf9m6/test-cluster-nggwq"
I1119 03:37:34.817808   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k567n" "machine"="test-mhc-machine-x9jfv" "namespace"="test-mhc-8rbrc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-pcgtv"}
E1119 03:37:34.860368   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-x9jfv\" not found" "controller"="machine" "name"="test-mhc-machine-x9jfv" "namespace"="test-mhc-8rbrc"
I1119 03:37:35.288125   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.871350   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.872478   10555 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.882473   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.883862   10555 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.893081   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" 
... skipping 2 lines ...
I1119 03:37:35.903675   10555 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.904958   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.905864   10555 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.914862   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" 
I1119 03:37:35.914918   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.289165   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.289655   10555 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-qzgqg/test-mhc-qlnkn/mhc-ms-pxtst-gtvjg/"
I1119 03:37:36.297630   10555 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.304101   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.304157   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.305103   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.305462   10555 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-qzgqg/test-mhc-qlnkn/mhc-ms-pxtst-gtvjg/"
I1119 03:37:36.311189   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.311463   10555 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.311546   10555 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-qzgqg/test-mhc-qlnkn/mhc-ms-pxtst-gtvjg/"
I1119 03:37:36.321179   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.321229   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.374509   10555 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-hs4tf" "namespace"="test-mhc-qzgqg" "count"=1
I1119 03:37:36.374570   10555 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-hs4tf" "namespace"="test-mhc-qzgqg" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-pxtst"
I1119 03:37:36.376654   10555 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-pxtst" "namespace"="test-mhc-qzgqg" "machine"="mhc-ms-pxtst-gtvjg"
I1119 03:37:36.383077   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-hs4tf" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" "cause"="cluster is being deleted" "node"=null
I1119 03:37:36.384535   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.384869   10555 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-qzgqg/test-mhc-qlnkn/mhc-ms-pxtst-gtvjg/"
I1119 03:37:36.386412   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hs4tf" "namespace"="test-mhc-qzgqg" "descendants"="Machine sets: mhc-ms-pxtst;Worker machines: mhc-ms-pxtst-gtvjg" "indirect descendants count"=1
I1119 03:37:36.386496   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qlnkn" "namespace"="test-mhc-qzgqg" 
I1119 03:37:36.396223   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-hs4tf" "namespace"="test-mhc-qzgqg" "descendants"="Worker machines: mhc-ms-pxtst-gtvjg" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I1119 03:37:36.423379   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-hs4tf" "machine"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg" "cause"="cluster is being deleted" "node"=null
E1119 03:37:36.473705   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-pxtst-gtvjg\" not found" "controller"="machine" "name"="mhc-ms-pxtst-gtvjg" "namespace"="test-mhc-qzgqg"
I1119 03:37:36.478622   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
inframachine created: test-mhc-machine-infra-ht4rc
I1119 03:37:36.495711   10555 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-dgg9b
I1119 03:37:36.627709   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:36.636039   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
... skipping 408 lines ...
I1119 03:37:37.484805   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.486564   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.488689   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.492044   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.494748   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.496282   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
E1119 03:37:37.519039   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gt9x5, got []"  "node"="test-mhc-node-gt9x5"
E1119 03:37:37.519039   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gt9x5, got []"  "node"="test-mhc-node-gt9x5"
node created: test-mhc-node-gt9x5
E1119 03:37:37.519314   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gt9x5, got []"  "node"="test-mhc-node-gt9x5"
I1119 03:37:37.561166   10555 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-dgg9b" "namespace"="test-mhc-lcclw" "noderef"="test-mhc-node-gt9x5"
I1119 03:37:37.562381   10555 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-dgg9b" "target"="test-mhc-lcclw/test-mhc-m7pzz/test-mhc-machine-dgg9b/"
I1119 03:37:37.598056   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.623288   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.629842   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.636867   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.641027   10555 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-dgg9b" "target"="test-mhc-lcclw/test-mhc-m7pzz/test-mhc-machine-dgg9b/test-mhc-node-gt9x5"
I1119 03:37:37.670856   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
Cleaning up nodes, machines and infra machines.
I1119 03:37:37.688700   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.691648   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.696798   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m7pzz" "namespace"="test-mhc-lcclw" 
I1119 03:37:37.704092   10555 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-tm6vv" "namespace"="test-mhc-lcclw" "count"=1
... skipping 22 lines ...
I1119 03:37:37.814899   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.822739   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.826743   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.828591   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.830520   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.832392   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
E1119 03:37:37.834223   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dgg9b\" not found" "controller"="machine" "name"="test-mhc-machine-dgg9b" "namespace"="test-mhc-lcclw"
I1119 03:37:37.834350   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.836110   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.837923   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.839979   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.842433   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:37.844811   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
... skipping 491 lines ...
I1119 03:37:38.838831   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.840800   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.843433   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.844072   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.845251   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.847300   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
E1119 03:37:38.847870   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
I1119 03:37:38.847937   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.852016   10555 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-gwhsq" "target"="test-mhc-r9qcw/test-mhc-7tq5g/test-mhc-machine-gwhsq/"
node created: test-mhc-node-wh9hb
E1119 03:37:38.881933   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wh9hb, got []"  "node"="test-mhc-node-wh9hb"
E1119 03:37:38.882126   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wh9hb, got []"  "node"="test-mhc-node-wh9hb"
E1119 03:37:38.882585   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wh9hb, got []"  "node"="test-mhc-node-wh9hb"
E1119 03:37:38.882643   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wh9hb, got []"  "node"="test-mhc-node-wh9hb"
I1119 03:37:38.888380   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.892707   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.912016   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.917529   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.930139   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.937657   10555 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-gwhsq" "target"="test-mhc-r9qcw/test-mhc-7tq5g/test-mhc-machine-gwhsq/test-mhc-node-wh9hb"
I1119 03:37:38.966577   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
E1119 03:37:38.968905   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8rbrc/test-cluster-k567n"
I1119 03:37:38.972221   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:38.997965   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
Cleaning up nodes, machines and infra machines.
I1119 03:37:39.009936   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:39.014963   10555 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-gwhsq" "target"="test-mhc-r9qcw/test-mhc-7tq5g/test-mhc-machine-gwhsq/"
I1119 03:37:39.024388   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dbwcf" "namespace"="test-mhc-r9qcw" "descendants"="Worker machines: test-mhc-machine-gwhsq" "indirect descendants count"=1
I1119 03:37:39.031890   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dbwcf" "namespace"="test-mhc-r9qcw" "descendants"="Worker machines: test-mhc-machine-gwhsq" "indirect descendants count"=1
E1119 03:37:39.040586   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-7tq5g\" not found" "controller"="machinehealthcheck" "name"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw"
--- PASS: TestMachineHealthCheck_Reconcile (37.97s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.18s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.20s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.27s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (1.32s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (1.32s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E1119 03:37:39.043732   10555 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
E1119 03:37:39.045088   10555 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
E1119 03:37:39.046482   10555 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E1119 03:37:39.046666   10555 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
E1119 03:37:39.046946   10555 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
I1119 03:37:39.049550   10555 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I1119 03:37:39.050104   10555 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E1119 03:37:39.051378   10555 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
E1119 03:37:39.061438   10555 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
E1119 03:37:39.063673   10555 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 73 lines ...
I1119 03:37:39.368279   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I1119 03:37:39.368328   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" 
I1119 03:37:39.386058   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9fmbd-6657c7fddb-scxqp\"" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" 
I1119 03:37:39.455497   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I1119 03:37:39.455547   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" 
I1119 03:37:39.469023   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9fmbd-cdfc6fd6c-ggk9p\"" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" 
E1119 03:37:39.553274   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.553437   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.553930   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.656792   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.656841   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.656871   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.656919   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.656871   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.656968   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj, got []"  "node"="md-9fmbd-cdfc6fd6c-ggk9p-zd6fj"
E1119 03:37:39.682512   10555 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-9fmbd-cdfc6fd6c-ggk9p-zd6fj for machine md-test/md-9fmbd-cdfc6fd6c-ggk9p: the cache is not started, can not read objects" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" 
I1119 03:37:39.725307   10555 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I1119 03:37:39.725351   10555 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I1119 03:37:39.732933   10555 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "machine"="md-9fmbd-6657c7fddb-r9zlb"
I1119 03:37:39.843112   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I1119 03:37:39.843199   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" 
I1119 03:37:39.848352   10555 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dbwcf" "machine"="test-mhc-machine-gwhsq" "namespace"="test-mhc-r9qcw" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wh9hb"}
I1119 03:37:39.853876   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9fmbd-cdfc6fd6c-jcqf9\"" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" 
E1119 03:37:39.891694   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-gwhsq\" not found" "controller"="machine" "name"="test-mhc-machine-gwhsq" "namespace"="test-mhc-r9qcw"
E1119 03:37:39.892335   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
E1119 03:37:39.892346   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
E1119 03:37:39.892416   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
E1119 03:37:39.997712   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
E1119 03:37:39.997765   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
E1119 03:37:39.997779   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
E1119 03:37:39.997804   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
E1119 03:37:39.998603   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
E1119 03:37:39.998653   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-jcqf9-tqfgt, got []"  "node"="md-9fmbd-cdfc6fd6c-jcqf9-tqfgt"
I1119 03:37:40.040872   10555 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7tq5g" "namespace"="test-mhc-r9qcw" 
I1119 03:37:40.049220   10555 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I1119 03:37:40.049269   10555 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I1119 03:37:40.059001   10555 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "machine"="md-9fmbd-6657c7fddb-nmgcn"
I1119 03:37:40.169070   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I1119 03:37:40.169112   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" 
I1119 03:37:40.183424   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9fmbd-cdfc6fd6c-8gqrr\"" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" 
E1119 03:37:40.261248   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
E1119 03:37:40.261254   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
E1119 03:37:40.261254   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
E1119 03:37:40.264443   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
E1119 03:37:40.264511   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
E1119 03:37:40.264575   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
E1119 03:37:40.264630   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
E1119 03:37:40.264682   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
E1119 03:37:40.264725   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-cdfc6fd6c-8gqrr-f8m4r, got []"  "node"="md-9fmbd-cdfc6fd6c-8gqrr-f8m4r"
I1119 03:37:40.327057   10555 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I1119 03:37:40.327100   10555 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I1119 03:37:40.330984   10555 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9fmbd-6657c7fddb" "namespace"="md-test" "machine"="md-9fmbd-6657c7fddb-scxqp"
I1119 03:37:40.575385   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I1119 03:37:40.575428   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" 
I1119 03:37:40.588998   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9fmbd-74d45c49c5-s7kfr\"" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" 
E1119 03:37:40.667923   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
E1119 03:37:40.668045   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
E1119 03:37:40.668099   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
E1119 03:37:40.770813   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
E1119 03:37:40.770852   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
E1119 03:37:40.771068   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
E1119 03:37:40.771088   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
E1119 03:37:40.771167   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
E1119 03:37:40.771216   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-s7kfr-pq8xr, got []"  "node"="md-9fmbd-74d45c49c5-s7kfr-pq8xr"
I1119 03:37:40.806611   10555 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I1119 03:37:40.806645   10555 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I1119 03:37:40.812660   10555 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "machine"="md-9fmbd-cdfc6fd6c-jcqf9"
E1119 03:37:40.892041   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
I1119 03:37:40.923094   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I1119 03:37:40.923247   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" 
I1119 03:37:40.932897   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9fmbd-74d45c49c5-gch7f\"" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" 
E1119 03:37:41.001932   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
E1119 03:37:41.001932   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
E1119 03:37:41.002324   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
E1119 03:37:41.005190   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
E1119 03:37:41.005282   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
E1119 03:37:41.005356   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
E1119 03:37:41.005396   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
E1119 03:37:41.005406   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
E1119 03:37:41.005422   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-gch7f-597n6, got []"  "node"="md-9fmbd-74d45c49c5-gch7f-597n6"
I1119 03:37:41.037368   10555 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I1119 03:37:41.037405   10555 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I1119 03:37:41.041247   10555 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-9fmbd-cdfc6fd6c" "namespace"="md-test" "machine"="md-9fmbd-cdfc6fd6c-8gqrr"
I1119 03:37:41.150597   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I1119 03:37:41.150638   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" 
I1119 03:37:41.161940   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-9fmbd-74d45c49c5-lbcqb\"" "machineset"="md-9fmbd-74d45c49c5" "namespace"="md-test" 
E1119 03:37:41.280544   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.280908   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.281112   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.384659   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.384793   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.384655   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.384839   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.385644   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.385704   10555 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-9fmbd-74d45c49c5-lbcqb-q5p5z, got []"  "node"="md-9fmbd-74d45c49c5-lbcqb-q5p5z"
E1119 03:37:41.412228   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qzgqg/test-cluster-hs4tf"
I1119 03:37:41.413100   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9fmbd-74d45c49c5,md-9fmbd-cdfc6fd6c;Worker machines: md-9fmbd-6657c7fddb-pr9g4,md-9fmbd-74d45c49c5-gch7f,md-9fmbd-74d45c49c5-lbcqb,md-9fmbd-74d45c49c5-s7kfr,md-9fmbd-cdfc6fd6c-ggk9p,md-9fmbd-6657c7fddb-x494k" "indirect descendants count"=8
•I1119 03:37:41.418261   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9fmbd-74d45c49c5,md-9fmbd-cdfc6fd6c;Worker machines: md-9fmbd-74d45c49c5-lbcqb,md-9fmbd-74d45c49c5-s7kfr,md-9fmbd-cdfc6fd6c-ggk9p,md-9fmbd-6657c7fddb-x494k,md-9fmbd-6657c7fddb-pr9g4,md-9fmbd-74d45c49c5-gch7f" "indirect descendants count"=8
•E1119 03:37:41.537348   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-jb672\" not found" "controller"="cluster" "name"="test1-jb672" "namespace"="default"
I1119 03:37:41.964956   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:41.964991   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:41.981194   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
I1119 03:37:41.981236   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
E1119 03:37:42.020708   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-cdfc6fd6c-ggk9p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-cdfc6fd6c-ggk9p" "namespace"="md-test"
•I1119 03:37:42.693962   10555 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-5lc77" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I1119 03:37:42.810167   10555 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-5lc77" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E1119 03:37:42.814376   10555 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-5lc77" "namespace"="default"
E1119 03:37:43.048686   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-s7kfr\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-s7kfr" "namespace"="md-test"
E1119 03:37:43.837809   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lcclw/test-cluster-tm6vv"
E1119 03:37:43.841088   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
•E1119 03:37:44.074310   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-gch7f\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-gch7f" "namespace"="md-test"
E1119 03:37:44.855467   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-s5x5l\" not found" "controller"="cluster" "name"="test3-s5x5l" "namespace"="default"
I1119 03:37:45.101799   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:45.101854   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:45.106410   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
I1119 03:37:45.106444   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
E1119 03:37:45.110967   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-cdfc6fd6c-ggk9p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-cdfc6fd6c-ggk9p" "namespace"="md-test"
E1119 03:37:45.856305   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
E1119 03:37:46.116676   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-s7kfr\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-s7kfr" "namespace"="md-test"
E1119 03:37:46.880086   10555 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-r9qcw/test-cluster-dbwcf"
E1119 03:37:46.880684   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
•E1119 03:37:47.121598   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-gch7f\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-gch7f" "namespace"="md-test"
I1119 03:37:47.881238   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9fmbd-74d45c49c5,md-9fmbd-cdfc6fd6c;Worker machines: md-9fmbd-6657c7fddb-x494k,md-9fmbd-6657c7fddb-pr9g4,md-9fmbd-74d45c49c5-gch7f,md-9fmbd-74d45c49c5-lbcqb,md-9fmbd-74d45c49c5-s7kfr,md-9fmbd-cdfc6fd6c-ggk9p" "indirect descendants count"=8
E1119 03:37:47.885456   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
E1119 03:37:48.130781   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-cdfc6fd6c-ggk9p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-cdfc6fd6c-ggk9p" "namespace"="md-test"
E1119 03:37:48.886222   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
I1119 03:37:49.135924   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:49.135979   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:49.141765   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
I1119 03:37:49.141806   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
E1119 03:37:49.146170   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-s7kfr\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-s7kfr" "namespace"="md-test"
E1119 03:37:49.896535   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
•E1119 03:37:50.151395   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-gch7f\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-gch7f" "namespace"="md-test"
E1119 03:37:50.897310   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
E1119 03:37:51.156559   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-cdfc6fd6c-ggk9p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-cdfc6fd6c-ggk9p" "namespace"="md-test"
E1119 03:37:51.898045   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
E1119 03:37:52.157170   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-tjpqj\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-tjpqj" "namespace"="test-mhc-pj2cm"
E1119 03:37:52.907865   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
E1119 03:37:53.163304   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-s7kfr\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-s7kfr" "namespace"="md-test"
E1119 03:37:53.908695   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
I1119 03:37:54.167837   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:54.167880   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:54.171915   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
I1119 03:37:54.171962   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
E1119 03:37:54.176467   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-gch7f\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-gch7f" "namespace"="md-test"
I1119 03:37:54.909399   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9fmbd-74d45c49c5,md-9fmbd-cdfc6fd6c;Worker machines: md-9fmbd-6657c7fddb-pr9g4,md-9fmbd-74d45c49c5-gch7f,md-9fmbd-74d45c49c5-lbcqb,md-9fmbd-74d45c49c5-s7kfr,md-9fmbd-cdfc6fd6c-ggk9p,md-9fmbd-6657c7fddb-x494k" "indirect descendants count"=8
E1119 03:37:54.910016   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
E1119 03:37:55.176874   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2lrdb\" for machine \"test-mhc-machine-bz8mv\" in namespace \"test-mhc-pj2cm\": Cluster.cluster.x-k8s.io \"test-cluster-2lrdb\" not found" "controller"="machine" "name"="test-mhc-machine-bz8mv" "namespace"="test-mhc-pj2cm"
E1119 03:37:55.910797   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
E1119 03:37:56.182089   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-cdfc6fd6c-ggk9p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-cdfc6fd6c-ggk9p" "namespace"="md-test"
E1119 03:37:56.911601   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
E1119 03:37:57.200784   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-s7kfr\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-s7kfr" "namespace"="md-test"
E1119 03:37:57.912401   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
E1119 03:37:58.206389   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-gch7f\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-gch7f" "namespace"="md-test"
E1119 03:37:58.913214   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
I1119 03:37:59.210585   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:59.210624   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:37:59.214368   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
I1119 03:37:59.214410   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
E1119 03:37:59.218934   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-cdfc6fd6c-ggk9p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-cdfc6fd6c-ggk9p" "namespace"="md-test"
E1119 03:37:59.913957   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
I1119 03:38:00.234240   10555 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-h4wcd" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E1119 03:38:00.248606   10555 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-h4wcd" "namespace"="default" 
E1119 03:38:00.264666   10555 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-h4wcd" "namespace"="default"
E1119 03:38:00.914897   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
E1119 03:38:01.270385   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-s7kfr\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-s7kfr" "namespace"="md-test"
I1119 03:38:01.915706   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-9fmbd-74d45c49c5,md-9fmbd-cdfc6fd6c;Worker machines: md-9fmbd-74d45c49c5-s7kfr,md-9fmbd-cdfc6fd6c-ggk9p,md-9fmbd-6657c7fddb-x494k,md-9fmbd-6657c7fddb-pr9g4,md-9fmbd-74d45c49c5-gch7f,md-9fmbd-74d45c49c5-lbcqb" "indirect descendants count"=8
E1119 03:38:01.916442   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
E1119 03:38:02.275699   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-gch7f\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-gch7f" "namespace"="md-test"
E1119 03:38:02.917302   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5lc77: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5lc77" "namespace"="default"
E1119 03:38:03.280705   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-cdfc6fd6c-ggk9p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-cdfc6fd6c-ggk9p" "namespace"="md-test"
E1119 03:38:03.918257   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-z5rrw: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-z5rrw" "namespace"="default"
I1119 03:38:04.285542   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:38:04.285597   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-x494k" "namespace"="md-test" 
I1119 03:38:04.289939   10555 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
I1119 03:38:04.289989   10555 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-9fmbd-6657c7fddb-pr9g4" "namespace"="md-test" 
I1119 03:38:04.305941   10555 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-h4wcd" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I1119 03:38:04.306233   10555 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-h4wcd" "namespace"="default" "noderef"="id-node-1"
E1119 03:38:04.319573   10555 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-h4wcd" "namespace"="default"

------------------------------
• [SLOW TEST:15.065 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 25 lines ...
I1119 03:38:05.021425   10555 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"
•I1119 03:38:05.022786   10555 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"
I1119 03:38:05.023414   10555 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"
I1119 03:38:05.023957   10555 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I1119 03:38:05.023985   10555 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I1119 03:38:05.024658   10555 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E1119 03:38:05.025891   10555 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" 
•I1119 03:38:05.099583   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-6j5tc" "namespace"="ms-test" "creating"=2 "need"=2
I1119 03:38:05.099624   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-6j5tc" "namespace"="ms-test" 
I1119 03:38:05.112833   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-6j5tc-btg86\"" "machineset"="ms-6j5tc" "namespace"="ms-test" 
I1119 03:38:05.112889   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-6j5tc" "namespace"="ms-test" 
I1119 03:38:05.128210   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-6j5tc-fv48w\"" "machineset"="ms-6j5tc" "namespace"="ms-test" 
I1119 03:38:05.233465   10555 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-6j5tc" "namespace"="ms-test" "creating"=1 "need"=2
I1119 03:38:05.233514   10555 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-6j5tc" "namespace"="ms-test" 
I1119 03:38:05.250517   10555 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-6j5tc-p96wz\"" "machineset"="ms-6j5tc" "namespace"="ms-test" 
E1119 03:38:05.325079   10555 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-9fmbd-74d45c49c5-s7kfr\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-9fmbd-74d45c49c5-s7kfr" "namespace"="md-test"
E1119 03:38:05.481444   10555 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-6j5tc-p96wz-fh56x for machine ms-test/ms-6j5tc-p96wz: the cache is not started, can not read objects" "machineset"="ms-6j5tc" "namespace"="ms-test" 
I1119 03:38:05.604755   10555 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-6j5tc-p96wz,ms-6j5tc-fv48w" "indirect descendants count"=2
•

Ran 16 of 16 Specs in 26.542 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (26.54s)
PASS
Tearing down test suite
E1119 03:38:05.608200   10555 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1119 03:38:05.608250   10555 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-527594821/tls.crt: no such file or directory"  
E1119 03:38:05.608265   10555 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1119 03:38:05.608277   10555 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-527594821/tls.crt: no such file or directory"  
I1119 03:38:05.608488   10555 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I1119 03:38:05.608558   10555 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I1119 03:38:05.608597   10555 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I1119 03:38:05.608616   10555 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I1119 03:38:05.608526   10555 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I1119 03:38:05.608545   10555 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I1119 03:38:05.608699   10555 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E1119 03:38:05.638636   10555 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:38603/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1295&timeout=10s&timeoutSeconds=393&watch=true: dial tcp 127.0.0.1:38603: connect: connection refused
E1119 03:38:05.638653   10555 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:38603/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1295&timeout=10s&timeoutSeconds=579&watch=true: dial tcp 127.0.0.1:38603: connect: connection refused
E1119 03:38:05.639046   10555 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:38603/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1295&timeout=10s&timeoutSeconds=522&watch=true: dial tcp 127.0.0.1:38603: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	82.008s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.01s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 261 lines ...
I1119 03:36:55.720160   10792 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I1119 03:36:55.735802   10792 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":{}}}
I1119 03:36:55.936199   10792 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I1119 03:36:55.936256   10792 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I1119 03:36:56.239009   10792 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I1119 03:36:56.789612   10792 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E1119 03:36:58.888866   10792 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-h8mzr/test-cluster"
•E1119 03:36:59.343440   10792 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-wjtxw/test-cluster"
•E1119 03:36:59.881288   10792 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:46733/?timeout=50ms: dial tcp 127.0.0.1:46733: connect: connection refused"  "cluster"="cluster-cache-test-4945x/test-cluster"
•I1119 03:37:00.103351   10792 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}}}
I1119 03:37:00.203721   10792 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I1119 03:37:00.203780   10792 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I1119 03:37:00.396024   10792 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I1119 03:37:00.396162   10792 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E1119 03:37:00.438197   10792 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:33865/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:33865: connect: connection refused


Ran 5 of 5 Specs in 15.566 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (15.57s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	15.734s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 201 lines ...
I1119 03:37:09.707856   11628 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39367
I1119 03:37:09.708002   11628 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
--- PASS: TestClusterToKubeadmControlPlaneNoControlPlane (0.00s)
=== RUN   TestClusterToKubeadmControlPlaneOtherControlPlane
--- PASS: TestClusterToKubeadmControlPlaneOtherControlPlane (0.00s)
=== RUN   TestReconcileUpdateObservedGeneration
--- FAIL: TestReconcileUpdateObservedGeneration (10.92s)
    controller_test.go:230: 
        Timed out after 10.000s.
        Expected
            <int64>: 2
        to equal
            <int64>: 1
=== RUN   TestReconcileNoClusterOwnerRef
I1119 03:37:20.633207   11628 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
E1119 03:37:20.634612   11628 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
I1119 03:37:20.635334   11628 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I1119 03:37:20.635530   11628 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I1119 03:37:35.233229   11628 scale.go:173]  "msg"="Waiting for machines to be deleted" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "Machines"=""
=== RUN   TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue
I1119 03:37:35.233448   11628 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "failures"="machine  reports APIServerPodHealthy condition is false (Error, )"
=== RUN   TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass
--- PASS: TestPreflightChecks (0.00s)
    --- PASS: TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass (0.00s)
... skipping 18 lines ...
=== RUN   TestAPIs
Running Suite: Controller Suite
===============================
Random Seed: 1668829016
Will run 1 of 1 specs

E1119 03:37:35.261673   11628 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-mebq01\" not found" "kubeadmControlPlane"="kcp-foo-mebq01" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.024 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I1119 03:37:35.263450   11628 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-zhu7mu" "kubeadmControlPlane"="kcp-foo-zhu7mu" "namespace"="test" 
I1119 03:37:36.025439   11628 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-zhu7mu" "kubeadmControlPlane"="kcp-foo-zhu7mu" "namespace"="test" "needRollout"=["kcp-foo-zhu7mu-9jn94"]
I1119 03:37:36.025630   11628 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-zhu7mu" "kubeadmControlPlane"="kcp-foo-zhu7mu" "namespace"="test" "failures"="[machine kcp-foo-zhu7mu-2mvbn does not have APIServerPodHealthy condition, machine kcp-foo-zhu7mu-2mvbn does not have ControllerManagerPodHealthy condition, machine kcp-foo-zhu7mu-2mvbn does not have SchedulerPodHealthy condition, machine kcp-foo-zhu7mu-2mvbn does not have EtcdPodHealthy condition, machine kcp-foo-zhu7mu-2mvbn does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (0.76s)
FAIL
I1119 03:37:36.026775   11628 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	39.649s
I1119 03:37:06.607317   11562 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"
I1119 03:37:06.607446   11562 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I1119 03:37:06.607475   11562 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"
I1119 03:37:06.607491   11562 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I1119 03:37:06.607563   11562 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"
I1119 03:37:06.607580   11562 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1668829014
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.002 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: 1668829014
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
E1119 03:37:08.081239   11562 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"  
E1119 03:37:16.404338   11562 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"  
E1119 03:37:25.390436   11562 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"  
E1119 03:37:36.520712   11562 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"  
E1119 03:37:52.993972   11562 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"  
E1119 03:38:06.002608   11562 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"  
E1119 03:38:23.650050   11562 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"  
E1119 03:38:44.573427   11562 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"  
E1119 03:39:15.589941   11562 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"  
E1119 03:40:00.747129   11562 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 83 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
E1119 03:40:00.754972   11562 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1119 03:40:00.755009   11562 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-882604675/tls.crt: no such file or directory"  
I1119 03:40:00.755039   11562 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	186.048s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I1119 03:37:17.139368   11914 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I1119 03:37:17.139735   11914 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I1119 03:37:17.240147   11914 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I1119 03:37:17.340694   11914 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I1119 03:37:17.340767   11914 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I1119 03:37:17.484174   11914 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-l7r9mv"} 
E1119 03:37:17.517579   11914 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"
•I1119 03:37:18.579097   11914 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-3gqjnt"} 
E1119 03:37:18.617893   11914 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"
•E1119 03:37:19.684386   11914 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"
E1119 03:37:20.704510   11914 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"
•E1119 03:37:21.828624   11914 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"
E1119 03:37:22.852806   11914 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"
•E1119 03:37:23.873051   11914 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"
•I1119 03:37:23.878255   11914 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I1119 03:37:23.878255   11914 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I1119 03:37:23.878302   11914 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 


Ran 5 of 5 Specs in 19.941 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (19.94s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	19.989s
?   	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
E1119 03:37:08.357682   12089 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.01s)
    --- 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 ...
•I1119 03:37:19.708428   12089 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1119 03:37:19.742120   12089 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1119 03:37:19.744501   12089 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I1119 03:37:19.778449   12089 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}}}
I1119 03:37:19.783817   12089 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I1119 03:37:19.813697   12089 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E1119 03:37:19.816454   12089 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1119 03:37:19.816520   12089 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-943307176/tls.crt: no such file or directory"  
E1119 03:37:19.816545   12089 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1119 03:37:19.816564   12089 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-943307176/tls.crt: no such file or directory"  
I1119 03:37:19.816686   12089 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 11.452 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.45s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.693s
?   	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 201 lines ...
I1119 03:37:45.270360   15130 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I1119 03:37:45.270565   15130 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I1119 03:37:45.271436   15130 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I1119 03:37:45.271636   15130 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=42681
I1119 03:37:45.271711   15130 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••I1119 03:37:46.224519   15130 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E1119 03:37:46.224520   15130 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E1119 03:37:46.224584   15130 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-938994718/tls.crt: no such file or directory"  


Ran 14 of 14 Specs in 7.217 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (7.22s)
=== RUN   TestToUnstructured
=== RUN   TestToUnstructured/with_a_typed_object
=== RUN   TestToUnstructured/with_an_unstructured_object
--- PASS: TestToUnstructured (0.00s)
    --- PASS: TestToUnstructured/with_a_typed_object (0.00s)
... skipping 105 lines ...
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#01 (0.00s)
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#02 (0.00s)
=== RUN   TestFromUnstructured
--- PASS: TestFromUnstructured (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/yaml	0.035s
FAIL
make: *** [Makefile:116: test] Error 1