This job view page is being replaced by Spyglass soon. Check out the new job view.
PRykakarap: 🐛 Fix the observedGeneration update
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2021-07-12 16:42
Elapsed4m46s
Revision90135212c719ccceb2be71c351e2ffc1e0d42d3a
Refs 4920

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0712 16:44:56.776843    8462 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0712 16:44:56.777392    8462 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0712 16:44:56.778283    8462 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0712 16:44:56.778482    8462 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39849
I0712 16:44:56.778709    8462 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0712 16:44:57.285898    8462 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" 
•E0712 16:44:57.310780    8462 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:44:57.310840    8462 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-642046602/tls.crt: no such file or directory"  
E0712 16:44:57.310860    8462 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:44:57.310880    8462 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-642046602/tls.crt: no such file or directory"  
I0712 16:44:57.311028    8462 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.250 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.25s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	61.626s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.01s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 302 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 ...
I0712 16:44:28.778959   10545 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}}}
I0712 16:44:28.778990   10545 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0712 16:44:28.779020   10545 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0712 16:44:28.784414   10545 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
I0712 16:44:28.784448   10545 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
I0712 16:44:28.787276   10545 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1
2021/07/12 16:44:29 http: TLS handshake error from 127.0.0.1:59570: 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
I0712 16:44:29.175545   10545 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"
I0712 16:44:29.178421   10545 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
I0712 16:44:29.223831   10545 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
I0712 16:44:29.225409   10545 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"
E0712 16:44:29.227294   10545 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
I0712 16:44:29.227774   10545 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
I0712 16:44:29.557090   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0712 16:44:29.559294   10545 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0712 16:44:29.567879   10545 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wqfq8" "namespace"="test-machine-watches-fjxm2" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0712 16:44:29.567967   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0712 16:44:29.676388   10545 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wqfq8" "namespace"="test-machine-watches-fjxm2" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0712 16:44:29.676480   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0712 16:44:29.776956   10545 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-wqfq8" "namespace"="test-machine-watches-fjxm2" "noderef"="node-1"
E0712 16:44:29.789302   10545 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0712 16:44:29.789356   10545 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0712 16:44:29.888008   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-wqfq8\" in namespace \"test-machine-watches-fjxm2\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-wqfq8" "namespace"="test-machine-watches-fjxm2"
E0712 16:44:30.915585   10545 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-wqfq8\" in namespace \"test-machine-watches-fjxm2\", requeuing: requeue in 1s"  
E0712 16:44:30.921999   10545 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-wqfq8\" in namespace \"test-machine-watches-fjxm2\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-wqfq8\" in namespace \"test-machine-watches-fjxm2\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-wqfq8" "namespace"="test-machine-watches-fjxm2"
--- PASS: TestWatches (1.74s)
=== 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
I0712 16:44:31.153320   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-8jv4c" "namespace"="test-machine-watches-fjxm2" "count"=1
I0712 16:44:31.153392   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-8jv4c" "namespace"="test-machine-watches-fjxm2" "descendants"="Worker machines: machine-created-wqfq8" "indirect descendants count"=0
I0712 16:44:31.169190   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-8jv4c" "namespace"="test-machine-watches-fjxm2" "count"=1
I0712 16:44:31.169262   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-8jv4c" "namespace"="test-machine-watches-fjxm2" "descendants"="Worker machines: machine-created-wqfq8" "indirect descendants count"=0
I0712 16:44:31.922541   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-8jv4c" "machine"="machine-created-wqfq8" "namespace"="test-machine-watches-fjxm2" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"4b08f67f-04f5-4011-b056-05d666aca74f","apiVersion":"v1"}
E0712 16:44:31.982447   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-wqfq8\" not found" "controller"="machine" "name"="machine-created-wqfq8" "namespace"="test-machine-watches-fjxm2"
E0712 16:44:33.025335   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-8zw8d\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-x2p2q\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-x2p2q: secrets \"machine-reconcile-x2p2q-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-8zw8d" "namespace"="default"
I0712 16:44:34.025866   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-x2p2q" "machine"="machine-created-8zw8d" "namespace"="default" "cause"="noderef is nil" "node"=null
I0712 16:44:34.061852   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-x2p2q" "machine"="machine-created-8zw8d" "namespace"="default" "cause"="noderef is nil" "node"=null
I0712 16:44:34.093285   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-x2p2q" "machine"="machine-created-8zw8d" "namespace"="default" "cause"="noderef is nil" "node"=null
E0712 16:44:34.192133   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-8zw8d\" not found" "controller"="machine" "name"="machine-created-8zw8d" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.24s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.24s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 13 lines ...
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0712 16:44:34.218501   10545 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"
E0712 16:44:34.220154   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-x2p2q\" not found" "controller"="cluster" "name"="machine-reconcile-x2p2q" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0712 16:44:34.222721   10545 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
I0712 16:44:34.226814   10545 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.01s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.00s)
... skipping 111 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0712 16:44:34.334881   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvzrc" "namespace"="test-mhc-cmtqq" 
I0712 16:44:34.357812   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0712 16:44:34.357944   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-qrnzt\" not found"  "cluster"="test-mhc-cmtqq/test-cluster-qrnzt"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
E0712 16:44:34.462156   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-nvzrc\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-nvzrc\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-nvzrc" "namespace"="test-mhc-cmtqq"
I0712 16:44:35.465083   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-slg9w" "namespace"="test-mhc-pcljd" 
I0712 16:44:35.465193   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rbr2s" "namespace"="test-mhc-r5bq6" 
I0712 16:44:35.465227   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvzrc" "namespace"="test-mhc-cmtqq" 
I0712 16:44:35.465260   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hxqx2" "namespace"="test-mhc-wndd5" 
I0712 16:44:35.488430   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:44:35.512938   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hxqx2" "namespace"="test-mhc-wndd5" 
I0712 16:44:35.586301   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hxqx2" "namespace"="test-mhc-wndd5" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0712 16:44:35.589360   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wndd5/test-cluster-5v2rt"
E0712 16:44:35.591232   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-5v2rt\" not found" "controller"="cluster" "name"="test-cluster-5v2rt" "namespace"="test-mhc-wndd5"
I0712 16:44:35.604795   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2ld7x" "namespace"="test-mhc-6stlz" 
I0712 16:44:35.633549   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:44:35.665153   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2ld7x" "namespace"="test-mhc-6stlz" 
E0712 16:44:35.724794   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6stlz/test-cluster-mtss4"
I0712 16:44:35.729477   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2ld7x" "namespace"="test-mhc-6stlz" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0712 16:44:35.849517   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
inframachine created: test-mhc-machine-infra-lhqkh
I0712 16:44:35.870125   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-p7mv9
I0712 16:44:35.970782   10545 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-hmkb6/test-mhc-ww9g5/test-mhc-machine-p7mv9/"
E0712 16:44:35.981259   10545 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-rvx89"
node created: test-mhc-node-rvx89
E0712 16:44:35.981894   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rvx89, got []"  "node"="test-mhc-node-rvx89"
inframachine created: test-mhc-machine-infra-kzpcz
I0712 16:44:36.013347   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
machine created: test-mhc-machine-vmfjw
I0712 16:44:36.027230   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.033670   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.034739   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
... skipping 65 lines ...
I0712 16:44:36.194763   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.197583   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.199396   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.200591   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.202852   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.205708   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.206924   10545 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-hmkb6/test-mhc-ww9g5/test-mhc-machine-vmfjw/"
I0712 16:44:36.218950   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.219285   10545 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-hmkb6/test-mhc-ww9g5/test-mhc-machine-vmfjw/"
node created: test-mhc-node-mlv6p
E0712 16:44:36.221781   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mlv6p, got []"  "node"="test-mhc-node-mlv6p"
E0712 16:44:36.223343   10545 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-mlv6p"
I0712 16:44:36.231208   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.258237   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
Cleaning up nodes, machines and infra machines.
I0712 16:44:36.267498   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:36.267922   10545 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hmkb6/test-mhc-ww9g5/test-mhc-machine-p7mv9/"
I0712 16:44:36.302470   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jm9xv" "machine"="test-mhc-machine-p7mv9" "namespace"="test-mhc-hmkb6" "cause"="no control plane members" "node"={"name":"test-mhc-node-rvx89"}
E0712 16:44:36.325864   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hmkb6/test-cluster-jm9xv"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0712 16:44:36.386616   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-p7mv9\" not found" "controller"="machine" "name"="test-mhc-machine-p7mv9" "namespace"="test-mhc-hmkb6"
E0712 16:44:36.427816   10545 machinehealthcheck_controller.go:167] controllers/MachineHealthCheck "msg"="Failed to reconcile MachineHealthCheck" "error"="failed to patch unhealthy machine status for machine: test-mhc-hmkb6/test-mhc-machine-p7mv9: [Machine.cluster.x-k8s.io \"test-mhc-machine-p7mv9\" not found, machines.cluster.x-k8s.io \"test-mhc-machine-p7mv9\" not found]" "cluster"="test-cluster-jm9xv" 
E0712 16:44:36.433562   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[failed to patch unhealthy machine status for machine: test-mhc-hmkb6/test-mhc-machine-p7mv9: [Machine.cluster.x-k8s.io \"test-mhc-machine-p7mv9\" not found, machines.cluster.x-k8s.io \"test-mhc-machine-p7mv9\" not found], machinehealthchecks.cluster.x-k8s.io \"test-mhc-ww9g5\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6"
inframachine created: test-mhc-machine-infra-lfshs
machine created: test-mhc-machine-9rlh2
E0712 16:44:36.608230   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-fjxm2/machine-reconcile-8jv4c"
E0712 16:44:37.387012   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:44:37.433859   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ww9g5" "namespace"="test-mhc-hmkb6" 
I0712 16:44:37.433961   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:37.458559   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:44:37.487844   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:37.500120   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:37.501232   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
... skipping 442 lines ...
I0712 16:44:38.396025   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.397315   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.397828   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.398951   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.400684   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.402381   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.402633   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-9rlh2/"
E0712 16:44:38.403166   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
E0712 16:44:38.417502   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bgdbs, got []"  "node"="test-mhc-node-bgdbs"
node created: test-mhc-node-bgdbs
I0712 16:44:38.425354   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.425654   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-9rlh2/"
I0712 16:44:38.431249   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
inframachine created: test-mhc-machine-infra-ncl6s
machine created: test-mhc-machine-j8mbr
I0712 16:44:38.449847   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.455049   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:38.456089   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
... skipping 415 lines ...
I0712 16:44:39.449726   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.451398   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.455776   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.458113   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.459355   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.460568   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
E0712 16:44:39.461428   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:44:39.461818   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.463087   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.464650   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.465863   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.466960   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:39.468003   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
... skipping 309 lines ...
I0712 16:44:40.462116   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:40.464451   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:40.472044   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:40.474564   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:40.475979   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:40.478672   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:40.479173   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-j8mbr/"
I0712 16:44:40.487846   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:40.488237   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-j8mbr/"
E0712 16:44:40.489194   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:44:40.489228   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:40.489571   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-j8mbr/"
E0712 16:44:40.575173   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7d5h8, got []"  "node"="test-mhc-node-7d5h8"
node created: test-mhc-node-7d5h8
I0712 16:44:40.581928   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
inframachine created: test-mhc-machine-infra-jq8zv
I0712 16:44:40.598935   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
machine created: test-mhc-machine-jccp6
I0712 16:44:40.602719   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
... skipping 276 lines ...
I0712 16:44:41.507073   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.509687   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.514223   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.518612   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.523047   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.524808   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
E0712 16:44:41.527737   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:44:41.530199   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.533857   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.535380   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.537190   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.538644   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:41.540192   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
... skipping 301 lines ...
I0712 16:44:42.543860   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.545292   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.546546   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.547764   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.548853   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.550650   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.551050   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-jccp6/"
I0712 16:44:42.564239   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.564747   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-jccp6/"
I0712 16:44:42.570967   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.571683   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-jccp6/"
E0712 16:44:42.577534   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
node created: test-mhc-node-n989j
E0712 16:44:42.620006   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n989j, got []"  "node"="test-mhc-node-n989j"
Cleaning up nodes, machines and infra machines.
I0712 16:44:42.642426   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.643025   10545 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-nfprs/test-mhc-9hj6f/test-mhc-machine-jccp6/test-mhc-node-n989j"
I0712 16:44:42.654165   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9hj6f" "namespace"="test-mhc-nfprs" 
I0712 16:44:42.654754   10545 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-nfprs/test-mhc-9hj6f/test-mhc-machine-jccp6/"
Cleaning up nodes, machines and infra machines.
I0712 16:44:42.700566   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2hcfg" "namespace"="test-mhc-nfprs" "count"=2
I0712 16:44:42.700650   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2hcfg" "namespace"="test-mhc-nfprs" "descendants"="Worker machines: test-mhc-machine-9rlh2,test-mhc-machine-j8mbr,test-mhc-machine-jccp6" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0712 16:44:42.706519   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2hcfg" "namespace"="test-mhc-nfprs" "count"=2
I0712 16:44:42.706581   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2hcfg" "namespace"="test-mhc-nfprs" "descendants"="Worker machines: test-mhc-machine-jccp6,test-mhc-machine-9rlh2,test-mhc-machine-j8mbr" "indirect descendants count"=1
... skipping 7 lines ...
I0712 16:44:42.890634   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:42.932372   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:43.013379   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:43.178846   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:43.500427   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:43.578095   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2hcfg" "machine"="test-mhc-machine-jccp6" "namespace"="test-mhc-nfprs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-n989j"}
E0712 16:44:43.621358   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jccp6\" not found" "controller"="machine" "name"="test-mhc-machine-jccp6" "namespace"="test-mhc-nfprs"
I0712 16:44:44.141496   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:44.622004   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2hcfg" "machine"="test-mhc-machine-j8mbr" "namespace"="test-mhc-nfprs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-7d5h8"}
E0712 16:44:44.688698   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-j8mbr\" not found" "controller"="machine" "name"="test-mhc-machine-j8mbr" "namespace"="test-mhc-nfprs"
I0712 16:44:45.422570   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:45.689312   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2hcfg" "machine"="test-mhc-machine-9rlh2" "namespace"="test-mhc-nfprs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-bgdbs"}
E0712 16:44:45.731438   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9rlh2\" not found" "controller"="machine" "name"="test-mhc-machine-9rlh2" "namespace"="test-mhc-nfprs"
E0712 16:44:46.731829   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
E0712 16:44:47.719763   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-nfprs/test-cluster-2hcfg"
I0712 16:44:47.743814   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:47.765180   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
E0712 16:44:47.771598   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
node created: test-mhc-node-grjnd
E0712 16:44:47.778513   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-grjnd, got []"  "node"="test-mhc-node-grjnd"
I0712 16:44:47.784848   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:47.795019   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
inframachine created: test-mhc-machine-infra-sxhlc
I0712 16:44:47.820143   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
machine created: test-mhc-machine-knjhl
I0712 16:44:47.848966   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
... skipping 6 lines ...
I0712 16:44:48.500515   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:48.785575   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:48.791607   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:48.802685   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:48.810562   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:48.819711   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
E0712 16:44:48.822778   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:44:48.823317   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
node created: test-mhc-node-wb8th
E0712 16:44:48.849744   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wb8th, got []"  "node"="test-mhc-node-wb8th"
I0712 16:44:48.862333   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
inframachine created: test-mhc-machine-infra-9jks8
machine created: test-mhc-machine-wwvjj
I0712 16:44:48.888168   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:48.906485   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:49.149038   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
... skipping 7 lines ...
I0712 16:44:49.935163   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:49.940581   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:49.949519   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:49.959293   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:49.974496   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
node created: test-mhc-node-2nqxm
E0712 16:44:50.001356   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2nqxm, got []"  "node"="test-mhc-node-2nqxm"
I0712 16:44:50.026438   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
Cleaning up nodes, machines and infra machines.
I0712 16:44:50.048741   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:50.074030   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-m8g5w" "machine"="test-mhc-machine-knjhl" "namespace"="test-mhc-5gq28" "cause"="no control plane members" "node"={"name":"test-mhc-node-wb8th"}
Cleaning up nodes, machines and infra machines.
I0712 16:44:50.106775   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-m8g5w" "namespace"="test-mhc-5gq28" "count"=3
I0712 16:44:50.106872   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-m8g5w" "namespace"="test-mhc-5gq28" "descendants"="Worker machines: test-mhc-machine-wwvjj,test-mhc-machine-xrl62,test-mhc-machine-knjhl" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
I0712 16:44:50.111272   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-m8g5w" "namespace"="test-mhc-5gq28" "count"=3
I0712 16:44:50.111335   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-m8g5w" "namespace"="test-mhc-5gq28" "descendants"="Worker machines: test-mhc-machine-xrl62,test-mhc-machine-knjhl,test-mhc-machine-wwvjj" "indirect descendants count"=0
E0712 16:44:50.122958   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-knjhl\" not found" "controller"="machine" "name"="test-mhc-machine-knjhl" "namespace"="test-mhc-5gq28"
inframachine created: test-mhc-machine-infra-lmcbr
machine created: test-mhc-machine-r5d89
E0712 16:44:50.265228   10545 machinehealthcheck_controller.go:167] controllers/MachineHealthCheck "msg"="Failed to reconcile MachineHealthCheck" "error"="failed to patch machine status for machine: test-mhc-5gq28/test-mhc-machine-knjhl: [Machine.cluster.x-k8s.io \"test-mhc-machine-knjhl\" not found, machines.cluster.x-k8s.io \"test-mhc-machine-knjhl\" not found]" "cluster"="test-cluster-m8g5w" 
E0712 16:44:50.265586   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch machine status for machine: test-mhc-5gq28/test-mhc-machine-knjhl: [Machine.cluster.x-k8s.io \"test-mhc-machine-knjhl\" not found, machines.cluster.x-k8s.io \"test-mhc-machine-knjhl\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28"
I0712 16:44:51.123466   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-m8g5w" "machine"="test-mhc-machine-wwvjj" "namespace"="test-mhc-5gq28" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2nqxm"}
E0712 16:44:51.188138   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wwvjj\" not found" "controller"="machine" "name"="test-mhc-machine-wwvjj" "namespace"="test-mhc-5gq28"
I0712 16:44:51.265932   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:51.288858   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:44:51.406788   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cx8sg" "namespace"="test-mhc-5gq28" 
I0712 16:44:51.406862   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:51.412679   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:52.188662   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-m8g5w" "machine"="test-mhc-machine-xrl62" "namespace"="test-mhc-5gq28" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-grjnd"}
E0712 16:44:52.254265   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xrl62\" not found" "controller"="machine" "name"="test-mhc-machine-xrl62" "namespace"="test-mhc-5gq28"
E0712 16:44:53.257169   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:44:54.266173   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.272015   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
node created: test-mhc-node-c8gbw
E0712 16:44:54.283225   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-c8gbw, got []"  "node"="test-mhc-node-c8gbw"
E0712 16:44:54.283459   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-c8gbw, got []"  "node"="test-mhc-node-c8gbw"
I0712 16:44:54.291612   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.296830   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
inframachine created: test-mhc-machine-infra-s26k4
I0712 16:44:54.315261   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.316349   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.320988   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
... skipping 6 lines ...
I0712 16:44:54.357390   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.365874   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.371805   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.398144   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.410974   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.437626   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
E0712 16:44:54.445661   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d744x, got []"  "node"="test-mhc-node-d744x"
node created: test-mhc-node-d744x
E0712 16:44:54.445848   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d744x, got []"  "node"="test-mhc-node-d744x"
I0712 16:44:54.448031   10545 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-k2szf" "namespace"="test-mhc-8nlch" "noderef"="test-mhc-node-d744x"
E0712 16:44:54.457107   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d744x, got []"  "node"="test-mhc-node-d744x"
E0712 16:44:54.457158   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d744x, got []"  "node"="test-mhc-node-d744x"
E0712 16:44:54.457192   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d744x, got []"  "node"="test-mhc-node-d744x"
E0712 16:44:54.457221   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d744x, got []"  "node"="test-mhc-node-d744x"
I0712 16:44:54.457618   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
inframachine created: test-mhc-machine-infra-ls5r9
machine created: test-mhc-machine-6bwxm
I0712 16:44:54.666810   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.673091   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
Cleaning up nodes, machines and infra machines.
I0712 16:44:54.690522   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.690640   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2vndm" "machine"="test-mhc-machine-6bwxm" "namespace"="test-mhc-8nlch" "cause"="noderef is nil" "node"=null
I0712 16:44:54.697411   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
Cleaning up nodes, machines and infra machines.
I0712 16:44:54.710877   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.711506   10545 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8nlch/test-mhc-scllp/test-mhc-machine-r5d89/"
I0712 16:44:54.759551   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:54.760539   10545 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8nlch/test-mhc-scllp/test-mhc-machine-r5d89/"
I0712 16:44:54.761309   10545 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8nlch/test-mhc-scllp/test-mhc-machine-k2szf/"
E0712 16:44:54.766163   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6bwxm\" not found" "controller"="machine" "name"="test-mhc-machine-6bwxm" "namespace"="test-mhc-8nlch"
I0712 16:44:54.772355   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2vndm" "namespace"="test-mhc-8nlch" "count"=2
I0712 16:44:54.772809   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2vndm" "namespace"="test-mhc-8nlch" "descendants"="Worker machines: test-mhc-machine-r5d89,test-mhc-machine-k2szf" "indirect descendants count"=0
I0712 16:44:54.777985   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-2vndm" "namespace"="test-mhc-8nlch" "count"=2
I0712 16:44:54.778048   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2vndm" "namespace"="test-mhc-8nlch" "descendants"="Worker machines: test-mhc-machine-k2szf,test-mhc-machine-r5d89" "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
E0712 16:44:54.793699   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-scllp\" not found" "controller"="machinehealthcheck" "name"="test-mhc-scllp" "namespace"="test-mhc-8nlch"
inframachine created: test-mhc-machine-infra-mbswm
machine created: test-mhc-machine-4frw5
E0712 16:44:55.124837   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5gq28/test-cluster-m8g5w"
I0712 16:44:55.769212   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2vndm" "machine"="test-mhc-machine-r5d89" "namespace"="test-mhc-8nlch" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-c8gbw"}
I0712 16:44:55.793931   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-scllp" "namespace"="test-mhc-8nlch" 
I0712 16:44:55.794005   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:55.809013   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0712 16:44:55.820988   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-r5d89\" not found" "controller"="machine" "name"="test-mhc-machine-r5d89" "namespace"="test-mhc-8nlch"
I0712 16:44:55.832800   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:55.833872   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:55.835938   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:55.837633   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:55.839374   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:55.841081   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
... skipping 487 lines ...
I0712 16:44:56.851332   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.854209   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.860556   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.862504   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.864389   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.866272   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
E0712 16:44:56.867473   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-k2szf\" not found" "controller"="machine" "name"="test-mhc-machine-k2szf" "namespace"="test-mhc-8nlch"
I0712 16:44:56.869448   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.871366   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.873466   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.875160   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.876849   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:56.878628   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
... skipping 474 lines ...
I0712 16:44:57.873943   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.876438   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.878158   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.878730   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.879832   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.881795   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.882019   10545 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-6c7s5/test-mhc-5rjts/test-mhc-machine-4frw5/"
E0712 16:44:57.890352   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:44:57.902315   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.902781   10545 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-6c7s5/test-mhc-5rjts/test-mhc-machine-4frw5/"
I0712 16:44:57.904498   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.904757   10545 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-6c7s5/test-mhc-5rjts/test-mhc-machine-4frw5/"
E0712 16:44:57.940123   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jt7r5, got []"  "node"="test-mhc-node-jt7r5"
node created: test-mhc-node-jt7r5
E0712 16:44:57.941080   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jt7r5, got []"  "node"="test-mhc-node-jt7r5"
I0712 16:44:57.947726   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.962298   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.967424   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.972773   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.973142   10545 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-6c7s5/test-mhc-5rjts/test-mhc-machine-4frw5/test-mhc-node-jt7r5"
I0712 16:44:57.991321   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.991736   10545 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-6c7s5/test-mhc-5rjts/test-mhc-machine-4frw5/test-mhc-node-jt7r5"
I0712 16:44:57.992400   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.992645   10545 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-6c7s5/test-mhc-5rjts/test-mhc-machine-4frw5/test-mhc-node-jt7r5"
Cleaning up nodes, machines and infra machines.
I0712 16:44:57.996407   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:57.996614   10545 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-6c7s5/test-mhc-5rjts/test-mhc-machine-4frw5/"
I0712 16:44:58.011462   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jwrp2" "namespace"="test-mhc-6c7s5" "descendants"="Worker machines: test-mhc-machine-4frw5" "indirect descendants count"=1
I0712 16:44:58.015873   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jwrp2" "namespace"="test-mhc-6c7s5" "descendants"="Worker machines: test-mhc-machine-4frw5" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0712 16:44:58.098708   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" "creating"=1 "need"=1
I0712 16:44:58.098760   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:44:58.110043   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-ffpxv-v87nx\"" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:44:58.172487   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5rjts" "namespace"="test-mhc-6c7s5" 
I0712 16:44:58.190364   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
I0712 16:44:58.209814   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:44:58.215757   10545 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:44:58.341026   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
I0712 16:44:58.893978   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jwrp2" "machine"="test-mhc-machine-4frw5" "namespace"="test-mhc-6c7s5" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jt7r5"}
E0712 16:44:58.955893   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-4frw5\" not found" "controller"="machine" "name"="test-mhc-machine-4frw5" "namespace"="test-mhc-6c7s5"
I0712 16:44:59.349049   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
E0712 16:44:59.794347   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8nlch/test-cluster-2vndm"
I0712 16:44:59.969304   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
I0712 16:44:59.970243   10545 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:44:59.979842   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
I0712 16:44:59.980213   10545 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:44:59.989130   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9" 
I0712 16:44:59.989177   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9" 
I0712 16:44:59.994734   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
I0712 16:44:59.994768   10545 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.000211   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.000570   10545 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-dk7z9/test-mhc-z4nnq/mhc-ms-ffpxv-v87nx/"
I0712 16:45:00.001932   10545 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.006693   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.006747   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.008285   10545 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.013510   10545 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.016366   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9" 
... skipping 7 lines ...
I0712 16:45:00.035966   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.035992   10545 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" "machine"="mhc-ms-ffpxv-v87nx"
I0712 16:45:00.041492   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-zmmmc" "machine"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9" "cause"="cluster is being deleted" "node"=null
I0712 16:45:00.042991   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.044251   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zmmmc" "namespace"="test-mhc-dk7z9" "descendants"="Machine sets: mhc-ms-ffpxv;Worker machines: mhc-ms-ffpxv-v87nx" "indirect descendants count"=1
I0712 16:45:00.044438   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
E0712 16:45:00.053649   10545 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-ffpxv\" not found" "machineset"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9" 
E0712 16:45:00.053732   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-ffpxv\" not found" "controller"="machineset" "name"="mhc-ms-ffpxv" "namespace"="test-mhc-dk7z9"
I0712 16:45:00.054210   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zmmmc" "namespace"="test-mhc-dk7z9" "descendants"="Worker machines: mhc-ms-ffpxv-v87nx" "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
I0712 16:45:00.140081   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
inframachine created: test-mhc-machine-infra-2fs85
I0712 16:45:00.158381   10545 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
... skipping 25 lines ...
I0712 16:45:00.263501   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.265330   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.267232   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.268965   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.269646   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.270135   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-zmmmc" "machine"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9" "cause"="cluster is being deleted" "node"=null
E0712 16:45:00.367966   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n44f5, got []"  "node"="test-mhc-node-n44f5"
E0712 16:45:00.368259   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n44f5, got []"  "node"="test-mhc-node-n44f5"
node created: test-mhc-node-n44f5
E0712 16:45:00.368340   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n44f5, got []"  "node"="test-mhc-node-n44f5"
I0712 16:45:00.393930   10545 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-x24kn" "target"="test-mhc-fc6hv/test-mhc-hpm9w/test-mhc-machine-x24kn/"
E0712 16:45:00.394331   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-ffpxv-v87nx\" not found" "controller"="machine" "name"="mhc-ms-ffpxv-v87nx" "namespace"="test-mhc-dk7z9"
I0712 16:45:00.551307   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z4nnq" "namespace"="test-mhc-dk7z9" 
I0712 16:45:00.551392   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.571022   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.582966   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.586117   10545 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-x24kn" "target"="test-mhc-fc6hv/test-mhc-hpm9w/test-mhc-machine-x24kn/test-mhc-node-n44f5"
I0712 16:45:00.604326   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.607351   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
Cleaning up nodes, machines and infra machines.
I0712 16:45:00.625453   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.629093   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
I0712 16:45:00.637793   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hpm9w" "namespace"="test-mhc-fc6hv" 
... skipping 334 lines ...
I0712 16:45:01.428515   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.430329   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.432079   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.433838   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.435553   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.437261   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
E0712 16:45:01.438145   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-x24kn\" not found" "controller"="machine" "name"="test-mhc-machine-x24kn" "namespace"="test-mhc-fc6hv"
I0712 16:45:01.438993   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.440674   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.442425   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.444127   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.447884   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:01.449650   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
... skipping 485 lines ...
I0712 16:45:02.442907   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.444987   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.448108   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.448836   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.450121   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.452002   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.455301   10545 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-5qz2s" "target"="test-mhc-kftbz/test-mhc-5w4zc/test-mhc-machine-5qz2s/"
I0712 16:45:02.467068   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
node created: test-mhc-node-8jzr8
E0712 16:45:02.527967   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8jzr8, got []"  "node"="test-mhc-node-8jzr8"
E0712 16:45:02.527967   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8jzr8, got []"  "node"="test-mhc-node-8jzr8"
E0712 16:45:02.528187   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8jzr8, got []"  "node"="test-mhc-node-8jzr8"
E0712 16:45:02.528540   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8jzr8, got []"  "node"="test-mhc-node-8jzr8"
I0712 16:45:02.542879   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.569636   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.580544   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.586102   10545 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-5qz2s" "target"="test-mhc-kftbz/test-mhc-5w4zc/test-mhc-machine-5qz2s/test-mhc-node-8jzr8"
I0712 16:45:02.647362   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.651201   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.654741   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.683983   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.686268   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.696070   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
Cleaning up nodes, machines and infra machines.
I0712 16:45:02.697976   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.701961   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
I0712 16:45:02.713031   10545 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-5qz2s" "target"="test-mhc-kftbz/test-mhc-5w4zc/test-mhc-machine-5qz2s/"
I0712 16:45:02.714852   10545 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-48jn6" "machine"="test-mhc-machine-5qz2s" "namespace"="test-mhc-kftbz" "cause"="no control plane members" "node"={"name":"test-mhc-node-8jzr8"}
I0712 16:45:02.720833   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-48jn6" "namespace"="test-mhc-kftbz" "count"=1
I0712 16:45:02.720959   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-48jn6" "namespace"="test-mhc-kftbz" "descendants"="Worker machines: test-mhc-machine-5qz2s" "indirect descendants count"=0
I0712 16:45:02.725811   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-48jn6" "namespace"="test-mhc-kftbz" "count"=1
I0712 16:45:02.725865   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-48jn6" "namespace"="test-mhc-kftbz" "descendants"="Worker machines: test-mhc-machine-5qz2s" "indirect descendants count"=0
E0712 16:45:02.738622   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-5w4zc\" not found" "controller"="machinehealthcheck" "name"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz"
--- PASS: TestMachineHealthCheck_Reconcile (28.43s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.15s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.14s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.59s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.09s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0712 16:45:02.740166   10545 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
E0712 16:45:02.742014   10545 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
E0712 16:45:02.743763   10545 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0712 16:45:02.744021   10545 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
E0712 16:45:02.744488   10545 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
I0712 16:45:02.747204   10545 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0712 16:45:02.747848   10545 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0712 16:45:02.749654   10545 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
E0712 16:45:02.759036   10545 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
E0712 16:45:02.760759   10545 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 62 lines ...

I0712 16:45:02.846813   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0712 16:45:02.846868   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
I0712 16:45:02.870630   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-8g6zk-6657c7fddb-l9kt5\"" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
I0712 16:45:02.870698   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
I0712 16:45:02.889168   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-8g6zk-6657c7fddb-dp7kp\"" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
E0712 16:45:02.902956   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5qz2s\" not found" "controller"="machine" "name"="test-mhc-machine-5qz2s" "namespace"="test-mhc-kftbz"
I0712 16:45:02.999050   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0712 16:45:02.999104   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
I0712 16:45:03.010327   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-8g6zk-6657c7fddb-xkr5n\"" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
I0712 16:45:03.010417   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
I0712 16:45:03.021896   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-8g6zk-6657c7fddb-sl7kf\"" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
E0712 16:45:03.037380   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6c7s5/test-cluster-jwrp2"
I0712 16:45:03.053729   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:45:03.053780   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
I0712 16:45:03.067132   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8g6zk-6657c7fddb-d9nj9\"" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" 
I0712 16:45:03.193623   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0712 16:45:03.193682   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" 
I0712 16:45:03.208099   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8g6zk-cdfc6fd6c-fb2nk\"" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" 
E0712 16:45:03.260188   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.260188   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.260681   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.364280   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.364339   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.364468   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.364508   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.364515   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.364537   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw, got []"  "node"="md-8g6zk-cdfc6fd6c-fb2nk-r9pvw"
E0712 16:45:03.412541   10545 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-8g6zk-cdfc6fd6c-fb2nk-r9pvw for machine md-test/md-8g6zk-cdfc6fd6c-fb2nk: the cache is not started, can not read objects" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" 
I0712 16:45:03.451436   10545 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0712 16:45:03.451490   10545 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:45:03.461603   10545 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "machine"="md-8g6zk-6657c7fddb-xkr5n"
I0712 16:45:03.484957   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0712 16:45:03.485007   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" 
I0712 16:45:03.502197   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8g6zk-cdfc6fd6c-zxkps\"" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" 
E0712 16:45:03.607720   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
E0712 16:45:03.607906   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
E0712 16:45:03.607921   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
E0712 16:45:03.610411   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
E0712 16:45:03.610470   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
E0712 16:45:03.610636   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
E0712 16:45:03.610681   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
E0712 16:45:03.610642   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
E0712 16:45:03.610722   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-zxkps-kwbtn, got []"  "node"="md-8g6zk-cdfc6fd6c-zxkps-kwbtn"
I0712 16:45:03.664462   10545 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0712 16:45:03.664549   10545 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:45:03.668895   10545 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "machine"="md-8g6zk-6657c7fddb-d9nj9"
I0712 16:45:03.699833   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:45:03.699883   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" 
I0712 16:45:03.733394   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8g6zk-cdfc6fd6c-tmz8n\"" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" 
I0712 16:45:03.738869   10545 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5w4zc" "namespace"="test-mhc-kftbz" 
E0712 16:45:03.770209   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.770209   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.770333   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.874619   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.874679   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.874619   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.874713   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.874910   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.874947   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-cdfc6fd6c-tmz8n-pnxgj, got []"  "node"="md-8g6zk-cdfc6fd6c-tmz8n-pnxgj"
E0712 16:45:03.947099   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:45:03.956766   10545 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0712 16:45:03.956810   10545 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:45:03.962338   10545 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8g6zk-6657c7fddb" "namespace"="md-test" "machine"="md-8g6zk-6657c7fddb-sl7kf"
I0712 16:45:04.101807   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0712 16:45:04.101862   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" 
I0712 16:45:04.121374   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8g6zk-74d45c49c5-b6gvc\"" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" 
E0712 16:45:04.192659   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
E0712 16:45:04.192659   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
E0712 16:45:04.192676   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
E0712 16:45:04.195786   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
E0712 16:45:04.195841   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
E0712 16:45:04.195786   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
E0712 16:45:04.195855   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
E0712 16:45:04.195875   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
E0712 16:45:04.195914   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-b6gvc-gkvfs, got []"  "node"="md-8g6zk-74d45c49c5-b6gvc-gkvfs"
I0712 16:45:04.239565   10545 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0712 16:45:04.239611   10545 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0712 16:45:04.245406   10545 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "machine"="md-8g6zk-cdfc6fd6c-zxkps"
I0712 16:45:04.355418   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0712 16:45:04.355467   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" 
I0712 16:45:04.367332   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8g6zk-74d45c49c5-9jzgf\"" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" 
E0712 16:45:04.459864   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
E0712 16:45:04.459882   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
E0712 16:45:04.459940   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
E0712 16:45:04.463318   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
E0712 16:45:04.463343   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
E0712 16:45:04.463380   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
E0712 16:45:04.463384   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
E0712 16:45:04.463318   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
E0712 16:45:04.463417   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-9jzgf-qd7dq, got []"  "node"="md-8g6zk-74d45c49c5-9jzgf-qd7dq"
I0712 16:45:04.545051   10545 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0712 16:45:04.545103   10545 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0712 16:45:04.553779   10545 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-8g6zk-cdfc6fd6c" "namespace"="md-test" "machine"="md-8g6zk-cdfc6fd6c-tmz8n"
I0712 16:45:04.587629   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:45:04.587689   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" 
I0712 16:45:04.599868   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-8g6zk-74d45c49c5-wxf5v\"" "machineset"="md-8g6zk-74d45c49c5" "namespace"="md-test" 
E0712 16:45:04.782372   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
E0712 16:45:04.782423   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
E0712 16:45:04.782572   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
E0712 16:45:04.788360   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
E0712 16:45:04.788431   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
E0712 16:45:04.788657   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
E0712 16:45:04.788659   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
E0712 16:45:04.788691   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
E0712 16:45:04.788699   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-8g6zk-74d45c49c5-wxf5v-pczc8, got []"  "node"="md-8g6zk-74d45c49c5-wxf5v-pczc8"
I0712 16:45:04.854627   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8g6zk-74d45c49c5,md-8g6zk-cdfc6fd6c;Worker machines: md-8g6zk-6657c7fddb-dp7kp,md-8g6zk-74d45c49c5-9jzgf,md-8g6zk-74d45c49c5-b6gvc,md-8g6zk-74d45c49c5-wxf5v,md-8g6zk-cdfc6fd6c-fb2nk,md-8g6zk-6657c7fddb-l9kt5" "indirect descendants count"=8
E0712 16:45:04.856589   10545 machinedeployment_controller.go:149] controllers/MachineDeployment "msg"="Failed to reconcile MachineDeployment" "error"="MachineDeployment.cluster.x-k8s.io \"md-8g6zk\" not found" "machinedeployment"="md-8g6zk" "namespace"="md-test" 
E0712 16:45:04.857032   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="MachineDeployment.cluster.x-k8s.io \"md-8g6zk\" not found" "controller"="machinedeployment" "name"="md-8g6zk" "namespace"="md-test"
I0712 16:45:04.858513   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8g6zk-74d45c49c5,md-8g6zk-cdfc6fd6c;Worker machines: md-8g6zk-74d45c49c5-9jzgf,md-8g6zk-74d45c49c5-b6gvc,md-8g6zk-74d45c49c5-wxf5v,md-8g6zk-cdfc6fd6c-fb2nk,md-8g6zk-6657c7fddb-l9kt5,md-8g6zk-6657c7fddb-dp7kp" "indirect descendants count"=8
•I0712 16:45:04.859346   10545 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"
I0712 16:45:04.860416   10545 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0712 16:45:04.860475   10545 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"
I0712 16:45:04.862301   10545 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0712 16:45:04.862357   10545 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
... skipping 14 lines ...
I0712 16:45:04.884902   10545 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"
•I0712 16:45:04.886950   10545 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"
I0712 16:45:04.887672   10545 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"
I0712 16:45:04.888267   10545 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0712 16:45:04.888297   10545 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0712 16:45:04.888752   10545 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0712 16:45:04.890533   10545 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" 
•I0712 16:45:04.971112   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:04.971165   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:04.992449   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:04.992498   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:05.055603   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-5cg9m" "namespace"="ms-test" "creating"=2 "need"=2
I0712 16:45:05.055650   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-5cg9m" "namespace"="ms-test" 
E0712 16:45:05.079748   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-dk7z9/test-cluster-zmmmc"
I0712 16:45:05.088661   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-5cg9m-xmdrr\"" "machineset"="ms-5cg9m" "namespace"="ms-test" 
I0712 16:45:05.088710   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-5cg9m" "namespace"="ms-test" 
I0712 16:45:05.144907   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-5cg9m-zb72c\"" "machineset"="ms-5cg9m" "namespace"="ms-test" 
E0712 16:45:05.160428   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-cdfc6fd6c-fb2nk\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-cdfc6fd6c-fb2nk" "namespace"="md-test"
I0712 16:45:05.283528   10545 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-5cg9m" "namespace"="ms-test" "creating"=1 "need"=2
I0712 16:45:05.283587   10545 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-5cg9m" "namespace"="ms-test" 
I0712 16:45:05.309772   10545 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-5cg9m-fpd74\"" "machineset"="ms-5cg9m" "namespace"="ms-test" 
E0712 16:45:05.397118   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-xmdrr-djzdt, got []"  "node"="ms-5cg9m-xmdrr-djzdt"
E0712 16:45:05.397173   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-xmdrr-djzdt, got []"  "node"="ms-5cg9m-xmdrr-djzdt"
E0712 16:45:05.400290   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-xmdrr-djzdt, got []"  "node"="ms-5cg9m-xmdrr-djzdt"
E0712 16:45:05.400371   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-xmdrr-djzdt, got []"  "node"="ms-5cg9m-xmdrr-djzdt"
E0712 16:45:05.400476   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-xmdrr-djzdt, got []"  "node"="ms-5cg9m-xmdrr-djzdt"
E0712 16:45:05.400574   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-xmdrr-djzdt, got []"  "node"="ms-5cg9m-xmdrr-djzdt"
E0712 16:45:05.432568   10545 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-5cg9m-xmdrr-djzdt for machine ms-test/ms-5cg9m-xmdrr: the cache is not started, can not read objects" "machineset"="ms-5cg9m" "namespace"="ms-test" 
E0712 16:45:05.442701   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-fpd74-rw42v, got []"  "node"="ms-5cg9m-fpd74-rw42v"
E0712 16:45:05.442775   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-fpd74-rw42v, got []"  "node"="ms-5cg9m-fpd74-rw42v"
E0712 16:45:05.546790   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-fpd74-rw42v, got []"  "node"="ms-5cg9m-fpd74-rw42v"
E0712 16:45:05.546822   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-fpd74-rw42v, got []"  "node"="ms-5cg9m-fpd74-rw42v"
E0712 16:45:05.546850   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-fpd74-rw42v, got []"  "node"="ms-5cg9m-fpd74-rw42v"
E0712 16:45:05.546864   10545 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-5cg9m-fpd74-rw42v, got []"  "node"="ms-5cg9m-fpd74-rw42v"
E0712 16:45:05.660201   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fc6hv/test-cluster-lcjbc"
I0712 16:45:05.669477   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-5cg9m-xmdrr,ms-5cg9m-fpd74" "indirect descendants count"=2
I0712 16:45:05.674607   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-5cg9m-xmdrr,ms-5cg9m-fpd74" "indirect descendants count"=2
••E0712 16:45:05.809796   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-lhsll\" not found" "controller"="cluster" "name"="test1-lhsll" "namespace"="default"
I0712 16:45:06.165401   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:06.165453   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:06.169850   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:06.169896   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
E0712 16:45:06.201680   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-b6gvc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-b6gvc" "namespace"="md-test"
•I0712 16:45:06.960162   10545 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-6hxhg" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0712 16:45:07.082246   10545 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-6hxhg" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0712 16:45:07.087688   10545 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-6hxhg" "namespace"="default"
E0712 16:45:07.240949   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-9jzgf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-9jzgf" "namespace"="md-test"
E0712 16:45:08.113766   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
•E0712 16:45:08.313775   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-cdfc6fd6c-fb2nk\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-cdfc6fd6c-fb2nk" "namespace"="md-test"
E0712 16:45:09.125458   10545 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kftbz/test-cluster-48jn6"
E0712 16:45:09.137796   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-dglvc\" not found" "controller"="cluster" "name"="test3-dglvc" "namespace"="default"
E0712 16:45:09.330428   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-b6gvc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-b6gvc" "namespace"="md-test"
E0712 16:45:10.138715   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
I0712 16:45:10.335052   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:10.335093   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:10.339252   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:10.339291   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
E0712 16:45:10.344193   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-9jzgf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-9jzgf" "namespace"="md-test"
I0712 16:45:11.148051   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8g6zk-74d45c49c5,md-8g6zk-cdfc6fd6c;Worker machines: md-8g6zk-cdfc6fd6c-fb2nk,md-8g6zk-6657c7fddb-l9kt5,md-8g6zk-6657c7fddb-dp7kp,md-8g6zk-74d45c49c5-9jzgf,md-8g6zk-74d45c49c5-b6gvc,md-8g6zk-74d45c49c5-wxf5v" "indirect descendants count"=8
E0712 16:45:11.148491   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
•E0712 16:45:11.388359   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-cdfc6fd6c-fb2nk\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-cdfc6fd6c-fb2nk" "namespace"="md-test"
I0712 16:45:12.148959   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-5cg9m-xmdrr,ms-5cg9m-fpd74" "indirect descendants count"=2
E0712 16:45:12.152847   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
E0712 16:45:12.426018   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-b6gvc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-b6gvc" "namespace"="md-test"
E0712 16:45:13.153519   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
E0712 16:45:13.430875   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-9jzgf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-9jzgf" "namespace"="md-test"
E0712 16:45:14.162886   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
•I0712 16:45:14.435180   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:14.435214   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:14.438421   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:14.438454   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
E0712 16:45:14.454366   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-cdfc6fd6c-fb2nk\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-cdfc6fd6c-fb2nk" "namespace"="md-test"
E0712 16:45:15.163583   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
E0712 16:45:15.475084   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-b6gvc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-b6gvc" "namespace"="md-test"
E0712 16:45:16.164271   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
E0712 16:45:16.480234   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-9jzgf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-9jzgf" "namespace"="md-test"
E0712 16:45:17.183898   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
E0712 16:45:17.480650   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jm9xv\" for machine \"test-mhc-machine-vmfjw\" in namespace \"test-mhc-hmkb6\": Cluster.cluster.x-k8s.io \"test-cluster-jm9xv\" not found" "controller"="machine" "name"="test-mhc-machine-vmfjw" "namespace"="test-mhc-hmkb6"
I0712 16:45:18.184514   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8g6zk-74d45c49c5,md-8g6zk-cdfc6fd6c;Worker machines: md-8g6zk-74d45c49c5-wxf5v,md-8g6zk-cdfc6fd6c-fb2nk,md-8g6zk-6657c7fddb-l9kt5,md-8g6zk-6657c7fddb-dp7kp,md-8g6zk-74d45c49c5-9jzgf,md-8g6zk-74d45c49c5-b6gvc" "indirect descendants count"=8
E0712 16:45:18.185068   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
E0712 16:45:18.490486   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-cdfc6fd6c-fb2nk\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-cdfc6fd6c-fb2nk" "namespace"="md-test"
I0712 16:45:19.185559   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-5cg9m-xmdrr,ms-5cg9m-fpd74" "indirect descendants count"=2
E0712 16:45:19.186168   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
I0712 16:45:19.494665   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:19.494701   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:19.498194   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:19.498232   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
E0712 16:45:19.504739   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-b6gvc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-b6gvc" "namespace"="md-test"
E0712 16:45:20.186794   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
E0712 16:45:20.509441   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-9jzgf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-9jzgf" "namespace"="md-test"
E0712 16:45:21.187619   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
E0712 16:45:21.523895   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-cdfc6fd6c-fb2nk\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-cdfc6fd6c-fb2nk" "namespace"="md-test"
E0712 16:45:22.188371   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
E0712 16:45:22.529011   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-b6gvc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-b6gvc" "namespace"="md-test"
E0712 16:45:23.189112   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
I0712 16:45:23.533090   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:23.533127   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:23.536624   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:23.536659   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
E0712 16:45:23.540600   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-9jzgf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-9jzgf" "namespace"="md-test"
E0712 16:45:24.189832   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
I0712 16:45:24.555075   10545 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-bms7t" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0712 16:45:24.565290   10545 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-bms7t" "namespace"="default" 
E0712 16:45:24.577518   10545 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-bms7t" "namespace"="default"
I0712 16:45:25.190426   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-8g6zk-74d45c49c5,md-8g6zk-cdfc6fd6c;Worker machines: md-8g6zk-cdfc6fd6c-fb2nk,md-8g6zk-6657c7fddb-l9kt5,md-8g6zk-6657c7fddb-dp7kp,md-8g6zk-74d45c49c5-9jzgf,md-8g6zk-74d45c49c5-b6gvc,md-8g6zk-74d45c49c5-wxf5v" "indirect descendants count"=8
E0712 16:45:25.190864   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
E0712 16:45:25.582254   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-cdfc6fd6c-fb2nk\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-cdfc6fd6c-fb2nk" "namespace"="md-test"
I0712 16:45:26.191407   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-5cg9m-xmdrr,ms-5cg9m-fpd74" "indirect descendants count"=2
E0712 16:45:26.191908   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
E0712 16:45:26.587002   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-b6gvc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-b6gvc" "namespace"="md-test"
E0712 16:45:27.192760   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-6hxhg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-6hxhg" "namespace"="default"
E0712 16:45:27.593691   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-8g6zk-74d45c49c5-9jzgf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-8g6zk-74d45c49c5-9jzgf" "namespace"="md-test"
E0712 16:45:28.193503   10545 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-k92s2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-k92s2" "namespace"="default"
I0712 16:45:28.597945   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:28.597994   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-l9kt5" "namespace"="md-test" 
I0712 16:45:28.601967   10545 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:28.602002   10545 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-8g6zk-6657c7fddb-dp7kp" "namespace"="md-test" 
I0712 16:45:28.619491   10545 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-bms7t" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0712 16:45:28.619697   10545 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-bms7t" "namespace"="default" "noderef"="id-node-1"
E0712 16:45:28.630761   10545 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-bms7t" "namespace"="default"
I0712 16:45:29.248315   10545 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-6bmsm" "namespace"="default" "count"=1
I0712 16:45:29.248404   10545 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-6bmsm" "namespace"="default" "descendants"="Control plane machines: test6-bms7t" "indirect descendants count"=0

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


Ran 16 of 16 Specs in 26.485 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (26.49s)
PASS
Tearing down test suite
E0712 16:45:29.248960   10545 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:45:29.249015   10545 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-801946388/tls.crt: no such file or directory"  
E0712 16:45:29.249029   10545 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:45:29.249041   10545 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-801946388/tls.crt: no such file or directory"  
I0712 16:45:29.249085   10545 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:45:29.249095   10545 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0712 16:45:29.249125   10545 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:45:29.249138   10545 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0712 16:45:29.249159   10545 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0712 16:45:29.249186   10545 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0712 16:45:29.249197   10545 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
E0712 16:45:29.282005   10545 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:33317/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1289&timeout=10s&timeoutSeconds=569&watch=true: dial tcp 127.0.0.1:33317: connect: connection refused
E0712 16:45:29.282037   10545 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:33317/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1289&timeout=10s&timeoutSeconds=504&watch=true: dial tcp 127.0.0.1:33317: connect: connection refused
E0712 16:45:29.282490   10545 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:33317/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1289&timeout=10s&timeoutSeconds=593&watch=true: dial tcp 127.0.0.1:33317: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	73.720s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 261 lines ...
I0712 16:44:31.057040   10983 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0712 16:44:31.097296   10983 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":{}}}
I0712 16:44:31.298676   10983 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0712 16:44:31.298735   10983 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0712 16:44:31.561207   10983 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0712 16:44:32.088107   10983 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0712 16:44:34.117580   10983 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-x2rqb/test-cluster"
•E0712 16:44:34.576173   10983 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-k66gl/test-cluster"
•E0712 16:44:35.129950   10983 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:35811/?timeout=50ms: dial tcp 127.0.0.1:35811: connect: connection refused"  "cluster"="cluster-cache-test-rpskr/test-cluster"
•I0712 16:44:35.355426   10983 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}}}
I0712 16:44:35.455943   10983 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0712 16:44:35.456002   10983 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0712 16:44:35.690742   10983 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:44:35.690829   10983 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0712 16:44:35.690844   10983 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:44:35.690891   10983 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-329466130/tls.crt: no such file or directory"  
E0712 16:44:35.776157   10983 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:42507/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:42507: connect: connection refused


Ran 5 of 5 Specs in 18.286 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (18.29s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	18.423s
?   	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 ...
=== RUN   TestClusterToKubeadmControlPlaneOtherControlPlane
I0712 16:44:40.261490   11617 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
--- PASS: TestClusterToKubeadmControlPlaneOtherControlPlane (0.00s)
=== RUN   TestReconcileUpdateObservedGeneration
I0712 16:44:40.261681   11617 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=44613
I0712 16:44:40.261865   11617 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
--- FAIL: TestReconcileUpdateObservedGeneration (0.52s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x40 pc=0x1721c6a]

goroutine 1226 [running]:
testing.tRunner.func1(0xc0009cc400)
	/usr/local/go/src/testing/testing.go:874 +0x3a3
panic(0x192d340, 0x2c79c40)
... skipping 3 lines ...
sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers.TestReconcileUpdateObservedGeneration(0xc0009cc400)
	/home/prow/go/src/sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers/controller_test.go:200 +0x9ee
testing.tRunner(0xc0009cc400, 0x1c38080)
	/usr/local/go/src/testing/testing.go:909 +0xc9
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:960 +0x350
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	13.498s
I0712 16:44:39.999541   11521 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"
I0712 16:44:39.999644   11521 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:44:39.999673   11521 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"
I0712 16:44:39.999687   11521 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:44:39.999757   11521 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"
I0712 16:44:39.999772   11521 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1626108266
Will run 7 of 7 specs

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

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 271 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
E0712 16:44:43.501532   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:44:51.824678   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:45:00.814710   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:45:11.945001   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:45:28.418243   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:45:41.426840   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:45:59.074283   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:46:19.997728   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:46:51.014359   11521 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:47:36.171582   11521 workload_cluster.go:325]  "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 71 lines ...
=== RUN   TestClusterStatus/returns_cluster_status
=== RUN   TestClusterStatus/returns_cluster_status_with_kubeadm_config
--- PASS: TestClusterStatus (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status_with_kubeadm_config (0.00s)
PASS
E0712 16:47:36.180581   11521 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:47:36.180641   11521 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-313273145/tls.crt: no such file or directory"  
E0712 16:47:36.180661   11521 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:47:36.180679   11521 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-313273145/tls.crt: no such file or directory"  
I0712 16:47:36.180955   11521 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	190.260s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0712 16:44:49.230338   11817 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0712 16:44:49.230535   11817 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0712 16:44:49.330935   11817 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0712 16:44:49.431330   11817 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0712 16:44:49.431409   11817 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0712 16:44:49.534205   11817 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-rillnz"} 
E0712 16:44:49.557706   11817 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"
•I0712 16:44:50.647225   11817 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-4qt0cq"} 
E0712 16:44:50.725002   11817 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"
•E0712 16:44:51.797443   11817 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"
•E0712 16:44:52.820174   11817 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"
E0712 16:44:54.007384   11817 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"
•E0712 16:44:55.035003   11817 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"
E0712 16:44:56.050604   11817 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"
•I0712 16:44:56.054701   11817 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0712 16:44:56.054768   11817 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
E0712 16:44:56.054798   11817 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:44:56.054852   11817 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-851657861/tls.crt: no such file or directory"  
I0712 16:44:56.054906   11817 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 5 of 5 Specs in 21.052 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (21.05s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	21.135s
?   	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
E0712 16:44:43.276398   12171 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 96 lines ...
•I0712 16:44:54.531608   12171 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0712 16:44:54.534252   12171 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0712 16:44:54.563115   12171 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


Ran 9 of 9 Specs in 11.255 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.26s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.546s
?   	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 209 lines ...
Patch Helper
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39
  Should patch conditions
  /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:102
    on a clusterv1.Cluster object
    /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:150
      should not return an error if there is an unresolvable conflict but the conditions is owned by the controller [It]
      /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:324

      Timed out after 10.000s.
      Expected
          <bool>: false
      to be true
... skipping 10 lines ...
•••••••I0712 16:45:27.403306   14998 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



Summarizing 1 Failure:

[Fail] Patch Helper Should patch conditions on a clusterv1.Cluster object [It] should not return an error if there is an unresolvable conflict but the conditions is owned by the controller 
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:363

Ran 14 of 14 Specs in 17.695 seconds
FAIL! -- 13 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestPatch (17.70s)
=== RUN   TestToUnstructured
=== RUN   TestToUnstructured/with_a_typed_object
=== RUN   TestToUnstructured/with_an_unstructured_object
--- PASS: TestToUnstructured (0.00s)
    --- PASS: TestToUnstructured/with_a_typed_object (0.00s)
    --- PASS: TestToUnstructured/with_an_unstructured_object (0.00s)
... skipping 2 lines ...
=== RUN   TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields
=== RUN   TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields
--- PASS: TestUnsafeFocusedUnstructured (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=spec,_should_only_return_spec_and_common_fields (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/_condition-setter_object,_should_only_return_status_(without_conditions)_and_common_fields (0.00s)
    --- PASS: TestUnsafeFocusedUnstructured/focus=status_w/o_condition-setter_object,_should_only_return_status_and_common_fields (0.00s)
FAIL
FAIL	sigs.k8s.io/cluster-api/util/patch	17.732s
?   	sigs.k8s.io/cluster-api/util/predicates	[no test files]
?   	sigs.k8s.io/cluster-api/util/record	[no test files]
=== RUN   TestSortForCreate
--- PASS: TestSortForCreate (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/resource	0.008s
... skipping 64 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.034s
FAIL
make: *** [Makefile:116: test] Error 1
+ EXIT_VALUE=2
+ set +o xtrace